Zimbra stopped working

Discuss your pilot or production implementation with other Zimbra admins or our engineers.
Post Reply
jakebriems
Posts: 13
Joined: Fri Sep 12, 2014 10:08 pm

Zimbra stopped working

Post by jakebriems »

Zimbra has been running well for a week now. Yesterday morning I get a call saying that one of our users can't access their email (in outlook.) i try to access the 7071 zimbra admin, but that page doesn't come up. additionally the webmail doesn't work either. I ssh in and "service zimbra restart"
the only thing I noticed was that on the service shutdown, the smtp part failed to shutdown (probably because it had already abnormally shutdown.)
Everything came up fine and is working well again.
How do I track down the root cause of this problem? Which logs would provide me with clues as to what went wrong?
ideas?
jb
rsharpe
Outstanding Member
Outstanding Member
Posts: 254
Joined: Fri Sep 12, 2014 9:59 pm

Zimbra stopped working

Post by rsharpe »

A good place to start is /var/log/zimbra.log and another good one for ya would be /opt/zimbra/tomcat/logs/catalina.out
bobby
Outstanding Member
Outstanding Member
Posts: 515
Joined: Fri Sep 12, 2014 10:01 pm

Zimbra stopped working

Post by bobby »

it's always good before restarting zimbra to first check "su - zimbra; zmcontrol status" to find out if something isn't running. if you can't log in anywhere, the answer is likely tomcat ;)
i think catalina.out gets zeroed out each time tomcat starts, though as long as tomcat hasn't completely died, the current thread dump gets saved as "stacktrace."
jakebriems
Posts: 13
Joined: Fri Sep 12, 2014 10:08 pm

Zimbra stopped working

Post by jakebriems »

so in /var/log/zimbra.log I see the following (I cut out parts that seemed to not be related)
Apr 9 10:03:03 [MAILSERVER] zimbramon[11431]: 11431:info: 2006-04-09 10:03:01, STATUS: [MAILSERVER].[DOMAIN].com: antispam: Running

Apr 9 10:03:03 [MAILSERVER] zimbramon[11431]: 11431:info: 2006-04-09 10:03:01, STATUS: [MAILSERVER].[DOMAIN].com: antivirus: Running

Apr 9 10:03:03 [MAILSERVER] zimbramon[11431]: 11431:info: 2006-04-09 10:03:01, STATUS: [MAILSERVER].[DOMAIN].com: ldap: Running

Apr 9 10:03:03 [MAILSERVER] zimbramon[11431]: 11431:info: 2006-04-09 10:03:01, STATUS: [MAILSERVER].[DOMAIN].com: logger: Running

Apr 9 10:03:03 [MAILSERVER] zimbramon[11431]: 11431:info: 2006-04-09 10:03:01, STATUS: [MAILSERVER].[DOMAIN].com: mailbox: Running

Apr 9 10:03:03 [MAILSERVER] zimbramon[11431]: 11431:info: 2006-04-09 10:03:01, STATUS: [MAILSERVER].[DOMAIN].com: mta: Running

Apr 9 10:03:03 [MAILSERVER] zimbramon[11431]: 11431:info: 2006-04-09 10:03:01, STATUS: [MAILSERVER].[DOMAIN].com: snmp: Running

Apr 9 10:03:03 [MAILSERVER] zimbramon[11431]: 11431:info: 2006-04-09 10:03:01, STATUS: [MAILSERVER].[DOMAIN].com: spell: Running


Apr 9 10:03:07 [MAILSERVER] postfix/smtpd[11601]: initializing the server-side TLS engine

Apr 9 10:03:07 [MAILSERVER] postfix/smtpd[11603]: initializing the server-side TLS engine

Apr 9 10:03:16 [MAILSERVER] postfix/anvil[9449]: statistics: max connection rate 1/60s for (smtp:64.90.194.246) at Apr 9 09:58:55

Apr 9 10:03:16 [MAILSERVER] postfix/anvil[9449]: statistics: max connection count 1 for (smtp:64.90.194.246) at Apr 9 09:58:55

