Zimbra offers Open Source email server software and shared calendar for Linux and the Mac
Go Back   Zimbra :: Forums > Zimbra Collaboration Suite > Installation

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.

Reply
 
LinkBack Thread Tools Search this Thread Display Modes
  #1 (permalink)  
Old 07-16-2007, 02:22 PM
emx emx is offline
Intermediate Member
 
Posts: 19
Default 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...
Reply With Quote
  #2 (permalink)  
Old 07-16-2007, 03:56 PM
Former Zimbran
 
Posts: 5,606
Default

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.
Reply With Quote
  #3 (permalink)  
Old 07-16-2007, 04:20 PM
emx emx is offline
Intermediate Member
 
Posts: 19
Default 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>
Reply With Quote
  #4 (permalink)  
Old 07-16-2007, 04:40 PM
Former Zimbran
 
Posts: 5,606
Default

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.
Reply With Quote
  #5 (permalink)  
Old 07-17-2007, 11:57 AM
emx emx is offline
Intermediate Member
 
Posts: 19
Question 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).
Reply With Quote
  #6 (permalink)  
Old 07-17-2007, 12:02 PM
Former Zimbran
 
Posts: 5,606
Default

Take a look here:
bad file descriptor
Reply With Quote
  #7 (permalink)  
Old 07-17-2007, 12:05 PM
Former Zimbran
 
Posts: 5,606
Default

I'm sorry,
I should have asked for this sooner:

What's in your /var/log/zimbra.log ?
Reply With Quote
  #8 (permalink)  
Old 07-17-2007, 12:41 PM
emx emx is offline
Intermediate Member
 
Posts: 19
Default /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..
Reply With Quote
  #9 (permalink)  
Old 07-17-2007, 12:57 PM
Former Zimbran
 
Posts: 5,606
Default

Is that the ip of the server? Can you telnet to port 10024 on your server? Does it work?
Reply With Quote
  #10 (permalink)  
Old 07-17-2007, 02:57 PM
emx emx is offline
Intermediate Member
 
Posts: 19
Thumbs up '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.
Reply With Quote
Reply


Thread Tools Search this Thread
Search this Thread:

Advanced Search
Display Modes


Similar Threads

Why Join?

Registering let's you ask questions, makes it easier to search, displays any files attached to posts, and notifies you about replies.

blog.zimbra.com




 

SEO by vBSEO ©2011, Crawlability, Inc.