Debugging getmail delivery errors

[Stephen Finucane]

On Sun, 2019-06-16 at 18:13 +0100, Christopher Baines wrote:
> Christopher Baines <mail at cbaines.net> writes:
> 
> > Christopher Baines <mail at cbaines.net> writes:
> > 
> > > The Patchwork instance [1] I've been playing with has been working quite
> > > nicely, but recently getmail doesn't want to stay up, as I think it's
> > > having problems delivering a specific email (this is from the getmail
> > > logs):
> > > 
> > >   Delivery error (command patchwork-admin 25561 error (1, ))
> > >     msg 517/525 (5397 bytes), delivery error (command patchwork-admin 25561 error (1, ))
> > > 
> > > Any tips on debugging this? I haven't even worked out what message it
> > > might be yet, and I'm not sure if the parsemail command does any
> > > logging?
> > 
> > To answer my own question, eventually I worked out that Getmail logs
> > more detailed information to the syslog, including the message id.
> > 
> > Comparing this to the Maildir on the mailserver, I was able to identify
> > the email causing the issue.
> > 
> > I then manually ran the patchwork-admin parsemail command. Initially it
> > gave no output, but running it with DEBUG=True in the Django settings
> > did output the error to the console. I think when DEBUG=False, the error
> > is sent by email (with the default logging configuration).
> > 
> > I've now got a stacktrace at least, and it seems the error relates to a
> > database constraint...

Thanks for looking into this and not getting to it sooner myself. If
you have any additional notes on how you debugged this issue and
wouldn't mind dumping them into an email or Etherpad somewhere, I'd be
happy to whip up an official debugging document. That would make for
two good things to come out of this unfortunate affair (the other being
your hopefully now-working deployment).

> Ah, and it looks like there is an unreleased change that'll resolve this
> issue [1] :)

I'll look into backporting this an including it in a future v2.1.4
patch. Not sure why I didn't do it the first day, to be honest.

Cheers,
Stephen

> 1: https://github.com/getpatchwork/patchwork/commit/300ba3eb283ab1af3dc5924e5ed540159c3ee0bc
> 
> > Error when parsing incoming email
> > Traceback (most recent call last):
> >   File "/gnu/store/6n0kq26d2l9wgakfd0grk2lg9dss3n44-python-django-1.11.20/lib/python3.7/site-packages/django/db/backends/utils.py", line 64, in execute
> >     return self.cursor.execute(sql, params)
> > psycopg2.IntegrityError: duplicate key value violates unique constraint "patchwork_comment_msgid_patch_id_e8c15ff3_uniq"
> > DETAIL:  Key (msgid, submission_id)=(<20190613074916.GB1145 at macbook41>, 14273) already exists.
> > 
> > 
> > The above exception was the direct cause of the following exception:
> > 
> > Traceback (most recent call last):
> >   File "/gnu/store/ipj0q47w6gwyg95sj6jcxy2civlrwpdc-patchwork-2.1.2/lib/python3.7/site-packages/patchwork/management/commands/parsemail.py", line 79, in handle
> >     result = parse_mail(mail, options['list_id'])
> >   File "/gnu/store/ipj0q47w6gwyg95sj6jcxy2civlrwpdc-patchwork-2.1.2/lib/python3.7/site-packages/patchwork/parser.py", line 1172, in parse_mail
> >     comment.save()
> >   File "/gnu/store/ipj0q47w6gwyg95sj6jcxy2civlrwpdc-patchwork-2.1.2/lib/python3.7/site-packages/patchwork/models.py", line 614, in save
> >     super(Comment, self).save(*args, **kwargs)
> >   File "/gnu/store/ipj0q47w6gwyg95sj6jcxy2civlrwpdc-patchwork-2.1.2/lib/python3.7/site-packages/patchwork/models.py", line 356, in save
> >     super(EmailMixin, self).save(*args, **kwargs)
> >   File "/gnu/store/6n0kq26d2l9wgakfd0grk2lg9dss3n44-python-django-1.11.20/lib/python3.7/site-packages/django/db/models/base.py", line 808, in save
> >     force_update=force_update, update_fields=update_fields)
> >   File "/gnu/store/6n0kq26d2l9wgakfd0grk2lg9dss3n44-python-django-1.11.20/lib/python3.7/site-packages/django/db/models/base.py", line 838, in save_base
> >     updated = self._save_table(raw, cls, force_insert, force_update, using, update_fields)
> >   File "/gnu/store/6n0kq26d2l9wgakfd0grk2lg9dss3n44-python-django-1.11.20/lib/python3.7/site-packages/django/db/models/base.py", line 924, in _save_table
> >     result = self._do_insert(cls._base_manager, using, fields, update_pk, raw)
> >   File "/gnu/store/6n0kq26d2l9wgakfd0grk2lg9dss3n44-python-django-1.11.20/lib/python3.7/site-packages/django/db/models/base.py", line 963, in _do_insert
> >     using=using, raw=raw)
> >   File "/gnu/store/6n0kq26d2l9wgakfd0grk2lg9dss3n44-python-django-1.11.20/lib/python3.7/site-packages/django/db/models/manager.py", line 85, in manager_method
> >     return getattr(self.get_queryset(), name)(*args, **kwargs)
> >   File "/gnu/store/6n0kq26d2l9wgakfd0grk2lg9dss3n44-python-django-1.11.20/lib/python3.7/site-packages/django/db/models/query.py", line 1079, in _insert
> >     return query.get_compiler(using=using).execute_sql(return_id)
> >   File "/gnu/store/6n0kq26d2l9wgakfd0grk2lg9dss3n44-python-django-1.11.20/lib/python3.7/site-packages/django/db/models/sql/compiler.py", line 1112, in execute_sql
> >     cursor.execute(sql, params)
> >   File "/gnu/store/6n0kq26d2l9wgakfd0grk2lg9dss3n44-python-django-1.11.20/lib/python3.7/site-packages/django/db/backends/utils.py", line 79, in execute
> >     return super(CursorDebugWrapper, self).execute(sql, params)
> >   File "/gnu/store/6n0kq26d2l9wgakfd0grk2lg9dss3n44-python-django-1.11.20/lib/python3.7/site-packages/django/db/backends/utils.py", line 64, in execute
> >     return self.cursor.execute(sql, params)
> >   File "/gnu/store/6n0kq26d2l9wgakfd0grk2lg9dss3n44-python-django-1.11.20/lib/python3.7/site-packages/django/db/utils.py", line 94, in __exit__
> >     six.reraise(dj_exc_type, dj_exc_value, traceback)
> >   File "/gnu/store/6n0kq26d2l9wgakfd0grk2lg9dss3n44-python-django-1.11.20/lib/python3.7/site-packages/django/utils/six.py", line 685, in reraise
> >     raise value.with_traceback(tb)
> >   File "/gnu/store/6n0kq26d2l9wgakfd0grk2lg9dss3n44-python-django-1.11.20/lib/python3.7/site-packages/django/db/backends/utils.py", line 64, in execute
> >     return self.cursor.execute(sql, params)
> > django.db.utils.IntegrityError: duplicate key value violates unique constraint "patchwork_comment_msgid_patch_id_e8c15ff3_uniq"
> > DETAIL:  Key (msgid, submission_id)=(<20190613074916.GB1145 at macbook41>, 14273) already exists.
> 
> _______________________________________________
> Patchwork mailing list
> Patchwork at lists.ozlabs.org
> https://lists.ozlabs.org/listinfo/patchwork