Apr 9 10:03:16 [MAILSERVER] postfix/anvil[9449]: statistics: max cache size 1 at Apr 9 09:58:55

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: connect from carpal.[DOMAIN].com[204.246.136.82]

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: connect from carpal.[DOMAIN].com[204.246.136.82]

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: setting up TLS connection from carpal.[DOMAIN].com[204.246.136.82]

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: SSL_accept:before/accept initialization

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: read from 082260E8 [08230310] (11 bytes => -1 (0xFFFFFFFF))

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: SSL_accept:error in SSLv2/v3 read client hello A

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: setting up TLS connection from carpal.[DOMAIN].com[204.246.136.82]

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: SSL_accept:before/accept initialization

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: read from 082260E8 [08230310] (11 bytes => -1 (0xFFFFFFFF))

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: SSL_accept:error in SSLv2/v3 read client hello A

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: read from 082260E8 [08230310] (11 bytes => 11 (0xB))

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: 0000 80 7c 01 03 01 00 63 00|00 00 10 .|....c. ...

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: read from 082260E8 [0823031B] (115 bytes => -1 (0xFFFFFFFF))

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: SSL_accept:error in SSLv2/v3 read client hello B

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: read from 082260E8 [0823031B] (115 bytes => 115 (0x73))

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: 0000 00 00 39 00 00 38 00 00|35 00 00 16 00 00 13 00 ..9..8.. 5.......

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: 0010 00 0a 07 00 c0 00 00 33|00 00 32 00 00 2f 03 00 .......3 ..2../..

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: 0020 80 00 00 66 00 00 05 00|00 04 01 00 80 08 00 80 ...f.... ........

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: 0030 00 00 63 00 00 62 00 00|61 00 00 15 00 00 12 00 ..c..b.. a.......

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: 0040 00 09 06 00 40 00 00 65|00 00 64 00 00 60 00 00 ....@..e ..d..`..

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: 0050 14 00 00 11 00 00 08 00|00 06 04 00 80 00 00 03 ........ ........

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: 0060 02 00 80 cd 9c bf bf b0|cd 3c d5 18 2f e4 86 97 ........ .
Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: 0070 63 2c f1 c,.

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: SSL_accept:SSLv3 read client hello A

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: SSL_accept:SSLv3 write server hello A

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: SSL_accept:SSLv3 write certificate A

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: read from 082260E8 [08230310] (11 bytes => 11 (0xB))

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: 0000 80 7c 01 03 01 00 63 00|00 00 10 .|....c. ...

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: read from 082260E8 [0823031B] (115 bytes => -1 (0xFFFFFFFF))

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: SSL_accept:error in SSLv2/v3 read client hello B

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: read from 082260E8 [0823031B] (115 bytes => 115 (0x73))

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: 0000 00 00 39 00 00 38 00 00|35 00 00 16 00 00 13 00 ..9..8.. 5.......

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: 0010 00 0a 07 00 c0 00 00 33|00 00 32 00 00 2f 03 00 .......3 ..2../..

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: 0020 80 00 00 66 00 00 05 00|00 04 01 00 80 08 00 80 ...f.... ........

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: 0030 00 00 63 00 00 62 00 00|61 00 00 15 00 00 12 00 ..c..b.. a.......

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: 0040 00 09 06 00 40 00 00 65|00 00 64 00 00 60 00 00 ....@..e ..d..`..

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: 0050 14 00 00 11 00 00 08 00|00 06 04 00 80 00 00 03 ........ ........

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: 0060 02 00 80 62 85 4e fa a2|e7 ba 51 90 0b c1 70 b0 ...b.N.. ..Q...p.
Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: read from 082260E8 [08230315] (134 bytes => -1 (0xFFFFFFFF))

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: SSL_accept:error in SSLv3 read client certificate A

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: read from 082260E8 [08230315] (134 bytes => 134 (0x86))

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: 0000 10 00 00 82 00 80 7e ff|a6 0f 69 8c 1f b5 ea 88 ......~. ..i.....

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: 0010 6f a4 12 ce 8e a9 41 de|b3 d0 ba 95 f6 2a 7b fe o.....A. .....*{.

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: 0020 1c 02 ae 11 19 a7 dc 2b|f1 8e ae c8 cf 86 89 d6 .......+ ........

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: 0030 e1 7a fd 8d 32 ce 1f 45|64 17 7a 20 3b bb bf 6e .z..2..E d.z ;..n

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: 0040 3f 02 bf 9c 3f fd cd d9|df dd b0 6c ee 54 35 44 ?...?... ...l.T5D

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: 0050 da b8 cc c5 71 15 b2 ba|2f 52 48 34 37 01 3f 4f ....q... /RH47.?O

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: 0060 47 b9 18 e6 be 26 e6 53|90 5e 2d 3a 3f 37 ea 03 G....&.S .^-:?7..

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: 0070 b1 a0 4d 03 35 2d 98 ec|d0 a4 8d 95 a9 74 35 a7 ..M.5-.. .....t5.

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11601]: 0080 42 50 8e 48 e4 ae BP.H..

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: read from 082260E8 [08230310] (5 bytes => 5 (0x5))

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: 0000 16 03 01 00 86 .....

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: read from 082260E8 [08230315] (134 bytes => -1 (0xFFFFFFFF))

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: SSL_accept:error in SSLv3 read client certificate A

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: read from 082260E8 [08230315] (134 bytes => 134 (0x86))

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: 0000 10 00 00 82 00 80 ab 30|15 07 49 c6 c5 78 dd 9c .......0 ..I..x..

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: 0010 e3 05 40 c3 ef 9c 4a 38|49 63 1a aa e2 41 ab 57 ..@...J8 Ic...A.W

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: 0020 fa 96 bd b5 e7 c8 3d 0b|58 d2 ca 95 97 02 42 a9 ......=. X.....B.

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: 0030 17 94 8f ad 23 f9 bb 45|34 f3 30 4b 5e 1c 35 49 ....#..E 4.0K^.5I

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: 0040 90 28 f4 a7 31 22 54 6f|72 0b ee 55 0a 1e d7 c6 .(..1"To r..U....

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: 0050 91 d3 25 a3 c9 18 8a 4b|0c de 8c a5 b8 33 ef cf ..%....K .....3..

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: 0060 a3 c4 4a 81 8b 2f 0d 29|ec a1 bd a4 54 47 94 0a ..J../.) ....TG..

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: 0070 fe 64 5f 04 73 89 ed 18|02 79 d0 fb 8d 91 d8 ec .d_.s... .y......

