Post install : Zimbra start up is taking upwards of 10 minutes

zcook · Post by **zcook** » Sun Oct 09, 2005 1:33 pm

On the system's first boot zimbra takes a solid 10 minutes to start up. Once the system is booted, stopping and starting the service takes closer to 1 minute.
Server response with AJAX forms and general page refreshes are also extremely slow. Much slower than the nifty online demo and so I'm lead to believe that my install is goofed. I'm testing this out at home before I propose it to my office so it could have to do that this machine is also DNS and running x-windows.
I'm running Cent OS 4.1, a RHEL clone.

Fresh off of boot, here's what /var/log/zimbra.log has to say.
Oct 9 13:01:13 mail postfix/smtpd[4521]: connect from localhost.localdomain[127.0.0.1]

Oct 9 13:01:13 mail postfix/smtpd[4521]: disconnect from localhost.localdomain[127.0.0.1]

Oct 9 13:01:41 mail postfix/smtp[20624]: connect to gsmtp83.google.com[66.249.83.27]: Connection timed out (port 25)

Oct 9 13:01:49 mail postfix/smtpd[4521]: connect from localhost.localdomain[127.0.0.1]

Oct 9 13:01:49 mail postfix/smtpd[4521]: disconnect from localhost.localdomain[127.0.0.1]

Oct 9 13:03:23 mail zimbramon[2564]: 2564:info: Starting services

Oct 9 13:03:24 mail zimbramon[2564]: 2564:info: STARTING ldap

Oct 9 13:03:24 mail zimbramon[2564]: 2564:info: start service ldap

Oct 9 13:03:24 mail zimbramon[2564]: 2564:info: start app ldap

Oct 9 13:03:24 mail zimbramon[2564]: 2564:info: Starting child ldap: (20051009130324)

Oct 9 13:03:32 mail zimbramon[2564]: 2564:info: STARTING services

Oct 9 13:03:32 mail zimbramon[2564]: 2564:info: STARTING snmp

Oct 9 13:03:32 mail zimbramon[2564]: 2564:info: start service snmp

Oct 9 13:03:32 mail zimbramon[2564]: 2564:info: start app swatch

Oct 9 13:03:32 mail zimbramon[2564]: 2564:info: Starting child swatch: (20051009130332)

Oct 9 13:06:53 mail zimbramon[2564]: 2564:info: STARTING antivirus

Oct 9 13:06:53 mail zimbramon[2564]: 2564:info: start service antivirus

Oct 9 13:06:53 mail zimbramon[2564]: 2564:info: start app amavisd

Oct 9 13:06:53 mail zimbramon[2564]: 2564:info: Starting child amavisd: (20051009130653)

Oct 9 13:07:02 mail amavis[3678]: starting. /opt/zimbra/amavisd/sbin/amavisd at mail.domain.com amavisd-new-2.3.1 (20050509), Unicode aware, LANG=en_US.UTF-8

Oct 9 13:07:02 mail amavis[3678]: user=501, EUID: 501 (501); group=, EGID: 501 502 501 5 (501 502 501 5)

Oct 9 13:07:02 mail amavis[3678]: Perl version 5.008005

Oct 9 13:07:03 mail amavis[3678]: INFO: no optional modules: Sys::Hostname::Long Mail::SPF::Query Razor2::Client::Agent Net::CIDR::Lite

Oct 9 13:07:03 mail amavis[3729]: Net::Server: Process Backgrounded

Oct 9 13:07:03 mail amavis[3729]: Net::Server: 2005/10/09-13:07:03 Amavis (type Net::Server::PreForkSimple) starting! pid(3729)

Oct 9 13:07:03 mail amavis[3729]: Net::Server: Binding to TCP port 10024 on host 127.0.0.1

Oct 9 13:07:03 mail amavis[3729]: Net::Server: Group Not Defined. Defaulting to EGID '501 502 501 5'

Oct 9 13:07:03 mail amavis[3729]: Net::Server: User Not Defined. Defaulting to EUID '501'

Oct 9 13:07:03 mail amavis[3729]: Module Amavis::Conf 2.038

Oct 9 13:07:03 mail amavis[3729]: Module Archive::Tar 1.24

