Can Not Start MTA

[rmvg]

Originally Posted by marcmac

I believe that the ssl portion of the connection is happy - the ssl warnings are due to it being a self-signed cert.

I agree ssl is now happy

Originally Posted by marcmac

The password verification failure is a different problem - are you using the full user@domain username?

Yes i am using the full login username user@domain.com

Originally Posted by marcmac

Is SASL logging anything?

Where do i look for SASL logging i tried var/log and /opt/zimbra/cyrus-sals/ but found nothing think FreeBSD uses auth.log but cannot seem to find anything relating to SASL on fedora install

Originally Posted by marcmac

As for snmp/logger - check /tmp/swatch.out and /tmp/logswatch.out - perhaps they can't read /var/log/zimbra.log?

*** logswatch version 3.1.1 (pid:460) started at Tue Nov 29 05:20:45 MST 2005

/tmp/logswatch.out

DBD::mysql::st execute failed: Column 'loghost' cannot be null at /opt/zimbra/bin/zmlogger line 127, <> line 15.
DBD::mysql::st execute failed: Column 'loghost' cannot be null at /opt/zimbra/bin/zmlogger line 127, <> line 16.

/tmp/swatch.out this on seems to be empty

*** swatch version 3.1.1 (pid:913) started at Tue Nov 29 05:20:59 MST 2005

Originally Posted by marcmac

For details on why things won't start - run
sh -x bin/zmloggerctl status
or
sh -x bin/zmswatchctl status

[zimbra@shoemasters snmp]$ sh -x bin/zmloggerctl status
sh: bin/zmloggerctl: No such file or directory
[zimbra@shoemasters snmp]$ cd /opt/zimbra/
[zimbra@shoemasters ~]$ sh -x bin/zmloggerctl status
+ BASE=/opt/zimbra
+ SCRIPTS='logmysql.server zmlogswatchctl'
+ case "$1" in
+ STATUS=0
+ for i in '$SCRIPTS'
+ '[' logmysql.server = logmysql.server ']'
+ /opt/zimbra/bin/logmysqladmin status
+ R=0
+ '[' 0 -ne 0 ']'
+ for i in '$SCRIPTS'
+ '[' zmlogswatchctl = logmysql.server ']'
+ /opt/zimbra/bin/zmlogswatchctl status
+ R=0
+ '[' 0 -ne 0 ']'
+ exit 0

[zimbra@shoemasters ~]$ sh -x bin/zmswatchctl status
+ BASE=/opt/zimbra
+ CONFIG=/opt/zimbra/conf/swatchrc
+ PIDFILE=/opt/zimbra/log/swatch.pid
+ '[' -f /opt/zimbra/log/swatch.pid ']'
++ cat /opt/zimbra/log/swatch.pid
+ PID=913
+ source /opt/zimbra/.bashrc
++ alias 'rm=rm -i'
++ alias 'cp=cp -i'
++ alias 'mv=mv -i'
++ alias 'h=history 40'
++ alias j=jobs
++ '[' -f /etc/bashrc ']'
++ . /etc/bashrc
++++ id -gn
++++ id -un
++++ id -u
+++ '[' zimbra = zimbra -a 500 -gt 99 ']'
+++ umask 002
+++ '[' '' ']'
++ ZIMBRA_HOME=/opt/zimbra
++ export ZIMBRA_HOME
++ JAVA_HOME=/opt/zimbra/java
++ export JAVA_HOME
++ PATH=/opt/zimbra/bin:/opt/zimbra/zimbramon:/opt/zimbra/postfix-2.2.3/sbin:/opt/zimbra/openldap/bin:/opt/zimbra/java/bin:/opt/zimbra/snmp/bin:/opt/zimbra/bin:/opt/zimbra/zimbramon:/opt/zimbra/postfix-2.2.3/sbin:/opt/zimbra/openldap/bin:/opt/zimbra/java/bin:/opt/zimbra/snmp/bin:/usr/kerberos/sbin:/usr/kerberos/bin:/usr/local/sbin:/usr/local/bin:/sbin:/bin:/usr/sbin:/usr/bin:/usr/X11R6/bin:/root/bin
++ export PATH
++ LD_LIBRARY_PATH=/opt/zimbra/lib:/opt/zimbra/lib:
++ export LD_LIBRARY_PATH
++ SNMPCONFPATH=/opt/zimbra/conf
++ export SNMPCONFPATH
++ PERLLIB=/opt/zimbra/zimbramon/lib:/opt/zimbra/zimbramon/lib/i386-linux-thread-multi:/opt/zimbra/zimbramon/lib/i586-linux-thread-multi:/opt/zimbra/zimbramon/lib/darwin-thread-multi-2level
++ export PERLLIB
+ case "$1" in
+ '[' x913 '!=' x ']'
+ kill -0 913
+ exit 0

