You are viewing a plain text version of this content. The canonical link for it is here.
Posted to modperl@perl.apache.org by "Philippe M. Chiasson" <go...@cpan.org> on 2003/07/04 14:26:17 UTC

Re: [mp2 Patch] BUG with mod_deflate and $|=1 (20014:Error string not specified)

On Thu, 2003-07-03 at 01:24, Bill Marrs wrote:
> This fixed the bug for me.

Great! Will commit it in the near future. (Can't seem to access the cvs
server right now, crappy internet cafe)

One thing that could help is if someone could take the time to write a
test for this bug.

Gozer out.

> At 10:48 AM 7/2/2003, you wrote:
> >  #define mpxs_output_flush(r, rcfg) \
> >      /* if ($|) */ \
> >-    if (IoFLUSH(PL_defoutgv)) { \
> >+    if (bytes > 0 && IoFLUSH(PL_defoutgv)) { \
> >          MP_FAILURE_CROAK(modperl_wbucket_flush(rcfg->wbucket, TRUE)); \
> >      }
> 
> 

Re: [mp2 Patch] BUG with mod_deflate and $|=1 (20014:Error string not specified)

Posted by Bill Marrs <bi...@apocalypse.org>.
>>I could upgrade to 2.0.47, but it seems unlikely that it would fix 
>>this.  Are you sure you're running a mod_perl without Philippe's fix (in 
>>Apache__RequestIO.h), I assumed he eventually checked it in.
>
>No, Philippe hasn't committed it, neither I have used it. If you can test 
>with 2.9.47 that will help. Otherwise I'll later try with .46 as well.

I just upgraded to Apache 2.0.47 and the latest CVS of mp2 and I'm 
reproducing it, same as I originally reported.

I tried a few variations to see if I could find other factors, but didn't 
have much luck.  The server I'm testing on is live (runs a small site), so 
I'm somewhat limited in what I can do.  But, I tried removing mod_rewrite, 
and mod_ssl from my server config and I still got the error in my tests.

I also tried varying the mod_deflate config (as you pointed out it was 
redundant/wrong)...

>>>Also Bill, why do you have this setup:
>>>
>>><Location /perl>
>>>   AddOutputFilterByType DEFLATE text/*
>>>   SetOutputFilter DEFLATE
>>></Location>
>>>
>>>why adding it twice? You need only the latter inside <Location>, or 
>>>alternatively only the former outside <Location> if you want it to be 
>>>set globally:
>>>http://httpd.apache.org/docs-2.0/mod/core.html#addoutputfilterbytype
>>
>>Ah, I misunderstood the mod_deflate docs.  I think at the time, it didn't 
>>seem to work with just one of them in-place, so I added the 
>>other.  *SHRUG*  I can't say I'm a pro at Apache config files, I just 
>>tinker until it works.  I assume this is irrelevant to the bug, though.
>
>I'm not sure if your config doesn't insert the filter twice. Need to check 
>whether SetOutputFilter overrides AddOutputFilterByType as well.

In my config, I have a deflate log:

DeflateFilterNote Input instream
DeflateFilterNote Output outstream
DeflateFilterNote Ratio ratio
LogFormat '"%r" %{outstream}n/%{instream}n (%{ratio}n%%) "%{User-agent}i"' 
deflate
CustomLog /var/log/httpd/deflate_log deflate

I was using this to verify that deflate was active or not.  What I found 
was that using "AddOutputFilterByType DEFLATE text/*" doesn't seem to 
activate deflate, no matter where I put it (in a <Location> or at the 
top-level of the config).  My deflate log shows that no compression is 
occurring.  "SetOutputFilter DEFLATE" does activate deflate globally (for 
all locations), no matter where I put it.  I'm afraid I don't find the 
mod_deflate docs very clear on placement.

When you were trying to reproduce, I don't know if you used my (redundant) 
config before, but if you only used "AddOutputFilterByType DEFLATE text/*", 
and not "SetOutputFilter DEFLATE", that might explain why you were not able 
to reproduce this, I don't think that activates deflate (at least that's 
what my deflate_log shows for me).

Otherwise, if you're still not reproducing this, I would assume there's 
some difference in the way we are building apache or our apache config 
files or perl?

Here's my Apache Configure line:

./configure --enable-modules=all --enable-mods-shared=all --enable-deflate 
--with-mpm=prefork --enable-rewrite --enable-ssl

Here are the Modules I load:

LoadModule cgi_module modules/mod_cgi.so

LoadModule access_module modules/mod_access.so
LoadModule log_config_module modules/mod_log_config.so
LoadModule env_module modules/mod_env.so
LoadModule expires_module modules/mod_expires.so
LoadModule headers_module modules/mod_headers.so
LoadModule setenvif_module modules/mod_setenvif.so
LoadModule mime_module modules/mod_mime.so
LoadModule autoindex_module modules/mod_autoindex.so
LoadModule asis_module modules/mod_asis.so
LoadModule info_module modules/mod_info.so
LoadModule vhost_alias_module modules/mod_vhost_alias.so
LoadModule dir_module modules/mod_dir.so
LoadModule alias_module modules/mod_alias.so
LoadModule rewrite_module modules/mod_rewrite.so

LoadModule perl_module modules/mod_perl.so
LoadModule ssl_module modules/mod_ssl.so

mod_cgi, mod_ssl and mod_rewrite seem to be innocent (when I removed them, 
it still failed), but maybe you're using a module that I'm not and this is 
causing your config to work better?   I think that I'm loading less modules 
than what is typical, I removed as many as I could to reduce memory usage a 
while ago.

*SHRUG*

One thing that may be relevant is tracking down where the "20014:Error" is 
coming from.  Web searching seems to associate it with Berkeley DB code, 
which seems odd to me, is Apache using Berkeley DB code somewhere (via a 
filter?)?

This isn't a very important issue for me.  I have a decent workaround 
(print " " instead of ""), plus I'm not really able to use mod_deflate that 
much anyway because it puts too much load on my server (mod_gzip with 
Apache 1.3 worked better for me).

Thanks

-bill







Re: [mp2 Patch] BUG with mod_deflate and $|=1 (20014:Error string not specified)

Posted by Stas Bekman <st...@stason.org>.
Bill Marrs wrote:
> At 04:24 AM 7/15/2003, Stas Bekman wrote:
> 
>> Philippe M. Chiasson wrote:
>>
>>> On Thu, 2003-07-03 at 01:24, Bill Marrs wrote:
>>>
>>>> This fixed the bug for me.
>>>
>>>
>>> Great! Will commit it in the near future. (Can't seem to access the cvs
>>> server right now, crappy internet cafe)
>>
>>
>> -1, this is a wrong solution. print ""; should flush just like it did 
>> in mod_perl 1.0 if $| == 1; Consider this script:
>>
>>     print "Content-type: text/plain\n\n";
>>     local $| = 0;
>>     print "start\n\n";
>>     local $| = 1;
>>     print "";
>>     sleep 5;
>>     local $| = 0;
>>     print "end\n";
>>
>> print "", must immediately flush the buffered data, since $| has 
>> changed from 0 to 1.
> 
> 
> This may be naive, but might it not flush the output buffer at the 4th 
> line (local $| = 1;)?  ...or does the flush only happen when print is 
> called.  Having to call print "" seems cumbersome to do a flush, but 
> maybe that's just the way Perl works?

There is $r->rflush for this purpose. This is not a perl API, but Apache API. 
You can also use IO::File or other IO packages that extend perl to provide 
this kind of API.

But this is how perl works, so we have to preserve it under mod_perl.

>>> One thing that could help is if someone could take the time to write a
>>> test for this bug.
>>
>>
>> Unfortunately I don't seem to be able to reproduce the problem, so I 
>> can't debug the problem. It could be a bug on the mod_deflate's behalf 
>> as well. Philippe, were you able to reproduce the problem with Bill's 
>> setup? I was writing a test, but couldn't get it to fail... may be 
>> because i was using 2.0.47. Bill, do you have the problem with the 
>> latest apache version?
> 
> 
> Did you see my note in the original post about this working fine under 
> mod_cgi, but causing the "20014:Error" only under mod_perl?  This seemed 
> to point the finger squarely at mod_perl.

If I was able to reproduce it I could tell, but I don't seem to.

> I could upgrade to 2.0.47, but it seems unlikely that it would fix 
> this.  Are you sure you're running a mod_perl without Philippe's fix (in 
> Apache__RequestIO.h), I assumed he eventually checked it in.

No, Philippe hasn't committed it, neither I have used it. If you can test with 
2.9.47 that will help. Otherwise I'll later try with .46 as well.

>> Also Bill, why do you have this setup:
>>
>> <Location /perl>
>>   AddOutputFilterByType DEFLATE text/*
>>   SetOutputFilter DEFLATE
>> </Location>
>>
>> why adding it twice? You need only the latter inside <Location>, or 
>> alternatively only the former outside <Location> if you want it to be 
>> set globally:
>> http://httpd.apache.org/docs-2.0/mod/core.html#addoutputfilterbytype
> 
> 
> Ah, I misunderstood the mod_deflate docs.  I think at the time, it 
> didn't seem to work with just one of them in-place, so I added the 
> other.  *SHRUG*  I can't say I'm a pro at Apache config files, I just 
> tinker until it works.  I assume this is irrelevant to the bug, though.

I'm not sure if your config doesn't insert the filter twice. Need to check 
whether SetOutputFilter overrides AddOutputFilterByType as well.



__________________________________________________________________
Stas Bekman            JAm_pH ------> Just Another mod_perl Hacker
http://stason.org/     mod_perl Guide ---> http://perl.apache.org
mailto:stas@stason.org http://use.perl.org http://apacheweek.com
http://modperlbook.org http://apache.org   http://ticketmaster.com


Re: [mp2 Patch] BUG with mod_deflate and $|=1 (20014:Error string not specified)

Posted by Bill Marrs <bi...@apocalypse.org>.
At 04:24 AM 7/15/2003, Stas Bekman wrote:
>Philippe M. Chiasson wrote:
>>On Thu, 2003-07-03 at 01:24, Bill Marrs wrote:
>>
>>>This fixed the bug for me.
>>
>>Great! Will commit it in the near future. (Can't seem to access the cvs
>>server right now, crappy internet cafe)
>
>-1, this is a wrong solution. print ""; should flush just like it did in 
>mod_perl 1.0 if $| == 1; Consider this script:
>
>     print "Content-type: text/plain\n\n";
>     local $| = 0;
>     print "start\n\n";
>     local $| = 1;
>     print "";
>     sleep 5;
>     local $| = 0;
>     print "end\n";
>
>print "", must immediately flush the buffered data, since $| has changed 
>from 0 to 1.

This may be naive, but might it not flush the output buffer at the 4th line 
(local $| = 1;)?  ...or does the flush only happen when print is 
called.  Having to call print "" seems cumbersome to do a flush, but maybe 
that's just the way Perl works?

>>One thing that could help is if someone could take the time to write a
>>test for this bug.
>
>Unfortunately I don't seem to be able to reproduce the problem, so I can't 
>debug the problem. It could be a bug on the mod_deflate's behalf as well. 
>Philippe, were you able to reproduce the problem with Bill's setup? I was 
>writing a test, but couldn't get it to fail... may be because i was using 
>2.0.47. Bill, do you have the problem with the latest apache version?

Did you see my note in the original post about this working fine under 
mod_cgi, but causing the "20014:Error" only under mod_perl?  This seemed to 
point the finger squarely at mod_perl.

I could upgrade to 2.0.47, but it seems unlikely that it would fix 
this.  Are you sure you're running a mod_perl without Philippe's fix (in 
Apache__RequestIO.h), I assumed he eventually checked it in.

>Also Bill, why do you have this setup:
>
><Location /perl>
>   AddOutputFilterByType DEFLATE text/*
>   SetOutputFilter DEFLATE
></Location>
>
>why adding it twice? You need only the latter inside <Location>, or 
>alternatively only the former outside <Location> if you want it to be set 
>globally:
>http://httpd.apache.org/docs-2.0/mod/core.html#addoutputfilterbytype

Ah, I misunderstood the mod_deflate docs.  I think at the time, it didn't 
seem to work with just one of them in-place, so I added the 
other.  *SHRUG*  I can't say I'm a pro at Apache config files, I just 
tinker until it works.  I assume this is irrelevant to the bug, though.

-bill




Re: [mp2 Patch] BUG with mod_deflate and $|=1 (20014:Error string not specified)

Posted by Bill Marrs <bi...@apocalypse.org>.
At 03:59 AM 7/17/2003, Philippe M. Chiasson wrote:
>And I've found what's hapenning. It's mod_deflate output filter that's not 
>proprely handling flush buckets, IMO.

But, I do get the error if I use mod_cgi instead of mod_perl to run the 
test script (both with mod_deflate).  So, I had thought this meant that 
mod_deflate was innocent.

-bill


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@perl.apache.org
For additional commands, e-mail: dev-help@perl.apache.org


Re: [mp2 Patch] BUG with mod_deflate and $|=1 (20014:Error string not specified)

Posted by Stas Bekman <st...@stason.org>.
Bill Marrs wrote:
> 
>> Please report to the list the bug id so we can document this issue for 
>> those who have the same problem with older httpds. Thanks.
> 
> 
> OK, I've posted it.
> 
> http://nagoya.apache.org/bugzilla/show_bug.cgi?id=22259
> 
> Thanks for the fix!

For the archives: This bug has been fixed in the current httpd-2.0 cvs, and 
will be also in the soon to be released 2.0.48.

__________________________________________________________________
Stas Bekman            JAm_pH ------> Just Another mod_perl Hacker
http://stason.org/     mod_perl Guide ---> http://perl.apache.org
mailto:stas@stason.org http://use.perl.org http://apacheweek.com
http://modperlbook.org http://apache.org   http://ticketmaster.com


Re: [mp2 Patch] BUG with mod_deflate and $|=1 (20014:Error string not specified)

Posted by Bill Marrs <bi...@apocalypse.org>.
>Please report to the list the bug id so we can document this issue for 
>those who have the same problem with older httpds. Thanks.

OK, I've posted it.

http://nagoya.apache.org/bugzilla/show_bug.cgi?id=22259

Thanks for the fix!

-bill


Re: [mp2 Patch] BUG with mod_deflate and $|=1 (20014:Error string not specified)

Posted by Stas Bekman <st...@stason.org>.
Bill Marrs wrote:
> 
>> Try this patch:
>> [...]
>>
>> Feel free to submit this bug report and the fix to httpd-dev. Please 
>> let me know if you do that, so I won't duplicate it. But I'd prefer 
>> that you do it so you can make sure that it gets fixed in the next 
>> release, since you need it working.
> 
> 
> I've just verified that your patch fixes my problem.

Great!

> I've never submitted a but report and fix to httpd-dev, but I'm willing 
> to do it.
> 
> How do I do it?

Open a bugzilla account and add a new bug report:
http://httpd.apache.org/bug_report.html

Please report to the list the bug id so we can document this issue for those 
who have the same problem with older httpds. Thanks.

__________________________________________________________________
Stas Bekman            JAm_pH ------> Just Another mod_perl Hacker
http://stason.org/     mod_perl Guide ---> http://perl.apache.org
mailto:stas@stason.org http://use.perl.org http://apacheweek.com
http://modperlbook.org http://apache.org   http://ticketmaster.com


Re: [mp2 Patch] BUG with mod_deflate and $|=1 (20014:Error string not specified)

Posted by Bill Marrs <bi...@apocalypse.org>.
>Try this patch:
>[...]
>
>Feel free to submit this bug report and the fix to httpd-dev. Please let 
>me know if you do that, so I won't duplicate it. But I'd prefer that you 
>do it so you can make sure that it gets fixed in the next release, since 
>you need it working.

I've just verified that your patch fixes my problem.

I've never submitted a but report and fix to httpd-dev, but I'm willing to 
do it.

How do I do it?

-bill



Re: [mp2 Patch] BUG with mod_deflate and $|=1 (20014:Error string not specified)

Posted by Slava Bizyayev <sb...@outlook.net>.
> Well, the problem is that I get this error in my error_log:
>
> [Mon Jul 21 14:18:55 2003] [error] 4297: ModPerl::RegistryBB: 20014:Error
> string not specified yet at /var/www/perl/test.pl line 6.
>
> Also, more important, the script seems to be terminating and/or any output
> following the 'print ""' is not sent to the client as far as I can tell.

This is another story! You have a problem with ModPerl::RegistryBB. HTTP log
can't help if ModPerl::RegistryBB aborts at that point. From my point of
view it is supposed to be a warning (or debug/warning) instead of the error
in ModPerl::RegistryBB, because it could be necessary sometimes to flush
empty string (for example, to overwrite the default chunking behavior of
core Apache).

Unfortunately, I can't look into the sources of Apache-2 now.

Can somebody help to patch this problem on Bill's machine first in order to
let us to go ahead with this research?

Thanks,
Slava


Re: [mp2 Patch] BUG with mod_deflate and $|=1 (20014:Error string not specified)

Posted by Stas Bekman <st...@stason.org>.
Bill Marrs wrote:
[...]
>> You would probably wish to append your script with
>> additional output after the empty string? Something like:
>>
>> #!/usr/bin/perl
>> $|=1;
>> print "Content-Type: text/html\n\n";
>> print "hello world<P>";
>> # This line causes the error (?)
>> print "";
>> print "hello again<P>";
>> ---
> 
> 
> When I do this, the mod_perl variant of the script fails to print "hello 
> again<P>".
> 
> mod_cgi prints everything just fine and gets no errors.
> 
> I changed my test script to print a bunch of `date`'s
> http://shevek.kenyonhill.com/cgi/test.pl
> http://shevek.kenyonhill.com/perl/test.pl

Sorry for getting late to this thread, this is a bug in mod_deflate. You don't 
see it in mod_cgi, because mod_cgi doesn't really handle buffering and 
flushing, since it just reads the data from the pipe to the process. 
mod_deflate didn't follow the deflate() spec, saying that the caller shouldn't 
call deflate, when there is no data to deflate. Try this patch:

Index: modules/filters/mod_deflate.c
===================================================================
RCS file: /home/cvs/httpd-2.0/modules/filters/mod_deflate.c,v
retrieving revision 1.26.2.5
diff -u -r1.26.2.5 mod_deflate.c
--- modules/filters/mod_deflate.c       17 May 2003 18:27:43 -0000      1.26.2.5
+++ modules/filters/mod_deflate.c       5 Aug 2003 06:37:59 -0000
@@ -529,9 +529,11 @@

          if (APR_BUCKET_IS_FLUSH(e)) {
              apr_bucket *bkt;
-            zRC = deflate(&(ctx->stream), Z_SYNC_FLUSH);
-            if (zRC != Z_OK) {
-                return APR_EGENERAL;
+            if (ctx->stream.avail_in > 0) {
+                zRC = deflate(&(ctx->stream), Z_SYNC_FLUSH);
+                if (zRC != Z_OK) {
+                    return APR_EGENERAL;
+                }
              }

              ctx->stream.next_out = ctx->buffer;

Feel free to submit this bug report and the fix to httpd-dev. Please let me 
know if you do that, so I won't duplicate it. But I'd prefer that you do it so 
you can make sure that it gets fixed in the next release, since you need it 
working.

__________________________________________________________________
Stas Bekman            JAm_pH ------> Just Another mod_perl Hacker
http://stason.org/     mod_perl Guide ---> http://perl.apache.org
mailto:stas@stason.org http://use.perl.org http://apacheweek.com
http://modperlbook.org http://apache.org   http://ticketmaster.com


Re: [mp2 Patch] BUG with mod_deflate and $|=1 (20014:Error string not specified)

Posted by Bill Marrs <bi...@apocalypse.org>.
>We can see that mod_cgi bufferizes the output and sends it with
>Content-Length HTTP header (to mod_deflate). Indeed mod_perl generates
>chunked response. Finally we have the same result. I don't see any problem
>at this moment.

Well, the problem is that I get this error in my error_log:

[Mon Jul 21 14:18:55 2003] [error] 4297: ModPerl::RegistryBB: 20014:Error 
string not specified yet at /var/www/perl/test.pl line 6.

Also, more important, the script seems to be terminating and/or any output 
following the 'print ""' is not sent to the client as far as I can tell.

>You would probably wish to append your script with
>additional output after the empty string? Something like:
>
>#!/usr/bin/perl
>$|=1;
>print "Content-Type: text/html\n\n";
>print "hello world<P>";
># This line causes the error (?)
>print "";
>print "hello again<P>";
>---

When I do this, the mod_perl variant of the script fails to print "hello 
again<P>".

mod_cgi prints everything just fine and gets no errors.

I changed my test script to print a bunch of `date`'s
http://shevek.kenyonhill.com/cgi/test.pl
http://shevek.kenyonhill.com/perl/test.pl

>It may cause a problem for chunked output if mod_deflate does not care to
>keep internal buffer and check its size when flushing...

I may not be understanding the output you sent or what you're saying, but I 
still don't follow why this would be a mod_deflate bug if mod_cgi with the 
same script has no problem.




Re: [mp2 Patch] BUG with mod_deflate and $|=1 (20014:Error string not specified)

Posted by Slava Bizyayev <sb...@outlook.net>.
Well, let's see:

==> (93.530) Outgoing Request <GET http://shevek.kenyonhill.com/cgi/test.pl
HTTP/1.1>
C05 --> S06 GET /cgi/test.pl HTTP/1.1
C05 --> S06 Accept: image/gif, image/x-xbitmap, image/jpeg, image/pjpeg,
application/msword, */*
C05 --> S06 Accept-Language: en-us
C05 --> S06 Accept-Encoding: gzip, deflate
C05 --> S06 User-Agent: Mozilla/4.0 (compatible; MSIE 6.0; Windows 98)
C05 --> S06 Host: shevek.kenyonhill.com
C05 --> S06 Accept-Charset: ISO-8859-1
== Body was 0 bytes ==

C05 <-- S06 HTTP/1.1 200 OK
C05 <-- S06 Date: Mon, 21 Jul 2003 16:30:59 GMT
C05 <-- S06 Server: Apache
C05 <-- S06 Vary: Accept-Encoding,User-Agent
C05 <-- S06 Content-Encoding: gzip
C05 <-- S06 Content-Length: 34
C05 <-- S06 Connection: close
C05 <-- S06 Content-Type: text/html; charset=ISO-8859-1
C05 <-- S06 == Incoming Body was 34 bytes ==
== real URL = http://shevek.kenyonhill.com/cgi/test.pl ==
== Transmission: text gzip  ==
== (93.640) Response 200 to <GET http://shevek.kenyonhill.com/cgi/test.pl
HTTP/1.1>
== Latency = 0.110 seconds, Extra Delay = 0.000 seconds
== Restored Body was 14 bytes ==
== Content Begin: ==
hello world<P>
== Content End ==

==> (164.770) Outgoing Request <GET
http://shevek.kenyonhill.com/perl/test.pl HTTP/1.1>
C05 --> S06 GET /perl/test.pl HTTP/1.1
C05 --> S06 Accept: image/gif, image/x-xbitmap, image/jpeg, image/pjpeg,
application/msword, */*
C05 --> S06 Accept-Language: en-us
C05 --> S06 Accept-Encoding: gzip, deflate
C05 --> S06 User-Agent: Mozilla/4.0 (compatible; MSIE 6.0; Windows 98)
C05 --> S06 Host: shevek.kenyonhill.com
C05 --> S06 Accept-Charset: ISO-8859-1
== Body was 0 bytes ==

C05 <-- S06 HTTP/1.1 200 OK
C05 <-- S06 Date: Mon, 21 Jul 2003 16:32:11 GMT
C05 <-- S06 Server: Apache
C05 <-- S06 Vary: Accept-Encoding,User-Agent
C05 <-- S06 Content-Encoding: gzip
C05 <-- S06 Connection: close
C05 <-- S06 Transfer-Encoding: chunked
C05 <-- S06 Content-Type: text/html; charset=ISO-8859-1
C05 <-- S06 == Incoming Body was 629 bytes ==
== real URL = http://shevek.kenyonhill.com/perl/test.pl ==
== Transmission: text gzip chunked ==
== Chunk Log ==
1e (hex) = 30 (dec)
245 (hex) = 581 (dec)
0 (hex) = 0 (dec)
== (164.880) Response 200 to <GET http://shevek.kenyonhill.com/perl/test.pl
HTTP/1.1>
== Latency = 0.110 seconds, Extra Delay = 0.000 seconds
== Restored Body was 14 bytes ==
== Content Begin: ==
hello world<P>
== Content End ==

We can see that mod_cgi bufferizes the output and sends it with
Content-Length HTTP header (to mod_deflate). Indeed mod_perl generates
chunked response. Finally we have the same result. I don't see any problem
at this moment. You would probably wish to append your script with
additional output after the empty string? Something like:

#!/usr/bin/perl
$|=1;
print "Content-Type: text/html\n\n";
print "hello world<P>";
# This line causes the error (?)
print "";
print "hello again<P>";
---

It may cause a problem for chunked output if mod_deflate does not care to
keep internal buffer and check its size when flushing...

Thanks,
Slava


----- Original Message ----- 
From: "Bill Marrs" <bi...@apocalypse.org>
To: "Slava Bizyayev" <sb...@outlook.net>; "Stas Bekman"
<st...@stason.org>; "Philippe M. Chiasson" <go...@cpan.org>
Cc: <mo...@perl.apache.org>
Sent: Monday, July 21, 2003 6:49 AM
Subject: Re: [mp2 Patch] BUG with mod_deflate and $|=1 (20014:Error string
not specified)


>
> >I can measure it myself if you can provide me with URLs to your resources
> >and identify them in terms of which one is mod_CGI and which is mod_perl.
>
> This is the mod_cgi one that works fine, no errors:
> http://shevek.kenyonhill.com/cgi/test.pl
>
> This is the mod_perl one (same script) that generates the "20014:Error" in
> the error_log.  Also, the page doesn't display correctly (it seems to
erase
> itself):
>
> http://shevek.kenyonhill.com/perl/test.pl
>
> This is the contents of test.pl:
>
> ---
> #!/usr/bin/perl
> $|=1;
> print "Content-Type: text/html\n\n";
> print "hello world<P>";
> # This line causes the error
> print "";
> ---
>
> Let me know if you need anything more.
>
>


Re: [mp2 Patch] BUG with mod_deflate and $|=1 (20014:Error string not specified)

Posted by Bill Marrs <bi...@apocalypse.org>.
>I can measure it myself if you can provide me with URLs to your resources
>and identify them in terms of which one is mod_CGI and which is mod_perl.

This is the mod_cgi one that works fine, no errors:
http://shevek.kenyonhill.com/cgi/test.pl

This is the mod_perl one (same script) that generates the "20014:Error" in 
the error_log.  Also, the page doesn't display correctly (it seems to erase 
itself):

http://shevek.kenyonhill.com/perl/test.pl

This is the contents of test.pl:

---
#!/usr/bin/perl
$|=1;
print "Content-Type: text/html\n\n";
print "hello world<P>";
# This line causes the error
print "";
---

Let me know if you need anything more.


Re: [mp2 Patch] BUG with mod_deflate and $|=1 (20014:Error string not specified)

Posted by Slava Bizyayev <sb...@outlook.net>.
It is supposed to be something like the following:

  C05 --> S06 GET /html/wowtmovie.html HTTP/1.1
  C05 --> S06 Accept: */*
  C05 --> S06 Accept-Language: en-us
  C05 --> S06 Accept-Encoding: gzip, deflate
  C05 --> S06 User-Agent: Mozilla/4.0 (compatible; MSIE 6.0; Windows 98)
  C05 --> S06 Host: devl4.outlook.net
  C05 --> S06 Pragma: no-cache
  C05 --> S06 Accept-Charset: ISO-8859-1
  == Body was 0 bytes ==

  C05 <-- S06 HTTP/1.1 200 OK
  C05 <-- S06 Date: Fri, 31 May 2002 17:36:57 GMT
  C05 <-- S06 Server: Apache/1.3.22 (Unix) Debian GNU/Linux mod_perl/1.26
  C05 <-- S06 X-Module-Sender: Apache::Dynagzip
  C05 <-- S06 Transfer-Encoding: chunked
  C05 <-- S06 Expires: Friday, 31-May-2002 17:41:57 GMT
  C05 <-- S06 Vary: Accept-Encoding
  C05 <-- S06 Content-Type: text/html; charset=iso-8859-1
  C05 <-- S06 Content-Encoding: gzip
  C05 <-- S06 == Incoming Body was 9411 bytes ==
  == Transmission: text gzip chunked ==
  == Chunk Log ==
  a (hex) = 10 (dec)
  1314 (hex) = 4884 (dec)
  3ed (hex) = 1005 (dec)
  354 (hex) = 852 (dec)
  450 (hex) = 1104 (dec)
  5e6 (hex) = 1510 (dec)
  0 (hex) = 0 (dec)
  == Latency = 0.170 seconds, Extra Delay = 0.440 seconds
  == Restored Body was 149208 bytes ==

Not necessarily the same...
To measure it you might want to use a proxy, or a sniffer.

I can measure it myself if you can provide me with URLs to your resources
and identify them in terms of which one is mod_CGI and which is mod_perl.

Thanks,
Slava


----- Original Message ----- 
From: "Bill Marrs" <bi...@apocalypse.org>
To: "Slava Bizyayev" <sb...@outlook.net>; "Stas Bekman"
<st...@stason.org>; "Philippe M. Chiasson" <go...@cpan.org>
Cc: <mo...@perl.apache.org>
Sent: Sunday, July 20, 2003 6:22 PM
Subject: Re: [mp2 Patch] BUG with mod_deflate and $|=1 (20014:Error string
not specified)


> At 11:07 AM 7/19/2003, Slava Bizyayev wrote:
> >May I see your client side HTTP log of the request-response transaction
> >through mod_cgi vs. mod_perl?
>
> I'm not sure what you mean.  Do you mean my access_log?  I have a
> deflate_log as well (that shows the compression stats as well).  But,
maybe
> you're talking about something else?  If so, how do I get what you want?
>
>
>


Re: [mp2 Patch] BUG with mod_deflate and $|=1 (20014:Error string not specified)

Posted by Bill Marrs <bi...@apocalypse.org>.
At 11:07 AM 7/19/2003, Slava Bizyayev wrote:
>May I see your client side HTTP log of the request-response transaction
>through mod_cgi vs. mod_perl?

I'm not sure what you mean.  Do you mean my access_log?  I have a 
deflate_log as well (that shows the compression stats as well).  But, maybe 
you're talking about something else?  If so, how do I get what you want?



Re: [mp2 Patch] BUG with mod_deflate and $|=1 (20014:Error string not specified)

Posted by Slava Bizyayev <sb...@outlook.net>.
May I see your client side HTTP log of the request-response transaction
through mod_cgi vs. mod_perl?

Thanks,
Slava

----- Original Message ----- 
From: "Bill Marrs" <bi...@apocalypse.org>
To: "Slava Bizyayev" <sb...@outlook.net>; "Stas Bekman"
<st...@stason.org>; "Philippe M. Chiasson" <go...@cpan.org>
Cc: <mo...@perl.apache.org>
Sent: Saturday, July 19, 2003 7:01 AM
Subject: Re: [mp2 Patch] BUG with mod_deflate and $|=1 (20014:Error string
not specified)


> At 07:16 PM 7/18/2003, Slava Bizyayev wrote:
> >In my understanding _it is_ a problem of mod_deflate.
>
> The error does not occur if I run the same test script under mod_cgi
> instead of mod_perl.  This suggests that the problem is in mod_perl not
> mod_deflate.
>
> right?
>
>
>


Re: [mp2 Patch] BUG with mod_deflate and $|=1 (20014:Error string not specified)

Posted by Bill Marrs <bi...@apocalypse.org>.
At 07:16 PM 7/18/2003, Slava Bizyayev wrote:
>In my understanding _it is_ a problem of mod_deflate.

The error does not occur if I run the same test script under mod_cgi 
instead of mod_perl.  This suggests that the problem is in mod_perl not 
mod_deflate.

right?



Re: [mp2 Patch] BUG with mod_deflate and $|=1 (20014:Error string not specified)

Posted by "Philippe M. Chiasson" <go...@cpan.org>.
On Tue, 2003-07-15 at 16:24, Stas Bekman wrote:
> Philippe M. Chiasson wrote:
> > On Thu, 2003-07-03 at 01:24, Bill Marrs wrote:
> > 
> >>This fixed the bug for me.
> > 
> > 
> > Great! Will commit it in the near future. (Can't seem to access the cvs
> > server right now, crappy internet cafe)
> 
> -1, this is a wrong solution. print ""; should flush just like it did in 
> mod_perl 1.0 if $| == 1; Consider this script:
> 
>      print "Content-type: text/plain\n\n";
>      local $| = 0;
>      print "start\n\n";
>      local $| = 1;
>      print "";
>      sleep 5;
>      local $| = 0;
>      print "end\n";
> 
> print "", must immediately flush the buffered data, since $| has changed from 
> 0 to 1.

You are correct Stas, my fix was not appropriate. I've spent some time
today digging around for it.

Basically, to reproduce, you need to use ModPerl::RegistryBB

PerlModule ModPerl::RegistryBB
<Location /registry_bb>
    PerlOptions +GlobalRequest
    SetHandler perl-script
    Options +ExecCGI
    PerlResponseHandler ModPerl::RegistryBB
    PerlOptions +ParseHeaders
    SetOutputFilter DEFLATE
</Location>

Then hit the server with

#> GET -H'Accept-encoding: gzip' http://localhost:8529/registry_bb/print.pl
[error] 30146: ModPerl::RegistryBB: 20014:Error string not specified yet at ModPerl-Registry/t/cgi-bin/print.pl line 6.

And I've found what's hapenning. It's mod_deflate output filter that's not proprely handling flush buckets, IMO.

From mod_deflate.c:520

        if (APR_BUCKET_IS_FLUSH(e)) {
            apr_bucket *bkt;
            zRC = deflate(&(ctx->stream), Z_SYNC_FLUSH);
            if (zRC != Z_OK) {
                return APR_EGENERAL;
            }

            ctx->stream.next_out = ctx->buffer;
            len = c->bufferSize - ctx->stream.avail_out;

            b = apr_bucket_heap_create((char *)ctx->buffer, len,
                                       NULL, f->c->bucket_alloc);
            APR_BRIGADE_INSERT_TAIL(ctx->bb, b);
            ctx->stream.avail_out = c->bufferSize;

            bkt = apr_bucket_flush_create(f->c->bucket_alloc);
            APR_BRIGADE_INSERT_TAIL(ctx->bb, bkt);
            ap_pass_brigade(f->next, ctx->bb);
            continue;
        }

Seems like the call to deflate() returns some error (sounds to me like
mod_defalte expects a FLUSH bucket to come _after_ some data was
processed, not an empty brigade with _just_ a FLUSH bucket.

In that case, deflate() returns Z_BUF_ERROR and mod_deflate's output
filter proceeds to bailing out with APR_EGENERAL (20014, BTW) and we get
our annoying warning.

So the good news is that's it a bug in mod_deflate ;-)

And the bad news is that someone more familier with zlib than me could
probably figure out how to know there is no new data available, bypass
the compression and just pass a flush bucket along.



> 
> > One thing that could help is if someone could take the time to write a
> > test for this bug.
> 
> Unfortunately I don't seem to be able to reproduce the problem, so I can't 
> debug the problem. It could be a bug on the mod_deflate's behalf as well. 
> Philippe, were you able to reproduce the problem with Bill's setup? I was 
> writing a test, but couldn't get it to fail... may be because i was using 
> 2.0.47. Bill, do you have the problem with the latest apache version?
> 
> Also Bill, why do you have this setup:
> 
> <Location /perl>
>    AddOutputFilterByType DEFLATE text/*
>    SetOutputFilter DEFLATE
> </Location>
> 
> why adding it twice? You need only the latter inside <Location>, or 
> alternatively only the former outside <Location> if you want it to be set 
> globally:
> http://httpd.apache.org/docs-2.0/mod/core.html#addoutputfilterbytype
> 
> __________________________________________________________________
> Stas Bekman            JAm_pH ------> Just Another mod_perl Hacker
> http://stason.org/     mod_perl Guide ---> http://perl.apache.org
> mailto:stas@stason.org http://use.perl.org http://apacheweek.com
> http://modperlbook.org http://apache.org   http://ticketmaster.com
-- 
--------------------------------------------------------------------------------
Philippe M. Chiasson /gozer\@(cpan|ectoplasm)\.org/ 88C3A5A5 (122FF51B/C634E37B)
http://gozer.ectoplasm.org/    F9BF E0C2 480E 7680 1AE5 3631 CB32 A107 88C3 A5A5
Q: It is impossible to make anything foolproof because fools are so ingenious.
perl -e'$$=\${gozer};{$_=unpack(P7,pack(L,$$));/^JAm_pH\n$/&&print||$$++&&redo}'


Re: [mp2 Patch] BUG with mod_deflate and $|=1 (20014:Error string not specified)

Posted by Slava Bizyayev <sb...@outlook.net>.
Hi guys,

In my understanding _it is_ a problem of mod_deflate. It's a bit tricky to
flush dynamically generated content over HTTP/1.1: Core Apache marks the end
of your document with empty chunk. When you flush an empty string in the
middle of your document Apache has no way to serve your directions, but to
create an empty chunk immediately. The first empty chunk received by the
client is recognized as the end of the document. The rest of the data stream
is just ignored.

I didn't have a chance to look into the source of mod_deflate yet, but this
definitely has to be taken into account over there. In my understanding it
would be the best our bet just to bring this issue to the attention of the
author of mod_deflate. It's supposed to be easy to fix.

Thanks,
Slava

----- Original Message ----- 
From: "Stas Bekman" <st...@stason.org>
To: "Philippe M. Chiasson" <go...@cpan.org>
Cc: "Bill Marrs" <bi...@apocalypse.org>; <mo...@perl.apache.org>
Sent: Tuesday, July 15, 2003 3:24 AM
Subject: Re: [mp2 Patch] BUG with mod_deflate and $|=1 (20014:Error string
not specified)


> Philippe M. Chiasson wrote:
> > On Thu, 2003-07-03 at 01:24, Bill Marrs wrote:
> >
> >>This fixed the bug for me.
> >
> >
> > Great! Will commit it in the near future. (Can't seem to access the cvs
> > server right now, crappy internet cafe)
>
> -1, this is a wrong solution. print ""; should flush just like it did in
> mod_perl 1.0 if $| == 1; Consider this script:
>
>      print "Content-type: text/plain\n\n";
>      local $| = 0;
>      print "start\n\n";
>      local $| = 1;
>      print "";
>      sleep 5;
>      local $| = 0;
>      print "end\n";
>
> print "", must immediately flush the buffered data, since $| has changed
from
> 0 to 1.
>
>
> > One thing that could help is if someone could take the time to write a
> > test for this bug.
>
> Unfortunately I don't seem to be able to reproduce the problem, so I can't
> debug the problem. It could be a bug on the mod_deflate's behalf as well.
> Philippe, were you able to reproduce the problem with Bill's setup? I was
> writing a test, but couldn't get it to fail... may be because i was using
> 2.0.47. Bill, do you have the problem with the latest apache version?
>
> Also Bill, why do you have this setup:
>
> <Location /perl>
>    AddOutputFilterByType DEFLATE text/*
>    SetOutputFilter DEFLATE
> </Location>
>
> why adding it twice? You need only the latter inside <Location>, or
> alternatively only the former outside <Location> if you want it to be set
> globally:
> http://httpd.apache.org/docs-2.0/mod/core.html#addoutputfilterbytype
>
> __________________________________________________________________
> Stas Bekman            JAm_pH ------> Just Another mod_perl Hacker
> http://stason.org/     mod_perl Guide ---> http://perl.apache.org
> mailto:stas@stason.org http://use.perl.org http://apacheweek.com
> http://modperlbook.org http://apache.org   http://ticketmaster.com
>
>


Re: [mp2 Patch] BUG with mod_deflate and $|=1 (20014:Error string not specified)

Posted by Stas Bekman <st...@stason.org>.
Philippe M. Chiasson wrote:
> On Thu, 2003-07-03 at 01:24, Bill Marrs wrote:
> 
>>This fixed the bug for me.
> 
> 
> Great! Will commit it in the near future. (Can't seem to access the cvs
> server right now, crappy internet cafe)

-1, this is a wrong solution. print ""; should flush just like it did in 
mod_perl 1.0 if $| == 1; Consider this script:

     print "Content-type: text/plain\n\n";
     local $| = 0;
     print "start\n\n";
     local $| = 1;
     print "";
     sleep 5;
     local $| = 0;
     print "end\n";

print "", must immediately flush the buffered data, since $| has changed from 
0 to 1.


> One thing that could help is if someone could take the time to write a
> test for this bug.

Unfortunately I don't seem to be able to reproduce the problem, so I can't 
debug the problem. It could be a bug on the mod_deflate's behalf as well. 
Philippe, were you able to reproduce the problem with Bill's setup? I was 
writing a test, but couldn't get it to fail... may be because i was using 
2.0.47. Bill, do you have the problem with the latest apache version?

Also Bill, why do you have this setup:

<Location /perl>
   AddOutputFilterByType DEFLATE text/*
   SetOutputFilter DEFLATE
</Location>

why adding it twice? You need only the latter inside <Location>, or 
alternatively only the former outside <Location> if you want it to be set 
globally:
http://httpd.apache.org/docs-2.0/mod/core.html#addoutputfilterbytype

__________________________________________________________________
Stas Bekman            JAm_pH ------> Just Another mod_perl Hacker
http://stason.org/     mod_perl Guide ---> http://perl.apache.org
mailto:stas@stason.org http://use.perl.org http://apacheweek.com
http://modperlbook.org http://apache.org   http://ticketmaster.com