Re: 'premature end of script headers' error

Bernhard,

I tracked the problem down to an error in my detector. It was trying to write to a file in /tmp as apache but the file was owned by me. Removing the write in my detector fixed the problem.

The exception that was generated was this:

2013-12-13 11:41:16,918 DEBUG Caught exception <type 'exceptions.IOError'>: [Errno 13] Permission denied: '/tmp/nic.log'

Note that this is an IOError exception. If you look at the HG source code in roundup/cgi/client.py you can find the inner_main method. Here is a skeleton of that method:

     def inner_main(self):
...
         try:
...
             try:
...
                 html = self.handle_action()
...
             except IOError:
                 # IOErrors here are due to the client disconnecting before
                 # receiving the reply.
                 pass
...

The detector got called about 7 levels down from handle_action(). Note that inner_main() ignores IOError exceptions. If something were written to the log in this except clause that would have saved me a lot of time. One of the first things I did was to turn on DEBUG logging. If I had seen the error in the log I would have been able to isolate the problem immediately. I suggest changing the above 'except IOError' clause to the following:

             except IOError as e:
                 # IOErrors here are due to the client disconnecting before
                 # receiving the reply.
                 # They can also be caused by detector errors.
                 import traceback
                 tb = traceback.format_exc()
                 lg = logging.getLogger('roundup')
                 lg.debug('Caught exception %s: %s\n%s' % (str(type(e)), e, tb))

[I shortened 'logger' to 'lg' to meet the 80 character line length restriction.] Of course, sending an email to the roundup admin is another approach. However for this case, the roundup admin shouldn't be bothered with client disconnect exceptions. I think logging it is the better approach.

I put the above IOError except clause code in my roundup/cgi/client.py (with the error put back in the detector) and got this in the log file:

2013-12-13 13:39:36,690 DEBUG Caught exception <type 'exceptions.IOError'>: [Errno 13] Permission denied: '/tmp/nic.log'
Traceback (most recent call last):
   File "/usr/local/lib/python2.7/site-packages/roundup/cgi/client.py", line 479, in inner_main
     html = self.handle_action()
   File "/usr/local/lib/python2.7/site-packages/roundup/cgi/client.py", line 1246, in handle_action
     return action_klass(self).execute()
   File "/usr/local/lib/python2.7/site-packages/roundup/cgi/actions.py", line 40, in execute
     return self.handle()
   File "/usr/local/lib/python2.7/site-packages/roundup/cgi/actions.py", line 630, in handle
     message = self._editnodes(props, links)
   File "/usr/local/lib/python2.7/site-packages/roundup/cgi/actions.py", line 451, in _editnodes
     props = self._changenode(cn, nodeid, props)
   File "/usr/local/lib/python2.7/site-packages/roundup/cgi/actions.py", line 513, in _changenode
     ret =  cl.set(nodeid, **props)
   File "/usr/local/lib/python2.7/site-packages/roundup/backends/rdbms_common.py", line 1723, in set
     self.fireReactors('set', nodeid, oldvalues)
   File "/usr/local/lib/python2.7/site-packages/roundup/hyperdb.py", line 1263, in fireReactors
     react(self.db, self, nodeid, oldvalues)
   File "/var/www/html/systems/detectors/nic_collector.py", line 72, in collector
     write_log('setting %s to %s' % (nic_fields[nic_field], SEP + SEP.join(new_values) + SEP))
   File "/var/www/html/systems/detectors/nic_collector.py", line 41, in write_log
     logfile = open('/tmp/nic.log', 'a')
IOError: [Errno 13] Permission denied: '/tmp/nic.log'

Tom Ekberg
Senior Computer Specialist, Lab Medicine
University of Washington Medical Center
1959 NE Pacific St, MS 357110
Seattle WA 98195
cell: (253) 561-2509
email: [email protected]

On Thu, 12 Dec 2013, Bernhard Reiter wrote:

> Tom,
>
> On Wednesday 11 December 2013 at 23:08:52, Tom Ekberg wrote:
>> Thank you for your response. I can find no traceback. None in the log file,
>> nor the apache ssl_error_log which is where I have seen stack traces
>> before. I peppered my systems tracker's roundup.cgi with more log messages
>> - there is no python error at that level.  I made sure to catch any
>> exception.
>
> hmmm, yes this is strange, but it was important to check.
>
>> I wrote a wrapper class (snarfed most of the code from
>> http://code.activestate.com/recipes/577555-object-wrapper-class/) to have
>> HTML text go to the log file as well as to sys.stdout. When I'm displaying
>> the issue detail (issue.item.html) I see lots of HMTL in the log file. When
>> I change a simple attribute and press the 'submit' button I see the SQL
>> statements that I saw before, but no HTML text. This is why apache is
>> complaining about the script headers - there aren't any. I'll have to dig
>> deeper in the roundup/cgi/* code to determine where the error is. I'm
>> thinking that something like this happens:
>>
>>    create DB transaction
>>    do a lot of selects
>>    perform update and inserts
>>    some unknown error happens
>>    transaction is aborted
>
> Yes, this seems to be a good starting hypothesis.
> You could try to verify it maybe by the database side,
> if there is more diagnostics, it may tell you if the transaction was actually
> aborted.
>
>> I'm pretty certain the database itself isn't the problem. I modified the
>> same issue's attribute with roundup-admin and it works fine. I also did the
>> UPDATE cut/pasted from the log using psql (the postgres command line) while
>> logged as the user I'm using in the tracker. That also works fine.
>
> It still could be the database because of timing or so, but I also would try
> to falsify other hypothesis first.
>
>> If you think I'm going down the wrong path (digging into the roundup/cgi/*
>> code) I'd appreciate your input.
>
> The result probably comes out of the db layer, maybe that is another place
> where you can try to detect and track the infection (bad behaviour
> propagating).
>
> Let us know about your progress. ;)
> Bernhard
>
> -- 
> www.intevation.de/~bernhard (CEO)    www.fsfe.org (Founding GA Member)
> Intevation GmbH, Osnabrück, Germany; Amtsgericht Osnabrück, HRB 18998
> Owned and run by Frank Koormann, Bernhard Reiter, Dr. Jan-Oliver Wagner
>

------------------------------------------------------------------------------
Rapidly troubleshoot problems before they affect your business. Most IT 
organizations don't have a clear picture of how application performance 
affects their revenue. With AppDynamics, you get 100% visibility into your 
Java,.NET, & PHP application. Start your 15-day FREE TRIAL of AppDynamics Pro!
http://pubads.g.doubleclick.net/gampad/clk?id=84349831&iu=/4140/ostg.clktrk

_______________________________________________
Roundup-users mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/roundup-users