I often have trouble saving.

Here is the errors from the log.

[Thu Feb 02 00:39:50 2006] [error] [client 192.168.1.9] ********************************, referer: http://www.lavrsen.dk/dakar/bin/edit/Main/TWikiPreferences?t=1138837178
[Thu Feb 02 00:39:50 2006] [error] [client 192.168.1.9] OopsException(attention/bad_script_parameters web=>Main topic=>TWikiPreferences params=>[save]), referer: http://www.lavrsen.dk/dakar/bin/edit/Main/TWikiPreferences?t=1138837178
[Thu Feb 02 00:39:50 2006] [error] [client 192.168.1.9] ********************************, referer: http://www.lavrsen.dk/dakar/bin/edit/Main/TWikiPreferences?t=1138837178
[Thu Feb 02 00:40:05 2006] [error] [client 192.168.1.9] ********************************, referer: http://www.lavrsen.dk/dakar/bin/edit/Main/TWikiPreferences?t=1138837178
[Thu Feb 02 00:40:05 2006] [error] [client 192.168.1.9] OopsException(attention/bad_script_parameters web=>Main topic=>TWikiPreferences params=>[save]), referer: http://www.lavrsen.dk/dakar/bin/edit/Main/TWikiPreferences?t=1138837178
[Thu Feb 02 00:40:05 2006] [error] [client 192.168.1.9] ********************************, referer: http://www.lavrsen.dk/dakar/bin/edit/Main/TWikiPreferences?t=1138837178
[Thu Feb 02 00:40:10 2006] [error] [client 192.168.1.9] ********************************, referer: http://www.lavrsen.dk/dakar/bin/edit/Main/TWikiPreferences?t=1138837178
[Thu Feb 02 00:40:10 2006] [error] [client 192.168.1.9] OopsException(attention/bad_script_parameters web=>Main topic=>TWikiPreferences params=>[save]), referer: http://www.lavrsen.dk/dakar/bin/edit/Main/TWikiPreferences?t=1138837178
[Thu Feb 02 00:40:10 2006] [error] [client 192.168.1.9] ********************************, referer: http://www.lavrsen.dk/dakar/bin/edit/Main/TWikiPreferences?t=1138837178 

---

Please complete bugreport:

• (Minimal) example of topic content having problems (included forms? special variables?)
• Plugins in use
• mod_perl setup

-- SP

mod_perl setup - see 1575

Plugins. All the ones in the distribution. No additional were added. I was setting up the standard Preferences settings mainly and adjusting the look and feel of left and top bars.

If you look carefully at the error message you can see that it was TWikiPreferences I was trying to save. I cannot remember if I created it or re-saved it when it happened. But I saw it again later in another topic.

I will add more info to this bug when I observe the error again. At least now you know that it is probably a good idea - if possible - to have a test server running and sometimes enable mod_perl and try to edit and save topics many times.

KJL

I am on SpeedyCGI myself (only on view). Sofar the only time it gives me any "troubles" is when I need to restart the back processes after having updated configure settings. Will be great if we get something re-producible to chew on on this bug, good idea to add details along the way.

I don't mind keeping this bug open - although save is often fast anyway, some people might prefer to run everything precompiled.

-- SP

Seen it again. This time with only view being mod_perl'ed

So maybe this is not a mod_perl thing.

It may be related to saving Preferences

I have attached screenshot

KJL

Tried hard to reproduce this, no luck.

Might be an interfering plugin - what plugins are enabled in the setup producing this error?

If you're on firefix, please use something like live http headers and report the save action incl. parameters (similar addons for other browsers exist / you can run a logging proxy), else please just go back in the browser and save the source code of the page / form you just submitted next time you see this error. Would be helpful

-- SP

I have been editing more topics. I started changing some user topics to the new form.

I have seen this error pop up again 3 times while adding a form.

And twice while saving. Not until the 3rd try could I save the topic.

And this was with mod_perl enabled only for view. This is not something I can put into production. It comes too often.

KJL

Did you get a chance to save submitted content when this happened, or inspect status of enabled non-standard plugins in your installation?

-- SP

