500 Server Error on 3.0 - works fine on 2.2.6

gboudreau · Mar 24, 2007

On 2.2.6, I get 200 OK:

Code:

["my.domain.com"] my.client.ip - - [23/Mar/2007:17:55:47 -0700] "GET /dataservice.asmx/RequestProgramData?UUID=EGU7TZLA1JA94H679Z9WVV5ETEEG17&ProviderId=A_00001&DaysRequested=8 HTTP/1.1" 200 438834 "-" "curl/7.13.1 (powerpc-apple-darwin8.0) libcurl/7.13.1 OpenSSL/0.9.7l zlib/1.2.3"

On 3.0, I get 500 Server Error:

Code:

["my.domain.com"] my.client.ip - - [23/Mar/2007:17:52:27 -0700] "GET /dataservice.asmx/RequestProgramData?UUID=EGU7TZLA1JA94H679Z9WVV5ETEEG17&ProviderId=A_00001&DaysRequested=8 HTTP/1.1" 500 394 "-" "curl/7.13.1 (powerpc-apple-darwin8.0) libcurl/7.13.1 OpenSSL/0.9.7l zlib/1.2.3"

Debug log from 3.0:

Code:

2007-03-23 17:52:27.265 [DEBUG] [*:80] New connection from my.client.ip:62163.
2007-03-23 17:52:27.265 [DEBUG] [*:80] 1 connections accepted!
2007-03-23 17:52:27.265 [DEBUG] [my.client.ip:62163-0] HttpIOLink::handleEvents() events=1!
2007-03-23 17:52:27.265 [DEBUG] [my.client.ip:62163-0] HttpConnection::onReadEx(), state: 0!
2007-03-23 17:52:27.265 [DEBUG] [my.client.ip:62163-0] readToHeaderBuf(). 
2007-03-23 17:52:27.265 [DEBUG] [my.client.ip:62163-0] Read from client: 271
2007-03-23 17:52:27.265 [DEBUG] [my.client.ip:62163-0] read 271 bytes to header buffer
2007-03-23 17:52:27.265 [DEBUG] [my.client.ip:62163-0] processHeader() return 0, header state: 3. 
2007-03-23 17:52:27.265 [DEBUG] [my.client.ip:62163-0] readToHeaderBuf() return 0. 
2007-03-23 17:52:27.265 [DEBUG] [my.client.ip:62163-0#my.domain.com] New request: 
        Method=[GET], URI=[/dataservice.asmx/RequestProgramData],
        QueryString=[UUID=EGU7TZLA1JA94H679Z9WVV5ETEEG17&ProviderId=A_00001&DaysRequested=8]
        Content Length=0
2007-03-23 17:52:27.265 [DEBUG] [my.client.ip:62163-0#my.domain.com] Find context with URI: [/], location: [/var/www/html/my.domain.com/]
2007-03-23 17:52:27.265 [DEBUG] [HTAccess] Updating configuration file [/var/www/html/my.domain.com/.htaccess]
2007-03-23 17:52:27.265 [DEBUG] [HTAccess] No change in configuration file [/var/www/html/my.domain.com/.htaccess].
2007-03-23 17:52:27.266 [DEBUG] [HTAccess] Updating configuration file [/var/www/html/my.domain.com/dataservice.asmx/.htaccess]
2007-03-23 17:52:27.266 [DEBUG] [HTAccess] No change in configuration file [/var/www/html/my.domain.com/dataservice.asmx/.htaccess].
2007-03-23 17:52:27.266 [DEBUG] [my.client.ip:62163-0#my.domain.com] Find .htaccess context with URI: [/dataservice.asmx/], location: [/var/www/html/my.domain.com/dataservice.asmx/]
2007-03-23 17:52:27.266 [DEBUG] [my.client.ip:62163-0#my.domain.com] processContextPath() return 0
2007-03-23 17:52:27.266 [DEBUG] [my.client.ip:62163-0#my.domain.com] run lsapi processor.
2007-03-23 17:52:27.266 [DEBUG] [uds://tmp/lshttpd/lsphp5.sock] connection available!
2007-03-23 17:52:27.266 [DEBUG] [uds://tmp/lshttpd/lsphp5.sock] request [my.client.ip:62163-0#my.domain.com:lsapi] is assigned with connection!
2007-03-23 17:52:27.266 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] request header is done
2007-03-23 17:52:27.266 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] ExtConn::continueRead()
2007-03-23 17:52:27.266 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] Request body done!
2007-03-23 17:52:27.266 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] ExtConn::suspendWrite()
2007-03-23 17:52:27.266 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] processNewReq() return 0. 
2007-03-23 17:52:27.268 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] ExtConn::onRead()
2007-03-23 17:52:27.268 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] LsapiConn::doRead()
2007-03-23 17:52:27.268 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] process packet header 8 bytes
2007-03-23 17:52:27.268 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] process packet header 0 bytes
2007-03-23 17:52:27.320 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] ExtConn::onRead()
2007-03-23 17:52:27.320 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] LsapiConn::doRead()
2007-03-23 17:52:27.320 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] process packet header 8 bytes
2007-03-23 17:52:27.320 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] process response header 185 bytes
2007-03-23 17:52:27.320 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] response header finished!
2007-03-23 17:52:27.320 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] GUNZIP response body!
2007-03-23 17:52:27.320 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] process packet header 8 bytes
2007-03-23 17:52:27.320 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] process response stream 15927 bytes, packet left: 16384
2007-03-23 17:52:27.320 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] HttpIOLink::continueWrite()...
2007-03-23 17:52:27.320 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] write resumed!
2007-03-23 17:52:27.320 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] HttpIOLink::handleEvents() events=4!
2007-03-23 17:52:27.320 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] HttpIOLink::suspendWrite()...
2007-03-23 17:52:27.320 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] HttpConnection::sendHttpError(),code=500 Internal Server Error
2007-03-23 17:52:27.320 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] HttpConnection::flush()!
2007-03-23 17:52:27.321 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] Written to client: 616
2007-03-23 17:52:27.321 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] HttpConnection::nextRequest()!
2007-03-23 17:52:27.321 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] HttpExtConnector::cleanUp() ...
2007-03-23 17:52:27.321 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] abort request... 
2007-03-23 17:52:27.321 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] [LSAPI] send abort packet!
2007-03-23 17:52:27.321 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] release ExtProcessor!
2007-03-23 17:52:27.321 [DEBUG] [idle] [ExtConn] close()
2007-03-23 17:52:27.321 [DEBUG] [uds://tmp/lshttpd/lsphp5.sock] add recycled connection to connection pool!
2007-03-23 17:52:27.321 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] Non-KeepAlive, CLOSING!
2007-03-23 17:52:27.321 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] Shutting down out-bound socket ...
2007-03-23 17:52:27.406 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] HttpIOLink::handleEvents() events=17!
2007-03-23 17:52:27.406 [DEBUG] [my.client.ip:62163-0#my.domain.com:lsapi] Close socket ...

Can't seem to find what is causing this...
Any idea ?

mistwang · Mar 24, 2007

Looks like your scripting engine sent back a response header indicating a compressed response body while the response body is not compressed, for some reason LSWS think the client is not capable of handling compressed response, so it try to uncompress it.

Have you enabled GZIP compression for dynamic content, maybe you need to flip that option under "server"->"tuning" tab.

gboudreau · Mar 24, 2007

This PHP script returns compressed content, and a header which says it will return compressed content (using deflate, not gzip) is also sent back.

I can confirm that using LS 2.2.6:

powermac:~ gb$ curl -i "http://my.domain.com/dataservice.asmx/RequestProgramData?UUID=EGU7TZLA1JA94H679Z9WVV5ETEEG17&ProviderId=A_00001&DaysRequested=8"
HTTP/1.1 200 OK
X-AspNet-Version: 1.1.4322
X-Powered-By: InteSoft-ASPAccelerator/2.2
Cache-Control: private, max-age=0
Content-Type: text/xml; charset=utf-8
Content-Encoding: deflate
Transfer-Encoding: chunked
Server: LiteSpeed
??=T?Hsecy?졎ƗJ??t?V??bZ?????H~)?;???Ͳ??'?=S?AVf???^f}u?4??{Sf????֤?R8_&Jf?W?Hbc?ҥ?{C???*??NL_?D???D*?d??=W??\OYny:??Z%???S^?2__.]?=?xf???uS?<uO???zi8<P?PID3?c??????
...

