How to tune or debug an incomming timeout

rojoblandino

Member
Sep 11, 2019
31
4
13
40
I have a FW and then my PMG server.

My PMG version is:

Code:
pmg-api/6.4-3/225ecb80 (running kernel: 5.4.106-1-pve)

My config is as follows:

Code:
composed.wl_bounce_relays = host.xx.yy.zz
dns.domain = xx.yy.zz
dns.fqdn = host.xx.yy.zz
dns.hostname = host
ipconfig.int_ip = A.B.C.D
pmg.admin.advfilter = 0
pmg.admin.avast = 0
pmg.admin.clamav = 1
pmg.admin.custom_check = 0
pmg.admin.custom_check_path = /usr/local/bin/pmg-custom-check
pmg.admin.dailyreport = 1
pmg.admin.demo = 0
pmg.admin.dkim_selector =
pmg.admin.dkim_sign = 0
pmg.admin.dkim_sign_all_mail = 0
pmg.admin.email = noc@xx.yy.zz
pmg.admin.http_proxy =
pmg.admin.statlifetime = 365
pmg.clamav.archiveblockencrypted = 0
pmg.clamav.archivemaxfiles = 1000
pmg.clamav.archivemaxrec = 5
pmg.clamav.archivemaxsize = 25000000
pmg.clamav.dbmirror = database.clamav.net
pmg.clamav.maxcccount = 0
pmg.clamav.maxscansize = 100000000
pmg.clamav.safebrowsing = 1
pmg.clamav.scriptedupdates = 0
pmg.mail.banner = MY PMG BANNER
pmg.mail.before_queue_filtering = 0
pmg.mail.conn_count_limit = 50
pmg.mail.conn_rate_limit = 0
pmg.mail.dnsbl_sites =
pmg.mail.dnsbl_threshold = 1
pmg.mail.dwarning = 4
pmg.mail.ext_port = 25
pmg.mail.greylist = 1
pmg.mail.greylist6 = 0
pmg.mail.greylistmask4 = 24
pmg.mail.greylistmask6 = 64
pmg.mail.helotests = 1
pmg.mail.hide_received = 1
pmg.mail.int_port = 26
pmg.mail.max_filters = 38
pmg.mail.max_policy = 5
pmg.mail.max_smtpd_in = 100
pmg.mail.max_smtpd_out = 100
pmg.mail.maxsize = 52428800
pmg.mail.message_rate_limit = 0
pmg.mail.ndr_on_block = 0
pmg.mail.rejectunknown = 1
pmg.mail.rejectunknownsender = 1
pmg.mail.relay = E.F.G.H
pmg.mail.relaynomx = 0
pmg.mail.relayport = 25
pmg.mail.relayprotocol = smtp
pmg.mail.smarthost =
pmg.mail.smarthostport = 25
pmg.mail.spf = 1
pmg.mail.tls = 1
pmg.mail.tlsheader = 1
pmg.mail.tlslog = 1
pmg.mail.verifyreceivers =
pmg.spam.bounce_score = 0
pmg.spam.clamav_heuristic_score = 3
pmg.spam.languages = all
pmg.spam.maxspamsize = 262144
pmg.spam.rbl_checks = 1
pmg.spam.use_awl = 1
pmg.spam.use_bayes = 1
pmg.spam.use_razor = 1
pmg.spam.wl_bounce_relays =
pmg.spamquar.allowhrefs = 1
pmg.spamquar.authmode = ticket
pmg.spamquar.hostname =
pmg.spamquar.lifetime = 30
pmg.spamquar.mailfrom = postmaster@xx.yy.zz
pmg.spamquar.port = 8006
pmg.spamquar.protocol = https
pmg.spamquar.quarantinelink = 0
pmg.spamquar.reportstyle = none
pmg.spamquar.viewimages = 1
pmg.virusquar.allowhrefs = 1
pmg.virusquar.lifetime = 30
pmg.virusquar.viewimages = 1
postfix.dnsbl_threshold = 1
postfix.int_ip = A.B.C.D
postfix.mynetworks = 127.0.0.0/8 [::1]/128 A.B.C.0/30
postfix.transportnets =
postfix.usepolicy = 1
postgres.version = 11

I am getting from my firewall "Incomplete" connections to my PMG but in my PMG i am not seeing anything on logs mail.info, mail.log, mail.warn or mail.err, about denied connections.

I was checking :

