NethServer Version: 7.9.2009
Hi all.
I have finally got around to properly playing with NethServer, to cut a long story short I’ve ended up scrapping an old install that had seen too much hackery and started again on a shiny new 7.9 install, this time with notes.
Initial reinstall threw up some interesting sync failures between WebTop 5 and a 'droid, digging deeper it seems there’s a more fundamental issue with mail - sent email is received and seemingly handed off to dovecot but doesn’t appear in inbox. Mail clients are putting it in the sent box.
Steps taken
Environment: ESXi, Existing sandpit AD domain that works.
- Installation - seems OK
- Do initial update of everything via server manager, reboot
- Set hostname, organisation, set NIC to static IP as green network, check DNS.
- Install open-vm-tools via yum.
- Upload signed TLS cert that that clients trust, reboot
- Drop custom template fragments for krb5.conf, smb.conf and sssd.conf in right place and join domain. It’s an old AD setup that is on death row m’kay? Reboot again to make sure base config is happy and users have right UID/GID from AD and we’re generally good to go.
- Install mail application
- Start banging head against imaginary wall (real walls hurt. I’m not that stupid)
Using a tablet on the same subnet I can configure an IMAP mail service and it connects. If I send an email to myself, it appears to be sent and I can see it appear in the outbox and then move to the sent mail items. The tablet does not complain, yet the mail never arrives.
I have also typed in a mail via telnet to port 25 and again it seems to be accepted but never arrives.
The logs seem to suggest that mail was correctly processed.
I have rebuilt the VM at least 3 times now, so on the older release I was playing with previously the basic email worked so this is really annoying me. It’s probably something really simple too.
Hopefully Helpful Logs:
/var/log/imap
Jan 3 17:32:28 snethwebtop dovecot: imap-login: Login: user=richard@test.mydomain.com, method=PLAIN, rip=2001:470:XXXX:XXXX:60bf:56e1:60bb:4679, lip=2001:470:XXXX:XXXX:20c:29ff:feed:24ca, mpid=28154, TLS, session=<heqf57DUhsEgAQRwbdwTAGC/VuFgu0Z5>
Jan 3 17:32:29 snethwebtop dovecot: imap(richard@test.mydomain.com): save: box=Sent, uid=2, msgid=lolpvi3dvei11jcgr27um6va.1641231148882@email.android.com, from=richard richard@test.mydomain.com, subject=Selftest 1731, flags=(\Seen)
Jan 3 17:32:29 snethwebtop dovecot: imap(richard@test.mydomain.com): Connection closed (UID FETCH finished 0.044 secs ago) in=1500 out=1724
/var/log/maillog
Jan 3 17:32:21 snethwebtop postfix/smtpd[28125]: connect from unknown[2001:470:XXXX:XXXX:60bf:56e1:60bb:4679]
Jan 3 17:32:21 snethwebtop rspamd[14624]: ; proxy; proxy_accept_socket: accepted milter connection from /var/run/rspamd/worker-proxy port 0
Jan 3 17:32:21 snethwebtop postfix/smtpd[28125]: 756AD52BD4: client=unknown[2001:470:XXXX:XXXX:60bf:56e1:60bb:4679], sasl_method=PLAIN, sasl_username=richard@test.mydomain.com
Jan 3 17:32:21 snethwebtop rspamd[14624]: ; milter; rspamd_milter_process_command: got connection from [2001:470:XXXX:XXXX:60bf:56e1:60bb:4679]:59700
Jan 3 17:32:21 snethwebtop postfix/cleanup[28141]: 756AD52BD4: message-id=<>
Jan 3 17:32:21 snethwebtop rspamd[14624]: ; proxy; rspamd_message_parse: loaded message; id: ; queue-id: <756AD52BD4>; size: 1200; checksum: <0956f1b409f2b56905a9795a71de0971>
Jan 3 17:32:21 snethwebtop rspamd[14624]: ; lua; settings.lua:366: apply static settings authenticated (id = 1937017268); authenticated matched; priority high
Jan 3 17:32:26 snethwebtop rspamd[14624]: ; lua; asn.lua:72: error querying dns “9.7.6.4.b.b.0.6.1.e.6.5.f.b.0.6.X.X.X.X.X.X.X.X.0.7.4.0.1.0.0.2.asn6.rspamd.com” on 127.0.0.1: query timed out
Jan 3 17:32:26 snethwebtop rspamd[14624]: ; proxy; rspamd_symcache_finalize_item: slow rule: ASN_CHECK(224): 5003.68 ms; enable slow timer delay
Jan 3 17:32:26 snethwebtop rspamd[14624]: ; proxy; dkim_symbol_callback: skip DKIM checks for local networks and authorized users
Jan 3 17:32:26 snethwebtop rspamd[14624]: ; lua; spf.lua:186: skip SPF checks for local networks and authorized users
Jan 3 17:32:26 snethwebtop rspamd[14624]: ; lua; dmarc.lua:349: skip DMARC checks as either SPF or DKIM were not checked
Jan 3 17:32:26 snethwebtop rspamd[14624]: ; lua; once_received.lua:99: Skipping once_received for authenticated user or local network
Jan 3 17:32:26 snethwebtop rspamd[14624]: ; proxy; rspamd_redis_connected: skip obtaining bayes tokens for BAYES_SPAM of classifier bayes: not enough learns 0; 200 required
Jan 3 17:32:26 snethwebtop rspamd[14624]: ; proxy; rspamd_redis_connected: skip obtaining bayes tokens for BAYES_HAM of classifier bayes: not enough learns 0; 200 required
Jan 3 17:32:26 snethwebtop rspamd[14624]: ; proxy; rspamd_stat_classifiers_process: skip statistics as SPAM class is missing
Jan 3 17:32:26 snethwebtop rspamd[14624]: ; proxy; rspamd_task_write_log: id: , qid: <756AD52BD4>, ip: 2001:470:XXXX:XXXX:60bf:56e1:60bb:4679, user: richard@test.mydomain.com, from: richard@test.mydomain.com, (default: F (no action): [3.50/20.00] [MISSING_MID(2.50){},MIME_BASE64_TEXT_BOGUS(1.00){},MIME_BASE64_TEXT(0.10){},MIME_GOOD(-0.10){multipart/alternative;text/plain;},ASN_FAIL(0.00){9.7.6.4.b.b.0.6.1.e.6.5.f.b.0.6.X.X.X.X.X.X.X.X.0.7.4.0.1.0.0.2.asn6.rspamd.com:query timed out;},FROM_EQ_ENVFROM(0.00){},FROM_HAS_DN(0.00){},MIME_TRACE(0.00){0:+;1:+;2:~;},RCPT_COUNT_ONE(0.00){1;},RCVD_COUNT_ZERO(0.00){0;},TO_DN_NONE(0.00){},TO_EQ_FROM(0.00){},TO_MATCH_ENVRCPT_ALL(0.00){}]), len: 1200, time: 5119.666ms, dns req: 1, digest: <0956f1b409f2b56905a9795a71de0971>, rcpts: richard@test.mydomain.com, mime_rcpts: richard@test.mydomain.com, settings_id: authenticated
Jan 3 17:32:26 snethwebtop rspamd[14624]: ; proxy; rspamd_protocol_http_reply: regexp statistics: 0 pcre regexps scanned, 1 regexps matched, 175 regexps total, 37 regexps cached, 0B scanned using pcre, 878B scanned total
Jan 3 17:32:26 snethwebtop opendkim[11443]: 756AD52BD4: [2001:470:XXXX:XXXX:60bf:56e1:60bb:4679] [2001:470:XXXX:XXXX:60bf:56e1:60bb:4679] not internal
Jan 3 17:32:26 snethwebtop opendkim[11443]: 756AD52BD4: not authenticated
Jan 3 17:32:26 snethwebtop postfix/qmgr[23237]: 756AD52BD4: from=richard@test.mydomain.com, size=1555, nrcpt=1 (queue active)
Jan 3 17:32:26 snethwebtop dovecot: lmtp(28148): Connect from local
Jan 3 17:32:26 snethwebtop dovecot: lmtp(richard): save: box=INBOX, uid=2, msgid=, from=richard richard@test.mydomain.com, subject=Selftest 1731, flags=()
Jan 3 17:32:26 snethwebtop dovecot: lmtp(richard): 6OHTKioz02H0bQAAhDw7cg: sieve: msgid=unspecified: stored mail into mailbox ‘INBOX’
Jan 3 17:32:26 snethwebtop dovecot: lmtp(28148): Disconnect from local: Successful qui
Jan 3 17:32:26 snethwebtop postfix/lmtp[28147]: 756AD52BD4: to=richard@test.mydomain.com, relay=snethwebtop.test.mydomain.com[/var/run/dovecot/lmtp], delay=5.3, delays=5.2/0.01/0.01/0.01, dsn=2.0.0, status=sent (250 2.0.0 richard@test.mydomain.com 6OHTKioz02H0bQAAhDw7cg Saved)
Jan 3 17:32:26 snethwebtop postfix/qmgr[23237]: 756AD52BD4: removed
I have not seen anything unduly alarming in other logs. Any clue gratefully received,
-R