fcgi fails for first request

[keturn <kevin@…>]

lighttpd-1.4.13, trac 0.10.3.1

I have lighttpd starting trac with a configuration like this:

    fastcgi.server = ("/trac" =>
        ("trac" =>
            ("socket" => "/tmp/trac.socket",
             "bin-path" => "/usr/share/trac/cgi-bin/trac.fcgi",
             "check-local" => "disable",
             "bin-environment" =>
                 ("TRAC_ENV" => "/home/trac/trac",
                  "PYTHON_EGG_CACHE" => "/home/trac/egg-cache")
            )))

The first time I try to load trac, lighttpd returns 500 and something like this in error.log:

2007-08-21 17:38:33: (mod_fastcgi.c.2879) got proc: pid: 5748 socket: unix:/tmp/trac.socket-3 load: 1
2007-08-21 17:38:34: (mod_fastcgi.c.2409) unexpected end-of-file (perhaps the fastcgi process died): pid: 5748 socket: unix:/tmp/trac.socket-3
2007-08-21 17:38:34: (mod_fastcgi.c.3194) response not received, request sent: 1229 on socket: unix:/tmp/trac.socket-3 for /trac , closing connection
2007-08-21 17:38:34: (mod_fastcgi.c.1490) released proc: pid: 5748 socket: unix:/tmp/trac.socket-3 load: 0

But the fcgi proccess did not die, as lighttpd speculates.

cranking up the debug level in trac.web._fcgi gave me this, but it doesn't appear to look any different for failing vs succeeding requests:

Aug 21 17:38:34 fcgi: read: fd = 2, type = 1, requestId = 1, contentLength = 8
Aug 21 17:38:34 fcgi: read: fd = 2, type = 4, requestId = 1, contentLength = 1189
Aug 21 17:38:34 fcgi: read: fd = 2, type = 4, requestId = 1, contentLength = 0
Aug 21 17:38:34 fcgi: write: fd = 2, type = 6, requestId = 1, contentLength = 151
Aug 21 17:38:34 fcgi: write: fd = 2, type = 6, requestId = 1, contentLength = 4057
Aug 21 17:38:34 fcgi: protocolStatus = 0, appStatus = 0
Aug 21 17:38:34 fcgi: write: fd = 2, type = 6, requestId = 1, contentLength = 0
Aug 21 17:38:34 fcgi: write: fd = 2, type = 3, requestId = 1, contentLength = 8
Aug 21 17:38:34 fcgi: end_request: flags = 0

trac.log doesn't seem to report any errors, saying just

2007-08-21 17:38:34,519 Trac[loader] DEBUG: Loading egg plugin openidauth.auth from /usr/lib/python2.5/site-packages/OpenIDAuth-0.1dev-py2.5.egg
2007-08-21 17:38:34,627 Trac[loader] DEBUG: Loading egg plugin openidauth.auth from /home/trac/trac/plugins/OpenIDAuth-0.1dev-py2.5.egg

The error seems to happen once for each trac.fcgi spawned. Subsequent requests to that fcgi server work fine.

Is there anywhere I can get more logging to find out why lighttpd got an unexpected EoF?

(also reported as http://trac.edgewall.org/ticket/5907 )

[jan]

The trac process seems to die before it sends a response.

Check that the PID is still running after the error is reported.

[keturn <kevin@…>]

The PID is indeed still running after the error.

[umito]

This problem is not limited to one person, as I have the same issue.

Using trac with lighttpd on a fresh ubuntu 7.10 server install, trac 0.10.4 & lighttpd 1.4.18 .

First request fails after starting the lighttpd server. After a F5 in the browser the page loads, and all the pages after this.

error.log from lighttpd:

 2008-01-31 17:02:08: (log.c.75) server started 
2008-01-31 17:02:13: (mod_fastcgi.c.2480) unexpected end-of-file (perhaps the fastcgi process died): pid: 6162 socket: unix:/tmp/trac-fastcgi-first.sock-3 
2008-01-31 17:02:13: (mod_fastcgi.c.3272) response not received, request sent: 949 on socket: unix:/tmp/trac-fastcgi-first.sock-3 for /first , closing connection 

lighttpd.conf

fastcgi.server = ("/first" =>
                   ("first" =>
                    ("socket" => "/tmp/trac-fastcgi-first.sock",
                     "bin-path" => "/usr/share/trac/cgi-bin/trac.fcgi",
                     "check-local" => "disable",
                     "bin-environment" =>
                       ("TRAC_ENV" => "/home/Peter/Data/trac/first")
                    )
                  )                 
                )