Self-test and incoming email postfix says yes, dovecot says nothing

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.

  1. Installation - seems OK
  2. Do initial update of everything via server manager, reboot
  3. Set hostname, organisation, set NIC to static IP as green network, check DNS.
  4. Install open-vm-tools via yum.
  5. Upload signed TLS cert that that clients trust, reboot
  6. 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.
  7. Install mail application
  8. 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

Articulate a bit more, dude. touching krb5 and sssd can lead to something not that nice. Starting from Dovecot which relies on users (and some more things) to validate mailboxes and addresses.
May i assume that this installation is “GREEN Network” only, as NethServer POV?

Hi Michael, thanks for looking.

Yes, GREEN only. There is a chance I may allow the real version to be contactable directly over internet but that’s a later experiment - but even then it’ll be behind a router firewall.

I have spent a lot of time with getting (mostly Ubuntu) based Linux hosts to play nicely with AD so know that it can be a fun, but it’s routine enough now I’ve even other VM setup to deploy this configuration by default.

In krb5:
12ad - new template to re-enable older enctypes to talk to AD

In sssd:
01provider_config : ldap_id_mapping = false - these are set in AD so I get consistency between hosts
02provider_sfu : new fragment to set the attributes for UID and GID to point to the right place
10base : default_domain_suffix is commented out for some reason I can’t remember…
20domain_primary : use_fully_qualified_names = False

All human users show up with correct names, groups, UID and GID on the Nethserver host, I see fully populated lists of users and groups in Server Manager too so that part looks good, and users can authenticate to IMAP using email address and AD password.

I’ve not seen anything in the logs to suggest a user authentication issue either - if there’s specific users needed from AD then a pointer to the doco will be much appreciated. From what I’ve managed to understand postfix should just work if you set the location of dovecot properly - and NethServer appears to be doing that. And since IMAP authentication works with full email address

But I’ll try again without the 10base and 20domain_primary changes and see if that makes a difference.

Cheers,
-R