Page 1 of 2 12 LastLast
Results 1 to 10 of 12

Thread: Bad file descriptor?

  1. #1
    Join Date
    Jul 2007
    Location
    Dublin, Ireland
    Posts
    19
    Rep Power
    8

    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...

  2. #2
    Join Date
    Oct 2005
    Location
    Thatcher, AZ
    Posts
    5,606
    Rep Power
    21

    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.

  3. #3
    Join Date
    Jul 2007
    Location
    Dublin, Ireland
    Posts
    19
    Rep Power
    8

    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>

  4. #4
    Join Date
    Oct 2005
    Location
    Thatcher, AZ
    Posts
    5,606
    Rep Power
    21

    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.

  5. #5
    Join Date
    Jul 2007
    Location
    Dublin, Ireland
    Posts
    19
    Rep Power
    8

    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).

  6. #6
    Join Date
    Oct 2005
    Location
    Thatcher, AZ
    Posts
    5,606
    Rep Power
    21

    Default

    Take a look here:
    bad file descriptor

  7. #7
    Join Date
    Oct 2005
    Location
    Thatcher, AZ
    Posts
    5,606
    Rep Power
    21

    Default

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

    What's in your /var/log/zimbra.log ?

  8. #8
    Join Date
    Jul 2007
    Location
    Dublin, Ireland
    Posts
    19
    Rep Power
    8

    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.

  9. #9
    Join Date
    Oct 2005
    Location
    Thatcher, AZ
    Posts
    5,606
    Rep Power
    21

    Default

    Is that the ip of the server? Can you telnet to port 10024 on your server? Does it work?

  10. #10
    Join Date
    Jul 2007
    Location
    Dublin, Ireland
    Posts
    19
    Rep Power
    8

    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.

Similar Threads

  1. centos 5 zimbra 4.5.6 no statistics
    By rutman286 in forum Installation
    Replies: 9
    Last Post: 08-14-2007, 10:30 AM
  2. Opensource backup Question.
    By nfear24 in forum Administrators
    Replies: 3
    Last Post: 04-01-2007, 12:47 AM
  3. Traslation SVN tree status
    By meikka in forum I18N/L10N - Translations
    Replies: 7
    Last Post: 02-13-2007, 11:13 AM
  4. zcs 4.0.3 amavisd gives bad file descriptor
    By Storm16 in forum Developers
    Replies: 0
    Last Post: 11-07-2006, 11:27 AM
  5. M3 problem with shares
    By titangears in forum Users
    Replies: 4
    Last Post: 01-12-2006, 01:01 PM

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •