How to tune or debug an incomming timeout

rojoblandino

Member
Sep 11, 2019
31
4
13
39
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?
 

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!

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!