Comment 3 for bug 1820552

Revision history for this message
Colin Watson (cjwatson) wrote :

Before fix:

2019-03-18 17:52:45 DEBUG Cronscript control file not found at file:cronscripts.ini
2019-03-18 17:52:45 INFO Creating lockfile: /var/lock/launchpad-process-mail.lock
2019-03-18 17:52:51 INFO Opening the mail box.
2019-03-18 17:52:51 INFO Processing mail /var/tmp/launchpad_script_mailbox/test-signed
2019-03-18 17:52:51 DEBUG Uploaded mail to librarian http://dogfood.launchpadlibrarian.net/412901065/a612f1ac-49a6-11e9-ad0b-e83935260ce2.txt
2019-03-18 17:52:51 DEBUG processing mail from 'Colin Watson <email address hidden>' message-id '<email address hidden>'
2019-03-18 17:52:51 DEBUG no rules relevant to 'mail.dkim_authentication.disabled'
2019-03-18 17:52:51 INFO Attempting DKIM authentication of message id='<email address hidden>' from='Colin Watson <email address hidden>' sender=None
2019-03-18 17:52:51 INFO DKIM verification result: trusted=False
2019-03-18 17:52:51 DEBUG DKIM debug log:
2019-03-18 17:52:51 DEBUG attempt gpg authentication for <Person at 0x7f5d225fdf10 cjwatson (Colin Watson)>
2019-03-18 17:52:51 ERROR An exception was raised inside the handler:
http://dogfood.launchpadlibrarian.net/412901065/a612f1ac-49a6-11e9-ad0b-e83935260ce2.txt
Traceback (most recent call last):
  File "/srv/launchpad.net/codelines/current/lib/lp/services/mail/incoming.py", line 439, in handleMail
    signature_timestamp_checker)
  File "/srv/launchpad.net/codelines/current/lib/lp/services/mail/incoming.py", line 524, in handle_one_mail
    principal = authenticateEmail(mail, signature_timestamp_checker)
  File "/srv/launchpad.net/codelines/current/lib/lp/services/mail/incoming.py", line 278, in authenticateEmail
    mail, principal, person, signature_timestamp_checker)
  File "/srv/launchpad.net/codelines/current/lib/lp/services/mail/incoming.py", line 315, in _gpgAuthenticateEmail
    canonicalise_line_endings(mail.signedContent), signature)
  File "/srv/launchpad.net/codelines/current/lib/lp/services/gpg/handler.py", line 250, in getVerifiedSignature
    key = self.retrieveKey(sig.fpr)
  File "/srv/launchpad.net/codelines/current/lib/lp/services/gpg/handler.py", line 458, in retrieveKey
    pubkey = self._getPubKey(fingerprint)
  File "/srv/launchpad.net/codelines/current/lib/lp/services/gpg/handler.py", line 547, in _getPubKey
    return self._grabPage('get', fingerprint)
  File "/srv/launchpad.net/codelines/current/lib/lp/services/gpg/handler.py", line 577, in _grabPage
    return urlfetch(url).content
  File "/srv/launchpad.net/codelines/current/lib/lp/services/timeout.py", line 399, in urlfetch
    return URLFetcher().fetch(url, **request_kwargs)
  File "/srv/launchpad.net/codelines/current/lib/lp/services/timeout.py", line 217, in call_with_timeout
    timeout = self.timeout
  File "/srv/launchpad.net/codelines/current/lib/lp/services/timeout.py", line 167, in __get__
    "no timeout set and there is no default timeout function.")
AssertionError: no timeout set and there is no default timeout function.
2019-03-18 17:52:51 INFO OOPS-edb8dc4cbfd1af8b52ac43b3ef9c1be6
2019-03-18 17:52:51 INFO error processing mail: Unhandled exception
2019-03-18 17:52:51 INFO oops OOPS-510ae3e17ea2d45d9905b7ae0b560407
2019-03-18 17:52:52 INFO Closing the mail box.
2019-03-18 17:52:52 DEBUG process-mail ran in 0.946924s (excl. load & lock)
2019-03-18 17:52:52 DEBUG Removing lock file: /var/lock/launchpad-process-mail.lock

After fix:

2019-03-18 17:59:34 DEBUG Cronscript control file not found at file:cronscripts.ini
2019-03-18 17:59:34 INFO Creating lockfile: /var/lock/launchpad-process-mail.lock
2019-03-18 17:59:39 INFO Opening the mail box.
2019-03-18 17:59:39 INFO Processing mail /var/tmp/launchpad_script_mailbox/test-signed
2019-03-18 17:59:39 DEBUG Uploaded mail to librarian http://dogfood.launchpadlibrarian.net/412901067/9981bc42-49a7-11e9-ad0b-e83935260ce2.txt
2019-03-18 17:59:39 DEBUG processing mail from 'Colin Watson <email address hidden>' message-id '<email address hidden>'
2019-03-18 17:59:39 DEBUG no rules relevant to 'mail.dkim_authentication.disabled'
2019-03-18 17:59:39 INFO Attempting DKIM authentication of message id='<email address hidden>' from='Colin Watson <email address hidden>' sender=None
2019-03-18 17:59:39 INFO DKIM verification result: trusted=False
2019-03-18 17:59:39 DEBUG DKIM debug log:
2019-03-18 17:59:39 DEBUG attempt gpg authentication for <Person at 0x7fce0929ad50 cjwatson (Colin Watson)>
2019-03-18 17:59:39 INFO Starting new HTTP connection (1): keyserver.internal
2019-03-18 17:59:39 DEBUG "GET /pks/lookup?fingerprint=on&op=get&search=0x393587D97D86500B HTTP/1.1" 200 None
2019-03-18 17:59:40 DEBUG got signature <lp.services.gpg.handler.PymeSignature object at 0x7fce0951e9d0>
2019-03-18 17:59:40 DEBUG gpg-signed message by key u'AC0A4FF12611B6FCCF01C111393587D97D86500B'
2019-03-18 17:59:40 WARNING No X-Launchpad-Original-To header was present in email: http://dogfood.launchpadlibrarian.net/412901067/9981bc42-49a7-11e9-ad0b-e83935260ce2.txt
2019-03-18 17:59:40 INFO OOPS-e36dd7b2f212f5ec9b4e954bdc6170af
2019-03-18 17:59:40 DEBUG mail was originally to: ['<email address hidden>']
2019-03-18 17:59:42 INFO Closing the mail box.
2019-03-18 17:59:42 DEBUG process-mail ran in 2.666249s (excl. load & lock)
2019-03-18 17:59:42 DEBUG Removing lock file: /var/lock/launchpad-process-mail.lock