Returning the same thing under 3.0 doesn't work, with Dynamic Compression On or Off.

I don't think LS should try to uncompress content if the script returns compressed content.
Enabling Dynamic Compression should only affect uncompressed content, which LS would try to compress before returning it to the client.

Thanks.

mistwang · Mar 24, 2007

I see, that's why.
Can you switch to gzip compression in PHP? or turn off compression in php and let LSWS handle this?

LSWS only support gzip compression, this special case will be fixed, deflated content will not be touched.

gboudreau · Mar 24, 2007

No, I can't use gzip instead of deflate. This script is used by a client which only understand deflate, and not gzip.

I'll wait for your fix; until then, I'll keep using 2.2.6.

Thanks.

mistwang · Mar 24, 2007

This issue should be addressed in 3.0.1 release.

gboudreau · Mar 24, 2007

Will LS 2.2.6 send me an email when 3.0.1 will be avail ?
Or will only 3.0 send notices about new 3.x releases ?

- Guillaume

mistwang · Mar 24, 2007

2.2.6 will notify you about hte new release.

500 Server Error on 3.0 - works fine on 2.2.6

gboudreau

Well-Known Member

mistwang

LiteSpeed Staff

gboudreau

Well-Known Member

mistwang

LiteSpeed Staff

gboudreau

Well-Known Member

mistwang

LiteSpeed Staff

gboudreau

Well-Known Member

mistwang

LiteSpeed Staff