Tracking center doesn't include all

L

Lazarus

Member
Apr 26, 2019
19
1
23
124
I'm trying find certain delivered messages (from today) in the tracking center, but even when looking at timestamps, recipients and sender I can't find a particular spammer. How can this be? I see it in /var/log/mail.log and mail.info, but not in tracking center. Is some process missing here?

Also, it hit me that the timestamp written in the logs don't contain year, but it's filterable on year... Would be nice if log used yyyy-MM-dd for date.
 
can you post what you see in the tracking center (where you'd expect it ) and the excerpt from the mail.log ?
 
From the log:
Code: 
root@mailgw:/var/log# grep JohnnyHale8 mail.*
mail.info:Dec  5 22:29:28 mailgw postfix/qmgr[1356247]: F23C482F1: from=<JohnnyHale8@hotmail.com>, size=88462, nrcpt=1 (queue active)
mail.info:Dec  5 22:29:30 mailgw postfix/qmgr[1356247]: 2C1438446: from=<JohnnyHale8@hotmail.com>, size=89679, nrcpt=1 (queue active)
mail.log:Dec  5 22:29:28 mailgw postfix/qmgr[1356247]: F23C482F1: from=<JohnnyHale8@hotmail.com>, size=88462, nrcpt=1 (queue active)
mail.log:Dec  5 22:29:30 mailgw postfix/qmgr[1356247]: 2C1438446: from=<JohnnyHale8@hotmail.com>, size=89679, nrcpt=1 (queue active)

Following those message ID's:
Code: 
root@mailgw:/var/log# grep -E '(F23C482F1|2C1438446)' mail.*
mail.info:Dec  5 22:29:27 mailgw postfix/smtpd[1383067]: F23C482F1: client=mail-he1eur04olkn0811.outbound.protection.outlook.com[2a01:111:f400:fe0d::811]
mail.info:Dec  5 22:29:28 mailgw postfix/cleanup[1383075]: F23C482F1: message-id=<VE1P192MB0845E79FAA2931618456A194E3189@VE1P192MB0845.EURP192.PROD.OUTLOOK.COM>
mail.info:Dec  5 22:29:28 mailgw postfix/qmgr[1356247]: F23C482F1: from=<JohnnyHale8@hotmail.com>, size=88462, nrcpt=1 (queue active)
mail.info:Dec  5 22:29:30 mailgw postfix/smtpd[1383080]: 2C1438446: client=localhost[127.0.0.1], orig_client=mail-he1eur04olkn0811.outbound.protection.outlook.com[2a01:111:f400:fe0d::811]
mail.info:Dec  5 22:29:30 mailgw postfix/cleanup[1383075]: 2C1438446: message-id=<VE1P192MB0845E79FAA2931618456A194E3189@VE1P192MB0845.EURP192.PROD.OUTLOOK.COM>
mail.info:Dec  5 22:29:30 mailgw postfix/qmgr[1356247]: 2C1438446: from=<JohnnyHale8@hotmail.com>, size=89679, nrcpt=1 (queue active)
mail.info:Dec  5 22:29:30 mailgw pmg-smtp-filter[1382208]: 82F2638E62B82B654: accept mail to <REDACTED@DOMAIN.TLD> (2C1438446) (rule: default-accept)
mail.info:Dec  5 22:29:30 mailgw postfix/lmtp[1383076]: F23C482F1: to=<REDACTED@DOMAIN.TLD>, relay=127.0.0.1[127.0.0.1]:10024, delay=2.4, delays=0.33/0.01/0/2, dsn=2.5.0, status=sent (250 2.5.0 OK (82F2638E62B82B654))
mail.info:Dec  5 22:29:30 mailgw postfix/qmgr[1356247]: F23C482F1: removed
mail.info:Dec  5 22:29:30 mailgw postfix/smtp[1383081]: 2C1438446: to=<REDACTED@DOMAIN.TLD>, relay=mailpx.DOMAIN.TLD[2a01:aaaa:2b:aaaa::6]:2225, delay=0.07, delays=0.01/0.01/0.02/0.03, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 389F81FF94)
mail.info:Dec  5 22:29:30 mailgw postfix/qmgr[1356247]: 2C1438446: removed
mail.log:Dec  5 22:29:27 mailgw postfix/smtpd[1383067]: F23C482F1: client=mail-he1eur04olkn0811.outbound.protection.outlook.com[2a01:111:f400:fe0d::811]
mail.log:Dec  5 22:29:28 mailgw postfix/cleanup[1383075]: F23C482F1: message-id=<VE1P192MB0845E79FAA2931618456A194E3189@VE1P192MB0845.EURP192.PROD.OUTLOOK.COM>
mail.log:Dec  5 22:29:28 mailgw postfix/qmgr[1356247]: F23C482F1: from=<JohnnyHale8@hotmail.com>, size=88462, nrcpt=1 (queue active)
mail.log:Dec  5 22:29:30 mailgw postfix/smtpd[1383080]: 2C1438446: client=localhost[127.0.0.1], orig_client=mail-he1eur04olkn0811.outbound.protection.outlook.com[2a01:111:f400:fe0d::811]
mail.log:Dec  5 22:29:30 mailgw postfix/cleanup[1383075]: 2C1438446: message-id=<VE1P192MB0845E79FAA2931618456A194E3189@VE1P192MB0845.EURP192.PROD.OUTLOOK.COM>
mail.log:Dec  5 22:29:30 mailgw postfix/qmgr[1356247]: 2C1438446: from=<JohnnyHale8@hotmail.com>, size=89679, nrcpt=1 (queue active)
mail.log:Dec  5 22:29:30 mailgw pmg-smtp-filter[1382208]: 82F2638E62B82B654: accept mail to <REDACTED@DOMAIN.TLD> (2C1438446) (rule: default-accept)
mail.log:Dec  5 22:29:30 mailgw postfix/lmtp[1383076]: F23C482F1: to=<REDACTED@DOMAIN.TLD>, relay=127.0.0.1[127.0.0.1]:10024, delay=2.4, delays=0.33/0.01/0/2, dsn=2.5.0, status=sent (250 2.5.0 OK (82F2638E62B82B654))
mail.log:Dec  5 22:29:30 mailgw postfix/qmgr[1356247]: F23C482F1: removed
mail.log:Dec  5 22:29:30 mailgw postfix/smtp[1383081]: 2C1438446: to=<REDACTED@DOMAIN.TLD>, relay=mailpx.DOMAIN.TLD[2a01:aaaa:2b:aaaa::6]:2225, delay=0.07, delays=0.01/0.01/0.02/0.03, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 389F81FF94)
mail.log:Dec  5 22:29:30 mailgw postfix/qmgr[1356247]: 2C1438446: removed