How can I? Once I have submitted the data I already have a new page. And saving a topic as source which is a form with data in the fields does not save the data just entered. The browser saves what was there before you edited anything.

And if I press back and save again it often goes well with the exact same data. I have seen the bug in different contexts and different topics. This bug is not related to the submitted data but to the internal perl code and variables that carry over data from previous executions.

Have you enabled mod_perl and have you tried intensively? If I sit and work with TWiki and save topics I may get the error one out of 20 or 50 saves.

If you have other ideas how I can debug the problem I will be happy to try. Right now I have turned off mod_perl. It is too unreliable for production.

I saw this bug already while I only had the standard distribution plugins only (all of them activated).

None of the plugins complain anywhere except ChecklistPlugin which is using a deprecated handler.

Here are the errors from Apache from period. I restarted the httpd daemon also.

[Sun Feb 05 17:44:27 2006] [error] [client 192.168.1.4] ********************************, referer: http://www.lavrsen.dk/dakar/bin/edit/Main/AbdulazizIsse?t=1139157861
[Sun Feb 05 17:44:27 2006] [error] [client 192.168.1.4] OopsException(attention/bad_script_parameters web=>Main topic=>AbdulazizIsse params=>[save]), referer: http://www.lavrsen.dk/dakar/bin/edit/Main/AbdulazizIsse?t=1139157861
[Sun Feb 05 17:44:27 2006] [error] [client 192.168.1.4] ********************************, referer: http://www.lavrsen.dk/dakar/bin/edit/Main/AbdulazizIsse?t=1139157861
[Sun Feb 05 17:44:40 2006] [error] [client 192.168.1.4] ********************************, referer: http://www.lavrsen.dk/dakar/bin/edit/Main/AbdulazizIsse?t=1139157861
[Sun Feb 05 17:44:40 2006] [error] [client 192.168.1.4] OopsException(attention/bad_script_parameters web=>Main topic=>AbdulazizIsse params=>[save]), referer: http://www.lavrsen.dk/dakar/bin/edit/Main/AbdulazizIsse?t=1139157861
[Sun Feb 05 17:44:40 2006] [error] [client 192.168.1.4] ********************************, referer: http://www.lavrsen.dk/dakar/bin/edit/Main/AbdulazizIsse?t=1139157861
[Sun Feb 05 17:45:07 2006] [error] [client 192.168.1.4] ********************************, referer: http://www.lavrsen.dk/dakar/bin/edit/Main/AbdulazizIsse?t=1139157901
[Sun Feb 05 17:45:07 2006] [error] [client 192.168.1.4] OopsException(attention/bad_script_parameters web=>Main topic=>AbdulazizIsse params=>[save]), referer: http://www.lavrsen.dk/dakar/bin/edit/Main/AbdulazizIsse?t=1139157901
[Sun Feb 05 17:45:07 2006] [error] [client 192.168.1.4] ********************************, referer: http://www.lavrsen.dk/dakar/bin/edit/Main/AbdulazizIsse?t=1139157901 
[Sun Feb 05 17:47:24 2006] [error] [client 192.168.1.4] [Sun Feb  5 17:47:24 2006] oops: Use of uninitialized value in substitution iterator at /usr/local/apache2/dakar/lib/TWiki/Search.pm line 824., referer: http://www.lavrsen.dk/dakar/bin/view/Main/KennethLavrsen
[Sun Feb 05 17:47:27 2006] [error] [client 192.168.1.4] File does not exist: /usr/local/apache2/htdocs/usr, referer: http://www.lavrsen.dk/dakar/bin/oops/Main/KennethLavrsen?template=oopsmore&param1=2&param2=2
[Sun Feb 05 17:47:41 2006] [error] [client 192.168.1.4] [Sun Feb  5 17:47:41 2006] oops: Use of uninitialized value in substitution iterator at /usr/local/apache2/dakar/lib/TWiki/Search.pm line 824., referer: http://www.lavrsen.dk/dakar/bin/view/Main/AbdulazizIsse
[Sun Feb 05 17:48:21 2006] [error] [client 192.168.1.4] ********************************, referer: http://www.lavrsen.dk/dakar/bin/edit/Main/AbdulazizIsse?t=1139158088
[Sun Feb 05 17:48:21 2006] [error] [client 192.168.1.4] OopsException(attention/bad_script_parameters web=>Main topic=>AbdulazizIsse params=>[save]), referer: http://www.lavrsen.dk/dakar/bin/edit/Main/AbdulazizIsse?t=1139158088
[Sun Feb 05 17:48:21 2006] [error] [client 192.168.1.4] ********************************, referer: http://www.lavrsen.dk/dakar/bin/edit/Main/AbdulazizIsse?t=1139158088
[Sun Feb 05 17:48:28 2006] [error] [client 192.168.1.4] ********************************, referer: http://www.lavrsen.dk/dakar/bin/edit/Main/AbdulazizIsse?t=1139158088
[Sun Feb 05 17:48:28 2006] [error] [client 192.168.1.4] OopsException(attention/bad_script_parameters web=>Main topic=>AbdulazizIsse params=>[save]), referer: http://www.lavrsen.dk/dakar/bin/edit/Main/AbdulazizIsse?t=1139158088
[Sun Feb 05 17:48:28 2006] [error] [client 192.168.1.4] ********************************, referer: http://www.lavrsen.dk/dakar/bin/edit/Main/AbdulazizIsse?t=1139158088
[Sun Feb 05 17:49:56 2006] [notice] SIGHUP received.  Attempting to restart
[Sun Feb 05 17:49:56 2006] [notice] Digest: generating secret for digest authentication ...
[Sun Feb 05 17:49:56 2006] [notice] Digest: done
[Sun Feb 05 17:49:56 2006] [notice] LDAP: Built with OpenLDAP LDAP SDK
[Sun Feb 05 17:49:56 2006] [notice] LDAP: SSL support unavailable
[Sun Feb 05 17:49:57 2006] [notice] Apache/2.0.55 (Unix) configured -- resuming normal operations
[Sun Feb 05 17:54:09 2006] [error] [client 192.168.1.4] [Sun Feb  5 17:54:09 2006] oops: Use of uninitialized value in substitution iterator at /usr/local/apache2/dakar/lib/TWiki/Search.pm line 824., referer: http://www.lavrsen.dk/dakar/bin/view/Main/KennethLavrsen
[Sun Feb 05 17:54:12 2006] [error] [client 192.168.1.4] File does not exist: /usr/local/apache2/htdocs/usr, referer: http://www.lavrsen.dk/dakar/bin/oops/Main/KennethLavrsen?template=oopsmore&param1=2&param2=2
[Sun Feb 05 17:54:20 2006] [error] [client 192.168.1.4] [Sun Feb  5 17:54:20 2006] oops: Use of uninitialized value in substitution iterator at /usr/local/apache2/dakar/lib/TWiki/Search.pm line 824., referer: http://www.lavrsen.dk/dakar/bin/view/Main/AlanPater

