IM port 5222 mysteriously stopped working. 5223 works?

[k1e0x]

Sometime during the day port 5222 on our server turned itself off.. This is kind of odd.

The day before it broke, we had installed commercial certs into the system, however it was running after we installed the certs and restarted a few times.

One of the things I was working on the day I noticed it break was setting Zimbra SMTP to operate on a port other than 25. So I had done the following as a test.

run
zmprov ms zimbra. zimbraSmtpPort 2525
zmprov mcf zimbraSmtpPort 2525

modified /opt/zimbra/postfix/conf/master.cf
#smtp inet n - n - - smtpd
2525 inet n - n - - smtpd

I later backed out these changes and opted to use another method to accomplish the same thing.

Around this time I noticed the messenger was not working.. the port was closed took me a while to figure out that 5222 was closed and 5223 was open.

Pidgin now requires the force old SSL option checked and port 5223 to work.

Anyone have any idea why?

[uxbod]

netstat -an | grep 52

anything in your logfiles ?

[k1e0x]

Try this..

nmap -p5222-5223 localhost

Starting Nmap 4.11 ( Nmap - Free Security Scanner For Network Exploration & Security Audits. ) at 2009-01-14 11:40 PST
Interesting ports on localhost.localdomain (127.0.0.1):
PORT STATE SERVICE
5222/tcp closed unknown
5223/tcp open unknown

netstat -an | grep 52
tcp 0 0 192.168.9.14:49527 192.168.9.14:389 ESTABLISHED
tcp 0 0 192.168.9.14:389 192.168.9.14:49527 ESTABLISHED
tcp 0 0 :::5223 :::* LISTEN
tcp 0 0 :::5269 :::* LISTEN
tcp 24 0 ::ffff:127.0.0.1:52112 ::ffff:127.0.0.1:7071 CLOSE_WAIT
tcp 0 0 ::ffff:192.168.9.14:5223 ::ffff:192.168.9.106:52523 ESTABLISHED


What log should I be looking in?

[uxbod]

/var/log/zimbra.log

[k1e0x]

[zimbra@zimbra ~]$ zmcontrol start
Host zimbra.domain.com
Starting ldap...Done.
Unable to determine enabled services from ldap.
Enabled services read from cache. Service list may be inaccurate.
Starting logger...Done.
Starting mailbox...Done.
Starting antispam...Done.
Starting antivirus...Done.
Starting archiving...Done.
Starting spell...Done.
Starting mta...Done.
Starting stats...Done.

During this time /var/log/zimbra.log produced..