1670318294814.png

I believe I should be seeing this message in the tracking center.
 
does it show if you enter the text in the filter instead?
 
you're also sure that the timeframe is correct? the gui uses the local time of the browser, but the log is displayed in the server time
 
dcsapak said:
you're also sure that the timeframe is correct? the gui uses the local time of the browser, but the log is displayed in the server time
Click to expand...
Yes, I’m sure of it. Twsted multiple stretches of this as well. But timestamp also brings me to the other issue I mentioned at start; year is ignored. How is PMG handling the log? Is it reading directly from the log file, or parses and stores in DB? The former seems a bit unlikely to me.
 
Lazarus said:
How is PMG handling the log? Is it reading directly from the log file, or parses and stores in DB? The former seems a bit unlikely to me.
Click to expand...
it reads the log directly. AFAIR the year is handled by assuming the current year, and when reading backwards through the logs, record the year change (jan -> dec)
(we have some improvement in the future planned such that the log is actually in the log)

can you maybe post the unfiltered logs from that time (anonymized if you want, but please in a way such that different ids and mails map uniquely)?
 
For completeness sake - the log-tracker/Tracking Center reads /var/log/syslog (and rotated variants) - in case you changed the syslog-configuration in a way that the mail facility does not end up there
 
dcsapak said:
it reads the log directly. AFAIR the year is handled by assuming the current year, and when reading backwards through the logs, record the year change (jan -> dec)
(we have some improvement in the future planned such that the log is actually in the log)

