Port 25 binding failed since 2.3.8
Issue #959
resolved
All others ports are ok.
But IPv4 Correct remote connection IPv4 and Port 25 SMTP server for incoming emails diag - >
Rollback to 2.3.7 : all work.
Any idea ?
Comments (19)
-
repo owner
-
repo owner
Also ss -l state listening please
-
reporter
On host or pod ?
I'm doing this for you tonight. By specifying the version of posteio each time. -
repo owner
You can do both, also please specify your internal network setup.
Thing is that there was upgrade nodejs 12 to v16 between 2.3.7 and 2.3.8 and it seems that it handles dual-stack (ipv4&ipv6) wildcard listen address differently. I suspect that it may be problem but Iam unable to hit the bug in my setup
-
reporter
Fedora 36 with podman
One interface with 2 ipv4 and 2ipv6
195.*/24
212.*/32
2001:bc8*/64
2001:bc8*/64Working with :
podman run -d --name posteio -h #-p 212.#:25:25 -p 212.#:80:80 -p 212.#:443:443 -p 212.#:465:465 -p 212.#:587:587 -p 212.#:143 -e TZ=Etc/UTC -v #:/data -t analogic/poste.io:2.3.7
host :cat /proc/sys/net/ipv6/bindv6only
0tcp 0 4096 212.#:imap 0.0.0.0:*
tcp 0 4096 212.#:http 0.0.0.0:*
tcp 0 4096 212.#:smtp 0.0.0.0:*
tcp 0 4096 212.#:urd 0.0.0.0:*
tcp 0 4096 212.#:https 0.0.0.0:*
tcp 0 4096 212.#submission 0.0.0.0:*pod :
podman exec posteio ss -l state listening
Netid Recv-Q Send-Q Local Address:Port Peer Address:Port
u_str 0 1000 /var/run/dovecot/login/ipc-proxy 370263 * 0
u_str 0 1000 /var/run/dovecot/stats-writer 370250 * 0
u_str 0 1024 /var/run/dovecot/login/imap 370266 * 0
u_str 0 100 /var/run/dovecot/login/dns-client 370278 * 0
u_str 0 1000 /var/run/dovecot/replicator 370252 * 0
u_str 0 1000 /var/run/dovecot/login/login 370284 * 0
u_str 0 4096 /var/run/dovecot/replication-notify 370253 * 0
u_str 0 1000 /var/run/dovecot/old-stats 370259 * 0
u_str 0 4096 /var/lib/rspamd/rspamd.sock 373391 * 0
u_str 0 1000 /var/run/dovecot/log-errors 370260 * 0
u_str 0 1000 /var/run/dovecot/stats-reader 370249 * 0
u_str 0 100 /var/run/dovecot/lmtp 370261 * 0
u_str 0 1000 /var/run/dovecot/ipc 370262 * 0
u_str 0 10 /var/run/dovecot/indexer-worker 370264 * 0
u_str 0 1000 /var/run/dovecot/indexer 370265 * 0
u_str 0 100 /var/run/dovecot/login/sieve 370248 * 0
u_str 0 1000 /var/run/dovecot/login/stats-writer 370251 * 0
u_str 0 1024 /var/run/dovecot/login/pop3 370254 * 0
u_str 0 1024 /var/run/dovecot/imap-urlauth-worker 370268 * 0
u_str 0 100 /var/run/dovecot/imap-urlauth 370270 * 0
u_str 0 4096 /var/run/dovecot/imap-hibernate 370275 * 0
u_str 0 100 /var/run/dovecot/doveadm-server 370276 * 0
u_str 0 100 /var/run/dovecot/dns-client 370277 * 0
u_str 0 1000 /var/run/dovecot/director-admin 370279 * 0
u_str 0 1000 /var/run/dovecot/director-userdb 370280 * 0
u_str 0 1024 /var/run/dovecot/imap-master 370267 * 0
u_str 0 100 /var/run/dovecot/dict 370281 * 0
u_str 0 511 /var/run/redis/redis.sock 373789 * 0
u_str 0 4096 /var/run/dovecot/dict-async 370282 * 0
u_str 0 4096 /var/run/dovecot/config 370283 * 0
u_str 0 1000 /var/run/dovecot/auth-login 370286 * 0
u_str 0 1024 /var/run/dovecot/token-login/imap-urlauth 370269 * 0
u_str 0 1000 /var/run/dovecot/auth-client 370287 * 0
u_str 0 1000 /var/run/dovecot/token-login/tokenlogin 370285 * 0
u_str 0 1000 /var/run/dovecot/auth-userdb 370288 * 0
u_str 0 1000 /var/run/dovecot/auth-master 370289 * 0
u_str 0 1000 /var/run/dovecot/auth-smtp 370290 * 0
u_str 0 100 /var/run/dovecot/auth-worker 370291 * 0
u_str 0 511 /var/run/php-fpm-admin.sock 368027 * 0
u_str 0 511 /var/run/php-fpm.sock 368029 * 0
u_str 0 1000 /var/run/dovecot/anvil 370292 * 0
u_str 0 1000 /var/run/dovecot/anvil-auth-penalty 370293 * 0
u_str 0 4096 /var/run/dovecot/imap-postlogin 370294 * 0
u_str 0 4096 /var/run/dovecot/pop3-postlogin 370295 * 0
u_str 0 15 /var/run/clamav/clamd.ctl 361827 * 0
u_str 0 4096 /var/run/dovecot/quota-status 370296 * 0
u_str 0 16 /var/run/dovecot/master 370297 * 0
tcp 0 100 0.0.0.0:4190 0.0.0.0:*
tcp 0 511 127.0.0.1:6379 0.0.0.0:*
tcp 0 4096 0.0.0.0:143 0.0.0.0:*
tcp 0 511 0.0.0.0:80 0.0.0.0:*
tcp 0 4096 0.0.0.0:110 0.0.0.0:*
tcp 0 511 0.0.0.0:443 0.0.0.0:*
tcp 0 4096 0.0.0.0:993 0.0.0.0:*
tcp 0 4096 0.0.0.0:995 0.0.0.0:*
tcp 0 4096 127.0.0.1:11332 0.0.0.0:*
tcp 0 4096 127.0.0.1:11333 0.0.0.0:*
tcp 0 4096 127.0.0.1:11334 0.0.0.0:*
tcp 0 511 127.0.0.1:11380 0.0.0.0:*
tcp 0 511 127.0.0.1:11381 0.0.0.0:*
tcp 0 100 [::]:4190 [::]:*
tcp 0 4096 [::]:143 [::]:*
tcp 0 511 :25 :
tcp 0 511 [::]:80 [::]:
tcp 0 4096 [::]:110 [::]:*
tcp 0 511 [::]:443 [::]:*
tcp 0 511 :465 :
tcp 0 511 :587 :
tcp 0 4096 [::]:993 [::]:
tcp 0 4096 [::]:995 [::]:
tcp 0 4096 [::1]:11334 [::]:*
tcp 0 4096 [::1]:11332 [::]:*podman exec posteio cat /proc/sys/net/ipv6/bindv6only
0Probleme with latest :
podman run -d --name posteio -h #-p 212.#:25:25 -p 212.#:80:80 -p 212.#:443:443 -p 212.#:465:465 -p 212.#:587:587 -p 212.#:143 -e TZ=Etc/UTC -v #:/data -t analogic/poste.io
host :cat /proc/sys/net/ipv6/bindv6only
0tcp 0 4096 212.#:imap 0.0.0.0:*
tcp 0 4096 212.#:http 0.0.0.0:*
tcp 0 4096 212.#:smtp 0.0.0.0:*
tcp 0 4096 212.#:urd 0.0.0.0:*
tcp 0 4096 212.#:https 0.0.0.0:*
tcp 0 4096 212.#submission 0.0.0.0:*pod :
podman exec posteio cat /proc/sys/net/ipv6/bindv6only
0podman exec posteio ss -l state listening
Netid Recv-Q Send-Q Local Address:Port Peer Address:Port
u_str 0 4096 /var/lib/rspamd/rspamd.sock 140817138 * 0
u_str 0 1024 /var/run/dovecot/token-login/imap-urlauth 140846716 * 0
u_str 0 1000 /var/run/dovecot/token-login/tokenlogin 140846732 * 0
u_str 0 511 /var/run/php-fpm-admin.sock 140844765 * 0
u_str 0 511 /var/run/php-fpm.sock 140844767 * 0
u_str 0 15 /var/run/clamav/clamd.ctl 140849442 * 0
u_str 0 511 /var/run/redis/redis.sock 140853910 * 0
u_str 0 1000 /var/run/dovecot/stats-reader 140846696 * 0
u_str 0 1000 /var/run/dovecot/stats-writer 140846697 * 0
u_str 0 1000 /var/run/dovecot/replicator 140846699 * 0
u_str 0 4096 /var/run/dovecot/replication-notify 140846700 * 0
u_str 0 1000 /var/run/dovecot/old-stats 140846706 * 0
u_str 0 1000 /var/run/dovecot/log-errors 140846707 * 0
u_str 0 100 /var/run/dovecot/lmtp 140846708 * 0
u_str 0 1000 /var/run/dovecot/ipc 140846709 * 0
u_str 0 10 /var/run/dovecot/indexer-worker 140846711 * 0
u_str 0 1000 /var/run/dovecot/indexer 140846712 * 0
u_str 0 1024 /var/run/dovecot/imap-master 140846714 * 0
u_str 0 1024 /var/run/dovecot/imap-urlauth-worker 140846715 * 0
u_str 0 100 /var/run/dovecot/imap-urlauth 140846717 * 0
u_str 0 4096 /var/run/dovecot/imap-hibernate 140846722 * 0
u_str 0 100 /var/run/dovecot/doveadm-server 140846723 * 0
u_str 0 100 /var/run/dovecot/dns-client 140846724 * 0
u_str 0 1000 /var/run/dovecot/director-admin 140846726 * 0
u_str 0 1000 /var/run/dovecot/director-userdb 140846727 * 0
u_str 0 100 /var/run/dovecot/dict 140846728 * 0
u_str 0 4096 /var/run/dovecot/dict-async 140846729 * 0
u_str 0 4096 /var/run/dovecot/config 140846730 * 0
u_str 0 1000 /var/run/dovecot/auth-login 140846733 * 0
u_str 0 1000 /var/run/dovecot/auth-client 140846734 * 0
u_str 0 1000 /var/run/dovecot/auth-userdb 140846735 * 0
u_str 0 1000 /var/run/dovecot/auth-master 140846736 * 0
u_str 0 1000 /var/run/dovecot/auth-smtp 140846737 * 0
u_str 0 100 /var/run/dovecot/auth-worker 140846738 * 0
u_str 0 1000 /var/run/dovecot/anvil 140846739 * 0
u_str 0 1000 /var/run/dovecot/anvil-auth-penalty 140846740 * 0
u_str 0 4096 /var/run/dovecot/imap-postlogin 140846741 * 0
u_str 0 4096 /var/run/dovecot/pop3-postlogin 140846742 * 0
u_str 0 4096 /var/run/dovecot/quota-status 140846743 * 0
u_str 0 16 /var/run/dovecot/master 140846744 * 0
u_str 0 100 /var/run/dovecot/login/sieve 140846695 * 0
u_str 0 1000 /var/run/dovecot/login/stats-writer 140846698 * 0
u_str 0 1024 /var/run/dovecot/login/pop3 140846701 * 0
u_str 0 1000 /var/run/dovecot/login/ipc-proxy 140846710 * 0
u_str 0 1024 /var/run/dovecot/login/imap 140846713 * 0
u_str 0 100 /var/run/dovecot/login/dns-client 140846725 * 0
u_str 0 1000 /var/run/dovecot/login/login 140846731 * 0
tcp 0 4096 127.0.0.1:11334 0.0.0.0:*
tcp 0 4096 127.0.0.1:11333 0.0.0.0:*
tcp 0 4096 127.0.0.1:11332 0.0.0.0:*
tcp 0 511 127.0.0.1:11381 0.0.0.0:*
tcp 0 511 127.0.0.1:11380 0.0.0.0:*
tcp 0 4096 0.0.0.0:993 0.0.0.0:*
tcp 0 4096 0.0.0.0:995 0.0.0.0:*
tcp 0 511 0.0.0.0:443 0.0.0.0:*
tcp 0 4096 0.0.0.0:110 0.0.0.0:*
tcp 0 511 0.0.0.0:80 0.0.0.0:*
tcp 0 4096 0.0.0.0:143 0.0.0.0:*
tcp 0 511 127.0.0.1:6379 0.0.0.0:*
tcp 0 100 0.0.0.0:4190 0.0.0.0:*
tcp 0 4096 [::1]:11332 [::]:*
tcp 0 4096 [::1]:11334 [::]:*
tcp 0 4096 [::]:993 [::]:*
tcp 0 4096 [::]:995 [::]:*
tcp 0 511 :587 :
tcp 0 511 :465 :
tcp 0 511 [::]:443 [::]:
tcp 0 4096 [::]:110 [::]:
tcp 0 511 [::]:80 [::]:*
tcp 0 511 :25 :
tcp 0 4096 [::]:143 [::]:
tcp 0 100 [::]:4190 [::]:*
-
repo owner
Hmm, it seems same. I am not really aware how podman works but is podman really opening port on host system side? Same problem apply with port 587 and 465 I suppose
-
reporter
Not. only IPv34 & port 25.
I try additionnals tests. -
reporter
Ports 587 is ok.
(i have updated server to latest version of fedora 37 & latest poste.io after validating 2.3.7 is ok)
Its only port 25 … -
reporter
I tried disabling firewalld to see if it didn't fit in the story, no change.
How does nodejs bind port 25 to Hakara in 2.3.7 to get "ESMTP Haraka/2.8.27 ready" -
repo owner
It is same process and it bind same way to 587 and 465. Is port 25 really not working? Just try to connect from outside and wait couple seconds. It might be diagnostics issue
-
reporter
Whats the Haraka version from 2.3.8 ?
-
reporter
Port 25 not working.
I try to telnet on it … works in 2.3.7 … failed in 2.3.8 and after -
repo owner
Look at log/s6/haraka-smtp/current for any errors, I am running out of ideas now
Also do ps aux to check if one of nodejs is not continuously restarting
-
reporter
There is an error loop in log (I hope it can help you) :
2022-11-01 16:01:47.128913500 [DEBUG] [-] [watch] wss client connected: _events,_eventsCount,_maxListeners,_binaryType,_closeCode,_closeFrameReceived,_closeFrameSent,_closeMessage,_closeTimer,_extensions,_paused,_protocol,_readyState,_receiver,_sender,_socket,_isServer
2022-11-01 16:01:51.692942500 [CRIT] [-] [core] TypeError [ERR_MISSING_ARGS]: The "options" or "port" or "path" argument must be specified
2022-11-01 16:01:51.692965500 [CRIT] [-] [core] at new NodeError (node:internal/errors:371:5)
2022-11-01 16:01:51.693017500 [CRIT] [-] [core] at Socket.connect (node:net:953:11)
2022-11-01 16:01:51.693024500 [CRIT] [-] [core] at Object.connect (node:net:203:17)
2022-11-01 16:01:51.693027500 [CRIT] [-] [core] at P0FClient.connect (/usr/lib/node_modules/Haraka/node_modules/haraka-plugin-p0f/index.js:22:25)
2022-11-01 16:01:51.693058500 [CRIT] [-] [core] at Timeout._onTimeout (/usr/lib/node_modules/Haraka/node_modules/haraka-plugin-p0f/index.js:53:66)
2022-11-01 16:01:51.693064500 [CRIT] [-] [core] at listOnTimeout (node:internal/timers:559:17)
2022-11-01 16:01:51.693083500 [CRIT] [-] [core] at processTimers (node:internal/timers:502:7)
2022-11-01 16:01:51.693642500 [NOTICE] [-] [core] Shutting down
2022-11-01 16:01:51.878229500 loaded TLD files:
2022-11-01 16:01:51.878251500 1=1495
2022-11-01 16:01:51.878255500 2=8570
2022-11-01 16:01:51.878258500 3=2448
2022-11-01 16:01:51.903058500 loaded 9192 Public Suffixes
2022-11-01 16:01:52.290042500 loglevel: PROTOCOL
2022-11-01 16:01:52.290135500 log format: DEFAULT
2022-11-01 16:01:52.290143500 Starting up Haraka version 2.8.28
2022-11-01 16:01:52.290270500 [INFO] [-] [core] Loading plugins
2022-11-01 16:01:52.290392500 [INFO] [-] [core] Loading plugin: auth/poste
2022-11-01 16:01:52.290424500 [DEBUG] [-] [core] no timeout in auth/poste.timeout
2022-11-01 16:01:52.290467500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.290506500 [DEBUG] [-] [core] plugin auth/poste timeout is: 30s
2022-11-01 16:01:52.290596500 [DEBUG] [-] [core] no timeout in auth/auth_base.timeout
2022-11-01 16:01:52.290634500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.290652500 [DEBUG] [-] [core] plugin auth/auth_base timeout is: 30s
2022-11-01 16:01:52.290690500 [INFO] [-] [auth/poste] default_auth_domain=, tls_required=true
2022-11-01 16:01:52.290828500 [DEBUG] [-] [core] registered hook capabilities to auth/poste.hook_capabilities priority 0
2022-11-01 16:01:52.290858500 [DEBUG] [-] [core] registered hook unrecognized_command to auth/poste.hook_unrecognized_command priority 0
2022-11-01 16:01:52.290874500 [INFO] [-] [core] Loading plugin: status_http
2022-11-01 16:01:52.290909500 [DEBUG] [-] [core] no timeout in status_http.timeout
2022-11-01 16:01:52.291001500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.291019500 [DEBUG] [-] [core] plugin status_http timeout is: 30s
2022-11-01 16:01:52.291033500 [DEBUG] [-] [core] no timeout in status.timeout
2022-11-01 16:01:52.291059500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.291076500 [DEBUG] [-] [core] plugin status timeout is: 30s
2022-11-01 16:01:52.291239500 [DEBUG] [-] [core] registered hook init_http to status_http.hook_init_http priority 0
2022-11-01 16:01:52.291315500 [DEBUG] [-] [core] registered hook capabilities to status_http.hook_capabilities priority 0
2022-11-01 16:01:52.291322500 [DEBUG] [-] [core] registered hook unrecognized_command to status_http.hook_unrecognized_command priority 0
2022-11-01 16:01:52.291325500 [DEBUG] [-] [core] registered hook init_master to status_http.hook_init_master priority 0
2022-11-01 16:01:52.291328500 [DEBUG] [-] [core] registered hook init_child to status_http.hook_init_child priority 0
2022-11-01 16:01:52.291340500 [INFO] [-] [core] Loading plugin: poste
2022-11-01 16:01:52.291475500 [DEBUG] [-] [core] no timeout in poste.timeout
2022-11-01 16:01:52.291482500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.291497500 [DEBUG] [-] [core] plugin poste timeout is: 30s
2022-11-01 16:01:52.291512500 [DEBUG] [-] [core] registered hook init_master to poste.init_sqlite priority 0
2022-11-01 16:01:52.291526500 [DEBUG] [-] [core] registered hook init_child to poste.init_sqlite priority 0
2022-11-01 16:01:52.291541500 [INFO] [-] [core] Loading plugin: limits
2022-11-01 16:01:52.291556500 [DEBUG] [-] [core] no timeout in limits.timeout
2022-11-01 16:01:52.291570500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.291584500 [DEBUG] [-] [core] plugin limits timeout is: 30s
2022-11-01 16:01:52.291685500 [DEBUG] [-] [core] registered hook queue_ok to limits.hook_queue_ok priority 0
2022-11-01 16:01:52.291702500 [DEBUG] [-] [core] registered hook data to limits.hook_data priority 0
2022-11-01 16:01:52.291732500 [INFO] [-] [core] Loading plugin: stats
2022-11-01 16:01:52.291738500 [DEBUG] [-] [core] no timeout in stats.timeout
2022-11-01 16:01:52.291740500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.291753500 [DEBUG] [-] [core] plugin stats timeout is: 30s
2022-11-01 16:01:52.291758500 [DEBUG] [-] [core] registered hook disconnect to stats.hook_disconnect priority 0
2022-11-01 16:01:52.291770500 [DEBUG] [-] [core] registered hook queue_ok to stats.hook_queue_ok priority 0
2022-11-01 16:01:52.291776500 [DEBUG] [-] [core] registered hook delivered to stats.hook_delivered priority 0
2022-11-01 16:01:52.291788500 [DEBUG] [-] [core] registered hook bounce to stats.hook_bounce priority 0
2022-11-01 16:01:52.291803500 [DEBUG] [-] [core] registered hook reset_transaction to stats.hook_reset_transaction priority 0
2022-11-01 16:01:52.291808500 [INFO] [-] [core] Loading plugin: guard
2022-11-01 16:01:52.291820500 [DEBUG] [-] [core] no timeout in guard.timeout
2022-11-01 16:01:52.291835500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.291849500 [DEBUG] [-] [core] plugin guard timeout is: 30s
2022-11-01 16:01:52.291855500 [DEBUG] [-] [core] registered hook connect_init to guard.hook_connect_init priority 0
2022-11-01 16:01:52.291867500 [DEBUG] [-] [core] registered hook mail to guard.hook_mail priority 0
2022-11-01 16:01:52.291873500 [DEBUG] [-] [core] registered hook connect to guard.hook_connect priority 0
2022-11-01 16:01:52.291885500 [DEBUG] [-] [core] registered hook deny to guard.hook_deny priority 0
2022-11-01 16:01:52.291899500 [INFO] [-] [core] Loading plugin: hello_block
2022-11-01 16:01:52.291905500 [DEBUG] [-] [core] no timeout in hello_block.timeout
2022-11-01 16:01:52.291917500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.291931500 [DEBUG] [-] [core] plugin hello_block timeout is: 30s
2022-11-01 16:01:52.291946500 [DEBUG] [-] [core] registered hook helo to hello_block.check_ymlf priority 0
2022-11-01 16:01:52.291951500 [DEBUG] [-] [core] registered hook ehlo to hello_block.check_ymlf priority 0
2022-11-01 16:01:52.291964500 [INFO] [-] [core] Loading plugin: block_bad_connections
2022-11-01 16:01:52.291978500 [DEBUG] [-] [core] no timeout in block_bad_connections.timeout
2022-11-01 16:01:52.291983500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.291996500 [DEBUG] [-] [core] plugin block_bad_connections timeout is: 30s
2022-11-01 16:01:52.292010500 [DEBUG] [-] [core] registered hook rcpt to block_bad_connections.hook_rcpt priority 0
2022-11-01 16:01:52.292015500 [DEBUG] [-] [core] registered hook rcpt_ok to block_bad_connections.hook_rcpt_ok priority 0
2022-11-01 16:01:52.292028500 [DEBUG] [-] [core] registered hook disconnect to block_bad_connections.hook_disconnect priority 0
2022-11-01 16:01:52.292042500 [INFO] [-] [core] Loading plugin: karma
2022-11-01 16:01:52.292057500 [DEBUG] [-] [core] no timeout in karma.timeout
2022-11-01 16:01:52.292062500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.292074500 [DEBUG] [-] [core] plugin karma timeout is: 30s
2022-11-01 16:01:52.292089500 [DEBUG] [-] [core] no timeout in haraka-plugin-redis.timeout
2022-11-01 16:01:52.292103500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.292122500 [DEBUG] [-] [core] plugin haraka-plugin-redis timeout is: 30s
2022-11-01 16:01:52.292142500 [DEBUG] [-] [core] registered hook init_master to karma.init_redis_plugin priority 0
2022-11-01 16:01:52.292157500 [DEBUG] [-] [core] registered hook init_child to karma.init_redis_plugin priority 0
2022-11-01 16:01:52.292162500 [DEBUG] [-] [core] registered hook connect_init to karma.results_init priority 0
2022-11-01 16:01:52.292174500 [DEBUG] [-] [core] registered hook connect_init to karma.ip_history_from_redis priority 0
2022-11-01 16:01:52.292189500 [DEBUG] [-] [core] registered hook deny to karma.hook_deny priority 0
2022-11-01 16:01:52.292194500 [DEBUG] [-] [core] registered hook connect to karma.hook_connect priority 0
2022-11-01 16:01:52.292213500 [DEBUG] [-] [core] registered hook helo to karma.hook_helo priority 0
2022-11-01 16:01:52.292219500 [DEBUG] [-] [core] registered hook ehlo to karma.hook_ehlo priority 0
2022-11-01 16:01:52.292231500 [DEBUG] [-] [core] registered hook vrfy to karma.hook_vrfy priority 0
2022-11-01 16:01:52.292236500 [DEBUG] [-] [core] registered hook noop to karma.hook_noop priority 0
2022-11-01 16:01:52.292249500 [DEBUG] [-] [core] registered hook data to karma.hook_data priority 0
2022-11-01 16:01:52.292263500 [DEBUG] [-] [core] registered hook queue to karma.hook_queue priority 0
2022-11-01 16:01:52.292278500 [DEBUG] [-] [core] registered hook reset_transaction to karma.hook_reset_transaction priority 0
2022-11-01 16:01:52.292283500 [DEBUG] [-] [core] registered hook unrecognized_command to karma.hook_unrecognized_command priority 0
2022-11-01 16:01:52.292295500 [DEBUG] [-] [core] registered hook mail to karma.hook_mail priority 0
2022-11-01 16:01:52.292310500 [DEBUG] [-] [core] registered hook rcpt to karma.hook_rcpt priority 0
2022-11-01 16:01:52.292315500 [DEBUG] [-] [core] registered hook rcpt_ok to karma.hook_rcpt_ok priority 0
2022-11-01 16:01:52.292327500 [DEBUG] [-] [core] registered hook data_post to karma.hook_data_post priority 0
2022-11-01 16:01:52.292342500 [DEBUG] [-] [core] registered hook disconnect to karma.hook_disconnect priority 0
2022-11-01 16:01:52.292347500 [INFO] [-] [core] Loading plugin: early_talker
2022-11-01 16:01:52.292359500 [DEBUG] [-] [core] no timeout in early_talker.timeout
2022-11-01 16:01:52.292374500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.292388500 [DEBUG] [-] [core] plugin early_talker timeout is: 30s
2022-11-01 16:01:52.292393500 [DEBUG] [-] [core] registered hook connect_init to early_talker.early_talker priority 0
2022-11-01 16:01:52.292405500 [DEBUG] [-] [core] registered hook data to early_talker.early_talker priority 0
2022-11-01 16:01:52.292420500 [INFO] [-] [core] Loading plugin: asn
2022-11-01 16:01:52.292425500 [DEBUG] [-] [core] no timeout in asn.timeout
2022-11-01 16:01:52.292437500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.292452500 [DEBUG] [-] [core] plugin asn timeout is: 30s
2022-11-01 16:01:52.292457500 [ERROR] [-] [asn] maxmind loaded but no GeoIP DBs found!
2022-11-01 16:01:52.292469500 [DEBUG] [-] [core] registered hook data_post to asn.add_header_asn priority 0
2022-11-01 16:01:52.292484500 [INFO] [-] [core] Loading plugin: helo.checks
2022-11-01 16:01:52.292489500 [DEBUG] [-] [core] no timeout in helo.checks.timeout
2022-11-01 16:01:52.292501500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.292515500 [DEBUG] [-] [core] plugin helo.checks timeout is: 30s
2022-11-01 16:01:52.292520500 [DEBUG] [-] [core] registered hook helo to helo.checks.proto_mismatch_smtp priority 0
2022-11-01 16:01:52.292532500 [DEBUG] [-] [core] registered hook ehlo to helo.checks.proto_mismatch_esmtp priority 0
2022-11-01 16:01:52.292547500 [DEBUG] [-] [core] registered hook helo to helo.checks.init priority 0
2022-11-01 16:01:52.292552500 [DEBUG] [-] [core] registered hook ehlo to helo.checks.init priority 0
2022-11-01 16:01:52.292565500 [DEBUG] [-] [core] registered hook helo to helo.checks.emit_log priority 0
2022-11-01 16:01:52.292579500 [DEBUG] [-] [core] registered hook ehlo to helo.checks.emit_log priority 0
2022-11-01 16:01:52.292584500 [INFO] [-] [core] Loading plugin: p0f
2022-11-01 16:01:52.292597500 [DEBUG] [-] [core] no timeout in p0f.timeout
2022-11-01 16:01:52.292611500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.292616500 [DEBUG] [-] [core] plugin p0f timeout is: 30s
2022-11-01 16:01:52.292629500 [DEBUG] [-] [core] registered hook init_master to p0f.start_p0f_client priority 0
2022-11-01 16:01:52.292643500 [DEBUG] [-] [core] registered hook init_child to p0f.start_p0f_client priority 0
2022-11-01 16:01:52.292648500 [DEBUG] [-] [core] registered hook lookup_rdns to p0f.query_p0f priority 0
2022-11-01 16:01:52.292660500 [DEBUG] [-] [core] registered hook data_post to p0f.add_p0f_header priority 0
2022-11-01 16:01:52.292680500 [INFO] [-] [core] Loading plugin: fcrdns
2022-11-01 16:01:52.292695500 [DEBUG] [-] [core] no timeout in fcrdns.timeout
2022-11-01 16:01:52.292700500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.292712500 [DEBUG] [-] [core] plugin fcrdns timeout is: 30s
2022-11-01 16:01:52.292726500 [DEBUG] [-] [core] registered hook connect_init to fcrdns.initialize_fcrdns priority 0
2022-11-01 16:01:52.292731500 [DEBUG] [-] [core] registered hook lookup_rdns to fcrdns.do_dns_lookups priority 0
2022-11-01 16:01:52.292744500 [DEBUG] [-] [core] registered hook data to fcrdns.add_message_headers priority 0
2022-11-01 16:01:52.292758500 [INFO] [-] [core] Loading plugin: geoip
2022-11-01 16:01:52.292763500 [DEBUG] [-] [core] no timeout in geoip.timeout
2022-11-01 16:01:52.292775500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.292790500 [DEBUG] [-] [core] plugin geoip timeout is: 30s
2022-11-01 16:01:52.292804500 [DEBUG] [-] [geoip] missing DB /opt/ipgeo/GeoLite2-City.mmdb
2022-11-01 16:01:52.292809500 [INFO] [-] [core] Loading plugin: dnsbl
2022-11-01 16:01:52.292821500 [DEBUG] [-] [core] no timeout in dnsbl.timeout
2022-11-01 16:01:52.292836500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.292841500 [DEBUG] [-] [core] plugin dnsbl timeout is: 30s
2022-11-01 16:01:52.292853500 [DEBUG] [-] [core] no timeout in dns_list_base.timeout
2022-11-01 16:01:52.292868500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.292873500 [DEBUG] [-] [core] plugin dns_list_base timeout is: 30s
2022-11-01 16:01:52.292885500 [DEBUG] [-] [dnsbl] looking up: 1.0.0.127.spamsources.fabel.dk.
2022-11-01 16:01:52.292900500 [DEBUG] [-] [dnsbl] looking up: 1.0.0.127.zen.spamhaus.org.
2022-11-01 16:01:52.292905500 [DEBUG] [-] [dnsbl] looking up: 1.0.0.127.b.barracudacentral.org.
2022-11-01 16:01:52.292917500 [DEBUG] [-] [dnsbl] looking up: 1.0.0.127.bl.spamcop.net.
2022-11-01 16:01:52.292931500 [DEBUG] [-] [dnsbl] will re-test list zones every 30 minutes
2022-11-01 16:01:52.292946500 [DEBUG] [-] [core] registered hook connect to dnsbl.connect_first priority 0
2022-11-01 16:01:52.292951500 [INFO] [-] [core] Loading plugin: mail_from.is_resolvable
2022-11-01 16:01:52.292964500 [DEBUG] [-] [core] no timeout in mail_from.is_resolvable.timeout
2022-11-01 16:01:52.292978500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.292983500 [DEBUG] [-] [core] plugin mail_from.is_resolvable timeout is: 30s
2022-11-01 16:01:52.292996500 [DEBUG] [-] [core] registered hook mail to mail_from.is_resolvable.hook_mail priority 0
2022-11-01 16:01:52.293010500 [INFO] [-] [core] Loading plugin: dkim_verify
2022-11-01 16:01:52.293025500 [DEBUG] [-] [core] no timeout in dkim_verify.timeout
2022-11-01 16:01:52.293031500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.293043500 [DEBUG] [-] [core] plugin dkim_verify timeout is: 30s
2022-11-01 16:01:52.293057500 [DEBUG] [-] [core] registered hook data_post to dkim_verify.hook_data_post priority 0
2022-11-01 16:01:52.293063500 [INFO] [-] [core] Loading plugin: spf
2022-11-01 16:01:52.293075500 [DEBUG] [-] [core] no timeout in spf.timeout
2022-11-01 16:01:52.293089500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.293094500 [DEBUG] [-] [core] plugin spf timeout is: 30s
2022-11-01 16:01:52.293115500 [DEBUG] [-] [core] registered hook helo to spf.helo_spf priority 0
2022-11-01 16:01:52.293134500 [DEBUG] [-] [core] registered hook ehlo to spf.helo_spf priority 0
2022-11-01 16:01:52.293149500 [DEBUG] [-] [core] registered hook mail to spf.hook_mail priority 0
2022-11-01 16:01:52.293164500 [INFO] [-] [core] Loading plugin: data.uribl
2022-11-01 16:01:52.293178500 [DEBUG] [-] [core] no timeout in data.uribl.timeout
2022-11-01 16:01:52.293183500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.293196500 [DEBUG] [-] [core] plugin data.uribl timeout is: 30s
2022-11-01 16:01:52.293215500 [DEBUG] [-] [data.uribl] Building new regexps from TLD file
2022-11-01 16:01:52.293220500 [DEBUG] [-] [core] registered hook lookup_rdns to data.uribl.hook_lookup_rdns priority 0
2022-11-01 16:01:52.293233500 [DEBUG] [-] [core] registered hook ehlo to data.uribl.hook_ehlo priority 0
2022-11-01 16:01:52.293238500 [DEBUG] [-] [core] registered hook helo to data.uribl.hook_helo priority 0
2022-11-01 16:01:52.293250500 [DEBUG] [-] [core] registered hook mail to data.uribl.hook_mail priority 0
2022-11-01 16:01:52.293265500 [DEBUG] [-] [core] registered hook data to data.uribl.hook_data priority 0
2022-11-01 16:01:52.293270500 [DEBUG] [-] [core] registered hook data_post to data.uribl.hook_data_post priority 0
2022-11-01 16:01:52.293282500 [NOTICE] [-] [core] the plugin data.headers has been replaced by 'headers'. Please update config/plugins
2022-11-01 16:01:52.293297500 [INFO] [-] [core] Loading plugin: headers
2022-11-01 16:01:52.293302500 [DEBUG] [-] [core] no timeout in headers.timeout
2022-11-01 16:01:52.293314500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.293328500 [DEBUG] [-] [core] plugin headers timeout is: 30s
2022-11-01 16:01:52.293335500 [DEBUG] [-] [core] registered hook data_post to headers.duplicate_singular priority 0
2022-11-01 16:01:52.293347500 [DEBUG] [-] [core] registered hook data_post to headers.missing_required priority 0
2022-11-01 16:01:52.293362500 [DEBUG] [-] [core] registered hook data_post to headers.invalid_return_path priority 0
2022-11-01 16:01:52.293367500 [DEBUG] [-] [core] registered hook data_post to headers.invalid_date priority 0
2022-11-01 16:01:52.293379500 [DEBUG] [-] [core] registered hook data_post to headers.user_agent priority 0
2022-11-01 16:01:52.293394500 [DEBUG] [-] [core] registered hook data_post to headers.direct_to_mx priority 0
2022-11-01 16:01:52.293409500 [DEBUG] [-] [core] registered hook data_post to headers.from_match priority 0
2022-11-01 16:01:52.293414500 [DEBUG] [-] [core] registered hook data_post to headers.delivered_to priority 0
2022-11-01 16:01:52.293426500 [DEBUG] [-] [core] registered hook data_post to headers.mailing_list priority 0
2022-11-01 16:01:52.293441500 [DEBUG] [-] [core] registered hook data_post to headers.from_phish priority 0
2022-11-01 16:01:52.293446500 [INFO] [-] [core] Loading plugin: known-senders
2022-11-01 16:01:52.293458500 [DEBUG] [-] [core] no timeout in known-senders.timeout
2022-11-01 16:01:52.293473500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.293478500 [DEBUG] [-] [core] plugin known-senders timeout is: 30s
2022-11-01 16:01:52.293490500 [DEBUG] [-] [core] no timeout in haraka-plugin-redis.timeout
2022-11-01 16:01:52.293505500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.293510500 [DEBUG] [-] [core] plugin haraka-plugin-redis timeout is: 30s
2022-11-01 16:01:52.293522500 [DEBUG] [-] [core] registered hook init_master to known-senders.init_redis_plugin priority 0
2022-11-01 16:01:52.293537500 [DEBUG] [-] [core] registered hook init_child to known-senders.init_redis_plugin priority 0
2022-11-01 16:01:52.293542500 [DEBUG] [-] [core] registered hook mail to known-senders.is_authenticated priority 0
2022-11-01 16:01:52.293555500 [DEBUG] [-] [core] registered hook rcpt_ok to known-senders.check_recipient priority 0
2022-11-01 16:01:52.293569500 [DEBUG] [-] [core] registered hook queue_ok to known-senders.update_sender priority 0
2022-11-01 16:01:52.293584500 [DEBUG] [-] [core] registered hook data_post to known-senders.is_dkim_authenticated priority 0
2022-11-01 16:01:52.293589500 [INFO] [-] [core] Loading plugin: bounce
2022-11-01 16:01:52.293601500 [DEBUG] [-] [core] no timeout in bounce.timeout
2022-11-01 16:01:52.293616500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.293621500 [DEBUG] [-] [core] plugin bounce timeout is: 30s
2022-11-01 16:01:52.293633500 [DEBUG] [-] [core] registered hook mail to bounce.reject_all priority 0
2022-11-01 16:01:52.293648500 [DEBUG] [-] [core] registered hook data to bounce.single_recipient priority 0
2022-11-01 16:01:52.293653500 [DEBUG] [-] [core] registered hook data to bounce.bad_rcpt priority 0
2022-11-01 16:01:52.293669500 [DEBUG] [-] [core] registered hook data_post to bounce.empty_return_path priority 0
2022-11-01 16:01:52.293675500 [DEBUG] [-] [core] registered hook data to bounce.bounce_spf_enable priority 0
2022-11-01 16:01:52.293687500 [DEBUG] [-] [core] registered hook data_post to bounce.bounce_spf priority 0
2022-11-01 16:01:52.293693500 [DEBUG] [-] [core] registered hook data_post to bounce.non_local_msgid priority 0
2022-11-01 16:01:52.293705500 [INFO] [-] [core] Loading plugin: log
2022-11-01 16:01:52.293719500 [DEBUG] [-] [core] no timeout in log.timeout
2022-11-01 16:01:52.293724500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.293736500 [DEBUG] [-] [core] plugin log timeout is: 30s
2022-11-01 16:01:52.293751500 [DEBUG] [-] [log] Plugin log: {"main":{"elasticsearch":false,"elasticsearch_host":"localhost:9200"}}
2022-11-01 16:01:52.293766500 [DEBUG] [-] [core] registered hook reset_transaction to log.hook_reset_transaction priority 0
2022-11-01 16:01:52.293771500 [DEBUG] [-] [core] registered hook disconnect to log.hook_disconnect priority 0
2022-11-01 16:01:52.293783500 [DEBUG] [-] [core] registered hook mail to log.hook_mail priority 0
2022-11-01 16:01:52.293798500 [DEBUG] [-] [core] registered hook deferred to log.hook_deferred priority 0
2022-11-01 16:01:52.293803500 [DEBUG] [-] [core] registered hook bounce to log.hook_bounce priority 0
2022-11-01 16:01:52.293815500 [DEBUG] [-] [core] registered hook delivered to log.hook_delivered priority 0
2022-11-01 16:01:52.293830500 [DEBUG] [-] [core] registered hook log to log.hook_log priority 0
2022-11-01 16:01:52.293835500 [INFO] [-] [core] Loading plugin: redis
2022-11-01 16:01:52.293847500 [DEBUG] [-] [core] no timeout in redis.timeout
2022-11-01 16:01:52.293862500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.293867500 [DEBUG] [-] [core] plugin redis timeout is: 30s
2022-11-01 16:01:52.293879500 [DEBUG] [-] [core] registered hook init_master to redis.init_redis_shared priority 0
2022-11-01 16:01:52.293893500 [DEBUG] [-] [core] registered hook init_child to redis.init_redis_shared priority 0
2022-11-01 16:01:52.293908500 [INFO] [-] [core] Loading plugin: relay
2022-11-01 16:01:52.293922500 [DEBUG] [-] [core] no timeout in relay.timeout
2022-11-01 16:01:52.293927500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.293940500 [DEBUG] [-] [core] plugin relay timeout is: 30s
2022-11-01 16:01:52.293954500 [DEBUG] [-] [core] registered hook connect_init to relay.acl priority 0
2022-11-01 16:01:52.293959500 [DEBUG] [-] [core] registered hook connect to relay.pass_relaying priority 0
2022-11-01 16:01:52.293971500 [DEBUG] [-] [core] registered hook get_mx to relay.force_routing priority 0
2022-11-01 16:01:52.293986500 [INFO] [-] [core] Loading plugin: tls
2022-11-01 16:01:52.294000500 [DEBUG] [-] [core] no timeout in tls.timeout
2022-11-01 16:01:52.294005500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.294017500 [DEBUG] [-] [core] plugin tls timeout is: 30s
2022-11-01 16:01:52.294032500 [INFO] [-] [core] loading tls.ini
2022-11-01 16:01:52.294037500 [DEBUG] [-] [core] loading dhparams from dhparams.pem
2022-11-01 16:01:52.294049500 [DEBUG] [-] [tls] Will disable STARTTLS for failing TLS hosts
2022-11-01 16:01:52.294064500 [DEBUG] [-] [core] registered hook capabilities to tls.advertise_starttls priority 0
2022-11-01 16:01:52.294078500 [DEBUG] [-] [core] registered hook unrecognized_command to tls.upgrade_connection priority 0
2022-11-01 16:01:52.294084500 [DEBUG] [-] [core] registered hook disconnect to tls.hook_disconnect priority 0
2022-11-01 16:01:52.294096500 [INFO] [-] [core] Loading plugin: queue/decide
2022-11-01 16:01:52.294122500 [DEBUG] [-] [core] no timeout in queue/decide.timeout
2022-11-01 16:01:52.294128500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.294145500 [DEBUG] [-] [core] plugin queue/decide timeout is: 30s
2022-11-01 16:01:52.294150500 [INFO] [-] [queue/decide] cfg={"main":{"quarantine_enabled":false,"quarantine_denied_emails":true,"quarantine_path":"/data/quarantine"},"rspamd":{"quarantine":12,"prefix":"S"}}
2022-11-01 16:01:52.294162500 [DEBUG] [-] [core] registered hook deny to queue/decide.hook_deny priority 0
2022-11-01 16:01:52.294177500 [DEBUG] [-] [core] registered hook queue_ok to queue/decide.hook_queue_ok priority 0
2022-11-01 16:01:52.294182500 [DEBUG] [-] [core] registered hook data_post to queue/decide.hook_data_post priority 0
2022-11-01 16:01:52.294194500 [INFO] [-] [core] Loading plugin: rcpt_database
2022-11-01 16:01:52.294209500 [DEBUG] [-] [core] no timeout in rcpt_database.timeout
2022-11-01 16:01:52.294214500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.294226500 [DEBUG] [-] [core] plugin rcpt_database timeout is: 30s
2022-11-01 16:01:52.294240500 [DEBUG] [-] [core] registered hook mail to rcpt_database.is_remote_sender priority 0
2022-11-01 16:01:52.294245500 [DEBUG] [-] [core] registered hook rcpt to rcpt_database.database_rcpt priority 0
2022-11-01 16:01:52.294257500 [DEBUG] [-] [core] registered hook data_post to rcpt_database.hook_data_post priority 0
2022-11-01 16:01:52.294272500 [DEBUG] [-] [core] registered hook get_mx to rcpt_database.hook_get_mx priority 0
2022-11-01 16:01:52.294277500 [INFO] [-] [core] Loading plugin: srs
2022-11-01 16:01:52.294290500 [DEBUG] [-] [core] no timeout in srs.timeout
2022-11-01 16:01:52.294304500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.294309500 [DEBUG] [-] [core] plugin srs timeout is: 30s
2022-11-01 16:01:52.294321500 [DEBUG] [-] [core] registered hook data_post to srs.hook_data_post priority 0
2022-11-01 16:01:52.294337500 [DEBUG] [-] [core] registered hook rcpt to srs.hook_rcpt priority 0
2022-11-01 16:01:52.294342500 [DEBUG] [-] [core] registered hook bounce to srs.hook_bounce priority 0
2022-11-01 16:01:52.294354500 [INFO] [-] [core] Loading plugin: dkim_sign
2022-11-01 16:01:52.294368500 [DEBUG] [-] [core] no timeout in dkim_sign.timeout
2022-11-01 16:01:52.294374500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.294386500 [DEBUG] [-] [core] plugin dkim_sign timeout is: 30s
2022-11-01 16:01:52.294400500 [DEBUG] [-] [core] registered hook pre_send_trans_email to dkim_sign.hook_pre_send_trans_email priority 0
2022-11-01 16:01:52.294406500 [DEBUG] [-] [core] registered hook queue_outbound to dkim_sign.hook_queue_outbound priority 0
2022-11-01 16:01:52.294418500 [INFO] [-] [core] Loading plugin: discard
2022-11-01 16:01:52.294433500 [DEBUG] [-] [core] no timeout in discard.timeout
2022-11-01 16:01:52.294447500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.294452500 [DEBUG] [-] [core] plugin discard timeout is: 30s
2022-11-01 16:01:52.294464500 [DEBUG] [-] [core] registered hook queue to discard.discard priority 0
2022-11-01 16:01:52.294479500 [DEBUG] [-] [core] registered hook queue_outbound to discard.discard priority 0
2022-11-01 16:01:52.294484500 [INFO] [-] [core] Loading plugin: dovecot_quota
2022-11-01 16:01:52.294496500 [DEBUG] [-] [core] no timeout in dovecot_quota.timeout
2022-11-01 16:01:52.294511500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.294516500 [DEBUG] [-] [core] plugin dovecot_quota timeout is: 30s
2022-11-01 16:01:52.294528500 [DEBUG] [-] [core] no timeout in rcpt_to.host_list_base.timeout
2022-11-01 16:01:52.294543500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.294548500 [DEBUG] [-] [core] plugin rcpt_to.host_list_base timeout is: 30s
2022-11-01 16:01:52.294560500 [DEBUG] [-] [core] registered hook mail to dovecot_quota.hook_mail priority 0
2022-11-01 16:01:52.294575500 [DEBUG] [-] [core] registered hook data_post to dovecot_quota.hook_data_post priority 0
2022-11-01 16:01:52.294580500 [INFO] [-] [core] Loading plugin: attachment
2022-11-01 16:01:52.294592500 [DEBUG] [-] [core] no timeout in attachment.timeout
2022-11-01 16:01:52.294611500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.294616500 [DEBUG] [-] [core] plugin attachment timeout is: 30s
2022-11-01 16:01:52.294628500 [DEBUG] [-] [core] registered hook data_post to attachment.wait_for_attachment_hooks priority 0
2022-11-01 16:01:52.294633500 [DEBUG] [-] [core] registered hook data_post to attachment.check_attachments priority 0
2022-11-01 16:01:52.294645500 [DEBUG] [-] [core] registered hook init_child to attachment.hook_init_child priority 0
2022-11-01 16:01:52.294660500 [DEBUG] [-] [core] registered hook init_master to attachment.hook_init_master priority 0
2022-11-01 16:01:52.294665500 [DEBUG] [-] [core] registered hook data to attachment.hook_data priority 0
2022-11-01 16:01:52.294678500 [INFO] [-] [core] Loading plugin: strict_from
2022-11-01 16:01:52.294693500 [DEBUG] [-] [core] no timeout in strict_from.timeout
2022-11-01 16:01:52.294699500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.294711500 [DEBUG] [-] [core] plugin strict_from timeout is: 30s
2022-11-01 16:01:52.294725500 [DEBUG] [-] [strict_from] Plugin enabled: {"main":{"disabled":true}}
2022-11-01 16:01:52.294730500 [DEBUG] [-] [strict_from] Plugin enabled: false
2022-11-01 16:01:52.294742500 [DEBUG] [-] [core] registered hook data_post to strict_from.from_check priority 0
2022-11-01 16:01:52.294757500 [INFO] [-] [core] Loading plugin: privacy
2022-11-01 16:01:52.294771500 [DEBUG] [-] [core] no timeout in privacy.timeout
2022-11-01 16:01:52.294776500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.294788500 [DEBUG] [-] [core] plugin privacy timeout is: 30s
2022-11-01 16:01:52.294802500 [DEBUG] [-] [core] registered hook queue_outbound to privacy.hook_queue_outbound priority 0
2022-11-01 16:01:52.294807500 [INFO] [-] [core] Loading plugin: inspection
2022-11-01 16:01:52.294820500 [DEBUG] [-] [core] no timeout in inspection.timeout
2022-11-01 16:01:52.294834500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.294839500 [DEBUG] [-] [core] plugin inspection timeout is: 30s
2022-11-01 16:01:52.294852500 [INFO] [-] [inspection] cfg={"main":{"log_subject":true,"copy_emails":false,"target_email":""}}
2022-11-01 16:01:52.294866500 [DEBUG] [-] [core] registered hook data_post to inspection.hook_data_post priority 0
2022-11-01 16:01:52.294881500 [INFO] [-] [core] Loading plugin: queue/dmarc-report-save
2022-11-01 16:01:52.294886500 [DEBUG] [-] [core] no timeout in queue/dmarc-report-save.timeout
2022-11-01 16:01:52.294898500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.294904500 [DEBUG] [-] [core] plugin queue/dmarc-report-save timeout is: 30s
2022-11-01 16:01:52.294916500 [DEBUG] [-] [core] registered hook queue to queue/dmarc-report-save.hook_queue priority 0
2022-11-01 16:01:52.294930500 [INFO] [-] [core] Loading plugin: queue/quarantine
2022-11-01 16:01:52.294935500 [DEBUG] [-] [core] no timeout in queue/quarantine.timeout
2022-11-01 16:01:52.294948500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.294962500 [DEBUG] [-] [core] plugin queue/quarantine timeout is: 30s
2022-11-01 16:01:52.294967500 [DEBUG] [-] [core] registered hook queue to queue/quarantine.quarantine priority 0
2022-11-01 16:01:52.294979500 [DEBUG] [-] [core] registered hook queue_outbound to queue/quarantine.quarantine priority 0
2022-11-01 16:01:52.294994500 [DEBUG] [-] [core] registered hook init_master to queue/quarantine.hook_init_master priority 0
2022-11-01 16:01:52.294999500 [INFO] [-] [core] Loading plugin: queue/generic
2022-11-01 16:01:52.295011500 [DEBUG] [-] [core] no timeout in queue/generic.timeout
2022-11-01 16:01:52.295026500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.295031500 [DEBUG] [-] [core] plugin queue/generic timeout is: 30s
2022-11-01 16:01:52.295043500 [DEBUG] [-] [core] registered hook queue to queue/generic.hook_queue priority 0
2022-11-01 16:01:52.295057500 [INFO] [-] [core] Loading plugin: watch
2022-11-01 16:01:52.295062500 [DEBUG] [-] [core] no timeout in watch.timeout
2022-11-01 16:01:52.295078500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.295083500 [DEBUG] [-] [core] plugin watch timeout is: 30s
2022-11-01 16:01:52.295095500 [DEBUG] [-] [core] no timeout in haraka-plugin-redis.timeout
2022-11-01 16:01:52.295143500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.295149500 [DEBUG] [-] [core] plugin haraka-plugin-redis timeout is: 30s
2022-11-01 16:01:52.295161500 [DEBUG] [-] [core] registered hook init_master to watch.redis_subscribe_all_results priority 0
2022-11-01 16:01:52.295166500 [DEBUG] [-] [core] registered hook init_child to watch.redis_subscribe_all_results priority 0
2022-11-01 16:01:52.295179500 [DEBUG] [-] [core] registered hook deny to watch.w_deny priority 0
2022-11-01 16:01:52.295184500 [DEBUG] [-] [core] registered hook queue_ok to watch.queue_ok priority 0
2022-11-01 16:01:52.295196500 [DEBUG] [-] [core] registered hook init_http to watch.hook_init_http priority 0
2022-11-01 16:01:52.295211500 [DEBUG] [-] [core] registered hook init_wss to watch.hook_init_wss priority 0
2022-11-01 16:01:52.295216500 [INFO] [-] [core] Loading plugin: limit
2022-11-01 16:01:52.295228500 [DEBUG] [-] [core] no timeout in limit.timeout
2022-11-01 16:01:52.295243500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.295258500 [DEBUG] [-] [core] plugin limit timeout is: 30s
2022-11-01 16:01:52.295263500 [DEBUG] [-] [core] no timeout in haraka-plugin-redis.timeout
2022-11-01 16:01:52.295275500 [DEBUG] [-] [core] no timeout in plugin_timeout
2022-11-01 16:01:52.295289500 [DEBUG] [-] [core] plugin haraka-plugin-redis timeout is: 30s
2022-11-01 16:01:52.295295500 [DEBUG] [-] [core] registered hook init_master to limit.init_redis_plugin priority 0
2022-11-01 16:01:52.295307500 [DEBUG] [-] [core] registered hook init_child to limit.init_redis_plugin priority 0
2022-11-01 16:01:52.299836500 [NOTICE] [-] [core] Listening on [::0]:25
2022-11-01 16:01:52.300019500 [NOTICE] [-] [server] Switching from current gid: 0
2022-11-01 16:01:52.300526500 [NOTICE] [-] [server] New gid: 8
2022-11-01 16:01:52.300580500 [NOTICE] [-] [server] Switching from current uid: 0
2022-11-01 16:01:52.300702500 [NOTICE] [-] [server] New uid: 88
2022-11-01 16:01:52.300735500 [DEBUG] [-] [server] running init_master hooks
2022-11-01 16:01:52.300811500 [DEBUG] [-] [server] running init_master hook in status_http plugin
2022-11-01 16:01:52.301572500 [DEBUG] [-] [server] hook=init_master plugin=status_http function=hook_init_master params="" retval=CONT msg=""
2022-11-01 16:01:52.301603500 [DEBUG] [-] [server] running init_master hook in poste plugin
2022-11-01 16:01:52.301727500 [DEBUG] [-] [server] hook=init_master plugin=poste function=init_sqlite params="" retval=CONT msg=""
2022-11-01 16:01:52.301780500 [DEBUG] [-] [server] running init_master hook in karma plugin
2022-11-01 16:01:52.304762500 [DEBUG] [-] [asn] origin.asn.cymru.com answers: 7819 | 66.128.48.0/20 | US | arin | 2006-08-17
2022-11-01 16:01:52.305047500 [INFO] [-] [asn] origin.asn.cymru.com succeeded
2022-11-01 16:01:52.305098500 [DEBUG] [-] [core] registered hook lookup_rdns to asn.lookup_via_dns priority 0
2022-11-01 16:01:52.305567500 [DEBUG] [-] [dnsbl] looking up: 2.0.0.127.spamsources.fabel.dk.
2022-11-01 16:01:52.305736500 [DEBUG] [-] [dnsbl] looking up: 2.0.0.127.b.barracudacentral.org.
2022-11-01 16:01:52.305846500 [DEBUG] [-] [dnsbl] looking up: 2.0.0.127.zen.spamhaus.org.
2022-11-01 16:01:52.305943500 [DEBUG] [-] [dnsbl] looking up: 2.0.0.127.bl.spamcop.net.
2022-11-01 16:01:52.309709500 [INFO] [-] [karma] connected to redis://127.0.0.1:6379
2022-11-01 16:01:52.309823500 [DEBUG] [-] [server] hook=init_master plugin=karma function=init_redis_plugin params="" retval=CONT msg=""
2022-11-01 16:01:52.309887500 [DEBUG] [-] [server] running init_master hook in p0f plugin
2022-11-01 16:01:52.310574500 [DEBUG] [-] [server] hook=init_master plugin=p0f function=start_p0f_client params="" retval=CONT msg=""
2022-11-01 16:01:52.310632500 [DEBUG] [-] [server] running init_master hook in known-senders plugin
2022-11-01 16:01:52.312972500 [WARN] [-] [dnsbl] zone 'zen.spamhaus.org' did not respond to test point (null)
2022-11-01 16:01:52.313126500 [WARN] [-] [dnsbl] disabling zone 'zen.spamhaus.org'
2022-11-01 16:01:52.313587500 [INFO] [-] [known-senders] connected to redis://127.0.0.1:6379
2022-11-01 16:01:52.313627500 [DEBUG] [-] [server] hook=init_master plugin=known-senders function=init_redis_plugin params="" retval=CONT msg=""
2022-11-01 16:01:52.313707500 [DEBUG] [-] [server] running init_master hook in redis plugin
2022-11-01 16:01:52.314813500 [INFO] [-] [redis] connected to redis://127.0.0.1:6379
2022-11-01 16:01:52.314914500 [DEBUG] [-] [server] hook=init_master plugin=redis function=init_redis_shared params="" retval=CONT msg=""
2022-11-01 16:01:52.314966500 [DEBUG] [-] [server] running init_master hook in attachment plugin
2022-11-01 16:01:52.315533500 [DEBUG] [-] [attachment] found bsdtar in /usr/bin
2022-11-01 16:01:52.315580500 [DEBUG] [-] [server] hook=init_master plugin=attachment function=hook_init_master params="" retval=CONT msg=""
2022-11-01 16:01:52.315621500 [DEBUG] [-] [server] running init_master hook in queue/quarantine plugin
2022-11-01 16:01:52.317975500 [DEBUG] [-] [geoip] loaded maxmind db /opt/ipgeo/GeoLite2-Country.mmdb
2022-11-01 16:01:52.318034500 [DEBUG] [-] [geoip] missing DB /opt/ipgeo/GeoLite2-ASN.mmdb
2022-11-01 16:01:52.318066500 [DEBUG] [-] [geoip] loaded maxmind with 1 DBs
2022-11-01 16:01:52.318130500 [DEBUG] [-] [core] registered hook connect to geoip.lookup_maxmind priority 0
2022-11-01 16:01:52.318170500 [DEBUG] [-] [core] registered hook data_post to geoip.add_headers priority 0
2022-11-01 16:01:52.318258500 [INFO] [-] [queue/quarantine] created /data/quarantine/tmp
2022-11-01 16:01:52.318485500 [INFO] [-] [queue/quarantine] Removing temporary files from: /data/quarantine/tmp
2022-11-01 16:01:52.318543500 [DEBUG] [-] [server] hook=init_master plugin=queue/quarantine function=hook_init_master params="" retval=CONT msg=""
2022-11-01 16:01:52.318581500 [DEBUG] [-] [server] running init_master hook in watch plugin
2022-11-01 16:01:52.320774500 [DEBUG] [-] [watch] psubscribed to result-*
2022-11-01 16:01:52.320959500 [DEBUG] [-] [server] hook=init_master plugin=watch function=redis_subscribe_all_results params="" retval=CONT msg=""
2022-11-01 16:01:52.321002500 [DEBUG] [-] [server] running init_master hook in limit plugin
2022-11-01 16:01:52.322004500 [INFO] [-] [limit] connected to redis://127.0.0.1:6379/4
2022-11-01 16:01:52.322199500 [DEBUG] [-] [server] hook=init_master plugin=limit function=init_redis_plugin params="" retval=CONT msg=""
2022-11-01 16:01:52.322648500 [INFO] [-] [core] [outbound] Loading outbound queue from /data/queue/smtp
2022-11-01 16:01:52.385834500 [INFO] [-] [core] express loaded at Server.http.express
2022-11-01 16:01:52.386845500 [INFO] [-] [core] express app is at Server.http.app
2022-11-01 16:01:52.387559500 [NOTICE] [-] [core] Listening on 127.0.0.1:11380
2022-11-01 16:01:52.387612500 [DEBUG] [-] [server] running init_http hooks
2022-11-01 16:01:52.387674500 [DEBUG] [-] [server] running init_http hook in status_http plugin
2022-11-01 16:01:52.393236500 [INFO] [-] [status_http] status init_http done
2022-11-01 16:01:52.393304500 [DEBUG] [-] [server] hook=init_http plugin=status_http function=hook_init_http params="" retval=CONT msg=""
2022-11-01 16:01:52.393321500 [DEBUG] [-] [server] running init_http hook in watch plugin
2022-11-01 16:01:52.393812500 [INFO] [-] [watch] watch init_http done
2022-11-01 16:01:52.393830500 [DEBUG] [-] [server] hook=init_http plugin=watch function=hook_init_http params="" retval=CONT msg=""
2022-11-01 16:01:52.393930500 [INFO] [-] [core] init_http_respond
2022-11-01 16:01:52.405904500 [INFO] [-] [core] Server.http.wss loaded
2022-11-01 16:01:52.405925500 [DEBUG] [-] [server] running init_wss hooks
2022-11-01 16:01:52.405972500 [DEBUG] [-] [server] running init_wss hook in watch plugin
2022-11-01 16:01:52.406049500 [INFO] [-] [watch] watch init_wss
2022-11-01 16:01:52.406088500 [INFO] [-] [watch] watch init_wss done
2022-11-01 16:01:52.406189500 [DEBUG] [-] [server] hook=init_wss plugin=watch function=hook_init_wss params="" retval=CONT msg=""
2022-11-01 16:01:52.406240500 [INFO] [-] [core] init_wss_respond
2022-11-01 16:01:52.406932500 [INFO] [-] [core] [outbound] Loading the queue...
2022-11-01 16:01:52.407064500 [DEBUG] [-] [core] [outbound] [pid: undefined] 0 files loaded
2022-11-01 16:01:52.407195500 [INFO] [-] [core] [outbound] [pid: undefined] 0 files in my delivery queue
2022-11-01 16:01:52.407229500 [INFO] [-] [core] [outbound] [pid: undefined] 0 files in my load queue
2022-11-01 16:01:52.407269500 [INFO] [-] [core] [outbound] [pid: undefined] 0 files in my temp fail queue
2022-11-01 16:01:52.758255500 [DEBUG] [-] [watch] wss client connected: _events,_eventsCount,_maxListeners,_binaryType,_closeCode,_closeFrameReceived,_closeFrameSent,_closeMessage,_closeTimer,_extensions,_paused,_protocol,_readyState,_receiver,_sender,_socket,_isServer
-
repo owner
Aha!
- please look at /admin/server/ - p0f will be down or restarting I guess
- also attach log/s6/p0f/current, there should be reason why p0f wont communicate with haraka
-
repo owner
I am planning to release next version soon and I would like to fix that - have you found anything?
-
reporter
log/s6/p0f/current
2022-11-08 10:08:48.327814500 [+] Closed 1 file descriptor.
2022-11-08 10:08:48.328848500 [+] Loaded 322 signatures from '/etc/p0f/p0f.fp'.
2022-11-08 10:08:48.328874500 [+] Intercepting traffic on interface 'eth0'.
2022-11-08 10:08:49.331056500 --- p0f 3.09b by Michal Zalewski lcamtuf@coredump.cx ---
2022-11-08 10:08:49.331070500
2022-11-08 10:08:49.331161500 [+] Closed 1 file descriptor.
2022-11-08 10:08:49.332190500 [+] Loaded 322 signatures from '/etc/p0f/p0f.fp'.
2022-11-08 10:08:49.332252500 [+] Intercepting traffic on interface 'eth0'.
2022-11-08 10:08:50.329378500 --- p0f 3.09b by Michal Zalewski lcamtuf@coredump.cx ---
2022-11-08 10:08:50.329393500
2022-11-08 10:08:50.329464500 [+] Closed 1 file descriptor.
2022-11-08 10:08:50.330331500 [+] Loaded 322 signatures from '/etc/p0f/p0f.fp'.
2022-11-08 10:08:50.330353500 [+] Intercepting traffic on interface 'eth0'.
2022-11-08 10:08:51.331239500 --- p0f 3.09b by Michal Zalewski lcamtuf@coredump.cx ---
2022-11-08 10:08:51.331253500
2022-11-08 10:08:51.331336500 [+] Closed 1 file descriptor.
2022-11-08 10:08:51.332345500 [+] Loaded 322 signatures from '/etc/p0f/p0f.fp'.
2022-11-08 10:08:51.332403500 [+] Intercepting traffic on interface 'eth0'.
2022-11-08 10:08:52.333767500 --- p0f 3.09b by Michal Zalewski lcamtuf@coredump.cx ---
2022-11-08 10:08:52.333781500
2022-11-08 10:08:52.333842500 [+] Closed 1 file descriptor.
2022-11-08 10:08:52.334901500 [+] Loaded 322 signatures from '/etc/p0f/p0f.fp'.
2022-11-08 10:08:52.334929500 [+] Intercepting traffic on interface 'eth0'.
2022-11-08 10:08:53.333263500 --- p0f 3.09b by Michal Zalewski lcamtuf@coredump.cx ---
2022-11-08 10:08:53.333279500
2022-11-08 10:08:53.333354500 [+] Closed 1 file descriptor.
2022-11-08 10:08:53.334358500 [+] Loaded 322 signatures from '/etc/p0f/p0f.fp'.
2022-11-08 10:08:53.334416500 [+] Intercepting traffic on interface 'eth0'.i dont find the /admin/server … in PS i dont show p0f
-
repo owner
- changed status to resolved
fix
#959missing path at reconnect at p0f plugin→ <<cset 2e82ebfb0ed3>>
-
reporter
I just tested it. It works. Thanks <3
- Log in to comment
Can you please cat
/proc/sys/net/ipv6/bindv6only ?