LSWS 3.0RC2 and trac-fcgi

Discussion in 'CGI/Perl/Python' started by Erg, Feb 21, 2007.

  1. Erg

    Erg New Member

    I'm trying to get LSWS 3.0RC2 running with trac.

    I have a functioning trac installation and an functioning installation of LSWS 3.0RC2. Some further informations about the setup of my server:
    My trac project resides in /srv/trac/dystopia
    All files are marked readable by LSWS.
    The trac.fcgi ist marked readable and executable and resides in /srv/trac

    I tried to run the trac.fcgi manually through python and piped the output through lynx and then i see a functioning website with my trac project. So the trac.fcgi can't be the problem.

    I set up everything according to the wiki-tutorial. A restart of LSWS shows, that the Listener and the Virtual Host are correctly set up. When trying to access trac via Browser i get a 503.

    Accordings to the LSWS stderr.log the following has happened:
    Code:
        210 close failed: [Errno 9] Bad file descriptor
        211 close failed: [Errno 9] Bad file descriptor
        212 close failed: [Errno 9] Bad file descriptor
        213 close failed: [Errno 9] Bad file descriptor
        214 close failed: [Errno 9] Bad file descriptor
    Everytime I try to access I get a bunch of these written to the stderr.log.

    So I pushed LSWS into debug logging mode in the hope of finding some instructing insights.

    I tried to read it all through but I can't figure out, where the problem is buried.

    The debug server log gives the following messages, when I try to access the trac project via browser.
    Code:
    2007-02-21 18:24:47.339	DEBUG	[UDS://tmp/lshttpd/admin_php.sock] add recycled connection to connection pool!
    2007-02-21 18:24:50.175	DEBUG	[87.162.5.26:21053-0#Dystopia] HttpIOLink::handleEvents() events=1!
    2007-02-21 18:24:50.187	DEBUG	[87.162.5.26:21053-0#Dystopia] HttpConnection::onReadEx(), state: 5!
    2007-02-21 18:24:50.187	DEBUG	[87.162.5.26:21053-0#Dystopia] HttpIOLink::suspendRead()...
    2007-02-21 18:24:50.601	DEBUG	[87.162.5.26:21053-0#Dystopia] peer connection close detected!
    2007-02-21 18:24:50.601	DEBUG	[87.162.5.26:21053-0#Dystopia] HttpExtConnector::cleanUp() ...
    2007-02-21 18:24:50.650	DEBUG	[87.162.5.26:21053-0#Dystopia] abort request...
    2007-02-21 18:24:50.650	DEBUG	[87.162.5.26:21053-0#Dystopia] FcgiConnection::abort()
    2007-02-21 18:24:50.650	DEBUG	[87.162.5.26:21053-0#Dystopia] read 0 bytes from Fast CGI.
    2007-02-21 18:24:50.650	DEBUG	[87.162.5.26:21053-0#Dystopia] [ExtConn] close()
    2007-02-21 18:24:50.650	DEBUG	[87.162.5.26:21053-0#Dystopia] [EXT] EndResponse( endCode=0, protocolStatus=0 )
    2007-02-21 18:24:50.650	DEBUG	[87.162.5.26:21053-0#Dystopia] release ExtProcessor!
    2007-02-21 18:24:50.650	DEBUG	[uds://tmp/lshttpd/dystopia_tracfcgi.sock] add recycled connection to connection pool!
    2007-02-21 18:24:50.650	DEBUG	[87.162.5.26:21053-0#Dystopia] HttpIOLink::continueWrite()...
    2007-02-21 18:24:50.650	DEBUG	[87.162.5.26:21053-0#Dystopia] write resumed!
    2007-02-21 18:24:50.650	DEBUG	[87.162.5.26:21053-0#Dystopia] release ExtProcessor!
    2007-02-21 18:24:50.650	DEBUG	[87.162.5.26:21053-0#Dystopia] Close socket ...
    2007-02-21 18:24:59.815	DEBUG	[*:6666] New connection from 87.162.5.26:21102.
    2007-02-21 18:24:59.815	DEBUG	[*:6666] 1 connections accepted!
    2007-02-21 18:24:59.815	DEBUG	[87.162.5.26:21102-0] HttpIOLink::handleEvents() events=1!
    2007-02-21 18:24:59.815	DEBUG	[87.162.5.26:21102-0] HttpConnection::onReadEx(), state: 0!
    2007-02-21 18:24:59.815	DEBUG	[87.162.5.26:21102-0] readToHeaderBuf().
    2007-02-21 18:24:59.815	DEBUG	[87.162.5.26:21102-0] Read from client: 586
    2007-02-21 18:24:59.815	DEBUG	[87.162.5.26:21102-0] read 586 bytes to header buffer
    2007-02-21 18:24:59.815	DEBUG	[87.162.5.26:21102-0] processHeader() return 0, header state: 3.
    2007-02-21 18:24:59.815	DEBUG	[87.162.5.26:21102-0] readToHeaderBuf() return 0.
    2007-02-21 18:24:59.815	DEBUG	[87.162.5.26:21102-0#Dystopia] New request:
    Method=[GET], URI=[/trac/],
    QueryString=[]
    Content Length=0
    2007-02-21 18:24:59.815	DEBUG	[87.162.5.26:21102-0#Dystopia] Find context with URI: [/trac/], location: []
    2007-02-21 18:24:59.815	DEBUG	[87.162.5.26:21102-0#Dystopia] processContextPath() return 0
    2007-02-21 18:24:59.815	DEBUG	[87.162.5.26:21102-0#Dystopia] run fcgi processor.
    2007-02-21 18:24:59.815	DEBUG	[uds://tmp/lshttpd/dystopia_tracfcgi.sock] connection available!
    2007-02-21 18:24:59.815	DEBUG	[uds://tmp/lshttpd/dystopia_tracfcgi.sock] request [87.162.5.26:21102-0#Dystopia:fcgi] is assigned with connection!
    2007-02-21 18:24:59.816	DEBUG	[87.162.5.26:21102-0#Dystopia:fcgi] [ExtConn] reconnect()
    2007-02-21 18:24:59.816	DEBUG	[trac - Dystopia] add child process pid: 8047
    2007-02-21 18:24:59.891	DEBUG	[trac - Dystopia] add child process pid: 8049
    2007-02-21 18:24:59.892	DEBUG	[trac - Dystopia] add child process pid: 8050
    2007-02-21 18:24:59.892	DEBUG	[87.162.5.26:21102-0#Dystopia:fcgi] [ExtConn] connecting to [uds://tmp/lshttpd/dystopia_tracfcgi.sock]...
    2007-02-21 18:24:59.892	DEBUG	[87.162.5.26:21102-0#Dystopia:fcgi] ExtConn::onWrite()
    2007-02-21 18:24:59.892	DEBUG	[87.162.5.26:21102-0#Dystopia:fcgi] FcgiConnection::doWrite()
    2007-02-21 18:24:59.892	DEBUG	[87.162.5.26:21102-0#Dystopia:fcgi] FcgiConnection::beginRequest()
    2007-02-21 18:24:59.892	DEBUG	[87.162.5.26:21102-0#Dystopia:fcgi] FcgiConnection::pendingWrite(),m_iCurStreamHeader=16
    2007-02-21 18:24:59.892	DEBUG	[87.162.5.26:21102-0#Dystopia:fcgi] request header is done
    2007-02-21 18:24:59.892	DEBUG	[87.162.5.26:21102-0#Dystopia:fcgi] FcgiConnection::beginReqBody()
    2007-02-21 18:24:59.892	DEBUG	[87.162.5.26:21102-0#Dystopia:fcgi] FcgiConnection::pendingEndStream()
    2007-02-21 18:24:59.892	DEBUG	[87.162.5.26:21102-0#Dystopia:fcgi] ExtConn::continueRead()
    2007-02-21 18:24:59.892	DEBUG	[87.162.5.26:21102-0#Dystopia:fcgi] Request body done!
    2007-02-21 18:24:59.892	DEBUG	[87.162.5.26:21102-0#Dystopia:fcgi] FcgiConnection::endOfReqBody()
    2007-02-21 18:24:59.892	DEBUG	[87.162.5.26:21102-0#Dystopia:fcgi] FcgiConnection::pendingEndStream()
    2007-02-21 18:24:59.892	DEBUG	[87.162.5.26:21102-0#Dystopia:fcgi] FcgiConnection::flush()
    2007-02-21 18:24:59.892	DEBUG	[87.162.5.26:21102-0#Dystopia:fcgi] FcgiConnection::suspendWrite()
    2007-02-21 18:24:59.892	DEBUG	[87.162.5.26:21102-0#Dystopia:fcgi] processNewReq() return 0.
    2007-02-21 18:25:01.470	DEBUG	Remove pid: 8050
    2007-02-21 18:25:01.470	DEBUG	Remove pid: 8049
    2007-02-21 18:25:01.470	DEBUG	Remove pid: 8047
    2007-02-21 18:25:29.059	DEBUG	[87.162.5.26:21102-0#Dystopia:fcgi] connection to [uds://tmp/lshttpd/dystopia_tracfcgi.sock] on request #0, error: Connection timed out!
    2007-02-21 18:25:29.076	DEBUG	[87.162.5.26:21102-0#Dystopia:fcgi] [ExtConn] close()
    2007-02-21 18:25:29.095	DEBUG	[trac - Dystopia] kill pid 7773 associated with ProcInfo
    2007-02-21 18:25:29.095	DEBUG	[uds://tmp/lshttpd/dystopia_tracfcgi.sock] No Request has been processed successfully through this connection, the maximum connections allowed will be reduced!
    2007-02-21 18:25:29.095	DEBUG	[87.162.5.26:21102-0#Dystopia:fcgi] HttpExtConnector::tryRecover()...
    2007-02-21 18:25:29.095	DEBUG	[87.162.5.26:21102-0#Dystopia:fcgi] trying to recover from connection problem, attempt: #1!
    And after this everything happens again with the next connection try.


    I'm at the end of my latin, please help me.
  2. mistwang

    mistwang LiteSpeed Staff

    Please try the 3.0 preview release by change 3.0RC2 to 3.0 in the download package. that might be caused by a bug has been fixed in 3.0 package.
  3. Erg

    Erg New Member

    Ok I updated LSWS to 3.0 from RC2.

    After successful update and a restart I get a bunch of the following debug errors when I try to access trac.fcgi
    Code:
    2007-02-21 19:52:12.300	DEBUG	Failed to execute 'mpstat' command: No such file or directory
    I have no clue what this error message is trying to tell me. 'mpstat'? o_O Have I missed something crucial?
  4. mistwang

    mistwang LiteSpeed Staff

    That's because mpstat shell command was not installed on your server, which is not a big deal, we use mpstat output in our realtime status report, you can ignore that. It does not related to the trac.fcgi 503 errors.
  5. Erg

    Erg New Member

    After compiling sysstats and gaining mpstat with this, I don't get this message anymore. That's quite fine with me, but now my trac-FastCGI doesn't throw any debug message in the LSWS logs. Curios enough as it might be it doesn't load in browser either.

    The only message which stays constant ist die "bad file descriptor" message in the stderr.log

    Is it possible to install an older LSWS over an newer one and then degrade LSWS to an older version?

    Or do you have another idea what might help me?
  6. mistwang

    mistwang LiteSpeed Staff

  7. mistwang

    mistwang LiteSpeed Staff

    You can also check out the configuration of our demo server, there is a Trac demo.
  8. Erg

    Erg New Member

    Yes thanks a lot, this I will do and then report back if I had success.
  9. Erg

    Erg New Member

    Ok I triple checked everything. I have exactly the same configurations as your demo server. The tutorial you linked for me is the same as in your wiki. This is the tutorial I followed initally when setting up the trac project virtual host for the first time.

    After trying it so many times I believe that it isn't a problem of lsws. Maybe it is a problem of trac 0.11dev itself and its .fcgi script. I don't know right now and what's troubling me in solving is the message from the stderr.log
    Code:
    378 close failed: [Errno 9] Bad file descriptor
    You don't happen to have an idea what this is trying to tell me? For my understanding this normally tries to tell me, that a file is not correctly accessible via the file system. But this can't be the point here and why is it a failure during a closure?

    Nonetheless I will try to get to the bottom of this problem and first of all I will test if my lsws installation is capable of serving another python script.
  10. Joe Jacobs

    Joe Jacobs New Member

  11. mistwang

    mistwang LiteSpeed Staff

    you should enable debug logging, also check stderr.log
  12. Joe Jacobs

    Joe Jacobs New Member

    these are the errors generated for 1 request

    stderr.log:
    Code:
    2009-02-05 23:27:34.110 close failed: [Errno 9] Bad file descriptor
    2009-02-05 23:27:34.169 close failed: [Errno 9] Bad file descriptor
    2009-02-05 23:27:34.277 close failed: [Errno 9] Bad file descriptor
    2009-02-05 23:27:34.396 close failed: [Errno 9] Bad file descriptor
    
    trac vhost error log:
    Code:
    2009-02-05 23:28:04.067 [INFO] [ipaddress:15538-1#trac] ExtConn timed out while processing
    2009-02-05 23:28:04.067 [INFO] [ipaddress:15538-1#trac] connection to [uds://tmp/lshttpd/pytwitfcgi.sock] on request #0, Connection timed out!
    2009-02-05 23:28:04.067 [NOTICE] [ipaddress:15538-1#trac] oops! 503 Service Unavailable
    2009-02-05 23:28:04.067 [NOTICE] [ipaddress:15538-1#trac] Content len: 0, Request line:
    GET /pytwit/ HTTP/1.1
    
    any ideas?
  13. mistwang

    mistwang LiteSpeed Staff

    PM me a temp root login and LSWS web console login, I can take a look.
  14. Joe Jacobs

    Joe Jacobs New Member

    details pm-ed to you

Share This Page