Merge lp:~gary/launchpad/bug662912 into lp:launchpad

[Gary Poster]

Add diagnostics for bug 662912

This branch adds diagnostics to approach bug 662912. As noted in my comment #1 for that bug, I have a hypothesis that this is caused by a rejected hostname. This branch adds log messages for that case, plus all other cases that generate a 404 other than a simple missing file (_eb_getFileAlias in c/librarian/web.py).

It also puts the message about upstream librarians in the logfile so it is easier to see that the configuration is as expected.

It also creates a log file destination for development so developers can look at the locally-generated logs.

[Robert Collins (lifeless)]

The development target for logs is unneeded and harmful, please don't
do that. My librarian branch already captures the log per-test and
includes in the test details.

[Julian Edwards (julian-edwards)]

The test output won't change though will it? You need to change the testrunner config for that.

Everything else looks good although as I said on IRC, consider using addSystemEventTrigger instead of callWhenRunning, but that's optional.

review: Approve

[Gary Poster (gary)]

Thank you for the review and comments.

Robert approved the librarian change on IRC.

I looked at the addSystemEventTrigger approach. The behavior is identical to the callWhenRunning version. It's a bit longer spelling, but I guess it is a bit easier to understand the intent. That's a compelling argument, so I made the change.

Thanks again,

Gary

=== modified file '.bzrignore'
--- .bzrignore	2010-10-18 21:53:28 +0000
+++ .bzrignore	2010-10-25 22:09:50 +0000
@@ -80,3 +80,4 @@
 *.pt.py
 .project
 .pydevproject
+librarian.log

=== modified file 'configs/development/launchpad-lazr.conf'
--- configs/development/launchpad-lazr.conf	2010-10-21 03:22:06 +0000
+++ configs/development/launchpad-lazr.conf	2010-10-25 22:09:50 +0000
@@ -175,6 +175,7 @@
 [librarian_server]
 root: /var/tmp/fatsam
 launch: True
+logfile: librarian.log
 
 [malone]
 bugmail_error_from_address: [e-mail]

=== modified file 'daemons/librarian.tac'
--- daemons/librarian.tac	2010-10-20 18:43:29 +0000
+++ daemons/librarian.tac	2010-10-25 22:09:50 +0000
@@ -9,6 +9,8 @@
 from meliae import scanner
 
 from twisted.application import service, strports
+from twisted.internet import reactor
+from twisted.python import log
 from twisted.web import server
 
 from canonical.config import config, dbconfig
@@ -29,10 +31,14 @@
 if config.librarian_server.upstream_host:
     upstreamHost = config.librarian_server.upstream_host
     upstreamPort = config.librarian_server.upstream_port
-    print 'Using upstream librarian http://%s:%d' % (
-        upstreamHost, upstreamPort)
+    reactor.addSystemEventTrigger(
+        'before', 'startup', log.msg,
+        'Using upstream librarian http://%s:%d' %
+        (upstreamHost, upstreamPort))
 else:
     upstreamHost = upstreamPort = None
+    reactor.addSystemEventTrigger(
+        'before', 'startup', log.msg, 'Not using upstream librarian')
 
 application = service.Application('Librarian')
 librarianService = service.IServiceCollection(application)

=== modified file 'lib/canonical/librarian/web.py'
--- lib/canonical/librarian/web.py	2010-09-24 15:40:49 +0000
+++ lib/canonical/librarian/web.py	2010-10-25 22:09:50 +0000
@@ -7,6 +7,7 @@
 import time
 from urlparse import urlparse
 
+from twisted.python import log
 from twisted.web import resource, static, util, server, proxy
 from twisted.internet.threads import deferToThread
 
@@ -52,6 +53,8 @@
         try:
             aliasID = int(name)
         except ValueError:
+            log.msg(
+                "404: alias is not an int: %r" % (name,))
             return fourOhFour
 
         return LibraryFileAliasResource(self.storage, aliasID,
@@ -76,6 +79,8 @@
             try:
                 self.aliasID = int(filename)
             except ValueError:
+                log.msg(
+                    "404 (old URL): alias is not an int: %r" % (name,))
                 return fourOhFour
             filename = request.postpath[0]
 
@@ -95,6 +100,9 @@
                 netloc = netloc[:netloc.find(':')]
             expected_hostname = 'i%d.restricted.%s' % (self.aliasID, netloc)
             if expected_hostname != hostname:
+                log.msg(
+                    '404: expected_hostname != hostname: %r != %r' %
+                    (expected_hostname, hostname))
                 return fourOhFour
 
         token = request.args.get('token', [None])[0]
@@ -128,6 +136,9 @@
         # a crude form of access control (stuff we care about can have
         # unguessable names effectively using the filename as a secret).
         if dbfilename.encode('utf-8') != filename:
+            log.msg(
+                "404: dbfilename.encode('utf-8') != filename: %r != %r"
+                % (dbfilename.encode('utf-8'), filename))
             return fourOhFour
 
         if not restricted: