problem delivering messages

[Sandy Drobic]

Luís Cargnini wrote:
> /var/log/messages:
> 
> Jun 16 14:14:14 shark sudo: cargnini : TTY=pts/8 ; PWD=/home/cargnini
> ; USER=root ; COMMAND=/etc/init.d/sendmail restart
> Jun 16 14:14:16 shark sm-mta[26916]: NOQUEUE: SYSERR(root):
> /etc/mail/sendmail.cf: line 1842: Xclmilter: local socket name
> /var/run/clamav/clmilter.sock unsafe: Permission denied
> Jun 16 14:14:16 shark sm-cm[26925]: starting daemon (8.13.6): 
> queueing at 00:30:00
> Jun 16 14:14:17 shark sm-cm[26926]: k5GDjsLU014415: to=os at webmin.com,
> delay=03:28:23, xdelay=00:00:00, mailer=relay, pri=750437,
> relay=[127.0.0.1] [127.0.0.1], dsn=4.0.0, stat=Deferred: Connection
> refused by [127.0.0.1]
> Jun 16 14:14:21 shark sudo: cargnini : TTY=pts/8 ; PWD=/home/cargnini
> ; USER=root ; COMMAND=/etc/init.d/cyrus restart
> Jun 16 14:14:21 shark master[32565]: exiting on SIGTERM/SIGINT
> Jun 16 14:14:22 shark master[27040]: setrlimit: Unable to set file
> descriptors limit to -1: Operation not permitted
> Jun 16 14:14:22 shark master[27040]: retrying with 1024 (current max)
> Jun 16 14:14:22 shark master[27040]: process started
> Jun 16 14:14:22 shark master[27044]: about to exec 
> /usr/lib/cyrus/ctl_cyrusdb
> Jun 16 14:14:22 shark ctl_cyrusdb[27044]: recovering cyrus databases
> Jun 16 14:14:22 shark ctl_cyrusdb[27044]: skiplist: recovered
> /var/imap/mailboxes.db (3 records, 2448 bytes) in 0 seconds
> Jun 16 14:14:22 shark ctl_cyrusdb[27044]: skiplist: recovered
> /var/imap/annotations.db (0 records, 144 bytes) in 0 seconds
> Jun 16 14:14:22 shark ctl_cyrusdb[27044]: done recovering cyrus databases
> Jun 16 14:14:22 shark master[27088]: about to exec /usr/lib/cyrus/idled
> Jun 16 14:14:22 shark master[27040]: ready for work
> Jun 16 14:14:22 shark master[27120]: about to exec /usr/lib/cyrus/tls_prune
> Jun 16 14:14:22 shark master[27121]: about to exec 
> /usr/lib/cyrus/ctl_deliver
> Jun 16 14:14:22 shark master[27122]: about to exec 
> /usr/lib/cyrus/ctl_cyrusdb
> Jun 16 14:14:22 shark master[27123]: about to exec /usr/lib/cyrus/notifyd
> Jun 16 14:14:22 shark ctl_cyrusdb[27122]: checkpointing cyrus databases
> Jun 16 14:14:22 shark ctl_cyrusdb[27122]: archiving database file:
> /var/imap/annotations.db
> Jun 16 14:14:22 shark tls_prune[27120]: tls_prune: purged 0 out of 0 
> entries
> Jun 16 14:14:22 shark notify[27123]: executed
> Jun 16 14:14:23 shark master[27040]: process 27120 exited, status 0
> Jun 16 14:14:23 shark cyr_expire[27121]: skiplist: recovered
> /var/imap/deliver.db (0 records, 144 bytes) in 0 seconds
> Jun 16 14:14:23 shark cyr_expire[27121]: duplicate_prune: pruning back 3 
> days
> Jun 16 14:14:23 shark cyr_expire[27121]: duplicate_prune: purged 0 out
> of 0 entries
> Jun 16 14:14:23 shark cyr_expire[27121]: expunged 0 out of 0 messages
> from 0 mailboxes
> Jun 16 14:14:23 shark master[27040]: process 27121 exited, status 0
> Jun 16 14:14:23 shark ctl_cyrusdb[27122]: archiving database file:
> /var/imap/mailboxes.db
> Jun 16 14:14:23 shark ctl_cyrusdb[27122]: archiving log file:
> /var/imap/db/log.0000000001
> Jun 16 14:14:27 shark sudo: cargnini : TTY=pts/8 ; PWD=/home/cargnini
> ; USER=root ; COMMAND=/etc/init.d/saslauthd restart
> Jun 16 14:14:27 shark saslauthd[28798]: server_exit     : master exited: 
> 28798
> Jun 16 14:14:27 shark saslauthd[27192]: detach_tty      : master pid is: 
> 27192
> Jun 16 14:14:27 shark saslauthd[27192]: ipc_init        : listening on
> socket: /var/lib/sasl2/mux
> Jun 16 14:14:31 shark ctl_cyrusdb[27122]: done checkpointing cyrus 
> databases
> Jun 16 14:14:31 shark master[27040]: process 27122 exited, status 0
> Jun 16 14:14:35 shark su[27245]: Successful su for root by cargnini
> Jun 16 14:14:35 shark su[27245]: + pts/8 cargnini:root
> Jun 16 14:14:35 shark su(pam_unix)[27245]: session opened for user
> root by (uid=1000)
> Jun 16 14:14:49 shark master[27254]: about to exec /usr/lib/cyrus/imapd
> Jun 16 14:14:49 shark imap[27254]: executed
> Jun 16 14:14:49 shark imap[27254]: SQL engine 'mysql' not supported
> Jun 16 14:14:49 shark imap[27254]: auxpropfunc error no mechanism available
> Jun 16 14:14:49 shark imap[27254]: _sasl_plugin_load failed on
> sasl_auxprop_plug_init for plugin: sql
> Jun 16 14:14:49 shark imap[27254]: dracconn: localhost: RPC: Program
> not registered
> Jun 16 14:14:49 shark imap[27254]: DRAC notifications disabled
> Jun 16 14:14:49 shark imap[27254]: accepted connection
> Jun 16 14:14:52 shark imap(pam_unix)[27193]: authentication failure;
> logname= uid=0 euid=0 tty= ruser= rhost=  user=root
> Jun 16 14:14:54 shark saslauthd[27193]: DEBUG: auth_pam:
> pam_authenticate failed: Authentication failure
> Jun 16 14:14:54 shark saslauthd[27193]: do_auth         : auth
> failure: [user=root] [service=imap] [realm=] [mech=pam] [reason=PAM
> auth error]
> Jun 16 14:14:54 shark imap[27254]: badlogin: shark.hopto.org
> [127.0.0.1] plaintext root SASL(-13): authentication failure:
> checkpass failed
> Jun 16 14:15:13 shark su[27262]: Successful su for cyrus by root
> Jun 16 14:15:13 shark su[27262]: + pts/8 root:cyrus
> Jun 16 14:15:13 shark su(pam_unix)[27262]: session opened for user
> cyrus by (uid=0)
> Jun 16 14:15:16 shark imap[27254]: accepted connection
> Jun 16 14:15:20 shark imap[27254]: login: shark.hopto.org [127.0.0.1]
> cyrus plaintext User logged in
> Jun 16 14:16:16 shark master[27291]: about to exec /usr/lib/cyrus/lmtpd
> Jun 16 14:16:16 shark lmtpunix[27291]: executed
> Jun 16 14:16:16 shark lmtpunix[27291]: SQL engine 'mysql' not supported
> Jun 16 14:16:16 shark lmtpunix[27291]: auxpropfunc error no mechanism 
> available
> Jun 16 14:16:16 shark lmtpunix[27291]: _sasl_plugin_load failed on
> sasl_auxprop_plug_init for plugin: sql
> Jun 16 14:16:16 shark lmtpunix[27291]: accepted connection
> Jun 16 14:16:16 shark lmtpunix[27291]: lmtp connection preauth'd as postman
> 
> 
> 
> auth.log:
> Jun 16 14:14:27 shark saslauthd[28798]: server_exit     : master exited: 
> 28798
> Jun 16 14:14:27 shark saslauthd[27192]: detach_tty      : master pid is: 
> 27192
> Jun 16 14:14:27 shark saslauthd[27192]: ipc_init        : listening on
> socket: /var/lib/sasl2/mux
> Jun 16 14:14:35 shark su[27245]: Successful su for root by cargnini
> Jun 16 14:14:35 shark su[27245]: + pts/8 cargnini:root
> Jun 16 14:14:35 shark su(pam_unix)[27245]: session opened for user
> root by (uid=1000)
> Jun 16 14:14:49 shark imap[27254]: SQL engine 'mysql' not supported
> Jun 16 14:14:49 shark imap[27254]: auxpropfunc error no mechanism available
> Jun 16 14:14:49 shark imap[27254]: _sasl_plugin_load failed on
> sasl_auxprop_plug_init for plugin: sql
> Jun 16 14:14:52 shark imap(pam_unix)[27193]: authentication failure;
> logname= uid=0 euid=0 tty= ruser= rhost=  user=root
> Jun 16 14:14:54 shark saslauthd[27193]: DEBUG: auth_pam:
> pam_authenticate failed: Authentication failure
> Jun 16 14:14:54 shark saslauthd[27193]: do_auth         : auth
> failure: [user=root] [service=imap] [realm=] [mech=pam] [reason=PAM
> auth error]
> Jun 16 14:15:13 shark su[27262]: Successful su for cyrus by root
> Jun 16 14:15:13 shark su[27262]: + pts/8 root:cyrus
> Jun 16 14:15:13 shark su(pam_unix)[27262]: session opened for user
> cyrus by (uid=0)
> Jun 16 14:16:16 shark lmtpunix[27291]: SQL engine 'mysql' not supported
> Jun 16 14:16:16 shark lmtpunix[27291]: auxpropfunc error no mechanism 
> available
> Jun 16 14:16:16 shark lmtpunix[27291]: _sasl_plugin_load failed on
> sasl_auxprop_plug_init for plugin: sql
> 
> 
> commands used :
> imtest -u cyrus localhost -l login
> S: * OK shark.hopto.org Cyrus IMAP4 v2.2.12-Gentoo server ready
> C: C01 CAPABILITY
> S: * CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ MAILBOX-REFERRALS
> NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND
> BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE
> LISTEXT LIST-SUBSCRIBED X-NETSCAPE
> S: C01 OK Completed
> Please enter your password:
> C: L01 LOGIN root {10}
> S: + go ahead
> C: <omitted>
> 
> 
> shark ~ # su - cyrus
> cyrus at shark ~ $ !im
> imtest -u cyrus
> WARNING: no hostname supplied, assuming localhost
> 
> S: * OK shark.hopto.org Cyrus IMAP4 v2.2.12-Gentoo server ready
> C: C01 CAPABILITY
> S: * CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ MAILBOX-REFERRALS
> NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND
> BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE
> LISTEXT LIST-SUBSCRIBED X-NETSCAPE
> S: C01 OK Completed
> Please enter your password:
> C: L01 LOGIN cyrus {10}
> S: + go ahead
> C: <omitted>
> S: L01 OK User logged in
> Authenticated.
> Security strength factor: 0
> C: Q01 LOGOUT
> Connection closed.
> cyrus at shark ~ $ /usr/lib/cyrus/deliver
> 421-4.3.0 usage: deliver [-C <alt_config> ] [-m mailbox] [-a auth] [-r
> return_path] [-l] [-D]
> 421 4.3.0 v2.2.12-Gentoo
> cyrus at shark ~ $ /usr/lib/cyrus/deliver  -m user.cargnini < /tmp/mailteste
> +user.cargnini: Message contains invalid header
> cyrus at shark ~ $

If I disregard the unconfigured sql sasl plugin the log shows a working
Cyrus server.

Try to use the following commands:

	cyradm --user cyrus --auth login localhost
	localhost> lm

Do you see the mailbox of your user cargnini?

If so, let's try to authenticate with testsaslauthd:
	testsaslauthd -u cargnini -p ****** -s imap
     0: OK "Success."

When that works, you can try the deliver command again:
	echo "test" | \ /usr/lib/cyrus/bin/deliver -m Inbox cargnini

I looked up the manpage for deliver and discovered that the syntax for the
command was a bit different than what I remembered. ;-/

Also, if you don't see any error message but also no mail in Cyrus, it
could be because Cyrus surpresses duplicates.

Sandy