Random 404 pages

G

gwhite

Member
#1
#1
We are seeing in our access logs random 404 errors with one of our Rails Apps. We can't pinpoint a cause at this stage - seemingly users who are experiencing it can refresh the page and everything will be fine.
One thing we did notice was the "[NOTICE]..Request line:" message which is typically followed by the request is empty for these 404 errors.
We have evidence that rails itself is completing these requests despite the 404.
This is on a CentOS 5 platform with standard Litespeed version 3.3.18. I have attached a debug log that shows the access-log entries with 404s and the debug logging output.

192.168.100.1 - - [17/Oct/2008:13:45:02 -0700] "GET /website HTTP/1.1" 404 - "http://referer.com" "Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 6.0; WOW64; SLCC1; .NET CLR 2.0.50727; .NET CLR 3.0.04506; Media Center PC 5.0)"

2008-10-17 13:45:02.201 [DEBUG] [192.168.100.1:50252-31] HttpConnection::eek:nReadEx(), state: 0!
2008-10-17 13:45:02.201 [DEBUG] [192.168.100.1:50252-31] readToHeaderBuf().
2008-10-17 13:45:02.201 [DEBUG] [192.168.100.1:50252-31] read 959 bytes to header buffer
2008-10-17 13:45:02.201 [DEBUG] [192.168.100.1:50252-31] processHeader() return 0, header state: 3.
2008-10-17 13:45:02.201 [DEBUG] [192.168.100.1:50252-31] readToHeaderBuf() return 0.
2008-10-17 13:45:02.201 [NOTICE] [192.168.100.1:50252-31#thewebapp] Content len: 0, Request line:
2008-10-17 13:45:02.201 [DEBUG] [192.168.100.1:50252-31#thewebapp] File not found [/path/to/thewebapp/releases/20081015231404/public/website]
2008-10-17 13:45:02.201 [DEBUG] [192.168.100.1:50252-31#thewebapp] processContextPath() return 25
2008-10-17 13:45:02.201 [DEBUG] [192.168.100.1:50252-31#thewebapp] processNewReq() return 25.
2008-10-17 13:45:02.201 [DEBUG] [192.168.100.1:50252-31#thewebapp] HttpConnection::sendHttpError(),code=404 Not Found
2008-10-17 13:45:02.201 [DEBUG] [192.168.100.1:50252-31#thewebapp] redirect to:
2008-10-17 13:45:02.201 [DEBUG] [192.168.100.1:50252-31#thewebapp] processContextPath() return 0
2008-10-17 13:45:02.201 [DEBUG] [192.168.100.1:50252-31#thewebapp] run lsapi processor.
2008-10-17 13:45:02.201 [DEBUG] [192.168.100.1:50252-31#thewebapp:lsapi] ExtConn::continueRead()
2008-10-17 13:45:02.201 [DEBUG] [192.168.100.1:50252-31#thewebapp:lsapi] ExtConn::suspendWrite()
2008-10-17 13:45:02.201 [DEBUG] [192.168.100.1:50252-31#thewebapp:lsapi] ExtConn::eek:nRead()
2008-10-17 13:45:02.201 [DEBUG] [192.168.100.1:50252-31#thewebapp:lsapi] LsapiConn::doRead()
2008-10-17 13:45:03.381 [DEBUG] [192.168.100.1:50252-31#thewebapp:lsapi] HttpIOLink::suspendRead()...
2008-10-17 13:45:03.381 [DEBUG] [192.168.100.1:50252-31#thewebapp:lsapi] [LSAPI] send abort packet!
2008-10-17 13:45:03.381 [DEBUG] [192.168.100.1:50252-31#thewebapp:lsapi] Shutting down SSL ...
2008-10-17 13:45:03.382 [DEBUG] [192.168.100.1:50252-31#thewebapp:lsapi] Close socket ...

74.222.1.1 - - [17/Oct/2008:14:05:51 -0700] "GET /website/manager HTTP/1.1" 404 171 "-" "Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9.0.3) Gecko/2008092417 Firefox/3.0.3"

2008-10-17 14:05:51.577 [DEBUG] [74.222.1.1:2486-1] HttpConnection::eek:nReadEx(), state: 0!
2008-10-17 14:05:51.577 [DEBUG] [74.222.1.1:2486-1] readToHeaderBuf().
2008-10-17 14:05:51.577 [DEBUG] [74.222.1.1:2486-1] read 667 bytes to header buffer
2008-10-17 14:05:51.577 [DEBUG] [74.222.1.1:2486-1] processHeader() return 0, header state: 3.
2008-10-17 14:05:51.577 [DEBUG] [74.222.1.1:2486-1] readToHeaderBuf() return 0.
2008-10-17 14:05:51.577 [NOTICE] [74.222.1.1:2486-1#thewebapp] Content len: 0, Request line:
2008-10-17 14:05:51.577 [DEBUG] [74.222.1.1:2486-1#thewebapp] File not found [/path/to/thewebapp/releases/20081015231404/public/website/manager]
2008-10-17 14:05:51.577 [DEBUG] [74.222.1.1:2486-1#thewebapp] processContextPath() return 25
2008-10-17 14:05:51.577 [DEBUG] [74.222.1.1:2486-1#thewebapp] processNewReq() return 25.
2008-10-17 14:05:51.577 [DEBUG] [74.222.1.1:2486-1#thewebapp] HttpConnection::sendHttpError(),code=404 Not Found
2008-10-17 14:05:51.577 [DEBUG] [74.222.1.1:2486-1#thewebapp] redirect to:
2008-10-17 14:05:51.577 [DEBUG] [74.222.1.1:2486-1#thewebapp] processContextPath() return 0
2008-10-17 14:05:51.577 [DEBUG] [74.222.1.1:2486-1#thewebapp] run lsapi processor.
2008-10-17 14:05:51.577 [DEBUG] [74.222.1.1:2486-1#thewebapp:lsapi] ExtConn::continueRead()
2008-10-17 14:05:51.577 [DEBUG] [74.222.1.1:2486-1#thewebapp:lsapi] ExtConn::suspendWrite()
2008-10-17 14:05:51.577 [DEBUG] [74.222.1.1:2486-1#thewebapp:lsapi] ExtConn::eek:nRead()
2008-10-17 14:05:51.577 [DEBUG] [74.222.1.1:2486-1#thewebapp:lsapi] LsapiConn::doRead()
2008-10-17 14:05:51.585 [DEBUG] [74.222.1.1:2486-1#thewebapp:lsapi] ExtConn::eek:nRead()
2008-10-17 14:05:51.585 [DEBUG] [74.222.1.1:2486-1#thewebapp:lsapi] LsapiConn::doRead()
2008-10-17 14:05:51.585 [DEBUG] [74.222.1.1:2486-1#thewebapp:lsapi] GZIP response body!
2008-10-17 14:05:51.585 [DEBUG] [74.222.1.1:2486-1#thewebapp:lsapi] use CHUNKED encoding!
2008-10-17 14:05:51.586 [DEBUG] [74.222.1.1:2486-1#thewebapp:lsapi] HttpIOLink::suspendWrite()...
2008-10-17 14:05:51.586 [DEBUG] [74.222.1.1:2486-1#thewebapp:lsapi] ExtConn::eek:nRead()
2008-10-17 14:05:51.586 [DEBUG] [74.222.1.1:2486-1#thewebapp:lsapi] LsapiConn::doRead()
2008-10-17 14:05:51.586 [DEBUG] [74.222.1.1:2486-1#thewebapp:lsapi] [EXT] EndResponse( endCode=0, protocolStatus=0 )
2008-10-17 14:05:51.586 [DEBUG] [74.222.1.1:2486-1#thewebapp:lsapi] HttpIOLink::continueWrite()...
2008-10-17 14:05:51.586 [DEBUG] [74.222.1.1:2486-1#thewebapp:lsapi] write resumed!
2008-10-17 14:05:51.586 [DEBUG] [74.222.1.1:2486-1#thewebapp:lsapi] HttpConnection::flush()!
2008-10-17 14:05:51.586 [DEBUG] [74.222.1.1:2486-1#thewebapp:lsapi] HttpIOLink::flushSSL()...
2008-10-17 14:05:51.586 [DEBUG] [74.222.1.1:2486-1#thewebapp:lsapi] HttpConnection::nextRequest()!
 
M

mistwang

LiteSpeed Staff
#2
#2
For some reason, the first request was aborted.
[LSAPI] send abort packet!

Maybe something wrong with HTTP request from "Media Center PC 5.0" browser.

The second request is successfully completed, just the status code has not been change from 404 to 200, the rails app does not set it. So, it is normal.

Please try 3.3.20 see if it help or not.
 
You must log in or register to reply here.
Top