Persistent issue...

[John Szakmeister]

On Wed, May 4, 2011 at 8:04 AM, Andrew Bennetts
<andrew.bennetts at canonical.com> wrote:
> John Szakmeister wrote:
> […]
>> > That is an odd error.  The bzr log from the server would be the first
>> > place I'd look, it should log a traceback for that error.  (The client
>> > logs don't say much except that this error occurred part-way through a
>> > get_stream response body, which doesn't give many clues.)
>>
>> Tried looking there, but I honestly don't see anything.  Nothing in
>> the server logs themselves.  And nothing in .bzr.log... at least not
>> from any recent moment in history.   I do have enable_logging=False in
>> wsgi.make_app() because Apache screams about things being emitted on
>> stdout.  Perhaps that's part of the problem?
>
> Yes, that's a problem.  Although I think bzr's logging only writes to
> stderr (for sufficiently severe messages), not stdout?

Here's what mod_wsgi had to say:
[Thu May 05 05:28:09 2011] [error] [client 192.168.254.224] mod_wsgi
(pid=22232): Exception occurred processing WSGI script
'/srv/wsgi-scripts/bzr.wsgi'.
[Thu May 05 05:28:09 2011] [error] [client 192.168.254.224] Traceback
(most recent call last):
[Thu May 05 05:28:09 2011] [error] [client 192.168.254.224]   File
"/srv/wsgi-scripts/bzr.wsgi", line 66, in application
[Thu May 05 05:28:09 2011] [error] [client 192.168.254.224]
enable_logging=True)
[Thu May 05 05:28:09 2011] [error] [client 192.168.254.224]   File
"/var/lib/python-support/python2.5/bzrlib/transport/http/wsgi.py",
line 48, in make_app
[Thu May 05 05:28:09 2011] [error] [client 192.168.254.224]
bzrlib.trace.enable_default_logging()
[Thu May 05 05:28:09 2011] [error] [client 192.168.254.224]   File
"/var/lib/python-support/python2.5/bzrlib/trace.py", line 322, in
enable_default_logging
[Thu May 05 05:28:09 2011] [error] [client 192.168.254.224]
term_encoding = osutils.get_terminal_encoding()
[Thu May 05 05:28:09 2011] [error] [client 192.168.254.224]   File
"/var/lib/python-support/python2.5/bzrlib/osutils.py", line 454, in
get_terminal_encoding
[Thu May 05 05:28:09 2011] [error] [client 192.168.254.224]
output_encoding = getattr(sys.stdout, 'encoding', None)
[Thu May 05 05:28:09 2011] [error] [client 192.168.254.224] IOError:
sys.stdout access restricted by mod_wsgi

It apparently doesn't like the fact that we touch sys.stdout at all
(at least inspecting it's attributes).  Something in that path is also
looking a sys.stdin, which also causes a traceback.  I've put in the
directives to not restrict stdout and stdin in that way, and things
seem to behave, but it'd be nice if Bazaar wouldn't do that at all.
Depending on how my day goes, I may create a patch for that.

> If you can't use enable_logging=True, then take a look at what
> bzrlib.trace.enable_default_logging does and do a modified version.  The
> short answer is:
>
>    log_file = open('/var/log/bzr/trace.log', 'a')
>    bzrlib.trace.push_log_file(log_file)

I do get something, but not much at the moment:

Thu 2011-05-05 06:00:38 -0400

Thu 2011-05-05 06:00:38 -0400

That's just doing a pull against the repo (which did not fail with the
error mentioned earlier in the thread because I had to restart the
server).  I'll keep things configured this way for a while and see
what we can find out.

Thanks again Andrew!

-John