Oct 9 13:07:03 mail amavis[3729]: Module Archive::Zip 1.14

Oct 9 13:07:03 mail amavis[3729]: Module BerkeleyDB 0.26

Oct 9 13:07:03 mail amavis[3729]: Module Compress::Zlib 1.34

Oct 9 13:07:03 mail amavis[3729]: Module Convert::TNEF 0.17

Oct 9 13:07:03 mail amavis[3729]: Module Convert::UUlib 1.051

Oct 9 13:07:03 mail amavis[3729]: Module DBD::mysql 2.9005_3

Oct 9 13:07:03 mail amavis[3729]: Module DBI 1.47

Oct 9 13:07:03 mail amavis[3729]: Module DB_File 1.809

Oct 9 13:07:03 mail amavis[3729]: Module MIME::Entity 5.404

Oct 9 13:07:03 mail amavis[3729]: Module MIME::Parser 5.406

Oct 9 13:07:03 mail amavis[3729]: Module MIME::Tools 5.411

Oct 9 13:07:03 mail amavis[3729]: Module Mail::Header 1.62

Oct 9 13:07:03 mail amavis[3729]: Module Mail::Internet 1.62

Oct 9 13:07:03 mail amavis[3729]: Module Mail::SpamAssassin 3.000004

Oct 9 13:07:03 mail amavis[3729]: Module Net::Cmd 2.26

Oct 9 13:07:03 mail amavis[3729]: Module Net::DNS 0.51

Oct 9 13:07:03 mail amavis[3729]: Module Net::LDAP 0.32

Oct 9 13:07:03 mail amavis[3729]: Module Net::SMTP 2.29

Oct 9 13:07:03 mail amavis[3729]: Module Net::Server 0.87

Oct 9 13:07:03 mail amavis[3729]: Module Time::HiRes 1.65

Oct 9 13:07:03 mail amavis[3729]: Module Unix::Syslog 0.99

Oct 9 13:07:03 mail amavis[3729]: Amavis::DB code loaded

Oct 9 13:07:03 mail amavis[3729]: Amavis::Cache code loaded

Oct 9 13:07:03 mail amavis[3729]: SQL base code NOT loaded

Oct 9 13:07:03 mail amavis[3729]: SQL::Log code NOT loaded

Oct 9 13:07:03 mail amavis[3729]: SQL::Quarantine NOT loaded

Oct 9 13:07:03 mail amavis[3729]: Lookup::SQL code NOT loaded

Oct 9 13:07:03 mail amavis[3729]: Lookup::LDAP code loaded

Oct 9 13:07:03 mail amavis[3729]: AM.PDP prot code NOT loaded

Oct 9 13:07:03 mail amavis[3729]: SMTP-in prot code loaded

Oct 9 13:07:03 mail amavis[3729]: ANTI-VIRUS code loaded

Oct 9 13:07:03 mail amavis[3729]: ANTI-SPAM code loaded

Oct 9 13:07:03 mail amavis[3729]: Unpackers code loaded

Oct 9 13:07:03 mail amavis[3729]: Found $file at /usr/bin/file

Oct 9 13:07:03 mail amavis[3729]: No $dspam, not using it

Oct 9 13:07:03 mail amavis[3729]: Internal decoder for .mail

Oct 9 13:07:03 mail amavis[3729]: Internal decoder for .asc

Oct 9 13:07:03 mail amavis[3729]: Internal decoder for .uue

Oct 9 13:07:03 mail amavis[3729]: Internal decoder for .hqx

Oct 9 13:07:03 mail amavis[3729]: Internal decoder for .ync

Oct 9 13:07:03 mail amavis[3729]: No decoder for .F tried: unfreeze, freeze -d, melt, fcat

Oct 9 13:07:03 mail amavis[3729]: Found decoder for .Z at /usr/bin/gzip -d

Oct 9 13:07:03 mail amavis[3729]: Internal decoder for .gz

Oct 9 13:07:03 mail amavis[3729]: Found decoder for .gz at /usr/bin/gzip -d (backup, not used)

Oct 9 13:07:03 mail amavis[3729]: Found decoder for .bz2 at /usr/bin/bzip2 -d

Oct 9 13:07:03 mail amavis[3729]: No decoder for .lzo tried: lzop -d