Code:
 enp3s0                                                                   17:04
  ^                                                     r                   
  |                                                  r  r        rt         
  |                                                  rt rt       rt         
  |                                                  rt rt       rt         
  |                                      r     r     rt rt       rt    rt   
  |                                      r     r  r  rt rt rt    rt rt rt   
  |                                      r  r  r  rt rt rt rt rt rt rt rt   
  |                                   r  r  r  rt rt rt rt rt rt rt rt rt   
  |           r                       r  r  r  rt rt rt rt rt rt rt rt rt   
  |  rt    rt rt                      rt rt rt rt rt rt rt rt rt rt rt rt rt
 -+--------------------------------------------------------------------------->
  |  18 19 20 21 22 23 00 01 02 03 04 05 06 07 08 09 10 11 12 13 14 15 16 17
                                                                            
 h  rx (MiB)   tx (MiB)  ][  h  rx (MiB)   tx (MiB)  ][  h  rx (MiB)   tx (MiB)
18       62.2       60.9 ][ 02       19.0       14.2 ][ 10      386.0      377.8
19       37.1       31.3 ][ 03       24.6       16.8 ][ 11      423.6      380.8
20       71.1       68.3 ][ 04       25.9       21.6 ][ 12      232.2      223.7
21       88.4       72.8 ][ 05      160.0       51.2 ][ 13      203.9      194.5
22       33.6       17.5 ][ 06      280.8       67.6 ][ 14      406.3      397.2
23       29.5       18.2 ][ 07      188.9       61.1 ][ 15      224.3      219.6
00       15.6       22.5 ][ 08      276.3      151.7 ][ 16      279.8      278.0
01       16.4       14.9 ][ 09      243.1      208.9 ][ 17       45.2       45.2

In my logs i am seeing following info:

Code:
Jun  3 11:43:22 host postfix/postscreen[12753]: CONNECT from [I.J.K.L]:25977 to [A.B.C.D]:25
Jun  3 11:43:22 host postfix/postscreen[12753]: PASS OLD [I.J.K.L]:25977
Jun  3 14:10:00 host postfix/postscreen[12753]: CONNECT from [I.J.K.L]:25919 to [A.B.C.D]:25
Jun  3 14:10:00 host postfix/postscreen[12753]: PASS OLD [I.J.K.L]:25919

From the Client he got:
Code:
Jun  3 14:08:00 host.xx.yy.zz [A.B.C.D]:25 Connection timed out
Jun  3 14:08:10 host.xx.yy.zz [A.B.C.D]:25 Connection timed out
Jun  3 14:08:15 host.xx.yy.zz [A.B.C.D]:25 Connection timed out
Jun  3 14:08:20 host.xx.yy.zz [A.B.C.D]:25 Connection timed out
Jun  3 14:08:25 host.xx.yy.zz [A.B.C.D]:25 Connection timed out

The client got time out until it responds at 14:10:00 and i got the greeting. I see the incomplete connections throught firewall but on PMG i have check on the logs and got nothing at that moment.

I see in my FW a incomplete log at 14:00 and then after retrying i am seeing the log for the postcreen.

¿Where can i look for those drop connections?

If adjusting pmg.mail.conn_count_limit may fix and solve it, where and how can I see this drops for tunning this problem? I have tried adjusting thar parameter and nothing changed.
 
Last edited:
Could it be your firewall is blocking the connection for that particular source?
I have fortigate firewall and have similar issue when the sending email contain virus/malicious attachment.
 
Could it be your firewall is blocking the connection for that particular source?
I have fortigate firewall and have similar issue when the sending email contain virus/malicious attachment.
I thought of that too but in my firewall it is being allowed.

1623075417557.png



I have enable in my PMG logging by iptables and when i grep my syslog at the IP with problems i only got that they are reaching the PMG but no logs from postfix or pregreeting:

Code:
# grep 183.17.58.38 /var/log/syslog
Jun  7 07:56:36 host kernel: [ 4047.114463] SMTP LOG: IN=enp5s0f0 OUT= MAC=.... SRC=183.17.58.38 DST=W.X.Y.Z LEN=52 TOS=0x00 PREC=0x00 TTL=45 ID=23458 DF PROTO=TCP SPT=32107 DPT=25 WINDOW=8192 RES=0x00 SYN URGP=0
Jun  7 07:56:45 host kernel: [ 4056.158667] SMTP LOG: IN=enp5s0f0 OUT= MAC=.... SRC=183.17.58.38 DST=W.X.Y.Z LEN=48 TOS=0x00 PREC=0x00 TTL=45 ID=26726 DF PROTO=TCP SPT=32501 DPT=25 WINDOW=8192 RES=0x00 SYN URGP=0
Jun  7 08:11:49 host kernel: [ 4960.186488] SMTP LOG: IN=enp5s0f0 OUT= MAC=.... SRC=183.17.58.38 DST=W.X.Y.Z LEN=52 TOS=0x00 PREC=0x00 TTL=45 ID=6777 DF PROTO=TCP SPT=28715 DPT=25 WINDOW=8192 RES=0x00 SYN URGP=0
Jun  7 08:11:58 host kernel: [ 4969.277796] SMTP LOG: IN=enp5s0f0 OUT= MAC=.... SRC=183.17.58.38 DST=W.X.Y.Z LEN=48 TOS=0x00 PREC=0x00 TTL=45 ID=9924 DF PROTO=TCP SPT=32318 DPT=25 WINDOW=8192 RES=0x00 SYN URGP=0

It is different from those ones that are completting but i am seeing the logs of the pregreet and postscreen:

Code:
# grep 200.80.10.33 /var/log/syslog
Jun  7 08:04:11 host kernel: [ 4501.889490] SMTP LOG: IN=enp5s0f0 OUT= MAC=.... SRC=200.80.10.33 DST=W.X.Y.Z LEN=60 TOS=0x00 PREC=0x00 TTL=46 ID=44010 DF PROTO=TCP SPT=41492 DPT=25 WINDOW=14600 RES=0x00 SYN URGP=0
Jun  7 08:04:11 host postfix/postscreen[1012]: CONNECT from [200.80.10.33]:41492 to [W.X.Y.Z]:25
Jun  7 08:04:17 host postfix/postscreen[1012]: PASS NEW [200.80.10.33]:41492
Jun  7 08:04:17 host postfix/smtpd[2248]: connect from server.promocionesefectivas.com[200.80.10.33]
Jun  7 08:04:18 host postfix/smtpd[2248]: Anonymous TLS connection established from server.promocionesefectivas.com[200.80.10.33]: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
Jun  7 08:04:18 host postfix/smtpd[2248]: D1A182C288A: client=server.promocionesefectivas.com[200.80.10.33]
Jun  7 08:04:19 host postfix/smtpd[2248]: disconnect from server.promocionesefectivas.com[200.80.10.33] ehlo=2 starttls=1 mail=1 rcpt=1 data=1 quit=1 commands=7
Jun  7 08:04:19 host kernel: [ 4510.305274] Invalid packet: IN=enp5s0f0 OUT= MAC=.... SRC=200.80.10.33 DST=W.X.Y.Z LEN=40 TOS=0x00 PREC=0x00 TTL=46 ID=0 DF PROTO=TCP SPT=41492 DPT=25 WINDOW=0 RES=0x00 RST URGP=0
Jun  7 08:04:25 host postfix/smtpd[2428]: 05DED2C2887: client=localhost.localdomain[127.0.0.1], orig_client=server.promocionesefectivas.com[200.80.10.33]
Jun  7 08:11:16 host kernel: [ 4927.414481] SMTP LOG: IN=enp5s0f0 OUT= MAC=.... SRC=200.80.10.33 DST=W.X.Y.Z LEN=60 TOS=0x00 PREC=0x00 TTL=46 ID=48371 DF PROTO=TCP SPT=53458 DPT=25 WINDOW=14600 RES=0x00 SYN URGP=0
Jun  7 08:11:17 host postfix/postscreen[1012]: CONNECT from [200.80.10.33]:53458 to [W.X.Y.Z]:25
Jun  7 08:11:17 host postfix/postscreen[1012]: PASS OLD [200.80.10.33]:53458
Jun  7 08:11:17 host postfix/smtpd[2247]: connect from server.promocionesefectivas.com[200.80.10.33]
Jun  7 08:11:17 host postfix/smtpd[2247]: Anonymous TLS connection established from server.promocionesefectivas.com[200.80.10.33]: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
Jun  7 08:11:18 host postfix/smtpd[2247]: 14C752C287A: client=server.promocionesefectivas.com[200.80.10.33]
Jun  7 08:11:18 host postfix/smtpd[2247]: disconnect from server.promocionesefectivas.com[200.80.10.33] ehlo=2 starttls=1 mail=1 rcpt=1 data=1 quit=1 commands=7
Jun  7 08:11:23 host postfix/smtpd[4515]: A96932C287E: client=localhost.localdomain[127.0.0.1], orig_client=server.promocionesefectivas.com[200.80.10.33]
Jun  7 08:25:21 host kernel: [ 5771.741523] SMTP LOG: IN=enp5s0f0 OUT= MAC=.... SRC=200.80.10.33 DST=W.X.Y.Z LEN=60 TOS=0x00 PREC=0x00 TTL=46 ID=46032 DF PROTO=TCP SPT=51016 DPT=25 WINDOW=14600 RES=0x00 SYN URGP=0
Jun  7 08:25:21 host postfix/postscreen[1012]: CONNECT from [200.80.10.33]:51016 to [W.X.Y.Z]:25
Jun  7 08:25:21 host postfix/postscreen[1012]: PASS OLD [200.80.10.33]:51016
Jun  7 08:25:21 host postfix/smtpd[5139]: connect from server.promocionesefectivas.com[200.80.10.33]
Jun  7 08:25:22 host postfix/smtpd[5139]: Anonymous TLS connection established from server.promocionesefectivas.com[200.80.10.33]: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
Jun  7 08:25:22 host postfix/smtpd[5139]: 64DAE2C2890: client=server.promocionesefectivas.com[200.80.10.33]
Jun  7 08:25:22 host postfix/smtpd[5139]: disconnect from server.promocionesefectivas.com[200.80.10.33] ehlo=2 starttls=1 mail=1 rcpt=1 data=1 quit=1 commands=7
Jun  7 08:25:22 host kernel: [ 5773.493965] Invalid packet: IN=enp5s0f0 OUT= MAC=.... SRC=200.80.10.33 DST=W.X.Y.Z LEN=40 TOS=0x00 PREC=0x00 TTL=46 ID=0 DF PROTO=TCP SPT=51016 DPT=25 WINDOW=0 RES=0x00 RST URGP=0
Jun  7 08:25:27 host postfix/smtpd[4515]: E5AB22C2889: client=localhost.localdomain[127.0.0.1], orig_client=server.promocionesefectivas.com[200.80.10.33]

From the client side he sometimes got timeout and when my server take it, it sends all messages as if they were sent at the same hour.

What I need is to know the reason why PMG is droping messages, what kind of tunning should i do.

In an average of 6.57s i am getting 663MiB of emails and i am doubting of PMG.

I have 4 cores and 8G of RAM, and in my status my Hardware is fine.

There would be a queue in postfix or in a service in the PMG maybe I need to increase but I do not know where to see it or how to do it.
 
Last edited:
It is attending a qty of 7637 mailboxes.

In my sysctl.conf i have following lines:

Code:
net.ipv4.tcp_window_scaling = 1

net.ipv4.tcp_syncookies = 1

net.core.rmem_max = 16777216

net.core.wmem_max = 16777216

net.ipv4.tcp_rmem = 4096 87380 16777216

net.ipv4.tcp_wmem = 4096 65536 16777216

net.core.netdev_max_backlog = 5000

I have enable postfix verbosity and I am watching logs to 25 port but not to postfix, it seems there is a queue or option in postfix file i need to encrease.
 
Last edited:
I believe that my postfix in my PMG is not attending all incoming connections.

But i have tried to increase pmg.mail.conn_count_limit and nothing change.

How can i find what do I need to increase?
 
Jun 7 08:25:22 host kernel: [ 5773.493965] Invalid packet: IN=enp5s0f0 OUT= MAC=.... SRC=200.80.10.33 DST=W.X.Y.Z LEN=40 TOS=0x00 PREC=0x00 TTL=46 ID=0 DF PROTO=TCP SPT=51016 DPT=25 WINDOW=0 RES=0x00 RST URGP=0
Seems some packets are deemed invalid by your iptables configuration - I'd first check the source of this


# grep 183.17.58.38 /var/log/syslog Jun 7 07:56:36 host kernel: [ 4047.114463] SMTP LOG: IN=enp5s0f0 OUT= MAC=.... SRC=183.17.58.38 DST=W.X.Y.Z LEN=52 TOS=0x00 PREC=0x00 TTL=45 ID=23458 DF PROTO=TCP SPT=32107 DPT=25 WINDOW=8192 RES=0x00 SYN URGP=0
this only shows the inbound syn-packet - was there a response (syn+ack)?
is there any mention of dropped packets (e.g. due to conntrack tables being full) in the host's dmesg?