| Welcome to the Zimbra :: Forums! | |
Welcome, if you would like to post a comment please register.
We also encourage you to explore all things Zimbra with our team and members of the community.
|  | | 
07-16-2007, 02:22 PM
| | Intermediate Member | |
Posts: 19
| | Bad file descriptor? Trying to test mail delivery on a fresh Zimbra install (slightly modified to run in a vserver as described on Install VServer - ZimbraWiki)
The queue shows errors as follows: Code: root@zoo /usr/local/bin> mailq
-Queue ID- --Size-- ----Arrival Time---- -Sender/Recipient-------
442955482AF 581 Mon Jul 16 01:10:16 zimbra@zoo.zcsdomain.com
(host 88.88.88.198[88.88.88.198] said: 450 4.4.1 Can't connect to 88.88.88.198 port 10025, (Bad file descriptor) at (eval 51) line 145, line 914., MTA([88.88.88.198]:10025), id=11640-04 (in reply to end of DATA command))
admin@zcsdomain.com
483DA5482B7 4400 Mon Jul 16 11:59:38 name@externaldomain.com
(host 88.88.88.198[88.88.88.198] said: 450 4.4.1 Can't connect to 88.88.88.198 port 10025, (Bad file descriptor) at (eval 51) line 145, line 876., MTA([88.88.88.198]:10025), id=11640-03 (in reply to end of DATA command))
admin@zcsdomain.com
C8EB2548284 19539 Mon Jul 16 11:57:15 admin@zcsdomain.com
(host 88.88.88.198[88.88.88.198] said: 450 4.4.1 Can't connect to 88.88.88.198 port 10025, (Bad file descriptor) at (eval 51) line 145, line 838., MTA([88.88.88.198]:10025), id=11643-02 (in reply to end of DATA command))
name@externaldomain.com
-- 25 Kbytes in 3 Requests. The port 10025 is listening, though: Code: root@zoo /usr/local/bin> netstat -a|grep 10025
tcp 0 0 zoo.zcsdomain:10025 *:* LISTEN Here is the ps outpout: Code: root@zoo /usr/local/bin> ps faxj
PPID PID PGID SID TTY TPGID STAT UID TIME COMMAND
7806 8264 8264 7806 pts/0 8264 S+ 0 0:00 login
8264 8289 8289 8289 pts/1 25399 Ss 0 0:00 \_ /bin/bash -login
8289 25399 25399 8289 pts/1 25399 R+ 0 0:00 \_ ps faxj
0 1 1 1 ? -1 Ss 0 0:01 init [2]
1 31793 31793 31793 ? -1 Ss 0 0:02 /sbin/syslogd
1 31814 31814 31814 ? -1 Ss 0 0:00 /usr/sbin/cron
1 8471 8471 8471 ? -1 Ss 0 0:00 /usr/sbin/sshd
1 11119 11119 11119 ? -1 Ssl 1000 0:00 /opt/zimbra/openldap/libexec/slapd -l LOCAL0 -4 -u zimbra -h ldap://zoo.zcsdomain.com:389 -f /opt/zimbra/conf/s
1 11240 11083 8289 pts/1 25399 S 1000 0:00 /bin/sh /opt/zimbra/logger/mysql/bin/mysqld_safe --defaults-file=/opt/zimbra/conf/my.logger.cnf --ledir=/opt/zimbra
11240 11359 11083 8289 pts/1 25399 Sl 1000 0:01 \_ /opt/zimbra/logger/mysql/libexec/mysqld --defaults-file=/opt/zimbra/conf/my.logger.cnf --basedir=/opt/zimbra/lo
1 11247 11083 8289 pts/1 25399 S 1000 0:00 /usr/bin/perl /opt/zimbra/libexec/logswatch --config-file=/opt/zimbra/conf/logswatchrc --use-cpan-file-tail --scrip
11247 11258 11083 8289 pts/1 25399 S 1000 0:00 \_ /usr/bin/perl /tmp/.swatch_script.11247
11258 11278 11083 8289 pts/1 25399 S 1000 0:00 \_ /usr/bin/perl /opt/zimbra/libexec/zmlogger
1 11262 11083 8289 pts/1 25399 S 1000 0:03 /usr/bin/perl /opt/zimbra/libexec/zmmtaconfig
1 11268 11083 8289 pts/1 25399 S 1000 0:00 /bin/sh /opt/zimbra/mysql/bin/mysqld_safe --defaults-file=/opt/zimbra/conf/my.cnf --ledir=/opt/zimbra/mysql/libexec
11268 11312 11083 8289 pts/1 25399 Sl 1000 0:03 \_ /opt/zimbra/mysql/libexec/mysqld --defaults-file=/opt/zimbra/conf/my.cnf --basedir=/opt/zimbra/mysql --datadir=
1 11499 11499 11499 ? -1 Ss 0 0:00 /opt/zimbra/libexec/zmtomcatmgr start -Xms397m -Xmx397m -client -XX:NewRatio=2 -Djava.awt.headless=true
11499 11500 11500 11499 ? -1 Sl 1000 0:12 \_ /opt/zimbra/jdk1.5.0_08/bin/java -Xms397m -Xmx397m -client -XX:NewRatio=2 -Djava.awt.headless=true -Dcatalina.b
1 11539 11539 11539 ? -1 Ss 1000 2:31 /opt/zimbra/clamav/sbin/clamd --config-file /opt/zimbra/conf/clamd.conf
1 11542 11083 8289 pts/1 25399 S 1000 0:00 /usr/bin/perl /opt/zimbra/libexec/swatch --config-file=/opt/zimbra/conf/swatchrc --use-cpan-file-tail --script-dir=
11542 11550 11083 8289 pts/1 25399 S 1000 0:00 \_ /usr/bin/perl /tmp/.swatch_script.11542
1 11551 11551 11551 ? -1 Ss 1000 0:00 /opt/zimbra/httpd-2.0.54/bin/httpd -k start -f /opt/zimbra/conf/httpd.conf
11551 11552 11551 11551 ? -1 S 1000 0:00 \_ /opt/zimbra/httpd-2.0.54/bin/httpd -k start -f /opt/zimbra/conf/httpd.conf
11551 11553 11551 11551 ? -1 S 1000 0:00 \_ /opt/zimbra/httpd-2.0.54/bin/httpd -k start -f /opt/zimbra/conf/httpd.conf
11551 11558 11551 11551 ? -1 S 1000 0:00 \_ /opt/zimbra/httpd-2.0.54/bin/httpd -k start -f /opt/zimbra/conf/httpd.conf
11551 11559 11551 11551 ? -1 S 1000 0:00 \_ /opt/zimbra/httpd-2.0.54/bin/httpd -k start -f /opt/zimbra/conf/httpd.conf
11551 11560 11551 11551 ? -1 S 1000 0:00 \_ /opt/zimbra/httpd-2.0.54/bin/httpd -k start -f /opt/zimbra/conf/httpd.conf
1 11591 11591 11591 ? -1 Ss 1000 0:00 amavisd (master)
11591 11634 11591 11591 ? -1 S 1000 0:00 \_ amavisd (virgin child)
11591 11635 11591 11591 ? -1 S 1000 0:00 \_ amavisd (virgin child)
11591 11636 11591 11591 ? -1 S 1000 0:00 \_ amavisd (virgin child)
11591 11637 11591 11591 ? -1 S 1000 0:00 \_ amavisd (virgin child)
11591 11638 11591 11591 ? -1 S 1000 0:00 \_ amavisd (virgin child)
11591 11639 11591 11591 ? -1 S 1000 0:00 \_ amavisd (virgin child)
11591 11640 11591 11591 ? -1 S 1000 0:01 \_ amavisd (ch4-avail)
11591 11641 11591 11591 ? -1 S 1000 0:00 \_ amavisd (virgin child)
11591 11642 11591 11591 ? -1 S 1000 0:00 \_ amavisd (virgin child)
11591 11643 11591 11591 ? -1 S 1000 0:01 \_ amavisd (ch2-avail)
1 11619 11619 11619 ? -1 Ss 0 0:00 /opt/zimbra/postfix-2.2.9/libexec/master
11619 11629 11619 11619 ? -1 S 1001 0:00 \_ qmgr -l -t fifo -u
11619 13318 11619 11619 ? -1 S 1001 0:00 \_ tlsmgr -l -t unix -u
11619 21190 11619 11619 ? -1 S 1001 0:00 \_ pickup -l -t fifo -u
11619 25380 11619 11619 ? -1 S 1001 0:00 \_ showq -t unix -u
1 11627 11627 11627 ? -1 Ss 1000 0:00 /opt/zimbra/cyrus-sasl-2.1.21.ZIMBRA/sbin/saslauthd -r -a zimbra
11627 11630 11627 11627 ? -1 S 1000 0:00 \_ /opt/zimbra/cyrus-sasl-2.1.21.ZIMBRA/sbin/saslauthd -r -a zimbra
11627 11631 11627 11627 ? -1 S 1000 0:00 \_ /opt/zimbra/cyrus-sasl-2.1.21.ZIMBRA/sbin/saslauthd -r -a zimbra
11627 11632 11627 11627 ? -1 S 1000 0:00 \_ /opt/zimbra/cyrus-sasl-2.1.21.ZIMBRA/sbin/saslauthd -r -a zimbra
11627 11633 11627 11627 ? -1 S 1000 0:00 \_ /opt/zimbra/cyrus-sasl-2.1.21.ZIMBRA/sbin/saslauthd -r -a zimbra
root@zoo /usr/local/bin> Any suggestions? Did I screw up something by replacing 127.0.0.1 with my real IP in the config files?
Thanks... | 
07-16-2007, 03:56 PM
| | Former Zimbran | |
Posts: 5,606
| | Zimbra has it's own MTA, so anything that's "local" won't work. . .ie mailq isn't accurate.
You should stop your current MTA and start Zimbra's. | 
07-16-2007, 04:20 PM
| | Intermediate Member | |
Posts: 19
| | Only Zimbra is running Thanks for your answer however I am not running any other MTA than Zimbra's (see ps output above). This is a standard Zimbra install on a virgin system.
I used mailq to display the mail queue out of habit (/opt/zimbra/postfix/sbin/mailq) I didn't know it wasn't accurate. What is the proper way to display the mail queue under Zimbra?
The thing is, the mails shown above were not delivered, so something is definitely wrong. Could you point me in the right direction> | 
07-16-2007, 04:40 PM
| | Former Zimbran | |
Posts: 5,606
| | In the Zimbra administration Console, you'll see Mail Queue. You can view them there.
The mail spool isn't in the location that mailq was looking. . so any messages that are there are either being send locally by invoking sendmail or postfix. . or were there before zimbra started. | 
07-17-2007, 11:57 AM
| | Intermediate Member | |
Posts: 19
| | Same problem shown in web UI I have been to the web admin console and had a look at the mail queue.
It shows the same messages as my initial post, with the same error.
Any suggestion?
This is a default Zimbra install on a virgin system, no other MTA or any oher software has been installed, and I didn't deviate from the default configuration options. The only change, as mentioned in my original post, concerns the change of "127.0.0.1" to my real IP in configuration files (as recommended for a vserver install). | 
07-17-2007, 12:02 PM
| | Former Zimbran | |
Posts: 5,606
| | | 
07-17-2007, 12:05 PM
| | Former Zimbran | |
Posts: 5,606
| | I'm sorry,
I should have asked for this sooner:
What's in your /var/log/zimbra.log ? | 
07-17-2007, 12:41 PM
| | Intermediate Member | |
Posts: 19
| | /var/log/zimbra.log I will reboot and fsck the system. Meanwhile here is the log file you requested. You will notice the "connection refused" at the time of mail delivery. Code: Jul 17 18:14:48 zoo zimbramon[25320]: 25320:info: Starting services
Jul 17 18:14:48 zoo slapd[25358]: @(#) $OpenLDAP: slapd 2.3.34 (Mar 28 2007 13:45:10) $ ^Iroot@build-debian.liquidsys.com:/home/build/p4/main/ThirdParty/openldap/openldap-2.3.34/servers/slapd
Jul 17 18:14:48 zoo slapd[25359]: slapd starting
Jul 17 18:14:56 zoo zimbramon[25320]: 25320:info: Rewriting configs antispam antivirus webxml mailbox antispam antivirus mta sasl
Jul 17 18:15:02 zoo zimbramon[25320]: 25320:info: Starting logger
Jul 17 18:15:02 zoo zimbramon[25320]: 25320:info: Starting mailbox
Jul 17 18:15:16 zoo zmtomcatmgr[25723]: status requested
Jul 17 18:15:16 zoo zmtomcatmgr[25723]: file /opt/zimbra/log/zmtomcatmgr.pid does not exist
Jul 17 18:15:16 zoo zmtomcatmgr[25723]: assuming no other instance is running
Jul 17 18:15:16 zoo zmtomcatmgr[25723]: no manager process is running
Jul 17 18:15:16 zoo zmtomcatmgr[25730]: start requested
Jul 17 18:15:16 zoo zmtomcatmgr[25730]: checking if another instance of manager is already running
Jul 17 18:15:16 zoo zmtomcatmgr[25730]: file /opt/zimbra/log/zmtomcatmgr.pid does not exist
Jul 17 18:15:16 zoo zmtomcatmgr[25730]: assuming no other instance is running
Jul 17 18:15:16 zoo zmtomcatmgr[25731]: wrote manager pid 25731 to /opt/zimbra/log/zmtomcatmgr.pid
Jul 17 18:15:16 zoo zmtomcatmgr[25731]: manager started tomcat/JVM with pid 25732
Jul 17 18:15:16 zoo zimbramon[25320]: 25320:info: Starting antispam
Jul 17 18:15:16 zoo zimbramon[25320]: 25320:info: Starting antivirus
Jul 17 18:15:17 zoo clamd[25769]: clamd daemon 0.90.2 (OS: linux-gnu, ARCH: i386, CPU: i686)
Jul 17 18:15:17 zoo clamd[25769]: Log file size limited to 20971520 bytes.
Jul 17 18:15:17 zoo clamd[25769]: Reading databases from /opt/zimbra/clamav/db
Jul 17 18:15:17 zoo zimbramon[25320]: 25320:info: Starting snmp
Jul 17 18:15:17 zoo zimbramon[25320]: 25320:info: Starting spell
Jul 17 18:15:18 zoo zimbramon[25320]: 25320:info: Starting mta
Jul 17 18:15:19 zoo postfix/postqueue[25800]: fatal: Queue report unavailable - mail system is down
Jul 17 18:15:24 zoo postfix/postfix-script: warning: not owned by root: /opt/zimbra/postfix-2.2.9/conf/main.cf
Jul 17 18:15:24 zoo postfix/postfix-script: starting the Postfix mail system
Jul 17 18:15:24 zoo postfix/master[25848]: daemon started -- version 2.2.9, configuration /opt/zimbra/postfix-2.2.9/conf
Jul 17 18:15:24 zoo postfix/qmgr[25858]: 85B71548284: from=, size=547, nrcpt=1 (queue active)
Jul 17 18:15:24 zoo postfix/smtp[25859]: connect to 88.88.88.198[88.88.88.198]: Connection refused (port 10024)
Jul 17 18:15:25 zoo postfix/smtp[25859]: 85B71548284: to=, relay=none, delay=1547, status=deferred (connect to 88.88.88.198[88.88.88.198]: Connection refused)
Jul 17 18:15:25 zoo saslauthd[25856]: detach_tty : master pid is: 25856
Jul 17 18:15:25 zoo saslauthd[25856]: ipc_init : listening on socket: /opt/zimbra/cyrus-sasl-2.1.21.ZIMBRA/state/mux
Jul 17 18:15:31 zoo amavis[25753]: starting. /opt/zimbra/amavisd/sbin/amavisd at zoo.zcsdomain.com amavisd-new-2.4.3 (20060930), Unicode aware, LANG=C
Jul 17 18:15:31 zoo amavis[25753]: user=1000, EUID: 1000 (1000); group=, EGID: 103 104 103 5 4 (103 104 103 5 4); log_level=1
Jul 17 18:15:31 zoo amavis[25753]: Perl version 5.008008
Jul 17 18:15:33 zoo amavis[25753]: SpamControl: init_pre_chroot done
Jul 17 18:15:33 zoo amavis[25866]: Net::Server: Process Backgrounded
Jul 17 18:15:33 zoo amavis[25866]: Net::Server: 2007/07/17-18:15:33 Amavis (type Net::Server::PreForkSimple) starting! pid(25866)
Jul 17 18:15:33 zoo amavis[25866]: Net::Server: Binding to UNIX socket file /opt/zimbra/amavisd/amavisd.sock using SOCK_STREAM
Jul 17 18:15:33 zoo amavis[25866]: Net::Server: Binding to TCP port 10024 on host 88.88.88.198
Jul 17 18:15:33 zoo amavis[25866]: Net::Server: Group Not Defined. Defaulting to EGID '103 104 103 5 4'
Jul 17 18:15:33 zoo amavis[25866]: Net::Server: User Not Defined. Defaulting to EUID '1000'
Jul 17 18:15:33 zoo amavis[25866]: Module Amavis::Conf 2.072
Jul 17 18:15:33 zoo amavis[25866]: Module Archive::Tar 1.30
Jul 17 18:15:33 zoo amavis[25866]: Module Archive::Zip 1.18
Jul 17 18:15:33 zoo amavis[25866]: Module BerkeleyDB 0.31
Jul 17 18:15:33 zoo amavis[25866]: Module Compress::Zlib 2.004
Jul 17 18:15:33 zoo amavis[25866]: Module Convert::TNEF 0.17
Jul 17 18:15:33 zoo amavis[25866]: Module Convert::UUlib 1.08
Jul 17 18:15:33 zoo amavis[25866]: Module DBD::mysql 4.003
Jul 17 18:15:33 zoo amavis[25866]: Module DBI 1.54
Jul 17 18:15:33 zoo amavis[25866]: Module DB_File 1.815
Jul 17 18:15:33 zoo amavis[25866]: Module Digest::MD5 2.36
Jul 17 18:15:33 zoo amavis[25866]: Module MIME::Entity 5.420
Jul 17 18:15:33 zoo amavis[25866]: Module MIME::Parser 5.420
Jul 17 18:15:33 zoo amavis[25866]: Module MIME::Tools 5.420
Jul 17 18:15:33 zoo amavis[25866]: Module Mail::Header 1.74
Jul 17 18:15:33 zoo amavis[25866]: Module Mail::Internet 1.74
Jul 17 18:15:33 zoo amavis[25866]: Module Mail::SpamAssassin 3.001008
Jul 17 18:15:33 zoo amavis[25866]: Module Net::Cmd 2.27
Jul 17 18:15:33 zoo amavis[25866]: Module Net::DNS 0.59
Jul 17 18:15:33 zoo amavis[25866]: Module Net::LDAP 0.34
Jul 17 18:15:33 zoo amavis[25866]: Module Net::SMTP 2.30
Jul 17 18:15:33 zoo amavis[25866]: Module Net::Server 0.95
Jul 17 18:15:33 zoo amavis[25866]: Module Time::HiRes 1.9707
Jul 17 18:15:33 zoo amavis[25866]: Module Unix::Syslog 0.99
Jul 17 18:15:33 zoo amavis[25866]: Amavis::DB code loaded
Jul 17 18:15:33 zoo amavis[25866]: Amavis::Cache code loaded
Jul 17 18:15:33 zoo amavis[25866]: SQL base code NOT loaded
Jul 17 18:15:33 zoo amavis[25866]: SQL::Log code NOT loaded
Jul 17 18:15:33 zoo amavis[25866]: SQL::Quarantine NOT loaded
Jul 17 18:15:33 zoo amavis[25866]: Lookup::SQL code NOT loaded
Jul 17 18:15:33 zoo amavis[25866]: Lookup::LDAP code loaded
Jul 17 18:15:33 zoo amavis[25866]: AM.PDP-in proto code loaded
Jul 17 18:15:33 zoo amavis[25866]: SMTP-in proto code loaded
Jul 17 18:15:33 zoo amavis[25866]: Courier proto code NOT loaded
Jul 17 18:15:33 zoo amavis[25866]: SMTP-out proto code loaded
Jul 17 18:15:33 zoo amavis[25866]: Pipe-out proto code NOT loaded
Jul 17 18:15:33 zoo amavis[25866]: BSMTP-out proto code NOT loaded
Jul 17 18:15:33 zoo amavis[25866]: Local-out proto code loaded
Jul 17 18:15:33 zoo amavis[25866]: OS_Fingerprint code NOT loaded
Jul 17 18:15:33 zoo amavis[25866]: ANTI-VIRUS code loaded
Jul 17 18:15:33 zoo amavis[25866]: ANTI-SPAM code loaded
Jul 17 18:15:33 zoo amavis[25866]: ANTI-SPAM-SA code loaded
Jul 17 18:15:33 zoo amavis[25866]: Unpackers code loaded
Jul 17 18:15:33 zoo amavis[25866]: Found $file at /usr/bin/file
Jul 17 18:15:33 zoo amavis[25866]: No $dspam, not using it
Jul 17 18:15:33 zoo amavis[25866]: Internal decoder for .mail
Jul 17 18:15:33 zoo amavis[25866]: Internal decoder for .asc
Jul 17 18:15:33 zoo amavis[25866]: Internal decoder for .uue
Jul 17 18:15:33 zoo amavis[25866]: Internal decoder for .hqx
Jul 17 18:15:33 zoo amavis[25866]: Internal decoder for .ync
Jul 17 18:15:33 zoo amavis[25866]: No decoder for .F tried: unfreeze, freeze -d, melt, fcat
Jul 17 18:15:33 zoo amavis[25866]: Found decoder for .Z at /bin/uncompress
Jul 17 18:15:33 zoo amavis[25866]: Internal decoder for .gz
Jul 17 18:15:33 zoo amavis[25866]: No decoder for .bz2 tried: bzip2 -d
Jul 17 18:15:33 zoo amavis[25866]: No decoder for .lzo tried: lzop -d
Jul 17 18:15:33 zoo amavis[25866]: No decoder for .rpm tried: rpm2cpio.pl, rpm2cpio
Jul 17 18:15:33 zoo amavis[25866]: Found decoder for .cpio at /bin/cpio
Jul 17 18:15:33 zoo amavis[25866]: Found decoder for .tar at /bin/cpio
Jul 17 18:15:33 zoo amavis[25866]: No decoder for .deb tried: ar
Jul 17 18:15:33 zoo amavis[25866]: Internal decoder for .zip
Jul 17 18:15:33 zoo amavis[25866]: No decoder for .rar tried: rar, unrar
Jul 17 18:15:33 zoo amavis[25866]: No decoder for .arj tried: arj, unarj
Jul 17 18:15:33 zoo amavis[25866]: No decoder for .arc tried: nomarch, arc
Jul 17 18:15:33 zoo amavis[25866]: No decoder for .zoo tried: zoo
Jul 17 18:15:33 zoo amavis[25866]: No decoder for .lha tried: lha
Jul 17 18:15:33 zoo amavis[25866]: No decoder for .cab tried: cabextract
Jul 17 18:15:33 zoo amavis[25866]: No decoder for .tnef tried: tnef
Jul 17 18:15:33 zoo amavis[25866]: Internal decoder for .tnef
Jul 17 18:15:33 zoo amavis[25866]: No decoder for .exe tried: rar, unrar; lha; arj, unarj
Jul 17 18:15:33 zoo amavis[25866]: Using internal av scanner code for (primary) ClamAV-clamd
Jul 17 18:15:33 zoo amavis[25866]: Creating db in /opt/zimbra/amavisd/db/; BerkeleyDB 0.31, libdb 4.2
Jul 17 18:15:34 zoo amavis[25866]: SpamControl: initializing Mail::SpamAssassin
Jul 17 18:15:37 zoo amavis[25866]: SpamControl: init_pre_fork done
Jul 17 18:16:01 zoo CRON[26047]: (pam_unix) session opened for user zimbra by (uid=0)
Jul 17 18:16:09 zoo zmtomcatmgr[26137]: status requested
Jul 17 18:16:09 zoo zmtomcatmgr[26137]: status OK
Jul 17 18:16:10 zoo zimbramon[26048]: 26048:info: 2007-07-17 18:16:02, STATUS: zoo.zcsdomain.com: antispam: Running
Jul 17 18:16:10 zoo zimbramon[26048]: 26048:info: 2007-07-17 18:16:02, STATUS: zoo.zcsdomain.com: antivirus: Stopped
Jul 17 18:16:10 zoo zimbramon[26048]: 26048:info: 2007-07-17 18:16:02, STATUS: zoo.zcsdomain.com: ldap: Running
Jul 17 18:16:10 zoo zimbramon[26048]: 26048:info: 2007-07-17 18:16:02, STATUS: zoo.zcsdomain.com: logger: Running
Jul 17 18:16:10 zoo zimbramon[26048]: 26048:info: 2007-07-17 18:16:02, STATUS: zoo.zcsdomain.com: mailbox: Running
Jul 17 18:16:10 zoo zimbramon[26048]: 26048:info: 2007-07-17 18:16:02, STATUS: zoo.zcsdomain.com: mta: Running
Jul 17 18:16:10 zoo zimbramon[26048]: 26048:info: 2007-07-17 18:16:02, STATUS: zoo.zcsdomain.com: snmp: Running
Jul 17 18:16:10 zoo zimbramon[26048]: 26048:info: 2007-07-17 18:16:02, STATUS: zoo.zcsdomain.com: spell: Running
Jul 17 18:16:10 zoo CRON[26047]: (pam_unix) session closed for user zimbra
Jul 17 18:17:24 zoo clamd[25769]: Loaded 139821 signatures.
Jul 17 18:17:24 zoo clamd[25769]: Bound to tcp port 3310
Jul 17 18:17:24 zoo clamd[25769]: Setting connection queue length to 15
Jul 17 18:17:24 zoo clamd[25769]: Archive: Archived file size limit set to 104857600 bytes.
Jul 17 18:17:24 zoo clamd[25769]: Archive: Recursion level limit set to 8.
Jul 17 18:17:24 zoo clamd[25769]: Archive: Files limit set to 1000.
Jul 17 18:17:24 zoo clamd[25769]: Archive: Compression ratio limit set to 250.
Jul 17 18:17:24 zoo clamd[25769]: Archive support enabled.
Jul 17 18:17:24 zoo clamd[25769]: Archive: Blocking encrypted archives.
Jul 17 18:17:24 zoo clamd[25769]: Algorithmic detection enabled.
Jul 17 18:17:24 zoo clamd[25769]: Portable Executable support enabled.
Jul 17 18:17:24 zoo clamd[25769]: ELF support enabled.
Jul 17 18:17:24 zoo clamd[25769]: Mail files support enabled.
Jul 17 18:17:24 zoo clamd[25769]: Mail: Recursion level limit set to 64.
Jul 17 18:17:24 zoo clamd[25769]: OLE2 support enabled.
Jul 17 18:17:24 zoo clamd[25769]: PDF support disabled.
Jul 17 18:17:24 zoo clamd[25769]: HTML support enabled.
Jul 17 18:17:24 zoo clamd[25769]: Self checking every 1800 seconds.
Jul 17 18:18:01 zoo CRON[26214]: (pam_unix) session opened for user zimbra by (uid=0)
Jul 17 18:18:04 zoo zmtomcatmgr[26303]: status requested
Jul 17 18:18:04 zoo zmtomcatmgr[26303]: status OK
Last edited by emx; 07-17-2007 at 02:32 PM..
| 
07-17-2007, 12:57 PM
| | Former Zimbran | |
Posts: 5,606
| | Is that the ip of the server? Can you telnet to port 10024 on your server? Does it work? | 
07-17-2007, 02:57 PM
| | Intermediate Member | |
Posts: 19
| | 'Bad file descriptor' problem solved I have shutdown Zimbra, restarted the server, ran fsck (which reported no error).
The IP 88.88.88.198 is the IP of the Zimbra server.
Let's check the ports 10024 and 10025.
First, telnet to those ports. The port 10024 shows amavisd running: Code: root@zoo /opt/zimbra/log> nc 88.88.88.198 10024
220 [88.88.88.198] ESMTP amavisd-new service ready
root@zoo /opt/zimbra/log> The port 10025 however shows no response and disconnects after a couple of seconds. Code: root@zoo /opt/zimbra/log> nc 88.88.88.198 10025
root@zoo /opt/zimbra/log> Now let's check the open files using those ports.
Port 10025: Code: root@zoo /opt/zimbra/log> lsof|grep 10025
master 3215 root 101u IPv4 7908 TCP zoo.zcsdomain.com:10025 (LISTEN) Port 10024: Code: root@zoo /opt/zimbra/log> lsof|grep 10024
amavisd 3172 zimbra 5u IPv4 7676 TCP zoo.zcsdomain.com:10024 (LISTEN)
amavisd 3183 zimbra 5u IPv4 7676 TCP zoo.zcsdomain.com:10024 (LISTEN)
amavisd 3184 zimbra 5u IPv4 7676 TCP zoo.zcsdomain.com:10024 (LISTEN)
amavisd 3185 zimbra 5u IPv4 7676 TCP zoo.zcsdomain.com:10024 (LISTEN)
amavisd 3186 zimbra 5u IPv4 7676 TCP zoo.zcsdomain.com:10024 (LISTEN)
amavisd 3187 zimbra 5u IPv4 7676 TCP zoo.zcsdomain.com:10024 (LISTEN)
amavisd 3188 zimbra 5u IPv4 7676 TCP zoo.zcsdomain.com:10024 (LISTEN)
amavisd 3189 zimbra 5u IPv4 7676 TCP zoo.zcsdomain.com:10024 (LISTEN)
amavisd 3190 zimbra 5u IPv4 7676 TCP zoo.zcsdomain.com:10024 (LISTEN)
amavisd 3191 zimbra 5u IPv4 7676 TCP zoo.zcsdomain.com:10024 (LISTEN)
amavisd 3192 zimbra 5u IPv4 7676 TCP zoo.zcsdomain.com:10024 (LISTEN) Also the netstat output for 10024: Code: root@zoo /opt/zimbra/log> netstat -an|grep 10024
tcp 0 0 88.88.88.198:10024 0.0.0.0:* LISTEN And 10025: Code: root@zoo /opt/zimbra/log> netstat -an|grep 10025
tcp 0 0 88.88.88.198:10025 0.0.0.0:* LISTEN
Here is the logs output when I try to send a mail from a Zimbra user to an external email address. Gathered with tail -f /opt/zimbra/log/*.log /var/log/zimbra.log Code: ==> audit.log <==
2007-07-17 20:28:30,253 INFO [http-443-Processor99] [ip=213.79.39.134;ua=ZimbraWebClient - FF2.0 (Win)/undefined;] security - cmd=Auth; account=emx@zcsdomain.com; protocol=soap;
==> myslow.log <==
# Time: 070717 20:28:30
# User@Host: zimbra[zimbra] @ zoo.zcsdomain.com [88.88.88.198]
# Query_time: 0 Lock_time: 0 Rows_sent: 2 Rows_examined: 2
SELECT * FROM volume;
# User@Host: zimbra[zimbra] @ zoo.zcsdomain.com [88.88.88.198]
# Query_time: 0 Lock_time: 0 Rows_sent: 1 Rows_examined: 1
SELECT message_volume_id, secondary_message_volume_id, index_volume_id FROM current_volumes;
==> /var/log/zimbra.log <==
Jul 17 20:28:30 zoo slapd[2726]: is_entry_objectclass("", "2.5.6.1") no objectClass attribute
==> mailbox.log <==
2007-07-17 20:28:30,662 INFO [http-443-Processor99] [ip=213.79.39.134;ua=ZimbraWebClient - FF2.0 (Win)/undefined;] cache - Initializing folder and tag caches for mailbox 5
2007-07-17 20:28:30,784 INFO [IncomingDirectorySweeper] [] FileBlobStore - IncomingDirectorySweeper thread starting
2007-07-17 20:28:37,253 WARN [http-443-Processor99] [name=emx@zcsdomain.com;mid=5;ip=213.79.39.134;ua=ZimbraWebClient - FF2.0 (Win)/4.5.6_GA_1044.DEBIAN3.1;] op - PRIORITY 0 ==> 1000
2007-07-17 20:28:37,253 WARN [http-443-Processor99] [name=emx@zcsdomain.com;mid=5;ip=213.79.39.134;ua=ZimbraWebClient - FF2.0 (Win)/4.5.6_GA_1044.DEBIAN3.1;] op - PRIORITY 1 ==> 1000
2007-07-17 20:28:37,254 WARN [http-443-Processor99] [name=emx@zcsdomain.com;mid=5;ip=213.79.39.134;ua=ZimbraWebClient - FF2.0 (Win)/4.5.6_GA_1044.DEBIAN3.1;] op - PRIORITY 2 ==> 1000
2007-07-17 20:28:37,254 WARN [http-443-Processor99] [name=emx@zcsdomain.com;mid=5;ip=213.79.39.134;ua=ZimbraWebClient - FF2.0 (Win)/4.5.6_GA_1044.DEBIAN3.1;] op - PRIORITY 3 ==> 1000
2007-07-17 20:28:37,254 WARN [http-443-Processor99] [name=emx@zcsdomain.com;mid=5;ip=213.79.39.134;ua=ZimbraWebClient - FF2.0 (Win)/4.5.6_GA_1044.DEBIAN3.1;] op - PRIORITY 4 ==> 1000
==> /var/log/zimbra.log <==
Jul 17 20:28:30 zoo last message repeated 2 times
Jul 17 20:28:38 zoo slapd[2726]: <= bdb_equality_candidates: (zimbraCalResType) index_param failed (18)
Jul 17 20:28:38 zoo slapd[2726]: <= bdb_equality_candidates: (zimbraAccountStatus) index_param failed (18)
Jul 17 20:28:38 zoo slapd[2726]: <= bdb_equality_candidates: (zimbraAccountStatus) index_param failed (18)
Jul 17 20:28:38 zoo slapd[2726]: <= bdb_equality_candidates: (zimbraCalResType) index_param failed (18)
Jul 17 20:28:38 zoo slapd[2726]: <= bdb_equality_candidates: (zimbraAccountStatus) index_param failed (18)
==> mailbox.log <==
2007-07-17 20:28:41,116 INFO [http-443-Processor99] [name=emx@zcsdomain.com;mid=5;ip=213.79.39.134;ua=ZimbraWebClient - FF2.0 (Win)/4.5.6_GA_1044.DEBIAN3.1;] cache - Loading flagset cache
2007-07-17 20:28:41,122 INFO [http-443-Processor99] [name=emx@zcsdomain.com;mid=5;ip=213.79.39.134;ua=ZimbraWebClient - FF2.0 (Win)/4.5.6_GA_1044.DEBIAN3.1;] cache - Loading tagset cache
2007-07-17 20:29:07,869 INFO [http-443-Processor100] [name=emx@zcsdomain.com;mid=5;ip=213.79.39.134;ua=ZimbraWebClient - FF2.0 (Win)/4.5.6_GA_1044.DEBIAN3.1;] SendMsg - LC(mbox=7a5a5ca3-855c-49ca-987a-5738d4859d9f, sessions=[1])
2007-07-17 20:29:07,943 INFO [http-443-Processor100] [name=emx@zcsdomain.com;mid=5;ip=213.79.39.134;ua=ZimbraWebClient - FF2.0 (Win)/4.5.6_GA_1044.DEBIAN3.1;] JMSession - SMTP Server: zoo.zcsdomain.com
2007-07-17 20:29:08,200 INFO [http-443-Processor100] [name=emx@zcsdomain.com;mid=5;ip=213.79.39.134;ua=ZimbraWebClient - FF2.0 (Win)/4.5.6_GA_1044.DEBIAN3.1;] zimlet - Loaded class com.zimbra.cs.zimlet.handler.NANPHandler
2007-07-17 20:29:08,204 INFO [http-443-Processor100] [name=emx@zcsdomain.com;mid=5;ip=213.79.39.134;ua=ZimbraWebClient - FF2.0 (Win)/4.5.6_GA_1044.DEBIAN3.1;] zimlet - Loaded class com.zimbra.cs.zimlet.handler.RegexHandler
2007-07-17 20:29:08,583 INFO [http-443-Processor100] [name=emx@zcsdomain.com;mid=5;ip=213.79.39.134;ua=ZimbraWebClient - FF2.0 (Win)/4.5.6_GA_1044.DEBIAN3.1;] mailbox - Added message id=260 digest=Em2Fjj7US4na3Bkn8frpSLRhoz0= mailbox=5 rcpt=:API:
==> /var/log/zimbra.log <==
Jul 17 20:28:38 zoo slapd[2726]: <= bdb_equality_candidates: (zimbraAccountStatus) index_param failed (18)
Jul 17 20:29:08 zoo slapd[2726]: is_entry_objectclass("", "2.5.6.1") no objectClass attribute
Jul 17 20:29:08 zoo postfix/smtpd[5085]: connect from zoo.zcsdomain.com[88.88.88.198]
Jul 17 20:29:08 zoo slapd[2726]: <= bdb_equality_candidates: (zimbraDomainType) index_param failed (18)
Jul 17 20:29:08 zoo slapd[2726]: <= bdb_equality_candidates: (zimbraMailStatus) index_param failed (18)
Jul 17 20:29:08 zoo slapd[2726]: <= bdb_equality_candidates: (zimbraDomainType) index_param failed (18)
Jul 17 20:29:08 zoo slapd[2726]: <= bdb_equality_candidates: (zimbraMailStatus) index_param failed (18)
Jul 17 20:29:08 zoo postfix/smtpd[5085]: C95B354828B: client=zoo.zcsdomain.com[88.88.88.198]
Jul 17 20:29:08 zoo postfix/cleanup[5088]: C95B354828B: message-id=<19426064.01184704148055.JavaMail.root@zoo.zcsdomain.com>
Jul 17 20:29:08 zoo postfix/smtpd[5085]: disconnect from zoo.zcsdomain.com[88.88.88.198]
Jul 17 20:29:08 zoo postfix/qmgr[3223]: C95B354828B: from=, size=546, nrcpt=1 (queue active)
Jul 17 20:29:08 zoo last message repeated 3 times
Jul 17 20:29:08 zoo slapd[2726]: is_entry_objectclass("", "2.5.6.1") no objectClass attribute
Jul 17 20:29:08 zoo amavis[3192]: (03192-03) ESMTP::10024 /opt/zimbra/amavisd/tmp/amavis-20070717T202908-03192: -> SIZE=546 Received: from zoo.zcsdomain.com ([88.88.88.198]) by localhost (zoo.zcsdomain.com [88.88.88.198]) (amavisd-new, port 10024) with ESMTP for ; Tue, 17 Jul 2007 20:29:08 +0000 (UTC)
Jul 17 20:29:08 zoo amavis[3192]: (03192-03) Checking: eLACCsShQJmR [88.88.88.198] ->
Jul 17 20:29:12 zoo slapd[2726]: is_entry_objectclass("", "2.5.6.1") no objectClass attribute
Jul 17 20:29:12 zoo postfix/smtpd[5092]: connect from zoo.zcsdomain.com[88.88.88.198]
Jul 17 20:29:12 zoo postfix/smtpd[5092]: fatal: non-null host address bits in "88.88.88.198/27", perhaps you should use "88.88.88.192/27" instead
Jul 17 20:29:13 zoo amavis[3192]: (03192-03) (!)FWD via SMTP: -> , 450 4.4.1 Can't connect to 88.88.88.198 port 10025, (Bad file descriptor) at (eval 51) line 145, line 41., MTA([88.88.88.198]:10025), id=03192-03
Jul 17 20:29:13 zoo amavis[3192]: (03192-03) Blocked TEMPFAIL, [88.88.88.198] [88.88.88.198] -> , Message-ID: <19426064.01184704148055.JavaMail.root@zoo.zcsdomain.com>, mail_id: eLACCsShQJmR, Hits: -2.292, 4920 ms
Jul 17 20:29:13 zoo postfix/master[3215]: warning: process /opt/zimbra/postfix-2.2.9/libexec/smtpd pid 5092 exit status 1
Jul 17 20:29:13 zoo postfix/master[3215]: warning: /opt/zimbra/postfix-2.2.9/libexec/smtpd: bad command startup -- throttling
Jul 17 20:29:13 zoo postfix/smtp[5089]: C95B354828B: to=, relay=88.88.88.198[88.88.88.198], delay=5, status=deferred (host 88.88.88.198[88.88.88.198] said: 450 4.4.1 Can't connect to 88.88.88.198 port 10025, (Bad file descriptor) at (eval 51) line 145,
==> mailbox.log <==
2007-07-17 20:29:29,385 INFO [IndexWritersSweeperThread] [] MailboxIndex - open index writers sweep: before=1, closed=0, after=1 (0ms) Looking closely at the log I notice the following entry: Code: Jul 17 20:29:12 zoo postfix/smtpd[5092]: fatal: non-null host address bits in "88.88.88.198/27", perhaps you should use "88.88.88.192/27" instead Now it becomes clear that I should not have put the netmask /27 in the postfix config file master.cf, as shown below: Code: -o mynetworks=127.0.0.0/8,88.88.88.198/27 I remove the offending entry and now the master.cf config files shows the correct line: Code: -o mynetworks=127.0.0.0/8,88.88.88.198 After this I restart Zimbra with zmcontrol. The 'Bad file descriptor' problem is gone
Problem solved. | | Thread Tools | Search this Thread | | | | | Display Modes | Linear Mode | | Why Join? Registering let's you ask questions, makes it easier to search, displays any files attached to posts, and notifies you about replies.  |