Oct 9 13:07:03 mail amavis[3729]: Found decoder for .rpm at /usr/bin/rpm2cpio

Oct 9 13:07:03 mail amavis[3729]: Found decoder for .cpio at /usr/bin/pax

Oct 9 13:07:03 mail amavis[3729]: Found decoder for .tar at /usr/bin/pax

Oct 9 13:07:03 mail amavis[3729]: Internal decoder for .tar (backup, not used)

Oct 9 13:07:03 mail amavis[3729]: Found decoder for .deb at /usr/bin/ar

Oct 9 13:07:03 mail amavis[3729]: Internal decoder for .zip

Oct 9 13:07:03 mail amavis[3729]: No decoder for .rar tried: rar, unrar

Oct 9 13:07:03 mail amavis[3729]: No decoder for .arj tried: arj, unarj

Oct 9 13:07:03 mail amavis[3729]: No decoder for .arc tried: nomarch, arc

Oct 9 13:07:03 mail amavis[3729]: No decoder for .zoo tried: zoo

Oct 9 13:07:03 mail amavis[3729]: Found decoder for .lha at /usr/bin/lha

Oct 9 13:07:03 mail amavis[3729]: No decoder for .cab tried: cabextract

Oct 9 13:07:03 mail amavis[3729]: No decoder for .tnef tried: tnef

Oct 9 13:07:03 mail amavis[3729]: Internal decoder for .tnef

Oct 9 13:07:03 mail amavis[3729]: Found decoder for .exe at /usr/bin/lha

Oct 9 13:07:03 mail amavis[3729]: Using internal av scanner code for (primary) ClamAV-clamd

Oct 9 13:07:03 mail amavis[3729]: No primary av scanner: KasperskyLab AVP - aveclient

Oct 9 13:07:03 mail amavis[3729]: No primary av scanner: KasperskyLab AntiViral Toolkit Pro (AVP)

Oct 9 13:07:03 mail amavis[3729]: No primary av scanner: KasperskyLab AVPDaemonClient

Oct 9 13:07:03 mail amavis[3729]: No primary av scanner: CentralCommand Vexira (new) vascan

Oct 9 13:07:03 mail amavis[3729]: No primary av scanner: H+BEDV AntiVir or the (old) CentralCommand Vexira Antivirus

Oct 9 13:07:03 mail amavis[3729]: No primary av scanner: Command AntiVirus for Linux

Oct 9 13:07:03 mail amavis[3729]: No primary av scanner: Symantec CarrierScan via Symantec CommandLineScanner

Oct 9 13:07:03 mail amavis[3729]: No primary av scanner: Symantec AntiVirus Scan Engine

Oct 9 13:07:03 mail amavis[3729]: No primary av scanner: F-Secure Antivirus

Oct 9 13:07:03 mail amavis[3729]: No primary av scanner: CAI InoculateIT

Oct 9 13:07:03 mail amavis[3729]: No primary av scanner: CAI eTrust Antivirus

Oct 9 13:07:03 mail amavis[3729]: No primary av scanner: MkS_Vir for Linux (beta)

Oct 9 13:07:03 mail amavis[3729]: No primary av scanner: MkS_Vir daemon

Oct 9 13:07:03 mail amavis[3729]: No primary av scanner: ESET Software NOD32

Oct 9 13:07:03 mail amavis[3729]: No primary av scanner: ESET Software NOD32 - Client/Server Version

Oct 9 13:07:03 mail amavis[3729]: No primary av scanner: Norman Virus Control v5 / Linux

Oct 9 13:07:03 mail amavis[3729]: No primary av scanner: Panda Antivirus for Linux

Oct 9 13:07:03 mail amavis[3729]: No primary av scanner: NAI McAfee AntiVirus (uvscan)

Oct 9 13:07:03 mail amavis[3729]: No primary av scanner: VirusBuster

Oct 9 13:07:03 mail amavis[3729]: No primary av scanner: CyberSoft VFind

Oct 9 13:07:03 mail amavis[3729]: No primary av scanner: Ikarus AntiVirus for Linux

Oct 9 13:07:03 mail amavis[3729]: No primary av scanner: BitDefender