can you maybe post the unfiltered logs from that time (anonymized if you want, but please in a way such that different ids and mails map uniquely)?
Click to expand...
Will this be sufficient? It comes from cd /var/log ; grep -B 20 -A 20 -Hn --color 'Dec 5 22:29' syslog. Then I've changed my name, domain and IP (seen as REDACTED and 2a01:a:b:c::).


Code: 
syslog-9884627-Dec  5 22:26:04 mailgw postfix/postscreen[1383045]: CONNECT from [63.143.42.245]:56830 to [192.168.20.16]:25
syslog-9884628-Dec  5 22:26:04 mailgw postfix/postscreen[1383045]: HANGUP after 0 from [63.143.42.245]:56830 in tests before SMTP handshake
syslog-9884629-Dec  5 22:26:04 mailgw postfix/postscreen[1383045]: DISCONNECT [63.143.42.245]:56830
syslog-9884630-Dec  5 22:27:48 mailgw pmg-smtp-filter[1368803]: starting database maintenance
syslog-9884631-Dec  5 22:27:48 mailgw pmg-smtp-filter[1368803]: end database maintenance (3 ms)
syslog-9884632-Dec  5 22:27:56 mailgw pmgpolicy[22213]: starting policy database maintenance (greylist, rbl)
syslog-9884633-Dec  5 22:27:56 mailgw pmgpolicy[22213]: end policy database maintenance (11 ms, 1 ms)
syslog-9884634-Dec  5 22:28:17 mailgw postfix/postscreen[1383062]: CONNECT from [211.114.30.78]:52260 to [192.168.20.16]:25
syslog-9884635-Dec  5 22:28:23 mailgw postfix/postscreen[1383062]: PASS OLD [211.114.30.78]:52260
syslog-9884636-Dec  5 22:28:23 mailgw postfix/postscreen[1383062]: CONNECT from [2607:ff68:107::18]:33256 to [2a01:a:b:c::16]:25
syslog-9884637-Dec  5 22:28:23 mailgw postfix/postscreen[1383062]: HANGUP after 0 from [2607:ff68:107::18]:33256 in tests before SMTP handshake
syslog-9884638-Dec  5 22:28:23 mailgw postfix/postscreen[1383062]: DISCONNECT [2607:ff68:107::18]:33256
syslog-9884639-Dec  5 22:28:23 mailgw postfix/smtpd[1383067]: connect from unknown[211.114.30.78]
syslog-9884640-Dec  5 22:28:29 mailgw postfix/smtpd[1383067]: Anonymous TLS connection established from unknown[211.114.30.78]: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
syslog-9884641-Dec  5 22:28:32 mailgw postfix/smtpd[1383067]: lost connection after EHLO from unknown[211.114.30.78]
syslog-9884642-Dec  5 22:28:32 mailgw postfix/smtpd[1383067]: disconnect from unknown[211.114.30.78] ehlo=2 starttls=1 commands=3
syslog:9884643:Dec  5 22:29:18 mailgw postfix/postscreen[1383062]: CONNECT from [2a01:111:f400:fe0d::811]:40706 to [2a01:a:b:c::16]:25
syslog:9884644:Dec  5 22:29:24 mailgw postfix/postscreen[1383062]: PASS NEW [2a01:111:f400:fe0d::811]:40706
syslog:9884645:Dec  5 22:29:27 mailgw postfix/smtpd[1383067]: connect from mail-he1eur04olkn0811.outbound.protection.outlook.com[2a01:111:f400:fe0d::811]
syslog:9884646:Dec  5 22:29:27 mailgw postfix/smtpd[1383067]: Anonymous TLS connection established from mail-he1eur04olkn0811.outbound.protection.outlook.com[2a01:111:f400:fe0d::811]: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
syslog:9884647:Dec  5 22:29:27 mailgw pmgpolicy[1382782]: SPF says pass
syslog:9884648:Dec  5 22:29:27 mailgw postfix/smtpd[1383067]: F23C482F1: client=mail-he1eur04olkn0811.outbound.protection.outlook.com[2a01:111:f400:fe0d::811]
syslog:9884649:Dec  5 22:29:28 mailgw postfix/cleanup[1383075]: F23C482F1: message-id=<VE1P192MB0845E79FAA2931618456A194E3189@VE1P192MB0845.EURP192.PROD.OUTLOOK.COM>
syslog:9884650:Dec  5 22:29:28 mailgw postfix/qmgr[1356247]: F23C482F1: from=<JohnnyHale8@hotmail.com>, size=88462, nrcpt=1 (queue active)
syslog:9884651:Dec  5 22:29:28 mailgw pmg-smtp-filter[1382208]: 2022/12/05-22:29:28 CONNECT TCP Peer: "[127.0.0.1]:51564" Local: "[127.0.0.1]:10024"
syslog:9884652:Dec  5 22:29:28 mailgw pmg-smtp-filter[1382208]: 82F2638E62B82B654: new mail message-id=<VE1P192MB0845E79FAA2931618456A194E3189@VE1P192MB0845.EURP192.PROD.OUTLOOK.COM>#012
syslog:9884653:Dec  5 22:29:28 mailgw postfix/smtpd[1383067]: disconnect from mail-he1eur04olkn0811.outbound.protection.outlook.com[2a01:111:f400:fe0d::811] ehlo=2 starttls=1 mail=1 rcpt=1 bdat=1 quit=1 commands=7
syslog:9884654:Dec  5 22:29:30 mailgw pmg-smtp-filter[1382208]: 82F2638E62B82B654: SA score=2/5 time=1.954 bayes=0.00 autolearn=no autolearn_force=no hits=BAYES_00(-1.9),DKIM_SIGNED(0.1),DKIM_VALID(-0.1),DKIM_VALID_AU(-0.1),DKIM_VALID_EF(-0.1),FORGED_HOTMAIL_RCVD2(0.874),FREEMAIL_ENVFROM_END_DIGIT(0.25),FREEMAIL_FROM(0.001),HTML_MESSAGE(0.001),MALFORMED_FREEMAIL(2.799),MISSING_HEADERS(1.021),SPF_HELO_PASS(-0.001),SPF_PASS(-0.001)
syslog:9884655:Dec  5 22:29:30 mailgw postfix/smtpd[1383080]: connect from localhost[127.0.0.1]
syslog:9884656:Dec  5 22:29:30 mailgw postfix/smtpd[1383080]: 2C1438446: client=localhost[127.0.0.1], orig_client=mail-he1eur04olkn0811.outbound.protection.outlook.com[2a01:111:f400:fe0d::811]
syslog:9884657:Dec  5 22:29:30 mailgw postfix/cleanup[1383075]: 2C1438446: message-id=<VE1P192MB0845E79FAA2931618456A194E3189@VE1P192MB0845.EURP192.PROD.OUTLOOK.COM>
syslog:9884658:Dec  5 22:29:30 mailgw postfix/qmgr[1356247]: 2C1438446: from=<JohnnyHale8@hotmail.com>, size=89679, nrcpt=1 (queue active)
syslog:9884659:Dec  5 22:29:30 mailgw pmg-smtp-filter[1382208]: 82F2638E62B82B654: accept mail to <REDACTED@REDACTED.TLD> (2C1438446) (rule: default-accept)
syslog:9884660:Dec  5 22:29:30 mailgw postfix/smtpd[1383080]: disconnect from localhost[127.0.0.1] ehlo=1 xforward=1 mail=1 rcpt=1 data=1 commands=5
syslog:9884661:Dec  5 22:29:30 mailgw pmg-smtp-filter[1382208]: 82F2638E62B82B654: processing time: 2.008 seconds (1.954, 0.029, 0)
syslog:9884662:Dec  5 22:29:30 mailgw postfix/lmtp[1383076]: F23C482F1: to=<REDACTED@REDACTED.TLD>, relay=127.0.0.1[127.0.0.1]:10024, delay=2.4, delays=0.33/0.01/0/2, dsn=2.5.0, status=sent (250 2.5.0 OK (82F2638E62B82B654))
syslog:9884663:Dec  5 22:29:30 mailgw postfix/qmgr[1356247]: F23C482F1: removed
syslog:9884664:Dec  5 22:29:30 mailgw postfix/smtp[1383081]: Trusted TLS connection established to mailpx.REDACTED.TLD[2a01:a:b:c::6]:2225: TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (2048 bits)
syslog:9884665:Dec  5 22:29:30 mailgw postfix/smtp[1383081]: 2C1438446: to=<REDACTED@REDACTED.TLD>, relay=mailpx.REDACTED.TLD[2a01:a:b:c::6]:2225, delay=0.07, delays=0.01/0.01/0.02/0.03, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 389F81FF94)
syslog:9884666:Dec  5 22:29:30 mailgw postfix/qmgr[1356247]: 2C1438446: removed
syslog:9884667:Dec  5 22:29:50 mailgw pmg-smtp-filter[1368803]: starting database maintenance
syslog:9884668:Dec  5 22:29:50 mailgw pmg-smtp-filter[1368803]: end database maintenance (48 ms)
syslog:9884669:Dec  5 22:29:53 mailgw postfix/postscreen[1383062]: CONNECT from [182.106.184.218]:33537 to [192.168.20.16]:25
syslog:9884670:Dec  5 22:29:54 mailgw postfix/postscreen[1383062]: PREGREET 12 after 0.33 from [182.106.184.218]:33537: EHLO ADMIN\r\n
syslog:9884671:Dec  5 22:29:54 mailgw postfix/postscreen[1383062]: DISCONNECT [182.106.184.218]:33537
syslog-9884672-Dec  5 22:30:06 mailgw pmgpolicy[22213]: starting policy database maintenance (greylist, rbl)
syslog-9884673-Dec  5 22:30:06 mailgw pmgpolicy[22213]: end policy database maintenance (21 ms, 1 ms)
syslog-9884674-Dec  5 22:31:04 mailgw postfix/postscreen[1383062]: CONNECT from [63.143.42.245]:55458 to [192.168.20.16]:25
syslog-9884675-Dec  5 22:31:04 mailgw postfix/postscreen[1383062]: HANGUP after 0 from [63.143.42.245]:55458 in tests before SMTP handshake
syslog-9884676-Dec  5 22:31:04 mailgw postfix/postscreen[1383062]: DISCONNECT [63.143.42.245]:55458
syslog-9884677-Dec  5 22:31:50 mailgw pmg-smtp-filter[1368803]: starting database maintenance
syslog-9884678-Dec  5 22:31:50 mailgw pmg-smtp-filter[1368803]: end database maintenance (4 ms)
syslog-9884679-Dec  5 22:31:52 mailgw postfix/postscreen[1383062]: CONNECT from [205.201.128.5]:52500 to [192.168.20.16]:25
syslog-9884680-Dec  5 22:31:58 mailgw postfix/postscreen[1383062]: PASS OLD [205.201.128.5]:52500
syslog-9884681-Dec  5 22:31:58 mailgw postfix/smtpd[1383098]: connect from news.pastemagazine.com[205.201.128.5]
syslog-9884682-Dec  5 22:31:59 mailgw postfix/smtpd[1383098]: Anonymous TLS connection established from news.pastemagazine.com[205.201.128.5]: TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (2048 bits) server-digest SHA256
syslog-9884683-Dec  5 22:31:59 mailgw pmgpolicy[1382782]: SPF says pass
syslog-9884684-Dec  5 22:31:59 mailgw postfix/smtpd[1383098]: AA0D482FF: client=news.pastemagazine.com[205.201.128.5]
syslog-9884685-Dec  5 22:31:59 mailgw postfix/cleanup[1383102]: AA0D482FF: message-id=<3000f308a9833eb816c547467.89bfa222c1.20221205213132.dd0975fbfa.b44c39ef@news.pastemagazine.com>
syslog-9884686-Dec  5 22:31:59 mailgw postfix/qmgr[1356247]: AA0D482FF: from=<bounce-mc.us6_14802627.159689-89bfa222c1@news.pastemagazine.com>, size=31755, nrcpt=1 (queue active)
syslog-9884687-Dec  5 22:31:59 mailgw postfix/smtpd[1383098]: disconnect from news.pastemagazine.com[205.201.128.5] ehlo=2 starttls=1 mail=1 rcpt=1 data=1 quit=1 commands=7
syslog-9884688-Dec  5 22:31:59 mailgw pmg-smtp-filter[1382172]: 2022/12/05-22:31:59 CONNECT TCP Peer: "[127.0.0.1]:60122" Local: "[127.0.0.1]:10024"
syslog-9884689-Dec  5 22:31:59 mailgw pmg-smtp-filter[1382172]: 838E638E634FEBF56: new mail message-id=<3000f308a9833eb816c547467.89bfa222c1.20221205213132.dd0975fbfa.b44c39ef@news.pastemagazine.com>#012
syslog-9884690-Dec  5 22:32:02 mailgw pmg-smtp-filter[1382172]: 838E638E634FEBF56: SA score=0/5 time=2.015 bayes=0.00 autolearn=ham autolearn_force=no hits=AWL(-0.760),BAYES_00(-1.9),DKIM_SIGNED(0.1),DKIM_VALID(-0.1),DKIM_VALID_AU(-0.1),DKIM_VALID_EF(-0.1),HTML_MESSAGE(0.001),MIME_QP_LONG_LINE(0.001),SPF_HELO_PASS(-0.001),SPF_PASS(-0.001)
syslog-9884691-Dec  5 22:32:02 mailgw postfix/smtpd[1383107]: connect from localhost[127.0.0.1]
 