Apr 9 10:03:17 [MAILSERVER] postfix/smtpd[11603]: 0080 ee 6c 60 0a 2c 6b .l`.,k
Apr 9 10:03:19 [MAILSERVER] postfix/smtpd[11601]: disconnect from carpal.[DOMAIN].com[204.246.136.82]


Apr 9 10:03:27 [MAILSERVER] postfix/lmtp[11614]: A8B484880F: to=, relay=[MAILSERVER].[DOMAIN].com[65.73.180.147],

delay=8, status=deferred (lost connection with [MAILSERVER].[DOMAIN].com[65.73.180.147] while sending end of data -- message may be

sent more than once)

Apr 9 10:04:02 [MAILSERVER] zimbramon[11915]: 11915:info: 2006-04-09 10:04:01, STATUS: [MAILSERVER].[DOMAIN].com: antispam: Running

Apr 9 10:04:02 [MAILSERVER] zimbramon[11915]: 11915:info: 2006-04-09 10:04:01, STATUS: [MAILSERVER].[DOMAIN].com: antivirus: Running

Apr 9 10:04:02 [MAILSERVER] zimbramon[11915]: 11915:info: 2006-04-09 10:04:01, STATUS: [MAILSERVER].[DOMAIN].com: ldap: Running

Apr 9 10:04:02 [MAILSERVER] zimbramon[11915]: 11915:info: 2006-04-09 10:04:01, STATUS: [MAILSERVER].[DOMAIN].com: logger: Running

Apr 9 10:04:02 [MAILSERVER] zimbramon[11915]: 11915:info: 2006-04-09 10:04:01, STATUS: [MAILSERVER].[DOMAIN].com: mailbox: Stopped

Apr 9 10:04:02 [MAILSERVER] zimbramon[11915]: 11915:info: 2006-04-09 10:04:01, STATUS: [MAILSERVER].[DOMAIN].com: mta: Running

Apr 9 10:04:02 [MAILSERVER] zimbramon[11915]: 11915:info: 2006-04-09 10:04:01, STATUS: [MAILSERVER].[DOMAIN].com: snmp: Running

Apr 9 10:04:02 [MAILSERVER] zimbramon[11915]: 11915:info: 2006-04-09 10:04:01, STATUS: [MAILSERVER].[DOMAIN].com: spell: Running


Where [MAILSERVER] is the hostname of the zimbra machine and [DOMAIN] is our domain (e.g. example.com)
You'll notice that mailbox: Stopped happened at Apr 9th.
Any idea what went wrong?
jb
14319KevinH
Ambassador
Ambassador
Posts: 4558
Joined: Fri Sep 12, 2014 9:52 pm

Zimbra stopped working

Post by 14319KevinH »

You can see that lmtp can't connect so tomcat is stopped. Anything in /opt/zimbra/log/zimbra.log around the same time?
jakebriems
Posts: 13
Joined: Fri Sep 12, 2014 10:08 pm

Zimbra stopped working

Post by jakebriems »

Yes, there seemed to have been a "Java heap space" problem:
2006-04-09 09:59:59,092 INFO [LmtpServer-1690] [name=mnelson@[DOMAIN].com;] FileBlobStore - Stored size=6604 wrote=6604 path=/

opt/zimbra/store/incoming/1144558701730-98.msg vol=1 digest=xjqB0rrSb7TAUVB4smshVCsK8n8=

2006-04-09 09:59:59,092 INFO [LmtpServer-1690] [name=mnelson@[DOMAIN].com;] FileBlobStore - Renamed id=1373 mbox=2 oldpath=/op

t/zimbra/store/incoming/1144558701730-98.msg newpath=/opt/zimbra/store/0/2/msg/0/1373-2304.msg

2006-04-09 09:59:59,122 INFO [LmtpServer-1690] [name=mnelson@[DOMAIN].com;] mailbox - Added message id=1373 digest=xjqB0rrSb7T

AUVB4smshVCsK8n8= mailbox=2 rcpt=mnelson@[DOMAIN].com

2006-04-09 10:00:24,463 INFO [IndexWritersSweeper] [] MailboxIndex - open index writers sweep: before=1, closed=0, after=1 (

0ms)

2006-04-09 10:01:24,473 INFO [IndexWritersSweeper] [] MailboxIndex - open index writers sweep: before=1, closed=0, after=1 (

0ms)

2006-04-09 10:01:39,120 INFO [LmtpServer-1690] [] LmtpHandler - [10.10.10.1] quit from client

2006-04-09 10:01:39,120 INFO [LmtpServer-1690] [] ProtocolHandler - Handler exiting normally

2006-04-09 10:02:24,482 INFO [IndexWritersSweeper] [] MailboxIndex - open index writers sweep: before=1, closed=0, after=1 (

0ms)

2006-04-09 10:03:24,027 INFO [LmtpServer-1691] [] LmtpHandler - [10.10.10.1] connected

2006-04-09 10:03:24,287 INFO [LmtpServer-1691] [name=mnelson@[DOMAIN].com;] FileBlobStore - Stored size=3509 wrote=3509 path=/

opt/zimbra/store/incoming/1144558701730-99.msg vol=1 digest=4zarhiW5djnTpsmqlZWfFwsA4Hs=

2006-04-09 10:03:24,287 INFO [LmtpServer-1691] [name=mnelson@[DOMAIN].com;] FileBlobStore - Renamed id=1374 mbox=2 oldpath=/op

t/zimbra/store/incoming/1144558701730-99.msg newpath=/opt/zimbra/store/0/2/msg/0/1374-2305.msg

2006-04-09 10:03:24,322 INFO [LmtpServer-1691] [name=mnelson@[DOMAIN].com;] mailbox - Added message id=1374 digest=4zarhiW5djn

TpsmqlZWfFwsA4Hs= mailbox=2 rcpt=mnelson@[DOMAIN].com

2006-04-09 10:03:24,491 INFO [IndexWritersSweeper] [] MailboxIndex - open index writers sweep: before=1, closed=0, after=1 (

0ms)

2006-04-09 10:03:24,849 INFO [LmtpServer-1692] [] LmtpHandler - [10.10.10.1] connected

2006-04-09 10:03:27,049 FATAL [LmtpServer-1692] [] system - Fatal error occurred while handling connection

java.lang.OutOfMemoryError: Java heap space


What would have caused that? How might I prevent it in the future?
jb
14319KevinH
Ambassador
Ambassador
Posts: 4558
Joined: Fri Sep 12, 2014 9:52 pm

Zimbra stopped working

Post by 14319KevinH »

Hard to pin point the cause here. How much memory do you have? What's the user activity like? Number users? POP? IMAP? Web UI?
jakebriems
Posts: 13
Joined: Fri Sep 12, 2014 10:08 pm

Zimbra stopped working

Post by jakebriems »

2GB of RAM, 40 or so users. all secure pop3 with some using the web UI as well. Strangely though, the problem occured at 10am sunday morning with practically nobody using the system.
Is there a file where I can go to set my Java heap memory variable to a larger value?
jb
14319KevinH
Ambassador
Ambassador
Posts: 4558
Joined: Fri Sep 12, 2014 9:52 pm

Zimbra stopped working

Post by 14319KevinH »

You can up the % in zmlocalconfig, with 2GB you should already have plenty for a userbase that small.
Post Reply