Oct 9 13:07:03 mail amavis[3729]: No secondary av scanner: ClamAV-clamscan

Oct 9 13:07:03 mail amavis[3729]: No secondary av scanner: FRISK F-Prot Antivirus

Oct 9 13:07:03 mail amavis[3729]: No secondary av scanner: Trend Micro FileScanner

Oct 9 13:07:03 mail amavis[3729]: No secondary av scanner: drweb - DrWeb Antivirus

Oct 9 13:07:03 mail amavis[3729]: No secondary av scanner: KasperskyLab kavscanner

Oct 9 13:07:03 mail amavis[3729]: Creating db in /opt/zimbra/amavisd/db/; BerkeleyDB 0.26, libdb 4.2

Oct 9 13:07:03 mail amavis[3729]: SpamControl: initializing Mail::SpamAssassin

Oct 9 13:07:04 mail amavis[3729]: SpamControl: done

Oct 9 13:07:04 mail amavis[3772]: TIMING [total 5 ms] - bdb-open: 5 (100%)100, rundown: 0 (0%)100

Oct 9 13:07:04 mail amavis[3773]: TIMING [total 4 ms] - bdb-open: 4 (100%)100, rundown: 0 (0%)100

Oct 9 13:07:04 mail amavis[3774]: TIMING [total 5 ms] - bdb-open: 5 (100%)100, rundown: 0 (0%)100

Oct 9 13:07:04 mail amavis[3778]: TIMING [total 4 ms] - bdb-open: 4 (100%)100, rundown: 0 (0%)100

Oct 9 13:07:04 mail amavis[3779]: TIMING [total 5 ms] - bdb-open: 5 (100%)100, rundown: 0 (0%)100

Oct 9 13:07:04 mail zimbramon[2564]: 2564:info: start app clamd

Oct 9 13:07:04 mail zimbramon[2564]: 2564:info: Starting child clamd: (20051009130704)

Oct 9 13:07:12 mail clamd[4328]: Daemon started.

Oct 9 13:07:12 mail clamd[4328]: clamd daemon 0.85.1 (OS: linux-gnu, ARCH: i386, CPU: i686)

Oct 9 13:07:12 mail clamd[4328]: Log file size limited to 20971520 bytes.

Oct 9 13:07:12 mail clamd[4328]: Reading databases from /opt/zimbra/clamav/db

Oct 9 13:07:13 mail clamd[4328]: Protecting against 40507 viruses.

Oct 9 13:07:13 mail clamd[4380]: Bound to port 3310

Oct 9 13:07:13 mail clamd[4380]: Setting connection queue length to 15

Oct 9 13:07:13 mail clamd[4380]: Archive: Archived file size limit set to 104857600 bytes.

Oct 9 13:07:13 mail clamd[4380]: Archive: Recursion level limit set to 8.

Oct 9 13:07:13 mail clamd[4380]: Archive: Files limit set to 1000.

Oct 9 13:07:13 mail clamd[4380]: Archive: Compression ratio limit set to 250.

Oct 9 13:07:13 mail clamd[4380]: Archive support enabled.

Oct 9 13:07:13 mail clamd[4380]: Archive: RAR support disabled.

Oct 9 13:07:13 mail clamd[4380]: Portable Executable support enabled.

Oct 9 13:07:13 mail clamd[4380]: Mail files support enabled.

Oct 9 13:07:13 mail clamd[4380]: OLE2 support enabled.

Oct 9 13:07:13 mail clamd[4380]: HTML support enabled.

Oct 9 13:07:13 mail clamd[4380]: Self checking every 1800 seconds.

Oct 9 13:07:15 mail zimbramon[2564]: 2564:info: start app mtaconfig

Oct 9 13:07:16 mail zimbramon[2564]: 2564:info: Starting child mtaconfig: (20051009130716)

Oct 9 13:07:19 mail zimbramon[2564]: 2564:info: STARTING antispam

Oct 9 13:07:19 mail zimbramon[2564]: 2564:info: start service antispam

Oct 9 13:07:19 mail zimbramon[2564]: 2564:info: start app amavisd

Oct 9 13:07:19 mail zimbramon[2564]: 2564:err: Can't start running app amavisd

