LSWS 3.0RC2 and trac-fcgi

Erg · Feb 21, 2007

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.

mistwang · Feb 21, 2007

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.

Erg · Feb 21, 2007

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'?

Have I missed something crucial?

mistwang · Feb 21, 2007

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.

Erg · Feb 21, 2007

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?

mistwang · Feb 21, 2007

Yes, you downgrade to 2.2.6 release by running the installer then select "upgrade".

There is another tutorial you can follow at the end of
http://www.deveiate.org/projects/BlueCloth/wiki/TracFastCgi

There might be configuration errors, please double check your configurations.

mistwang · Feb 21, 2007

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

Erg · Feb 21, 2007

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

Erg · Feb 21, 2007

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.

Joe Jacobs · Feb 4, 2009

OK I know this is a really old ticket but I'm having the same problems. I've tested my trac install with tracd and I've followed this tutorial

http://www.litespeedtech.com/support/wiki/doku.php?id=litespeed_wiki:trac_fcgi_python

but I always get a 503 error every time I try to load the trac url. any idea how it was solved/what the issue was?

mistwang · Feb 5, 2009

you should enable debug logging, also check stderr.log

Joe Jacobs · Feb 5, 2009

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?

mistwang · Feb 6, 2009

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

Joe Jacobs · Feb 6, 2009

details pm-ed to you

LSWS 3.0RC2 and trac-fcgi

Erg

Member

mistwang

LiteSpeed Staff

Erg

Member

mistwang

LiteSpeed Staff

Erg

Member

mistwang

LiteSpeed Staff

mistwang

LiteSpeed Staff

Erg

Member

Erg

Member

Joe Jacobs

Member

mistwang

LiteSpeed Staff

Joe Jacobs

Member

mistwang

LiteSpeed Staff

Joe Jacobs

Member