PostgreSQL database package update broke Spam Quarantine?

[JellyBeanEnjoyer]

Noticed a spam message had gone AWOL (not showing up in Spam Quarantine). Referring to syslog at the time of evaluation:

May 13 11:34:57 prox postfix/smtpd[10630]: connect from my.home.mx[10.10.77.135]
May 13 11:34:57 prox postfix/smtpd[10630]: D7C2B80B00: client=my.home.mx[10.10.77.135]
May 13 11:34:57 prox postfix/cleanup[10634]: D7C2B80B00: message-id=<7af52ca956518851428a1a1f3.00742a19f4.20230513013415.ac6ec169d3.9ef56360@mail177.suw121.mcdlv.net>
May 13 11:34:57 prox postfix/qmgr[843]: D7C2B80B00: from=<bounce-mc.us7_150292902.15551913-00742a19f4@mail177.suw121.mcdlv.net>, size=50733, nrcpt=1 (queue active)
May 13 11:34:57 prox postfix/smtpd[10630]: disconnect from my.home.mx[10.10.77.135] ehlo=2 starttls=1 mail=1 rcpt=1 data=1 quit=1 commands=7
May 13 11:34:57 prox pmg-smtp-filter[6090]: 2023/05/13-11:34:57 CONNECT TCP Peer: "[127.0.0.1]:51166" Local: "[127.0.0.1]:10024"
May 13 11:34:57 prox pmg-smtp-filter[6090]: 60B53645EE941E880D: new mail message-id=<7af52ca956518851428a1a1f3.00742a19f4.20230513013415.ac6ec169d3.9ef56360@mail177.suw121.mcdlv.net>
May 13 11:35:00 prox pmg-smtp-filter[6090]: 60B53645EE941E880D: SA score=3/5 time=2.782 bayes=undefined autolearn=no autolearn_force=no hits=DKIMWL_WL_MED(-0.001),DKIM_SIGNED(0.1),DKIM_VALID(-0.1),HEADER_FROM_DIFFERENT_DOMAINS(0.25),HTML_MESSAGE(0.001),KAM_BODY_MARKETINGBL_PCCC(0.001),KAM_MARKETINGBL_PCCC(1),MIME_QP_LONG_LINE(0.001),RCVD_IN_DNSWL_NONE(-0.0001),RCVD_IN_HOSTKARMA_BL(1.5),RCVD_IN_MSPIKE_H2(-0.001),SPF_HELO_PASS(-0.001),T_SCC_BODY_TEXT_LINE(-0.01),URIBL_GREY(1.084)
May 13 11:35:00 prox pmg-smtp-filter[6090]: DBD::Pg::st execute failed: FATAL:  terminating connection due to administrator command
server closed the connection unexpectedly
    This probably means the server terminated abnormally
    before or while processing the request. at /usr/share/perl5/PMG/RuleDB/Spam.pm line 149, <GEN25> line 1157.
May 13 11:35:00 prox pmg-smtp-filter[6090]: ERROR: DBD::Pg::db do failed: no connection to the server at /usr/share/perl5/PMG/MailQueue.pm line 206, <GEN25> line 1157.
May 13 11:35:00 prox pmg-smtp-filter[6090]: 60B53645EE941E880D: moved mail for <my@email.com> to spam quarantine - 63A5F645EE944C47D8 (rule: Quarantine/Mark Spam (Level 3))
May 13 11:35:00 prox pmg-smtp-filter[6090]: 60B53645EE941E880D: processing time: 2.856 seconds (2.782, 0.047, 0)
May 13 11:35:00 prox pmg-smtp-filter[6090]: DBD::Pg::db do failed: no connection to the server at /usr/bin/pmg-smtp-filter line 783.
May 13 11:35:00 prox postfix/lmtp[10635]: D7C2B80B00: to=<my@email.com>, relay=127.0.0.1[127.0.0.1]:10024, delay=2.9, delays=0.01/0.02/0.04/2.9, dsn=2.5.0, status=sent (250 2.5.0 OK (60B53645EE941E880D))
May 13 11:35:00 prox postfix/qmgr[843]: D7C2B80B00: removed
May 13 11:35:00 prox pmg-smtp-filter[6090]: fast exit because of errors (free 289062912 bytes)
May 13 11:35:00 prox pmg-smtp-filter[6083]: Starting "1" children