Jan 14 12:01:07 zimbra zimbramon[25737]: 25737:info: Starting services initiated by zmcontrol 
Jan 14 12:01:08 zimbra slapd[25820]: @(#) $OpenLDAP: slapd 2.3.43 (Aug 20 2008 11:57:48) $ 	build@build10.lab.zimbra.com:/home/build/p4/FRANKLIN/ThirdParty/openldap/openldap-2.3.43.5z/servers/slapd 
Jan 14 12:01:09 zimbra slapd[25821]: slapd starting 
Jan 14 12:01:15 zimbra zimbramon[25737]: 25737:info: Rewriting configs  antispam amavis antivirus amavis archiving amavis   webxml mailbox amavis antispam antivirus mta sasl   
Jan 14 12:01:27 zimbra zimbramon[25737]: 25737:info: Starting logger via zmcontrol 
Jan 14 12:01:27 zimbra zimbramon[25737]: 25737:info: Starting mailbox via zmcontrol 
Jan 14 12:01:39 zimbra zimbramon[26904]: 26904:info: zmmtaconfig: zmmtaconfig started on zimbra.domain.com with loglevel=3 pid=26904 
Jan 14 12:02:03 zimbra zmmailboxdmgr[28240]: status requested
Jan 14 12:02:03 zimbra zmmailboxdmgr[28240]: file /opt/zimbra/log/zmmailboxd_manager.pid does not exist
Jan 14 12:02:03 zimbra zmmailboxdmgr[28240]: assuming no other instance is running
Jan 14 12:02:03 zimbra zmmailboxdmgr[28240]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Jan 14 12:02:03 zimbra zmmailboxdmgr[28240]: assuming no other instance is running
Jan 14 12:02:03 zimbra zmmailboxdmgr[28240]: no manager process is running
Jan 14 12:02:05 zimbra zimbramon[27892]: 27892:info: 2009-01-14 12:02:01, STATUS: zimbra.domain.com: antispam: Stopped 
Jan 14 12:02:05 zimbra zimbramon[27892]: 27892:info: 2009-01-14 12:02:01, STATUS: zimbra.domain.com: antivirus: Stopped 
Jan 14 12:02:05 zimbra zimbramon[27892]: 27892:info: 2009-01-14 12:02:01, STATUS: zimbra.domain.com: archiving: Stopped 
Jan 14 12:02:05 zimbra zimbramon[27892]: 27892:info: 2009-01-14 12:02:01, STATUS: zimbra.domain.com: zmmtaconfig: is running. 
Jan 14 12:02:05 zimbra zimbramon[27892]: 27892:info: 2009-01-14 12:02:01, STATUS: zimbra.domain.com: ldap: Running 
Jan 14 12:02:05 zimbra zimbramon[27892]: 27892:info: 2009-01-14 12:02:01, STATUS: zimbra.domain.com: logger: Running 
Jan 14 12:02:05 zimbra zimbramon[27892]: 27892:info: 2009-01-14 12:02:01, STATUS: zimbra.domain.com: mailbox: Stopped 
Jan 14 12:02:05 zimbra zimbramon[27892]: 27892:info: 2009-01-14 12:02:01, STATUS: zimbra.domain.com: zmmtaconfig: is running. 
Jan 14 12:02:05 zimbra zimbramon[27892]: 27892:info: 2009-01-14 12:02:01, STATUS: zimbra.domain.com: mta: Stopped 
Jan 14 12:02:05 zimbra zimbramon[27892]: 27892:info: 2009-01-14 12:02:01, STATUS: zimbra.domain.com: spell: Stopped 
Jan 14 12:02:05 zimbra zimbramon[27892]: 27892:info: 2009-01-14 12:02:01, STATUS: zimbra.domain.com: stats: Stopped 
Jan 14 12:02:08 zimbra zmmailboxdmgr[28418]: status requested
Jan 14 12:02:08 zimbra zmmailboxdmgr[28418]: file /opt/zimbra/log/zmmailboxd_manager.pid does not exist
Jan 14 12:02:08 zimbra zmmailboxdmgr[28418]: assuming no other instance is running
Jan 14 12:02:08 zimbra zmmailboxdmgr[28418]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Jan 14 12:02:08 zimbra zmmailboxdmgr[28418]: assuming no other instance is running
Jan 14 12:02:08 zimbra zmmailboxdmgr[28418]: no manager process is running
Jan 14 12:02:08 zimbra zmmailboxdmgr[28425]: start requested
Jan 14 12:02:08 zimbra zmmailboxdmgr[28425]: checking if another instance of manager is already running
Jan 14 12:02:08 zimbra zmmailboxdmgr[28425]: file /opt/zimbra/log/zmmailboxd_manager.pid does not exist
Jan 14 12:02:08 zimbra zmmailboxdmgr[28425]: assuming no other instance is running
Jan 14 12:02:08 zimbra zmmailboxdmgr[28425]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Jan 14 12:02:08 zimbra zmmailboxdmgr[28425]: assuming no other instance is running
Jan 14 12:02:08 zimbra zmmailboxdmgr[28426]: wrote manager pid 28426 to /opt/zimbra/log/zmmailboxd_manager.pid
Jan 14 12:02:08 zimbra zmmailboxdmgr[28427]: wrote java pid 28427 to /opt/zimbra/log/zmmailboxd_java.pid
Jan 14 12:02:08 zimbra zmmailboxdmgr[28426]: manager started mailboxd/JVM with pid 28427
Jan 14 12:02:08 zimbra zimbramon[25737]: 25737:info: Starting antispam via zmcontrol 
Jan 14 12:02:09 zimbra amavis[28480]: starting.  /opt/zimbra/amavisd/sbin/amavisd at zimbra.domain.com amavisd-new-2.5.4 (20080312), Unicode aware, LANG="en_US.UTF-8"
Jan 14 12:02:09 zimbra amavis[28480]: user=500, EUID: 500 (500);  group=, EGID: 500 501 500 5 4 (500 501 500 5 4)
Jan 14 12:02:09 zimbra amavis[28480]: Perl version               5.008008
Jan 14 12:02:09 zimbra amavis[28480]: SpamControl: init_pre_chroot done
Jan 14 12:02:09 zimbra amavis[28483]: Net::Server: Process Backgrounded
Jan 14 12:02:09 zimbra amavis[28483]: Net::Server: 2009/01/14-12:02:09 Amavis (type Net::Server::PreForkSimple) starting! pid(28483)
Jan 14 12:02:09 zimbra amavis[28483]: Net::Server: Binding to UNIX socket file /opt/zimbra/data/amavisd/amavisd.sock using SOCK_STREAM
Jan 14 12:02:09 zimbra amavis[28483]: Net::Server: Binding to TCP port 10024 on host 127.0.0.1
Jan 14 12:02:09 zimbra amavis[28483]: Net::Server: Group Not Defined.  Defaulting to EGID '500 501 500 5 4'
Jan 14 12:02:09 zimbra amavis[28483]: Net::Server: User Not Defined.  Defaulting to EUID '500'
Jan 14 12:02:09 zimbra amavis[28483]: Module Amavis::Conf        2.094
Jan 14 12:02:09 zimbra amavis[28483]: Module Archive::Zip        1.23
Jan 14 12:02:09 zimbra amavis[28483]: Module Compress::Zlib      1.42
Jan 14 12:02:09 zimbra amavis[28483]: Module Convert::TNEF       0.17
Jan 14 12:02:09 zimbra amavis[28483]: Module Convert::UUlib      1.11
Jan 14 12:02:09 zimbra amavis[28483]: Module DBD::mysql          4.007
Jan 14 12:02:09 zimbra amavis[28483]: Module DBI                 1.605
Jan 14 12:02:09 zimbra amavis[28483]: Module DB_File             1.817
Jan 14 12:02:09 zimbra amavis[28483]: Module Digest::MD5         2.36
Jan 14 12:02:09 zimbra amavis[28483]: Module Digest::SHA1        2.11
Jan 14 12:02:09 zimbra amavis[28483]: Module IO::Socket::INET6   2.51
Jan 14 12:02:09 zimbra amavis[28483]: Module MIME::Entity        5.426
Jan 14 12:02:09 zimbra amavis[28483]: Module MIME::Parser        5.426
Jan 14 12:02:09 zimbra amavis[28483]: Module MIME::Tools         5.426
Jan 14 12:02:09 zimbra amavis[28483]: Module Mail::Header        2.03
Jan 14 12:02:09 zimbra amavis[28483]: Module Mail::Internet      2.03
Jan 14 12:02:09 zimbra amavis[28483]: Module Mail::SpamAssassin  3.002005
Jan 14 12:02:09 zimbra amavis[28483]: Module Net::DNS            0.63
Jan 14 12:02:09 zimbra amavis[28483]: Module Net::LDAP           0.36
Jan 14 12:02:09 zimbra amavis[28483]: Module Net::Server         0.97
Jan 14 12:02:09 zimbra amavis[28483]: Module Time::HiRes         1.9715
Jan 14 12:02:09 zimbra amavis[28483]: Module URI                 1.37
Jan 14 12:02:09 zimbra amavis[28483]: Module Unix::Syslog        1.1
Jan 14 12:02:09 zimbra amavis[28483]: Amavis::DB code      NOT loaded
Jan 14 12:02:09 zimbra amavis[28483]: Amavis::Cache code   NOT loaded
Jan 14 12:02:09 zimbra amavis[28483]: SQL base code        NOT loaded
Jan 14 12:02:09 zimbra amavis[28483]: SQL::Log code        NOT loaded
Jan 14 12:02:09 zimbra amavis[28483]: SQL::Quarantine      NOT loaded
Jan 14 12:02:09 zimbra amavis[28483]: Lookup::SQL code     NOT loaded
Jan 14 12:02:09 zimbra amavis[28483]: Lookup::LDAP code    loaded
Jan 14 12:02:09 zimbra amavis[28483]: AM.PDP-in proto code loaded
Jan 14 12:02:09 zimbra amavis[28483]: SMTP-in proto code   loaded
Jan 14 12:02:09 zimbra amavis[28483]: Courier proto code   NOT loaded
Jan 14 12:02:09 zimbra amavis[28483]: SMTP-out proto code  loaded
Jan 14 12:02:09 zimbra amavis[28483]: Pipe-out proto code  NOT loaded
Jan 14 12:02:09 zimbra amavis[28483]: BSMTP-out proto code NOT loaded
Jan 14 12:02:09 zimbra amavis[28483]: Local-out proto code loaded
Jan 14 12:02:09 zimbra amavis[28483]: OS_Fingerprint code  NOT loaded
Jan 14 12:02:09 zimbra amavis[28483]: ANTI-VIRUS code      loaded
Jan 14 12:02:09 zimbra amavis[28483]: ANTI-SPAM code       loaded
Jan 14 12:02:09 zimbra amavis[28483]: ANTI-SPAM-SA code    loaded
Jan 14 12:02:09 zimbra amavis[28483]: Unpackers code       loaded
Jan 14 12:02:09 zimbra amavis[28483]: Found $file            at /usr/bin/file
Jan 14 12:02:09 zimbra amavis[28483]: No $dspam,             not using it
Jan 14 12:02:09 zimbra amavis[28483]: No $altermime,         not using it
Jan 14 12:02:09 zimbra amavis[28483]: Internal decoder for .mail
Jan 14 12:02:09 zimbra amavis[28483]: Internal decoder for .asc 
Jan 14 12:02:09 zimbra amavis[28483]: Internal decoder for .uue 
Jan 14 12:02:09 zimbra amavis[28483]: Internal decoder for .hqx 
Jan 14 12:02:09 zimbra amavis[28483]: Internal decoder for .ync 
Jan 14 12:02:09 zimbra amavis[28483]: No decoder for       .F    tried: unfreeze, freeze -d, melt, fcat
Jan 14 12:02:09 zimbra amavis[28483]: Found decoder for    .Z    at /usr/bin/gzip -d
Jan 14 12:02:09 zimbra amavis[28483]: Found decoder for    .gz   at /usr/bin/gzip -d
Jan 14 12:02:09 zimbra amavis[28483]: Found decoder for    .bz2  at /usr/bin/bzip2 -d
Jan 14 12:02:09 zimbra amavis[28483]: No decoder for       .lzo  tried: lzop -d
Jan 14 12:02:09 zimbra amavis[28483]: Found decoder for    .rpm  at /usr/bin/rpm2cpio
Jan 14 12:02:09 zimbra amavis[28483]: Found decoder for    .cpio at /usr/bin/pax
Jan 14 12:02:09 zimbra amavis[28483]: Found decoder for    .tar  at /usr/bin/pax
Jan 14 12:02:09 zimbra amavis[28483]: Found decoder for    .deb  at /usr/bin/ar
Jan 14 12:02:09 zimbra amavis[28483]: Internal decoder for .zip 
Jan 14 12:02:09 zimbra amavis[28483]: No decoder for       .7z   tried: 7zr, 7za, 7z
Jan 14 12:02:09 zimbra amavis[28483]: No decoder for       .rar  tried: rar, unrar
Jan 14 12:02:09 zimbra amavis[28483]: No decoder for       .arj  tried: arj, unarj
Jan 14 12:02:09 zimbra amavis[28483]: No decoder for       .arc  tried: nomarch, arc
Jan 14 12:02:09 zimbra amavis[28483]: No decoder for       .zoo  tried: zoo, unzoo
Jan 14 12:02:09 zimbra amavis[28483]: No decoder for       .lha  tried: lha
Jan 14 12:02:09 zimbra amavis[28483]: No decoder for       .cab  tried: cabextract
Jan 14 12:02:09 zimbra amavis[28483]: No decoder for       .tnef tried: tnef
Jan 14 12:02:09 zimbra amavis[28483]: Internal decoder for .tnef
Jan 14 12:02:09 zimbra amavis[28483]: No decoder for       .exe  tried: rar, unrar; lha; arj, unarj
Jan 14 12:02:09 zimbra amavis[28483]: Using primary internal av scanner code for ClamAV-clamd
Jan 14 12:02:09 zimbra amavis[28483]: SpamControl: initializing Mail::SpamAssassin
Jan 14 12:02:10 zimbra zimbramon[25737]: 25737:info: Starting antivirus via zmcontrol 
Jan 14 12:02:10 zimbra amavis[28483]: SpamControl: init_pre_fork done
Jan 14 12:02:10 zimbra clamd[28572]: clamd daemon 0.93.3 (OS: linux-gnu, ARCH: i386, CPU: i686) 
Jan 14 12:02:10 zimbra clamd[28572]: Log file size limited to 20971520 bytes. 
Jan 14 12:02:10 zimbra clamd[28572]: Reading databases from /opt/zimbra/data/clamav/db 
Jan 14 12:02:10 zimbra clamd[28572]: Not loading PUA signatures. 
Jan 14 12:02:13 zimbra clamd[28572]: Loaded 487171 signatures. 
Jan 14 12:02:13 zimbra clamd[28572]: TCP: Bound to port 3310 
Jan 14 12:02:13 zimbra clamd[28572]: TCP: Setting connection queue length to 15 
Jan 14 12:02:13 zimbra clamd[28584]: Limits: Global size limit set to 10240000 bytes. 
Jan 14 12:02:13 zimbra clamd[28584]: Limits: File size limit set to 10240000 bytes. 
Jan 14 12:02:13 zimbra clamd[28584]: Limits: Recursion level limit set to 16. 
Jan 14 12:02:13 zimbra clamd[28584]: Limits: Files limit set to 10000. 
Jan 14 12:02:13 zimbra clamd[28584]: Archive support enabled. 
Jan 14 12:02:13 zimbra clamd[28584]: Algorithmic detection enabled. 
Jan 14 12:02:13 zimbra clamd[28584]: Portable Executable support enabled. 
Jan 14 12:02:13 zimbra clamd[28584]: ELF support enabled. 
Jan 14 12:02:13 zimbra clamd[28584]: Mail files support enabled. 
Jan 14 12:02:13 zimbra clamd[28584]: OLE2 support enabled. 
Jan 14 12:02:13 zimbra clamd[28584]: PDF support disabled. 
Jan 14 12:02:13 zimbra clamd[28584]: HTML support enabled. 
Jan 14 12:02:13 zimbra clamd[28584]: Self checking every 1800 seconds. 
Jan 14 12:02:15 zimbra zimbramon[25737]: 25737:info: Starting archiving via zmcontrol 
Jan 14 12:02:15 zimbra zimbramon[25737]: 25737:info: Starting spell via zmcontrol 
Jan 14 12:02:15 zimbra zimbramon[25737]: 25737:info: Starting mta via zmcontrol 
Jan 14 12:02:30 zimbra postfix/postfix-script[29149]: warning: not owned by root: /opt/zimbra/postfix-2.4.7.5z/conf/main.cf
Jan 14 12:02:30 zimbra postfix/postfix-script[29163]: starting the Postfix mail system
Jan 14 12:02:30 zimbra postfix/master[29164]: daemon started -- version 2.4.7, configuration /opt/zimbra/postfix-2.4.7.5z/conf
Jan 14 12:02:30 zimbra saslauthd[29172]: detach_tty      : master pid is: 29172
Jan 14 12:02:30 zimbra saslauthd[29172]: ipc_init        : listening on socket: /opt/zimbra/cyrus-sasl-2.1.22.3z/state/mux
Jan 14 12:02:31 zimbra zimbramon[25737]: 25737:info: Starting stats via zmcontrol

Nothing very interesting.

[uxbod]

Starting ldap...Done.
Unable to determine enabled services from ldap.
Enabled services read from cache. Service list may be inaccurate.

Hmmm ... I think we need to check your DNS setup aswell.

cat /etc/hosts
cat /etc/resolv.conf
dig yourdomain mx
dig yourdomain any
host `hostname` <- note backticks and not single quotes

[k1e0x]

We already did 2 months ago.

Unable to determine enabled services from ldap message.

[k1e0x]

I should note, this is a diffrent system and totally diffrent site than the one in that post.. (this is CentOS5) but I'd still like to know what that error message *actually* means.

Here is the data from this system.

[root@zimbra ~]# cat /etc/hosts
# Do not remove the following line, or various programs
# that require network functionality will fail.
127.0.0.1 localhost.localdomain localhost
::1 localhost6.localdomain6 localhost6
192.168.9.14 zimbra.domain.com zimbra
192.168.9.120 qpsmtp.domain.com qpsmtp
[root@zimbra ~]# cat /etc/resolv.conf
search domain.com
nameserver 192.168.9.10
nameserver 192.168.9.13

# o1
nameserver 72.?.?.?

[root@zimbra ~]# dig domain.com mx

; <<>> DiG 9.3.4-P1 <<>> domain.com mx
;; global options: printcmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 19593
;; flags: qr aa rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 2, ADDITIONAL: 2

;; QUESTION SECTION:
;domain.com. IN MX

;; ANSWER SECTION:
domain.com. 3600 IN MX 10 postfix.domain.com. (<- I know nothing I can do about thisatm, Zibmra is aware of the transport.)

;; AUTHORITY SECTION:
domain.com. 3600 IN NS ns2.domain.net.
domain.com. 3600 IN NS ns1.domain.com.

;; ADDITIONAL SECTION:
postfix.domain.com. 3600 IN A 192.168.9.10
ns2.domain.net. 3600 IN A 76.?.?.?

;; Query time: 0 msec
;; SERVER: 192.168.9.10#53(192.168.9.10)
;; WHEN: Wed Jan 14 12:21:34 2009
;; MSG SIZE rcvd: 130

[root@zimbra ~]# dig domain.com any

; <<>> DiG 9.3.4-P1 <<>> domain.com any
;; global options: printcmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 4187
;; flags: qr aa rd ra; QUERY: 1, ANSWER: 5, AUTHORITY: 0, ADDITIONAL: 2

;; QUESTION SECTION:
;domain.com. IN ANY

;; ANSWER SECTION:
domain.com. 3600 IN MX 10 postfix.domain.com.
domain.com. 3600 IN A 192.168.9.10
domain.com. 3600 IN SOA ns1.domain.com. something.domain.com. 2009011401 3600 900 3600 1800
domain.com. 3600 IN NS ns2.domain.net.
domain.com. 3600 IN NS ns1.domain.com.

;; ADDITIONAL SECTION:
postfix.domain.com. 3600 IN A 192.168.9.10
ns2.domain.net. 3600 IN A 76.??.??.??

;; Query time: 0 msec
;; SERVER: 192.168.9.10#53(192.168.9.10)
;; WHEN: Wed Jan 14 12:23:50 2009
;; MSG SIZE rcvd: 188


[root@zimbra ~]# host `hostname`
zimbra.domain.com has address 192.168.9.14

[k1e0x]

As strange as it stopped working.. I noticed that port is back on now.. No config changes were made. The trivial (?) LDAP error is still occurring.