Here is the output of my /var/zimbra log very similar to previous post by kevindods

Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: connect from digi.spots.ab.ca[209.115.173.9]
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: setting up TLS connection from digi.spots.ab.ca[209.115.173.9]
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: SSL_accept:before/accept initialization
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: read from 089F0FB0 [089FE3E8] (11 bytes => -1 (0xFFFFFFFF))
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: SSL_accept:error in

================================================== ======

had to snip some of log out as to large to post

================================================== =======

w..<8.^K ..iXp..p
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0020 d1 aa 54 a9 04 80 06 81|b2 08 bb 20 d7 a4 51 e8 ..T..... ... ..Q.
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0030 4e 27 c8 2e 09 52 3c 7f|03 51 b6 ab 84 af b3 3e N'...R<. .Q.....>
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0040 47 81 e8 f5 ae 43 08 00|0b 9d f8 92 00 39 00 16 G....C.. .....9..
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0050 03 01 03 1e 0b 00 03 1a|00 03 17 00 03 14 30 82 ........ ......0.
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0060 03 10 30 82 02 79 a0 03|02 01 02 02 01 10 30 0d ..0..y.. ......0.
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0070 06 09 2a 86 48 86 f7 0d|01 01 04 05 00 30 68 31 ..*.H... .....0h1
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0080 0b 30 09 06 03 55 04 06|13 02 55 53 31 0c 30 0a .0...U.. ..US1.0.
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0090 06 03 55 04 08 13 03 4e|2f 41 31 0c 30 0a 06 03 ..U....N /A1.0...
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 00a0 55 04 07 13 03 4e 2f 41|31 23 30 21 06 03 55 04 U....N/A 1#0!..U.
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 00b0 0a 13 1a 5a 69 6d 62 72|61 20 43 6f 6c 6c 61 62 ...Zimbr a Collab
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 00c0 6f 72 61 74 69 6f 6e 20|53 75 69 74 65 31 18 30 oration Suite1.0
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 00d0 16 06 03 55 04 03 13 0f|73 68 6f 65 6d 61 73 74 ...U.... shoemast
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 00e0 65 72 73 2e 63 6f 6d 30|1e 17 0d 30 35 31 31 32 ers.com0 ...05112
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 00f0 39 31 32 30 39 34 32 5a|17 0d 30 36 31 31 32 39 9120942Z ..061129
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0100 31 32 30 39 34 32 5a 30|5a 31 0b 30 09 06 03 55 120942Z0 Z1.0...U
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0110 04 06 13 02 55 53 31 0c|30 0a 06 03 55 04 08 13 ....US1. 0...U...
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0120 03 4e 2f 41 31 23 30 21|06 03 55 04 0a 13 1a 5a .N/A1#0! ..U....Z
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0130 69 6d 62 72 61 20 43 6f|6c 6c 61 62 6f 72 61 74 imbra Co llaborat
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0140 69 6f 6e 20 53 75 69 74|65 31 18 30 16 06 03 55 ion Suit e1.0...U
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0150 04 03 13 0f 73 68 6f 65|6d 61 73 74 65 72 73 2e ....shoe masters.
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0160 63 6f 6d 30 81 9f 30 0d|06 09 2a 86 48 86 f7 0d com0..0. ..*.H...
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0170 01 01 01 05 00 03 81 8d|00 30 81 89 02 81 81 00 ........ .0......
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0180 b4 0a 28 54 1e 43 d6 1f|fe c1 6f 2d ba cb 8e 8d ..(T.C.. ..o-....
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0190 4a 64 c3 2a 12 06 07 5c|ea be 5f 67 34 6c 88 94 Jd.*...\ .._g4l..
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 01a0 3d 83 57 86 cd e9 a8 fb|a3 b2 78 5d a8 f5 48 0b =.W..... ..x]..H.
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 01b0 80 6f bd 27 b0 fa 50 5d|fe 64 89 6d 8d ae 8e f9 .o.'..P] .d.m....
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 01c0 cb ae 0c b3 35 d1 68 c8|40 f5 b6 9d f0 f2 fa a6 ....5.h. @.......
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 01d0 c1 45 b5 3b 5e f3 72 0f|95 fa 4b c1 00 f4 8e 14 .E.;^.r. ..K.....
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 01e0 fa 96 b9 64 43 18 ba d1|19 bf 07 34 a7 de ea bf ...dC... ...4....
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 01f0 26 1c eb 7a b2 f4 e2 3a|60 26 14 16 bf fe b6 73 &..z...: `&.....s
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0200 02 03 01 00 01 a3 81 d7|30 81 d4 30 09 06 03 55 ........ 0..0...U
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0210 1d 13 04 02 30 00 30 2c|06 09 60 86 48 01 86 f8 ....0.0, ..`.H...
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0220 42 01 0d 04 1f 16 1d 4f|70 65 6e 53 53 4c 20 47 B......O penSSL G
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0230 65 6e 65 72 61 74 65 64|20 43 65 72 74 69 66 69 enerated Certifi
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0240 63 61 74 65 30 1d 06 03|55 1d 0e 04 16 04 14 75 cate0... U......u
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0250 0f e1 f0 60 cd d8 e3 e4|68 60 aa 45 f7 b6 02 7e ...`.... h`.E...~
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0260 3a 2c 31 30 7a 06 03 55|1d 23 04 73 30 71 a1 6c :,10z..U .#.s0q.l
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0270 a4 6a 30 68 31 0b 30 09|06 03 55 04 06 13 02 55 .j0h1.0. ..U....U
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0280 53 31 0c 30 0a 06 03 55|04 08 13 03 4e 2f 41 31 S1.0...U ....N/A1
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0290 0c 30 0a 06 03 55 04 07|13 03 4e 2f 41 31 23 30 .0...U.. ..N/A1#0
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 02a0 21 06 03 55 04 0a 13 1a|5a 69 6d 62 72 61 20 43 !..U.... Zimbra C
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 02b0 6f 6c 6c 61 62 6f 72 61|74 69 6f 6e 20 53 75 69 ollabora tion Sui
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 02c0 74 65 31 18 30 16 06 03|55 04 03 13 0f 73 68 6f te1.0... U....sho
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 02d0 65 6d 61 73 74 65 72 73|2e 63 6f 6d 82 01 00 30 emasters .com...0
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 02e0 0d 06 09 2a 86 48 86 f7|0d 01 01 04 05 00 03 81 ...*.H.. ........
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 02f0 81 00 1b c7 31 77 9b 92|6c 2a c8 e2 32 fe 69 d6 ....1w.. l*..2.i.
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0300 8a ed 6e c6 2c 98 8e 95|b7 ac 2b c7 be c2 fe 6e ..n.,... ..+....n
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0310 d6 66 91 e7 4d 96 01 8a|f5 65 6d b5 da 18 b3 5d .f..M... .em....]
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0320 f0 72 50 47 62 bb 14 91|f6 84 ec 3b 1c a5 aa fe .rPGb... ...;....
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0330 b4 c5 f0 bd 22 2d 15 9f|52 a2 b6 0c bf 00 79 b5 ...."-.. R.....y.
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0340 ff 41 41 2a a8 be 1e 5a|fb 65 09 4a 52 67 47 70 .AA*...Z .e.JRgGp
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0350 26 53 9c 2f 5f 7b 49 fb|0d 38 8a 9f 40 8a 29 85 &S./_{I. .8..@.).
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0360 ad af 0c c7 86 fe a2 58|f1 10 31 c5 cf 4d a9 95 .......X ..1..M..
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0370 21 93 16 03 01 01 8d 0c|00 01 89 00 80 b0 fe b4 !....... ........
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0380 cf d4 55 07 e7 cc 88 59|0d 17 26 c5 0c a5 4a 92 ..U....Y ..&...J.
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0390 23 81 78 da 88 aa 4c 13|06 bf 5d 2f 9e bc 96 b8 #.x...L. ..]/....
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 03a0 51 00 9d 0c 0d 75 ad fd|3b b1 7e 71 4f 3f 91 54 Q....u.. ;.~qO?.T
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 03b0 14 44 b8 30 25 1c eb df|72 9c 4c f1 89 0d 68 3f .D.0%... r.L...h?
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 03c0 94 8e a4 fb 76 89 18 b2|91 16 90 01 99 66 8c 53 ....v... .....f.S
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 03d0 81 4e 27 3d 99 e7 5a 7a|af d5 ec e2 7e fa ed 01 .N'=..Zz ....~...
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 03e0 18 c2 78 25 59 06 5c 39|f6 cd 49 54 af c1 b1 ea ..x%Y.\9 ..IT....
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 03f0 4a f9 53 d0 df 6d af d4|93 e7 ba ae 9b 00 01 02 J.S..m.. ........
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0400 00 80 82 a1 34 7b d6 1c|7f 3e 56 ba 7f 18 b2 54 ....4{.. .>V....T
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0410 23 8d be c2 ed 72 62 ba|a5 9f 29 37 43 71 67 39 #....rb. ..)7Cqg9
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0420 77 5a 24 be ce 11 59 5f|e1 8d e7 12 ed e8 19 8d wZ$...Y_ ........
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0430 49 c7 a3 ef 12 38 af f3|f3 b9 5e 84 fc a3 0b e5 I....8.. ..^.....
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0440 ae 14 d9 24 cd c6 54 e6|cd 5e cb 91 50 fc 59 10 ...$..T. .^..P.Y.
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0450 c0 3a 89 af 96 6a 21 b6|e7 57 0c 35 fb 3b ed ef .:...j!. .W.5.;..
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0460 5a db ae 44 44 36 32 5a|07 83 d8 7a cc 4c 88 bb Z..DD62Z ...z.L..
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0470 c9 95 ec 5d 41 7b 0e a7|7d 36 ca 05 2a 9e 99 61 ...]A{.. }6..*..a
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0480 ba 75 00 80 39 d8 ea 47|7e 99 a8 9e 49 48 2f 28 .u..9..G ~...IH/(
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0490 3c d6 5e 43 85 81 25 f4|4f a2 ab c2 63 4e 0c 66 <.^C..%. O...cN.f
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 04a0 3e 82 26 80 96 27 05 af|52 53 28 04 b7 98 ea b1 >.&..'.. RS(.....
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 04b0 7a dc d2 6f db 7f 05 79|f0 aa 68 de c0 2f e5 23 z..o...y ..h../.#
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 04c0 f5 23 a3 e7 24 f5 df a0|d8 5d 13 79 9b 4c f0 2d .#..$... .].y.L.-
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 04d0 8f cf ae 62 c7 69 0b 80|f2 07 e9 c5 95 67 b8 98 ...b.i.. .....g..
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 04e0 da e5 9a 4e ef 03 4a 4e|a4 53 68 72 ad b1 ec 16 ...N..JN .Shr....
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 04f0 9a 29 95 37 5e dd a1 06|f9 44 09 77 23 43 e6 44 .).7^... .D.w#C.D
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 0500 43 a3 ad ba 16 03 01 00|04 0e C....... ..
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: 050a -
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: SSL_accept:SSLv3 flush data
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: read from 089F0FB0 [089FE3E8] (5 bytes => -1 (0xFFFFFFFF))
Nov 29 05:26:26 shoemasters postfix/smtpd[1059]: SSL_accept:error in SSLv3 read client certificate A
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: read from 089F0FB0 [089FE3E8] (5 bytes => 5 (0x5))
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: 0000 16 03 01 00 86 .....
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: read from 089F0FB0 [089FE3ED] (134 bytes => -1 (0xFFFFFFFF))
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: SSL_accept:error in SSLv3 read client certificate A
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: read from 089F0FB0 [089FE3ED] (134 bytes => 134 (0x86))
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: 0000 10 00 00 82 00 80 1e 6d|09 51 15 66 7c d6 cd ee .......m .Q.f|...
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: 0010 5a 6a de b3 f4 3e 6d a4|32 c1 ea 49 9e f0 c6 15 Zj...>m. 2..I....
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: 0020 c7 61 10 32 08 22 84 5b|00 a9 be 6e f1 1e 71 12 .a.2.".[ ...n..q.
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: 0030 fa 80 60 0c d4 75 0b 20|36 21 32 52 d8 8f 29 89 ..`..u. 6!2R..).
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: 0040 16 30 06 e8 52 c5 32 6b|45 97 0d 23 58 48 2b 48 .0..R.2k E..#XH+H
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: 0050 1e aa 31 4d b4 f8 1c 37|c7 b5 05 ca f8 38 39 6a ..1M...7 .....89j
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: 0060 82 0a 0c 74 7a e2 aa 16|b2 f2 2c 2f 4e 79 a5 67 ...tz... ..,/Ny.g
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: 0070 33 48 f0 66 55 f6 65 42|12 9e 27 78 04 22 8d 70 3H.fU.eB ..'x.".p
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: 0080 4b 2b 21 4c ab e9 K+!L..
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: SSL_accept:SSLv3 read client key exchange A
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: read from 089F0FB0 [089FE3E8] (5 bytes => -1 (0xFFFFFFFF))
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: SSL_accept:error in SSLv3 read certificate verify A
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: read from 089F0FB0 [089FE3E8] (5 bytes => 5 (0x5))
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: 0000 14 03 01 00 01 .....
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: read from 089F0FB0 [089FE3ED] (1 bytes => -1 (0xFFFFFFFF))
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: SSL_accept:error in SSLv3 read certificate verify A
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: read from 089F0FB0 [089FE3ED] (1 bytes => 1 (0x1))
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: 0000 01 .
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: read from 089F0FB0 [089FE3E8] (5 bytes => -1 (0xFFFFFFFF))
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: SSL_accept:error in SSLv3 read certificate verify A
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: read from 089F0FB0 [089FE3E8] (5 bytes => 5 (0x5))
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: 0000 16 03 01 00 30 ....0
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: read from 089F0FB0 [089FE3ED] (48 bytes => -1 (0xFFFFFFFF))
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: SSL_accept:error in SSLv3 read certificate verify A
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: read from 089F0FB0 [089FE3ED] (48 bytes => 48 (0x30))
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: 0000 07 5d fa 8b 1a b5 17 8c|66 b5 45 a2 55 12 e6 df .]...... f.E.U...
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: 0010 3f 7c ff 6c b0 56 43 34|6d 47 bf 2f 1f a4 c0 54 ?|.l.VC4 mG./...T
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: 0020 1a 13 8f 47 62 2c 65 36|36 63 33 f3 e9 99 d9 38 ...Gb,e6 6c3....8
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: SSL_accept:SSLv3 read finished A
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: SSL_accept:SSLv3 write change cipher spec A
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: SSL_accept:SSLv3 write finished A
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: write to 089F0FB0 [08A0C510] (59 bytes => 59 (0x3B))
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: 0000 14 03 01 00 01 01 16 03|01 00 30 a0 c5 d5 3c 5f ........ ..0...<_
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: 0010 44 a5 d1 11 dd 09 e2 09|f7 ac a3 5b 92 c4 42 f5 D....... ...[..B.
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: 0020 ca 3a 7f 88 c0 a0 42 31|8e 76 14 75 f2 7a 10 02 .:....B1 .v.u.z..
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: 0030 e8 f5 12 bc ab 51 4f e0|56 d1 7f .....QO. V..
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: SSL_accept:SSLv3 flush data
Nov 29 05:26:28 shoemasters postfix/smtpd[1059]: TLS connection established from digi.spots.ab.ca[209.115.173.9]: TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits)
Nov 29 05:26:41 shoemasters postfix/smtpd[1059]: warning: SASL authentication failure: Password verification failed
Nov 29 05:26:41 shoemasters postfix/smtpd[1059]: warning: digi.spots.ab.ca[209.115.173.9]: SASL PLAIN authentication failed
Nov 29 05:26:41 shoemasters postfix/smtpd[1059]: warning: digi.spots.ab.ca[209.115.173.9]: SASL LOGIN authentication failed
Nov 29 05:26:47 shoemasters postfix/smtpd[1059]: warning: SASL authentication failure: Password verification failed
Nov 29 05:26:47 shoemasters postfix/smtpd[1059]: warning: digi.spots.ab.ca[209.115.173.9]: SASL PLAIN authentication failed
Nov 29 05:26:47 shoemasters postfix/smtpd[1059]: warning: digi.spots.ab.ca[209.115.173.9]: SASL LOGIN authentication failed

[marcmac]

Ok - according to the script output, both status commands returned 0, so they should be up. Is zmcontrol still showing them down?

(The loghost cannot be null errors can be ignored - not everyone formats their logging the correct way *cough*log4j*cough)

So, I think the problem is definitely in SASL - I'll check out it's logging capabilities, but it should log to /var/log/zimbra.log (or /var/log/maillog, too)

[marcmac]

according to the saslauthd man page, it logs via LOG_AUTH, which (on my box) goes to /var/log/secure.

(check your /etc/syslog.conf if you don't see anything in that file)

[rmvg]

Yep /var/log/secure here is the output

Nov 29 05:20:20 shoemasters sudo: zimbra : TTY=pts/2 ; PWD=/root ; USER=root ; COMMAND=/opt/zimbra/postfix-2.2.3/sbin/postalias /etc/aliases
Nov 29 05:20:20 shoemasters sudo: zimbra : TTY=pts/2 ; PWD=/root ; USER=root ; COMMAND=/opt/zimbra/postfix-2.2.3/sbin/postfix stop
Nov 29 05:20:24 shoemasters sudo: zimbra : TTY=pts/2 ; PWD=/root ; USER=root ; COMMAND=/opt/zimbra/openldap/libexec/slapd -l LOCAL0 -4 -u zimbra -h ldaps:// ldap://:389/ -f /opt/zimbra/conf/slapd.conf
Nov 29 05:20:37 shoemasters sudo: zimbra : TTY=pts/2 ; PWD=/root ; USER=root ; COMMAND=/opt/zimbra/libexec/zmtomcatstart -Xms146m -Xmx146m -client -XX:NewRatio=2
Nov 29 05:20:56 shoemasters sudo: zimbra : TTY=pts/2 ; PWD=/root ; USER=root ; COMMAND=/opt/zimbra/postfix-2.2.3/sbin/postalias /etc/aliases
Nov 29 05:20:56 shoemasters sudo: zimbra : TTY=pts/2 ; PWD=/root ; USER=root ; COMMAND=/opt/zimbra/postfix-2.2.3/sbin/postfix start norewrite

I also am getting this forever i think

Nov 29 06:28:24 shoemasters sshd[6398]: Failed password for root from ::ffff:220.193.98.15 port 35795 ssh2
Nov 29 06:28:29 shoemasters sshd[6400]: Failed password for root from ::ffff:220.193.98.15 port 35977 ssh2
Nov 29 06:28:35 shoemasters sshd[6402]: Failed password for root from ::ffff:220.193.98.15 port 36161 ssh2
Nov 29 06:28:40 shoemasters sshd[6404]: Failed password for root from ::ffff:220.193.98.15 port 36343 ssh2
Nov 29 06:28:46 shoemasters sshd[6406]: Failed password for root from ::ffff:220.193.98.15 port 36531 ssh2
Nov 29 06:28:51 shoemasters sshd[6408]: Failed password for root from ::ffff:220.193.98.15 port 36712 ssh2
Nov 29 06:28:56 shoemasters sshd[6410]: Failed password for root from ::ffff:220.193.98.15 port 36896 ssh2
Nov 29 06:29:02 shoemasters sshd[6412]: Failed password for root from ::ffff:220.193.98.15 port 37086 ssh2
Nov 29 06:29:07 shoemasters sshd[6444]: Failed password for root from ::ffff:220.193.98.15 port 37262 ssh2

[marcmac]

Try running it in debug mode:

su - zimbra
zmsaslauthdctl stop

/opt/zimbra/cyrus-sasl-2.1.21.ZIMBRA/sbin/saslauthd -r -a zimbra -d

[rmvg]

seems to get stuck on babies waited about 10 mins gave up and used control c to kill command tried thunderbird agian and still nothing

[root@shoemasters ~]# su zimbra
[zimbra@shoemasters root]$ zmsaslauthdctl stop
/opt/zimbra/cyrus-sasl-2.1.21.ZIMBRA/sbin/saslauthd: no process killed
[zimbra@shoemasters root]$ /opt/zimbra/cyrus-sasl-2.1.21.ZIMBRA/sbin/saslauthd -r -a zimbra -d
saslauthd[10604] :main : num_procs : 5
saslauthd[10604] :main : mech_option: NULL
saslauthd[10604] :main : run_path : /opt/zimbra/cyrus-sasl-2.1.21.ZIMBRA/state
saslauthd[10604] :main : auth_mech : zimbra
saslauthd[10604] :ipc_init : using accept lock file: /opt/zimbra/cyrus-sasl-2.1.21.ZIMBRA/state/mux.accept
saslauthd[10604] :detach_tty : master pid is: 0
saslauthd[10604] :ipc_init : listening on socket: /opt/zimbra/cyrus-sasl-2.1.21.ZIMBRA/state/mux
saslauthd[10604] :main : using process model
saslauthd[10605] :get_accept_lock : acquired accept lock
saslauthd[10604] :have_baby : forked child: 10605
saslauthd[10604] :have_baby : forked child: 10606
saslauthd[10604] :have_baby : forked child: 10607
saslauthd[10604] :have_baby : forked child: 10608

Found this in my /var/log/secure

Nov 29 06:50:42 shoemasters sshd[8620]: Failed password for invalid user francis from ::ffff:220.193.98.15 port 57985 ssh2
Nov 29 06:50:44 shoemasters sshd[8622]: Invalid user francis from ::ffff:220.193.98.15
Nov 29 06:50:47 shoemasters sshd[8622]: Failed password for invalid user francis from ::ffff:220.193.98.15 port 58195 ssh2
Nov 29 06:50:49 shoemasters sshd[8624]: Invalid user harry from ::ffff:220.193.98.15
Nov 29 06:50:53 shoemasters sshd[8624]: Failed password for invalid user harry from ::ffff:220.193.98.15 port 58401 ssh2
Nov 29 06:50:55 shoemasters sshd[8626]: Invalid user harry from ::ffff:220.193.98.15
Nov 29 06:50:58 shoemasters sshd[8626]: Failed password for invalid user harry from ::ffff:220.193.98.15 port 58611 ssh2
Nov 29 06:51:00 shoemasters sshd[8628]: Invalid user harry from ::ffff:220.193.98.15
Nov 29 06:51:03 shoemasters sshd[8628]: Failed password for invalid user harry from ::ffff:220.193.98.15 port 58821 ssh2
Nov 29 07:28:36 shoemasters sshd[11752]: Accepted password for root from ::ffff:209.115.173.9 port 4674 ssh2

[marcmac]

Nov 29 07:28:36 shoemasters sshd[11752]: Accepted password for root from ::ffff:209.115.173.9 port 4674 ssh2

I hope that's you coming from that IP, because someone's trying to get into your server.

With sasl in debug mode, try the tls auth, and see what it spits out.

[rmvg]

Thats me but i do not know who francis or harry are have to keep my i on that.

the commands u gave me seemed to work better this time but some errors about pid

[root@shoemasters ~]# su zimbra
[zimbra@shoemasters root]$ zmsaslauthdctl stop
[zimbra@shoemasters root]$ /opt/zimbra/cyrus-sasl-2.1.21.ZIMBRA/sbin/saslauthd -r -a zimbra -d
saslauthd[14868] :main : num_procs : 5
saslauthd[14868] :main : mech_option: NULL
saslauthd[14868] :main : run_path : /opt/zimbra/cyrus-sasl-2.1.21.ZIMBRA/state
saslauthd[14868] :main : auth_mech : zimbra
saslauthd[14868] :main : could not open pid lock file: /opt/zimbra/cyrus-sasl-2.1.21.ZIMBRA/state/saslauthd.pid.lock
saslauthd[14868] :main : open: Permission denied
saslauthd[14868] :main : Check to make sure the directory exists and is
saslauthd[14868] :main : writeable by the user this process runs as.
[zimbra@shoemasters root]$


Nothing happening in the /var/log/secure when tring to send using thunderbird

figured i would try a zmcontrol stop/start but get the same errors as above and zimbra will not start mta

Starting mta...FAILED
DO: /opt/zimbra/postfix/sbin/postconf -e content_filter='smtp-amavis:[127.0.0.1]:10024'
DO: /opt/zimbra/postfix/sbin/postconf -e smtpd_sasl_auth_enable='yes'
DO: /opt/zimbra/postfix/sbin/postconf -e smtpd_tls_auth_only='yes'
DO: /opt/zimbra/postfix/sbin/postconf -e disable_dns_lookups='no'
DO: /opt/zimbra/postfix/sbin/postconf -e message_size_limit='10240000'
DO: /opt/zimbra/postfix/sbin/postconf -e relayhost=''
DO: /opt/zimbra/postfix/sbin/postconf -e smtpd_recipient_restrictions='reject_non_fqdn_reci pient, permit_sasl_authenticated, permit_mynetworks, reject_invalid_hostname, reject_non_fqdn_hostname, reject_non_fqdn_sender, reject_unauth_destination, permit'
saslauthd[16623] :main : could not open pid lock file: /opt/zimbra/cyrus-sasl-2.1.21.ZIMBRA/state/saslauthd.pid.lock
saslauthd[16623] :main : open: Permission denied
saslauthd[16623] :main : Check to make sure the directory exists and is
saslauthd[16623] :main : writeable by the user this process runs as.

[marcmac]

The permissions error came about because you ran the debug command as root. Kill sasl and re-run it as the zimbra user.

[rmvg]

opps sorry think i got it now here is the output during a thunderbird session

[zimbra@shoemasters root]$ zmcontrol stop
Host shoemasters.com
Stopping antispam...Done
Stopping antivirus...Done
Stopping ldap...Done
Stopping logger...Done
Stopping mailbox...Done
Stopping mta...Done
Stopping snmp...Done
Stopping spell...Done
[zimbra@shoemasters root]$ zmcontrol start
Host shoemasters.com
Starting ldap...Done.
Starting antispam...Done.
Starting antivirus...Done.
Starting logger...Done.
Starting mailbox...Done.
Starting mta...Done.
Starting snmp...Done.
Starting spell...Done.
[zimbra@shoemasters root]$ whoami
zimbra
[zimbra@shoemasters root]$ zmsaslauthdctl stop [zimbra@shoemasters root]$ /opt/zimbra/cyrus-sasl-2.1.21.ZIMBRA/sbin/saslauthd -r -a zimbra -d
saslauthd[20839] :main : num_procs : 5
saslauthd[20839] :main : mech_option: NULL
saslauthd[20839] :main : run_path : /opt/zimbra/cyrus-sasl-2.1.21.ZIMBRA/state
saslauthd[20839] :main : auth_mech : zimbra
saslauthd[20839] :ipc_init : using accept lock file: /opt/zimbra/cyrus-sasl-2.1.21.ZIMBRA/state/mux.accept
saslauthd[20839] :detach_tty : master pid is: 0
saslauthd[20839] :ipc_init : listening on socket: /opt/zimbra/cyrus-sasl-2.1.21.ZIMBRA/state/mux
saslauthd[20839] :main : using process model
saslauthd[20840] :get_accept_lock : acquired accept lock
saslauthd[20839] :have_baby : forked child: 20840
saslauthd[20839] :have_baby : forked child: 20841
saslauthd[20839] :have_baby : forked child: 20842
saslauthd[20839] :have_baby : forked child: 20843
saslauthd[20840] :rel_accept_lock : released accept lock
saslauthd[20841] :get_accept_lock : acquired accept lock
zmpost: cert checking is off - should only be done during test/development
saslauthd[20840] :do_auth : auth failure: [user=king@shoemasters.com] [service=smtp] [realm=shoemasters.com] [mech=zimbra] [reason=Unknown]
saslauthd[20840] :do_request : response: NO
saslauthd[20841] :rel_accept_lock : released accept lock
zmpost: cert checking is off - should only be done during test/development
saslauthd[20842] :get_accept_lock : acquired accept lock
saslauthd[20841] :do_auth : auth failure: [user=king@shoemasters.com] [service=smtp] [realm=shoemasters.com] [mech=zimbra] [reason=Unknown]
saslauthd[20841] :do_request : response: NO
saslauthd[20842] :rel_accept_lock : released accept lock
zmpost: cert checking is off - should only be done during test/development
saslauthd[20843] :get_accept_lock : acquired accept lock
saslauthd[20842] :do_auth : auth failure: [user=king@shoemasters.com] [service=smtp] [realm=shoemasters.com] [mech=zimbra] [reason=Unknown]
saslauthd[20842] :do_request : response: NO
saslauthd[20843] :rel_accept_lock : released accept lock
saslauthd[20839] :get_accept_lock : acquired accept lock
zmpost: cert checking is off - should only be done during test/development
saslauthd[20843] :do_auth : auth failure: [user=king@shoemasters.com] [service=smtp] [realm=shoemasters.com] [mech=zimbra] [reason=Unknown]
saslauthd[20843] :do_request : response: NO