Oct 9 13:07:19 mail zimbramon[2564]: 2564:info: start app mtaconfig

Oct 9 13:07:20 mail zimbramon[2564]: 2564:err: Can't start running app mtaconfig

Oct 9 13:07:20 mail zimbramon[2564]: 2564:info: STARTING mailbox

Oct 9 13:07:20 mail zimbramon[2564]: 2564:info: start service mailbox

Oct 9 13:07:20 mail zimbramon[2564]: 2564:info: start app mysql

Oct 9 13:07:21 mail zimbramon[2564]: 2564:info: Starting child mysql: (20051009130721)

Oct 9 13:07:25 mail zimbramon[2564]: 2564:info: start app tomcat

Oct 9 13:07:25 mail zimbramon[2564]: 2564:info: Starting child tomcat: (20051009130725)

Oct 9 13:07:26 mail zimbramon[2564]: 2564:info: STARTING mta

Oct 9 13:07:26 mail zimbramon[2564]: 2564:info: start service mta

Oct 9 13:07:26 mail zimbramon[2564]: 2564:info: start app saslauthd

Oct 9 13:07:26 mail zimbramon[2564]: 2564:info: Starting child saslauthd: (20051009130726)

Oct 9 13:07:38 mail zimbramon[2564]: 2564:info: start app mtaconfig

Oct 9 13:07:38 mail zimbramon[2564]: 2564:err: Can't start running app mtaconfig

Oct 9 13:07:38 mail zimbramon[2564]: 2564:info: start app postfix

Oct 9 13:07:38 mail zimbramon[2564]: 2564:err: SMTP RESPONSE: FAILURE from localhost: problem connecting to "localhost", port 25: Connection refused

Oct 9 13:07:38 mail zimbramon[2564]: 2564:info: Starting child postfix: (20051009130738)

Oct 9 13:07:48 mail postfix/postfix-script: warning: not owned by root: /opt/zimbra/postfix-2.2.3/conf/main.cf

Oct 9 13:07:48 mail postfix/postfix-script: starting the Postfix mail system

Oct 9 13:07:48 mail zimbramon[2564]: 2564:err: SMTP RESPONSE: FAILURE from localhost: problem connecting to "localhost", port 25: Connection refused

Oct 9 13:07:48 mail postfix/master[6935]: daemon started -- version 2.2.3, configuration /opt/zimbra/postfix-2.2.3/conf

Oct 9 13:07:48 mail postfix/qmgr[6937]: 860584C71C: from=, size=984, nrcpt=1 (queue active)

Oct 9 13:07:50 mail postfix/smtpd[6940]: initializing the server-side TLS engine

Oct 9 13:07:50 mail postfix/smtpd[6940]: connect from localhost.localdomain[127.0.0.1]

Oct 9 13:07:50 mail zimbramon[2564]: 2564:info: Doing startup

Oct 9 13:07:50 mail postfix/smtpd[6940]: disconnect from localhost.localdomain[127.0.0.1]

Oct 9 13:07:51 mail zimbramon[6944]: 6944:info: Zimbra Monitor startup: 6944

Oct 9 13:07:51 mail zimbramon[6944]: 6944:info: Process 4525 not found - removing /opt/zimbra/zimbramon/FIFO/zm.pid

Oct 9 13:07:51 mail zimbramon[6975]: 6975:info: Status monitor startup

Oct 9 13:07:51 mail zimbramon[6976]: 6976:info: Creating soap server on port 7777

Oct 9 13:08:00 mail postfix/smtpd[6940]: connect from localhost.localdomain[127.0.0.1]

Oct 9 13:08:00 mail postfix/smtpd[6940]: disconnect from localhost.localdomain[127.0.0.1]

Oct 9 13:08:11 mail postfix/smtpd[6940]: connect from localhost.localdomain[127.0.0.1]

Oct 9 13:08:11 mail postfix/smtpd[6940]: disconnect from localhost.localdomain[127.0.0.1]

Oct 9 13:08:23 mail postfix/smtp[6939]: connect to gmail-smtp-in.l.google.com[64.233.163.27]: Connection timed out (port 25)

Oct 9 13:08:48 mail postfix/smtpd[6940]: connect from localhost.localdomain[127.0.0.1]