KJL

Running with mod_perl on view only I often (maybe 1-5% of the time) see this error in the apache log.

[Wed Feb 08 10:06:21 2006] [error] [client 192.168.1.9] File does not exist: /usr/local/apache2/htdocs/usr, referer: http://www.lavrsen.dk/twiki/bin/view/Sandbox/TestTopic13
[Wed Feb 08 10:06:25 2006] [error] [client 192.168.1.9] File does not exist: /usr/local/apache2/htdocs/usr, referer: http://www.lavrsen.dk/twiki/bin/edit/Sandbox/TestTopic13?t=1139389576

It can happen on any topic and it is very random. I cannot figure out where it comes from. Note that it is an absolute path on the filesystem. Not something sent from the browser. Some code is looking for this path that does not exist on my computer. I have no usr directory below apache2. It seems to be a variable containing a path that gets an additional path appended partly. It looks like a variable that does not get initialized properly.

KJL

I need help how to provide more debug info about this problem. I am stuck until I get help.

Meanwhile - the mod_perl compatibility should be removed from the release note and replaced by the fact that TWiki 4.0 is still not mod_perl compatible. The frequency of error messages people get - even in a mod_perl for view only setup - is so high that you cannot run with mod_perl in a production environment. In my oppinion not enough developers have actually tried to run with mod_perl.