Package update itself appears to have succeeded w/o issue...

May 13 10:48:28 prox systemd[1]: Stopping PostgreSQL Cluster 13-main...
May 13 10:48:28 prox systemd[1]: [EMAIL]postgresql@13-main.service[/EMAIL]: Succeeded.
May 13 10:48:28 prox systemd[1]: Stopped PostgreSQL Cluster 13-main.
May 13 10:48:28 prox systemd[1]: [EMAIL]postgresql@13-main.service[/EMAIL]: Consumed 27.998s CPU time.
May 13 10:48:30 prox systemd[1]: Reloading.
May 13 10:48:31 prox systemd[1]: /lib/systemd/system/clamav-freshclam.service:11: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
May 13 10:48:31 prox systemd[1]: /lib/systemd/system/clamav-daemon.service:12: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
May 13 10:48:31 prox systemd[1]: Starting Daily apt download activities...
May 13 10:48:31 prox systemd[1]: Starting PostgreSQL Cluster 13-main...
May 13 10:48:31 prox systemd[1]: apt-daily.service: Succeeded.
May 13 10:48:31 prox systemd[1]: Finished Daily apt download activities.
May 13 10:48:33 prox systemd[1]: Started PostgreSQL Cluster 13-main.

Not sure what broke. I didn't reboot the Proxmox gateway after the database package update. I have now...hopefully everything's happy.

Edit: this issue appears to have broken tracking altogether; I can see an earlier message with 0/5 spam score also gave rise to the same error -

May 13 11:06:35 prox pmg-smtp-filter[6089]: DBD::pg::st execute failed: FATAL:  terminating connection due to administrator command server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. at /usr/share/perl5/PMG/RuleDB/Spam.pm line 149.

Edit: These are the updates I installed earlier which may have caused the issue:

libpq5: 13.10-0+deb11u1 ==> 13.11-0+deb11u1
postgresql-13: 13.10-0+deb11u1 ==> 13.11-0+deb11u1
postgresql-client-13: 13.10-0+deb11u1 ==> 13.11-0+deb11u1

 

[Stoiko Ivanov]

Noticed a spam message had gone AWOL (not showing up in Spam Quarantine). Referring to syslog at the time of evaluation:

just to get a better idea - the mail was neither delivered nor is it in the spam quarantine (as this would suggest)
or does the log for the mail just not show up in the Tracking center (as the subject of the thread suggests)?

It seems the issue was that pmg-smtp-filter could not write to the database (because it was in the process of restarting) - but I'd need to reproduce this here locally to see how to address this best (if possible)

 

[JellyBeanEnjoyer]

Apologies for the disparity in title/description - revised it to better reflect what I think has happened.

The PostgreSQL package update took place ~15 minutes before the issue was noticed (see timestamps). According to Syslog, the database update was successful and the database was up + running afterwards. No messages arrived or were processed during the package update window - I run a very quiet personal mail server, so the package update didn't coincide with any new emails coming in.

A spam message was processed after the package update (11:35). This was (apparently) quarantined, is visible in Message Tracking, but _isn't_ visible in Spam Quarantine. It was not delivered to my inbox. I don't know where this message ended up - it's still not visible in Spam Quarantine following a restart of the Proxmox server.

A ham message was also processed after the package update (11:06). This was delivered to my inbox and is visible in Message Tracking. No issues here, despite the (same) error message returned by pmg-smtp-filter - unless there's another aspect to message delivery/tracking that I haven't yet noticed.

To recap, the only _apparent_ issue, is the spam message getting lost (not visible in Spam Quarantine; not that concerning).

Seems almost like the database package update caused pmg-smtp-filter's database connection handle to go stale? Or some inconsistency/failed cleanup to indicate the package update finished ok?