Oct 9 13:08:48 mail postfix/smtpd[6940]: disconnect from localhost.localdomain[127.0.0.1]

Oct 9 13:08:53 mail postfix/smtp[6939]: connect to gmail-smtp-in.l.google.com[64.233.163.114]: Connection timed out (port 25)

Oct 9 13:09:23 mail postfix/smtp[6939]: connect to gsmtp83-2.google.com[66.249.83.114]: Connection timed out (port 25)

Oct 9 13:09:24 mail postfix/smtpd[6940]: connect from localhost.localdomain[127.0.0.1]

Oct 9 13:09:24 mail postfix/smtpd[6940]: disconnect from localhost.localdomain[127.0.0.1]

Oct 9 13:09:53 mail postfix/smtp[6939]: connect to gsmtp185.google.com[64.233.185.27]: Connection timed out (port 25)

Oct 9 13:10:00 mail postfix/smtpd[6940]: connect from localhost.localdomain[127.0.0.1]

Oct 9 13:10:00 mail postfix/smtpd[6940]: disconnect from localhost.localdomain[127.0.0.1]

Oct 9 13:10:23 mail postfix/smtp[6939]: connect to gsmtp185-2.google.com[64.233.185.114]: Connection timed out (port 25)

Oct 9 13:10:36 mail postfix/smtpd[6940]: connect from localhost.localdomain[127.0.0.1]

Oct 9 13:10:36 mail postfix/smtpd[6940]: disconnect from localhost.localdomain[127.0.0.1]
The google lines are likely referring to a test e-mail I sent to my own gmail address to see if zimbra would time bounce back the request since 'domain.com' is obviously not a public domain and I have not set up DNS forwarding. No bounced request, and no email received at gmail as expected... so I think that one e-mail has been bouncing around inside zimba for a good day or so now

Perhaps that's a bug? If the domain isn't found shouldn't an 'unknown address' error come up within a few seconds? I'm reading through the admin guide and options now to see if I can set up a time out period or something.

14319KevinH · Post by **14319KevinH** » Sun Oct 09, 2005 8:02 pm

What are the specs on your server? CPU/MEM/HD/etc

zcook · Post by **zcook** » Mon Oct 10, 2005 7:47 am

Being a test server it's really just a powerful desktop.
Athlon 64 3500+

1gb of DDR400

450gb no raid

nVidia 6600GT

14319KevinH · Post by **14319KevinH** » Mon Oct 10, 2005 11:51 am

That seems plenty for test box. Is there any CPU load or memory paging going on? Are you testing locally or from a networked client machine? If a client what's the config of the client?
Can you be more specfic about which actions are slow? Loading messages for reading, calender, etc.

17629anand · Post by **17629anand** » Mon Oct 10, 2005 3:25 pm

what does
$ vmstat 5
report in terms of CPU usage?
top in kernels 2.6 -> 2.6.9.preRHEL4update2 does not show high CPU using processes whose non-main thread is causing the load. But you can still run top to see if one of the non-JVM processes is sucking all the CPU.
but like KevinH said, what are the symptoms of the slowness? (before we are off diagnosing server health)

eger · Post by **eger** » Tue Dec 27, 2005 5:44 pm

I am also testing the Zimbra open source package in CentOS 4.x (RHEL 4 Clone) and am seeing the same problem. I was wondering if you modified you /etc/sysconfig/i18n file to remove the UTF strings?
Before I removed the UTF occurances in that file, Zimbra would spawn hundreds of unicode_start instances which would eventually bring the machine to a halt.
I thought this was the hanging problem also. But guess not.
I'd be interested if you have found a cure or know what is causing it.
Thanks!

marcmac · Post by **marcmac** » Tue Dec 27, 2005 5:47 pm

Which version of zimbra are you running?

phoenix · Post by **phoenix** » Thu Feb 03, 2011 8:01 am

[quote]Did they fix this? I am having simillar problems running zimbra

[/QUOTE]This thread is over five year olds, you should not resurrect old threads. Your version of Zimbra is likely to be somewhat different than the version(s) in this thread. How about giving full details of the version you have installed and a description of your problem plus exact steps to reproduce it, a 'me too' post doesn't actually give us much to go on.