mhmm when i paste that particular log into my log (at the right spot) i can find it in the tracking center no problem...
does the tracking center work for other mails for you?

what is your 'pmgversion -v' ?
 
Code: 
root@mailgw:~# pmgversion -v
proxmox-mailgateway-container: 7.1-1 (API: 7.1-4/523ac520, running kernel: 5.15.53-1-pve)
pmg-api: 7.1-4
pmg-gui: 3.1-3
clamav-daemon: 0.103.7+dfsg-0+deb11u1
ifupdown: 0.8.36+pve1
libarchive-perl: 3.4.0-1
libjs-extjs: 7.0.0-1
libjs-framework7: 4.4.7-1
libproxmox-acme-perl: 1.4.2
libproxmox-acme-plugins: 1.4.2
libpve-apiclient-perl: 3.2-1
libpve-common-perl: 7.2-2
libpve-http-server-perl: 4.1-3
libxdgmime-perl: 1.0-1
lvm2: not correctly installed
pmg-docs: 7.1-2
pmg-i18n: 2.7-2
pmg-log-tracker: 2.3.1-1
postgresql-13: 13.8-0+deb11u1
proxmox-mini-journalreader: 1.3-1
proxmox-spamassassin: 3.4.6-4
proxmox-widget-toolkit: 3.5.1
pve-xtermjs: 4.16.0-1
 
do you maybe have custom logrotate rules? or configured the system to not log to /var/log/sylog files?
 
You must log in or register to reply here.

About

The Proxmox community has been around for many years and offers help and support for Proxmox VE, Proxmox Backup Server, and Proxmox Mail Gateway.
We think our community is one of the best thanks to people like you!

Quick Navigation

Home Get Subscription Wiki Downloads Proxmox Customer Portal About

Get your subscription!

The Proxmox team works very hard to make sure you are running the best software and getting stable updates and security enhancements, as well as quick enterprise support. Tens of thousands of happy customers have a Proxmox subscription. Get yours easily in our online shop.

Buy now!
Community platform by XenForo® © 2010-2024 XenForo Ltd.
Top Bottom