KJL

About the File does not exist: /usr/local/apache2/htdocs/usr: In the error log, Apache reports only the uppermost path which is missing (the final /usr). It might be a hint if we knew the complete path of the url which has been actually requested. This should be available from the access log - check for a line with a status code 404 which occured at the same time than the line in the error log.
I'd guess your Apache's DocumentRoot is /usr/local/apache2/htdocs, so your Apache apparently got a request for a path beginning with /usr. So "someone", maybe TWiki, seems to occasionally write a file path instead of an URL path. Knowing the target may give a hint for the culprit - it may be a well hidden @import in a skin's stylesheet....
Finally, just to make sure: You don't have mod_rewrite in action, do you? I recall that I managed to create this sort of error messages with a bogus mod_rewrite configuration, so Apache itself did the mapping from URLspace to filespace twice....

TWiki:Main.HaraldJoerg

I have checked the access log. There is no request for any URL with /usr. It comes randomly. The error is the perl code looking for a file which is not there and doing it randomly. The URL which is being looked up when the error comes can be any normal Twiki URL for any topic. And when the error is added to the error log this is normally invisible to the browser. All seems fine. I do not know if the .../usr error is the same as the error that occurs with failing to save a topic. It is a different error message you get. But maybe the two are related to the same root cause.

But again. it is not the browser that asks for a url with htdocs/usr. The browser does not know absolute paths on the harddrive.

KJL

Sorry for being so insisting... but I still think we could dig something out of your access log file. You say, the error is the Perl code looking for a file? Sorry, but I doubt that. Errors caused by Perl code usually are looking different in the error log: They usually have at least the script name (e.g. view:) after the date in the error log. And if TWiki fails to find a file it needs, it complains rather verbosely. And it would probably give a file name different from /usr/local/apache2/htdocs/usr, which really looks like Apache's Document Root, of which neither TWiki nor perl should be aware. The lines you are quoting are too similar to what you would get if you request an url like http://www.lavrsen.dk/usr/local/apache2/dakar/*something* (without htdocs!).

I agree that the browser does not know about absolute paths. But a request can be invisible to the browser: Consider a script element with a src attribute, or an external style sheet containing classes which aren't actually used in the page. There could be some reference to "/usr/local..." hidden. The browser would call for that URL without making you know that it does. Let me try some wild guesses:

• TWiki does lots of redirects. Maybe in certain circumstances it is calculating a wrong URL - inserting e.g. $TWiki::cfg{PubDir} instead of $TWiki::cfg{PubUrlPath}?
• Apache itself can do internal redirects with mod_rewrite. In these cases you wouldn't see a request beginning with /usr in the access log, but mod_rewrite has a bunch of debugging options.
• Maybe some template, or some javascript code contains a variable like view and in a particular environment this is initialized from a bogus $ENV{SCRIPT_FILENAME} ending with a slash? I noticed that TWiki doesn't make any use of !view, with the exception of a unit test in the WysiwygPlugin. Strange enough.
• Do you have other mod_perl handlers active? Maybe something in Apache causes the server to try to get the URL /usr/... instead of feeding the path to Perl?

A browser's request to TWiki usually is causing quite a couple of HTTP requests to the server: HTML, CSS, JS, images (also those in the style sheet). If possible, please post the a portion of your access log around the time of these entries in your error log. There should be a 404 status code corresponding to the error log entry, or a 302, or ... from the same IP adress as given in the error log.

I don't have a clue whether the error is the same as the error when trying to save a topic, but I think this is worth another look at the access log: The oops you got seems to indicate that there haven't been any CGI parameters, which is really strange. You can easily reproduce the error when just pointing your browser to <http://develop.twiki.org/~develop/cgi-bin/save/Bugs/Item1576>. save ought to be called with a POST request, which should be visible in your access log. If there's a GET request for save, maybe this is another case of wrong redirection? POST requests shouldn't be redirected, but if so, they're converted to GET requests.

TWiki:Main.HaraldJoerg

I have done a new analysis of my logs.

In the period where I ran with full mod_perl (all scripts) I had the save error quite often.

In the period where I ran with view only the error message I reported at the top of this report has been seen 3 times only.

The strange htdocs/usr error has nothing to do with it. It continued also have mod_perl has been switched off. The root cause of this has been found. A configuration error in httpd.conf. I had this:

ErrorDocument 401 /usr/local/apache2/twiki/bin/view/TWiki/TWikiRegistration

It must be a relative URL like this

ErrorDocument 401 /twiki/bin/view/TWiki/TWikiRegistration

So one error possibility eliminated.

We still have the original bug report though. TWiki Dakar has a problem saving topics when mod_perl is fully enabled.

And I still need some hints how I can debug this error. If there is some extra statements I can add to the code to give more verbose errors in the code that saves a topic I will be happy to run with that for a while with mod_perl re-enabled.

KJL

The OopsException you are observing is triggered under one circumstance only; when the CGI query has no parameters at all. Since TWiki doesn't manipulate the parameters in the query (it reads, but does not write them) we can assume that the original query doesn't have any parameters. Now, since the "Save" button from an edit is a form submission with many parameters, we can assume that a multipart form POST request is being sent to the server, rather than a simple GET. So, at some point the parameters are being stripped from that POST request.

So, the challenge is to find out how the parameters are being lost. The best I can suggest is:

1. Review http://perl.apache.org/docs/1.0/guide/porting.html to make sure that nothing obvious was missed!
2. Instrument the code the observe the script parameters TWiki is receiving. If you add print STDERR join(' ',$query->params()); to the new method in TWiki/UI.pm just before the TWiki object is created, that should help.
3. Your access log should show the requests coming in, though won't show parameters. Perhaps there are some sniffers out therre that can help.

CC

Again me, guessing wildly: Apache 2.0.55 has a known problem with POST data in the following situation:

1. Requests are proxied/reverse proxied
2. Data are > 8kb (TWikiPreferences certainly is, but personal topics shouldn't be)

See http://issues.apache.org/bugzilla/show_bug.cgi?id=37145 There is another report of occasional data loss in POST requests with Kenneth's setup at http://aspn.activestate.com/ASPN/Mail/Message/modperl/3010400, but such reports have often been tracked back to errors in the application...

-- TWiki:Main.HaraldJoerg

I had not yet tried CC's proposal because I have been working all night the past days with the TWiki installation at work. But now I have implemented it. Now time must pass till the error has shown up.

Harald. As far as I know I do not use the proxy feature in my Apache. All I have is an alias. Is the error you refer to related to proxies only? I have read the bug report at Apache but cannot see from the many replies if this is a related problem.

KJL

Either I did not understand the instructions or something else is wrong. When I add the code line suggested TWiki fails with the error

Software error:
Undefined subroutine CGI::params at /usr/local/apache2/twiki/lib/TWiki/UI.pm line 89

I added this round line 88

    #Debug code added by Kenneth as guided by CC for item 1576 debugging
    print STDERR join(' ',$query->params());

    my $session = new TWiki( $user, $query );
    $session->enterContext( 'command_line' ) if $scripted;

    local $SIG{__DIE__} = \&Carp::confess;

KJL

The error I have quoted is related to proxies only. If you don't use reverse proxy, this can be ruled out. It was just a guess...

About the debugging code as suggested by CC: Replace $query->params() by $query->param(). I can't count how often I've made the same mistake myself.... And may I suggest to print something that can be easily searched for - like e.g.:

        print STDERR join(', ','####',$query->param(),"\n");

Otherwise the absence of parameters might be difficult to spot.

There is one other point where some debugging information could be collected: Add a couple of lines into the following block beginning at line 62 of UI.pm:

    if( $ENV{'GATEWAY_INTERFACE'} ) {
        # script is called by browser
        $query = new CGI;
# block added for debugging Item1576
        if ($ENV{REQUEST_METHOD}  eq  'POST') {
            print STDERR "#### Content length: $ENV{CONTENT_LENGTH}\n";
        }
# end block
    } else {

The reason is: For POST requests, this should be the length of the parameter list in Bytes. If you have zero Bytes here, then the error is likely to be in either mod_perl, or Apache, or Apache configuration: The environment variables are supplied by Apache's standard CGI procedures before perl is invoked. If you have a content length, but no parameters from the line suggested by CC, then we'll have to dig further into mod_perl, perl or TWiki. To me, TWiki's code looks mod_perl clean regarding the CGI parameters, since the CGI object is a lexical variable. But the world is always full of surprises....

TWiki:Main.HaraldJoerg

---

Sorry Kenneth, I should have read the CGI doc more carefully. Try print STDERR $query->Dump();

CC

I added this to UI.pm

    #Debug code added by Kenneth as guided by CC for item 1576 debugging
    print STDERR "KENNETH DEBUG DUMP\n";
    print STDERR $query->Dump();

    my $session = new TWiki( $user, $query );
    $session->enterContext( 'command_line' ) if $scripted;

And within 2 minutes of opening and saving a test topic I got the error. Note that in parallel there was traffic on the server.

I have attached the log file.

The error happened at the end where you find the text "bad_script_parameters" line 517 and forward.

I also wonder what all the other errors are that we see before. no_such_web is seen all the time when viewing a topic.

KJL

---

I am able to reproduce both the error messages - but only by strange settings and behaviour, and not directly mod_perl related.

The no_such_web error: This can be achieved surprisingly easy by setting the following bogus option in a preference page (just activate it by removing the #)

   * #Set USERSTYLEURL = url(/twiki/pub/TWiki/PatternSkin/print.css)

I couldn't find anything like that with TWiki search on www.lavrsen.dk, but maybe a grep for print.css in your data directory yields more....

I'd almost bet that your access log has lines reporting requests like

"GET /bin/view/Motion/url(/twiki/pub/TWiki/PatternSkin/print.css) HTTP/1.1"

The bad_script_parameters error: I reproduced this by

1. Editing a page
2. Going to preview (-> the URL in the location box contains /twiki/bin/save/)
3. Point the mouse in the location box and hit return

This can be easily ruled out by checking for requests like "GET /twiki/bin/save/ in your access log.

Anyway, having a look at the access log is almost always a good idea - getting the actual requests may reduce the number of places we have to look for the bugs.

TWiki:Main.HaraldJoerg

---

The error messages about no_such_web are no longer a mysterie. You may have them yourself if you have a Dakar that you keep up to date with SVN. See Item1674 where I raised the bug found and related fix.

The bad_script_parameters bug happens when doing a normal edit followed by a save and randomly. I have not found any strange things in the access log. I do not preview when I trigger the error. I go straight to save.

I noticed when I triggered the error that there was simultaneous traffic.

KJL

What is the next step? What can I provide of more debugging info?

I never received any feedback on what I uploaded.

KJL

Well, I'm still short of good ideas, but anyway: Your log file proves that there indeed isn't any query for the POST request in question. You could go one step backwards by checking whether there are any POST data at all with what I've suggested earlier: In line 62 of UI.pm, add

    if( $ENV{'GATEWAY_INTERFACE'} ) {
        # script is called by browser
        $query = new CGI;
# block added for debugging Item1576
        if ($ENV{REQUEST_METHOD}  eq  'POST') {
            print STDERR "#### Content length: $ENV{CONTENT_LENGTH}\n";
        }
# end block
    } else {

This will print the content length of POST requests (and only of those). But I'm afraid that the content length will be zero if the problem occurs, making it more likely that this is a genuine Apache/mod_perl problem. The problem with POST data is that they can be evaluated just once (data are read from STDIN). If "someone" is doing that before CGI.pm is seeing the data, then there isn't anything left to build a query from. CGI.pm is supposed to read the data from STDIN, but not to reset $ENV{CONTENT_LENGTH}.

Since last Friday I'm running mod_perl on Apache2 in my installation, but failed to see the error so far. The site is busy enough so that I can't run arbitrary tests on it, but not busy enough for simultaneous traffic :-(. Creating synthetical load with LWP::UserAgent is a bit of a pain since "true" TWiki requests aren't that simple and I need at least one view/edit/save loop working (or is there a cookbook/example for that?). I'll try that if I've some minutes to burn. Running mod_perl is going to be important for me because users start complaining about bad response times.

TWiki:Main.HaraldJoerg

---

As Harald says, the debugging seems to confirm that a save without any parameters is sent to the server. i can't tell if it was a POST or a GET, as you haven't given us the relevant access_log fragment. I now have several sites running with mod_perl, and have not yet seen this problem. The debugging tends to confirm that it is not TWiki that is at fault. So we have to think about the configuration of the server.

Possibly related?

http://comments.gmane.org/gmane.comp.apache.mod-backhand.general/245

There is one other thing we need to try, to confirm if it is Apache at fault. Please add the following before your debugging:

print STDERR "ZERO PARAMS FAILURE ",join(' ', map{ "$_= '$ENV{$_}'", keys %ENV),"\n" unless scalar($query->param());

We are looking for the environment variable GATEWAY_INTERFACE. If it is not set, or is set to the empty string or 0, but the script was invoked as the result of a POST, then GATEWAY_INTERFACE is not a reliable way of detecting a POST environment. The reason I want the whole %ENV hash is because if this is the problem, we need another way of detecting a browser environment (e.g. $ENV{MOD_PERL}). If GATEWAY_INTERFACE is set but you still see the error, then the problem is with the browser or with Apache (or possibly with the CGI module).

Note that this debugging may result in a lot of spam in your error log.

CC

I get this error when I add your debug code and TWiki stops working.

[Mon Feb 27 22:56:27 2006] view: syntax error at /usr/local/apache2/twiki/lib/TWiki/UI.pm line 91, near "%ENV)" [Mon Feb 27 22:56:27 2006] [error] [client 68.142.250.45] [Mon Feb 27 22:56:27 2006] view: syntax error at /usr/local/apache2/twiki/lib/TWiki/UI.pm line 156, near "=" [Mon Feb 27 22:56:27 2006] [error] [client 68.142.250.45] [Mon Feb 27 22:56:27 2006] view: Compilation failed in require at /usr/local/apache2/twiki/lib/TWiki/UI/View.pm line 40. [Mon Feb 27 22:56:27 2006] [error] [client 68.142.250.45] [Mon Feb 27 22:56:27 2006] view: BEGIN failed--compilation aborted at /usr/local/apache2/twiki/lib/TWiki/UI/View.pm line 40. [Mon Feb 27 22:56:27 2006] [error] [client 68.142.250.45] [Mon Feb 27 22:56:27 2006] view: Compilation failed in require at /usr/local/apache2/twiki/bin/view line 30. [Mon Feb 27 22:56:27 2006] [error] [client 68.142.250.45] [Mon Feb 27 22:56:27 2006] view: BEGIN failed--compilation aborted at /usr/local/apache2/twiki/bin/view line 30.

Does that code line work for you?

KJL

Got help from PTh and changed the code to

print STDERR "ZERO PARAMS FAILURE:\n ", join(' ', map{ my $l="$_ = $ENV{$_}\n"; $l} keys( %ENV )), "\n" unless scalar($query->param());

KJL

I have attached a combined error log, access log and the twiki.conf included in http.conf.

Note that I only run mod_perl for the view script. When I do that the error comes easily.

I have since run with mod_perl enabled for all scripts and so far I have not seen the save error.

But I had some other bugs when I ran 100% mod_perl. The one which is still not resolved is that you cannot login or at least the web left bar does not change to the logged in mode when you click the login link. There is an unresolved bug Item1575 that makes it impossible to run in full mod_perl with Apache login.

Can the bug get triggered by running save edit and save scripts as CGI and view as mod_perl?

Note that the log contains a lot of view edit save view edit save view edit save mixed with external traffic. It is the end of it all that the error happens and I stopped Apache right after and saved the tail of the logs.

KJL

During the critical view/edit/save cycle I could not find any request from other IP addresses, so it appears that one single user can provoke the error. All the requests during this cycle have been served from one socket connection (guessed from the fact that the view and the save have identical values for $ENV{REMOTE_PORT}). So maybe Apache fails to pass the correct read position to the child process if previous calls have been processed by mod_perl?

You write that with mod_perl enabled for all scripts you did not get the error again - that's in contrast to your previous observation that with full mod_perl you had the error quite often. Have you changed the mod_perl configuration since then? mod_perl itself has trace options, but IIRC they need to be enabled when compiling mod_perl, and I have never seen what they actually write and if it can be useful.

The logs show that the error is indeed caused by a POST request, and that this POST request has what I'd call a correct value for $ENV{CONTENT_LENGTH}. So Apache receives a Content-length header, yet CGI.pm apparently fails to read the corresponding request body from STDIN. Unfortunately CGI.pm completely fails to check the length it actually has read.

If you want to continue digging in that area, add the following code to one of your modules (I've been using TWiki.pm):

package CGI;
sub read_from_client {
    my($self, $buff, $len, $offset) = @_;
    local $^W=0;                # prevent a warning
    my $bytes_read = $MOD_PERL
        ? $self->r->read($$buff, $len, $offset)
        : read(\*STDIN, $$buff, $len, $offset);

    return $bytes_read if $bytes_read;
    if (defined $bytes_read) {
   # byte count of zero is EOF
   print STDERR "#### EOF on STDIN\n";
    }
    else {
   # undefined byte count is an error
   print STDERR "#### Couldn't read from STDIN: '$!'\n";
    }
}

1;

This is supposed to redefine CGI.pm='s subroutine =read_from_client. This should work without a warning unless you compile all of CGI.pm because in CGI.pm read_from_client is an autoloaded sub, compiled only at runtime. The replacement routine writes a line to STDERR if the attempt to read from STDIN results in either an EOF condition or an error. If we are very lucky, we get an error in the bad_script_parameters case.

TWiki:Main.HaraldJoerg

---

This is going beyond the bounds of what we should be trying to debug, I feel. This is clearly an Apache/mod_perl error, and nothing to do with TWiki. I am going to discard this report, though please feel free to continue discussing the problem here, especially when you get a response from the Apache/mod_perl people. You may consider enabling all your scripts for mod_perl, or using Speedycgi, as valid work-arounds.

CC

And I reopen it. It is not resolved.

Discard is for problems that "Discarded the issue was already fixed, or it's a duplicate, or an RTFM."

"I do not know how to fix it" is a not a good argument for discarding. Especially if you do not have a TWiki running on Apache2 when you test.

I told you I was away for two days and that I would investigate further if the bug is gone when you enable mod_perl for all scripts when I was back. The bug is random and I have not tested long enough to conclude that the bug is only there when only view for mod_perl is enabled.

The main reason why I do not run with mod_perl is Item1575 which makes mod_perl something I cannot possible use on my Motion site because it means that the login link appears dead. You have to edit a topic to really log in. I cannot have that running in production.

I also want to test mod_perl with the popular plugins. It takes time. But I am not giving up yet.

KJL

An idea for spending time better and more productively on this issue would be to start a parallel track at http://perl.apache.org/bugs/index.html. Poke around and see (mailarchives etc) what others did to resolve their bugs in similar situations and use trial and error from there.

- I'll be in the corner holding on to speedy.

-- SP

I have come a little further.

First I read the improved TWiki:Codev.ModPerlUnix topic.

There was some small problems with it which I changed (multiple edits over a few hours - final edit was a refactoring and removal of my comments below.

I found an error in my config. I had neer created a bin/LocalLib.cfg file. This is why I got @INC problems with the simple load script a few days ago and again when I tried tonight.

I then changed my httpd config so it follows the ModPerlUnix proposal so the following scripts: attach|edit|manage|rename|save|upload|view|.*auth

And with this combination I do not have the save problem. I tried 100s of times (fighting with BlackListPlugin) and with both IE and FF. Not a single failure.

Even better see Item1575

So if mod_perl runs fine like this - who cares about the view-only case.

Discarding for now. I re-open if I see problems the next days of actual use.

KJL