Bug 889193
| Summary: | Cannot connect to jabber server | ||||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
| Product: | [Community] Spacewalk | Reporter: | William Brown <william> | ||||||||||
| Component: | Server | Assignee: | Milan Zázrivec <mzazrivec> | ||||||||||
| Status: | CLOSED NOTABUG | QA Contact: | Red Hat Satellite QA List <satqe-list> | ||||||||||
| Severity: | unspecified | Docs Contact: | |||||||||||
| Priority: | unspecified | ||||||||||||
| Version: | 1.8 | ||||||||||||
| Target Milestone: | --- | ||||||||||||
| Target Release: | --- | ||||||||||||
| Hardware: | Unspecified | ||||||||||||
| OS: | Unspecified | ||||||||||||
| Whiteboard: | |||||||||||||
| Fixed In Version: | Doc Type: | Bug Fix | |||||||||||
| Doc Text: | Story Points: | --- | |||||||||||
| Clone Of: | Environment: | ||||||||||||
| Last Closed: | 2013-02-01 09:59:51 UTC | Type: | Bug | ||||||||||
| Regression: | --- | Mount Type: | --- | ||||||||||
| Documentation: | --- | CRM: | |||||||||||
| Verified Versions: | Category: | --- | |||||||||||
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |||||||||||
| Cloudforms Team: | --- | Target Upstream Version: | |||||||||||
| Embargoed: | |||||||||||||
| Bug Depends On: | |||||||||||||
| Bug Blocks: | 1484117 | ||||||||||||
| Attachments: |
|
||||||||||||
I tried Spacewalk 1.8 installation with the following packages installed: jabberd-2.2.14-4.fc17.i686 osa-dispatcher-5.11.14-1.fc17.noarch and jabberd as well as osa-dispatcher start just fine. Things worth investigating: * are jabberd services running (c2s, s2s, sm, router)? * are there any jabberd related errors in /var/log/messages? * is SSL for jabberd configured properly? * are there any SELinux denials? c2s, s2s, sm and router are all running.
Jabber related messages are as follows:
Dec 20 23:10:22 spacewalk jabberd/s2s[561]: attempting connection to router at 127.0.0.1, port=5347
Dec 20 23:10:22 spacewalk jabberd/router[535]: [127.0.0.1, port=60545] connect
Dec 20 23:10:22 spacewalk jabberd/s2s[561]: connection to router established
Dec 20 23:10:22 spacewalk jabberd/router[535]: [127.0.0.1, port=60545] authenticated as jabberd@jabberd-router
Dec 20 23:10:22 spacewalk jabberd/router[535]: [s2s] set as default route
Dec 20 23:10:22 spacewalk jabberd/router[535]: [s2s] online (bound to 127.0.0.1, port 60545)
Dec 20 23:10:22 spacewalk jabberd/s2s[561]: [0.0.0.0, port=5269] listening for connections
Dec 20 23:10:22 spacewalk jabberd/s2s[561]: ready for connections
Dec 20 23:13:16 spacewalk jabberd[500]: Starting router: [ OK ]
Dec 20 23:13:16 spacewalk jabberd/router[543]: starting up
Dec 20 23:13:16 spacewalk jabberd/router[543]: process id is 543, written to /var/lib/jabberd/pid/router.pid
Dec 20 23:13:16 spacewalk jabberd/sm[559]: starting up
Dec 20 23:13:16 spacewalk jabberd/router[543]: loaded user table (1 users)
Dec 20 23:13:16 spacewalk jabberd/router[543]: loaded filters (0 rules)
Dec 20 23:13:16 spacewalk jabberd/router[543]: [0.0.0.0, port=5347] listening for incoming connections
Dec 20 23:13:16 spacewalk jabberd[500]: Starting sm: [ OK ]
Dec 20 23:13:16 spacewalk jabberd/sm[559]: process id is 559, written to /var/lib/jabberd/pid/sm.pid
Dec 20 23:13:16 spacewalk jabberd/sm[559]: loading 'db' storage module
Dec 20 23:13:16 spacewalk jabberd[500]: Starting c2s: [ OK ]
Dec 20 23:13:16 spacewalk jabberd[500]: Starting s2s: [ OK ]
Dec 20 23:13:16 spacewalk jabberd/s2s[616]: starting up (interval=3, queue=60, keepalive=0, idle=86400)
Dec 20 23:13:16 spacewalk jabberd/s2s[616]: process id is 616, written to /var/lib/jabberd/pid/s2s.pid
Dec 20 23:13:16 spacewalk jabberd/s2s[616]: attempting connection to router at 127.0.0.1, port=5347
Dec 20 23:13:16 spacewalk jabberd/router[543]: [127.0.0.1, port=52517] connect
Dec 20 23:13:16 spacewalk jabberd/c2s[608]: starting up
Dec 20 23:13:17 spacewalk jabberd/c2s[608]: process id is 608, written to /var/lib/jabberd/pid/c2s.pid
Dec 20 23:13:17 spacewalk jabberd/c2s[608]: modules search path: /usr/lib64/jabberd
Dec 20 23:13:17 spacewalk jabberd/c2s[608]: loading 'db' authreg module
Dec 20 23:13:17 spacewalk jabberd/router[543]: [127.0.0.1, port=52517] authenticated as jabberd@jabberd-router
Dec 20 23:13:17 spacewalk jabberd/s2s[616]: connection to router established
Dec 20 23:13:17 spacewalk jabberd/router[543]: [s2s] set as default route
Dec 20 23:13:17 spacewalk jabberd/router[543]: [s2s] online (bound to 127.0.0.1, port 52517)
Dec 20 23:13:17 spacewalk jabberd/s2s[616]: [0.0.0.0, port=5269] listening for connections
Dec 20 23:13:17 spacewalk jabberd/s2s[616]: ready for connections
Dec 20 23:13:17 spacewalk osa-dispatcher[592]: RHN 592 2012/12/20 23:13:17 +10:30: ('Traceback (most recent call last):\n File "/usr/share/rhn/osad/jabber_lib.py", line 117, in main\n self.setup_config(config)\n File "/usr/share/rhn/osad/osa_dispatcher.py", line 112, in setup_config\n rhnSQL.initDB()\n File "/usr/lib/python2.7/site-packages/spacewalk/server/rhnSQL/__init__.py", line 124, in initDB\n __init__DB(backend, host, port, username, password, database)\n File "/usr/lib/python2.7/site-packages/spacewalk/server/rhnSQL/__init__.py", line 55, in __init__DB\n __DB.connect()\n File "/usr/lib/python2.7/site-packages/spacewalk/server/rhnSQL/driver_postgresql.py", line 171, in connect\n return self.connect(reconnect=0)\n File "/usr/lib/python2.7/site-packages/spacewalk/server/rhnSQL/driver_postgresql.py", line 163, in connect\n password=self.password, host=self.host, port=self.port)\n File "/usr/lib64/python2.7/site-packages/psycopg2/__init__.py", line 179, in connect\n connection_factory=connection_factory, async=async)\nSQLConnectError: (None, None, \'spaceschema\', \'Attempting Re-Connect to the database failed\')\n',)
There are a great deal of SELinux denials, but these seems to relate to monitoring in spacewalk, not jabber. Running setenforce 0, and checking the osa-dispatcher log shows the same error still occuring.
Finally, I'm not sure how to correctly check the SSL setup for jabber. I have not personally modified or touched the configuration so it should be "as configured" by the initial setup of spacewalk. Any instructions for this would be much appreciated.
That version of osa-dispatcher appears to be from the nightly repo. 5.11.10 is the version in the "stable" repo. I will try the nightly repo in the mean time however. I have tested the same installation process on i386, and cannot reproduce. Additionally, further inspection shows that jabbered is not runnig on 5222 on the x86_64 f17 machine, yet the correct configuration for this exists. Again, more advice would be welcome to help solve this issue. The logs from comment #0 show that at 2012/12/20 23:59:05 there was 'Unable to connect to the host and port specified' error, which would most likely be caused by a jabberd service (i.e. some or all of its daemons) not running; the logs from comment #2 show that at 2012/12/20 23:13:17 there was a SQLConnectError, which could be attributed to postgresql server not running. I don't think these two things are related, and also I don't know what happened between 23:13 and 23:59 on the problematic machine, so for further investigation, I'd like to -- once again -- ask for the following. Run as root: # service osa-dispatcher stop # service jabberd stop Now please attach content of /var/log/messages while doing: # service jabberd start And please attach content of /var/log/rhn/osa-dispatcher.log while doing: # service osa-dispatcher start Also, I'm happy to review jabberd's configuration files if you're willing to share them in this report (/etc/jabberd/{c2s,s2s,router,sm}.xml) Cheers. /var/log/messages
Jan 3 09:13:27 spacewalk jabberd[788]: Initializing jabberd processes ...
Jan 3 09:13:27 spacewalk jabberd[788]: Starting router: [ OK ]
Jan 3 09:13:27 spacewalk jabberd[788]: Starting sm: [ OK ]
Jan 3 09:13:27 spacewalk jabberd[788]: Starting c2s: [ OK ]
Jan 3 09:13:27 spacewalk jabberd[788]: Starting s2s: [ OK ]
Jan 3 09:13:28 spacewalk jabberd/s2s[815]: starting up (interval=3, queue=60, keepalive=0, idle=86400)
Jan 3 09:13:28 spacewalk jabberd/s2s[815]: process id is 815, written to /var/lib/jabberd/pid/s2s.pid
Jan 3 09:13:28 spacewalk jabberd/s2s[815]: attempting connection to router at 127.0.0.1, port=5347
Jan 3 09:13:28 spacewalk jabberd/s2s[815]: [6] [router] write error: Connection refused (111)
Jan 3 09:13:28 spacewalk jabberd/s2s[815]: connection to router closed
Jan 3 09:13:28 spacewalk jabberd/s2s[815]: attempting reconnect (3 left)
Jan 3 09:13:28 spacewalk jabberd/sm[801]: starting up
Jan 3 09:13:28 spacewalk jabberd/sm[801]: process id is 801, written to /var/lib/jabberd/pid/sm.pid
Jan 3 09:13:28 spacewalk jabberd/sm[801]: loading 'db' storage module
Jan 3 09:13:28 spacewalk jabberd/router[794]: starting up
Jan 3 09:13:28 spacewalk jabberd/router[794]: process id is 794, written to /var/lib/jabberd/pid/router.pid
Jan 3 09:13:28 spacewalk jabberd/router[794]: loaded user table (1 users)
Jan 3 09:13:28 spacewalk jabberd/router[794]: loaded filters (0 rules)
Jan 3 09:13:28 spacewalk jabberd/router[794]: [0.0.0.0, port=5347] listening for incoming connections
Jan 3 09:13:28 spacewalk jabberd/c2s[808]: starting up
Jan 3 09:13:28 spacewalk jabberd/c2s[808]: process id is 808, written to /var/lib/jabberd/pid/c2s.pid
Jan 3 09:13:28 spacewalk jabberd/c2s[808]: modules search path: /usr/lib64/jabberd
Jan 3 09:13:28 spacewalk jabberd/c2s[808]: loading 'db' authreg module
Jan 3 09:13:30 spacewalk jabberd/s2s[815]: attempting connection to router at 127.0.0.1, port=5347
Jan 3 09:13:30 spacewalk jabberd/router[794]: [127.0.0.1, port=53381] connect
Jan 3 09:13:30 spacewalk jabberd/s2s[815]: connection to router established
Jan 3 09:13:30 spacewalk jabberd/router[794]: [127.0.0.1, port=53381] authenticated as jabberd@jabberd-router
Jan 3 09:13:30 spacewalk jabberd/router[794]: [s2s] set as default route
Jan 3 09:13:30 spacewalk jabberd/router[794]: [s2s] online (bound to 127.0.0.1, port 53381)
Jan 3 09:13:30 spacewalk jabberd/s2s[815]: [0.0.0.0, port=5269] listening for connections
Jan 3 09:13:30 spacewalk jabberd/s2s[815]: ready for connections
/var/log/rhn/osa-dispatcher.log
2013/01/03 09:14:00 +10:30 831 0.0.0.0: osad/jabber_lib.__init__
2013/01/03 09:14:00 +10:30 831 0.0.0.0: osad/jabber_lib.print_message('socket error',)
2013/01/03 09:14:00 +10:30 831 0.0.0.0: osad/jabber_lib.print_message('Could not connect to jabber server', 'spacewalk.fy.id.au')
2013/01/03 09:14:00 +10:30 831 0.0.0.0: osad/jabber_lib.setup_connection('ERROR', 'Traceback (most recent call last):\n File "/usr/share/rhn/osad/jabber_lib.py", line 252, in setup_connection\n c = self._get_jabber_client(js)\n File "/usr/share/rhn/osad/jabber_lib.py", line 309, in _get_jabber_client\n c.connect()\n File "/usr/share/rhn/osad/jabber_lib.py", line 567, in connect\n jabber.Client.connect(self)\n File "/usr/lib/python2.7/site-packages/jabber/xmlstream.py", line 488, in connect\n raise socket.error("Unable to connect to the host and port specified")\nerror: Unable to connect to the host and port specified\n')
2013/01/03 09:14:00 +10:30 831 0.0.0.0: osad/jabber_lib.setup_connection('Could not connect to any jabber server',)
2013/01/03 09:14:00 +10:30 831 0.0.0.0: osad/jabber_lib.main('Unable to connect to jabber servers, sleeping 10 seconds',)
Created attachment 671731 [details]
c2s.xml from affected server
Created attachment 671732 [details]
router.xml from the affected systems
Created attachment 671733 [details]
s2s.xml from the affected server
Created attachment 671734 [details]
sm.xml from the affected server
OK, what does the following show? # egrep osa\|jabber /etc/rhn/rhn.conf At the point when osa-dispatcher starts, is the c2s process (and in fact all jabberd processes: c2s, s2s, sm, router) running? Is the 5222 port (used by c2s by default) on the spacewalk machine open for connections? [root@spacewalk ~]# egrep osa\|jabber /etc/rhn/rhn.conf server.jabber_server = spacewalk.fy.id.au osa-dispatcher.jabber_server = spacewalk.fy.id.au osa-dispatcher.osa_ssl_cert = /var/www/html/pub/RHN-ORG-TRUSTED-SSL-CERT [root@spacewalk ~]# ps aux | grep -i jabber jabber 699 0.0 0.1 54696 2676 ? S 09:01 0:00 /usr/bin/router -c /etc/jabberd//router.xml jabber 706 0.0 0.1 58840 2344 ? S 09:01 0:00 /usr/bin/sm -c /etc/jabberd//sm.xml jabber 713 0.0 0.1 58776 2244 ? S 09:01 0:00 /usr/bin/c2s -c /etc/jabberd//c2s.xml jabber 720 0.0 0.1 52900 2308 ? S 09:01 0:00 /usr/bin/s2s -c /etc/jabberd//s2s.xml No, port 5222 is not open. (In reply to comment #12) > [root@spacewalk ~]# egrep osa\|jabber /etc/rhn/rhn.conf > server.jabber_server = spacewalk.fy.id.au > osa-dispatcher.jabber_server = spacewalk.fy.id.au > osa-dispatcher.osa_ssl_cert = /var/www/html/pub/RHN-ORG-TRUSTED-SSL-CERT > > > [root@spacewalk ~]# ps aux | grep -i jabber > jabber 699 0.0 0.1 54696 2676 ? S 09:01 0:00 > /usr/bin/router -c /etc/jabberd//router.xml > jabber 706 0.0 0.1 58840 2344 ? S 09:01 0:00 /usr/bin/sm > -c /etc/jabberd//sm.xml > jabber 713 0.0 0.1 58776 2244 ? S 09:01 0:00 > /usr/bin/c2s -c /etc/jabberd//c2s.xml > jabber 720 0.0 0.1 52900 2308 ? S 09:01 0:00 > /usr/bin/s2s -c /etc/jabberd//s2s.xml > > No, port 5222 is not open. OK, the port 5222/TCP (which c2s binds to) needs to be open for connections for both osa-dispatcher (running on the spacewalk machine) and the osad(s) running on client machine(s). Netstat on the server shows no listening port on 5222. Additionally, IPTables has been temporarily disabled. c2s is running as shown previously. That's rather strange then.
According to the c2s.xml attached above, c2s should be listening on
port 5222.
Does the c2s process bind to some other port?
lsof -p `pidof c2s` -Pn|grep TCP
This produces no output. Double checking ps, shows that c2s is running. (In reply to comment #16) > This produces no output. Double checking ps, shows that c2s is running. I'm out of ideas then. Your jabberd configuration seems OK, c2s should be listening on 5222/TCP. SELinux perhaps? Needless to say, my testing installation of latest Spacewalk on Fedora 17 with jabberd-2.2.14-4.fc17.i686 works OK. SELinux has been set to permissive while testing this (But there are no denials anyway) I'm testing on x86_64 not i686. I have a fresh install of F17 i686 with spacewalk that works perfectly. The same steps on x86_64, cause this issue. I tested installation of Spacewalk 1.8 @ Fedora 17 x86_64: # lsof -p `pidof c2s` -Pn|grep TCP c2s 30370 jabber 5u IPv4 112959 0t0 TCP 127.0.0.1:40305->127.0.0.1:5347 (ESTABLISHED) c2s 30370 jabber 6u IPv4 100277 0t0 TCP *:5222 (LISTEN) all with jabberd-2.2.14-4.fc17.x86_64. Still not sure what's going on with the problematic installation. I'd probably suggest to debug the c2s run with: # service osa-dispatcher stop # service jabberd restart # killall c2s # runuser -s /bin/bash jabber -c "/usr/bin/c2s -D -c /etc/jabberd/c2s.xml" The last command should provide all kinds of debug info that could help the issue. [root@spacewalk ~]# runuser -s /bin/bash jabber -c "/usr/bin/c2s -D -c /etc/jabberd/c2s.xml" Tue Jan 8 10:12:34 2013 [notice] starting up Tue Jan 8 10:12:39 2013 [info] process id is 2189, written to /var/lib/jabberd/pid/c2s.pid Tue Jan 8 10:12:39 2013 [notice] modules search path: /usr/lib64/jabberd Tue Jan 8 10:12:39 2013 [info] loading 'db' authreg module Tue Jan 8 10:12:40 2013 authreg.c:73 preloaded module 'db' (not initialized yet) Is all I get, before it "hangs". Under normal circumstances, your output would look like: # runuser -s /bin/bash jabber -c "/usr/bin/c2s -D -c /etc/jabberd/c2s.xml" Tue Jan 8 02:37:14 2013 [notice] starting up Tue Jan 8 02:37:14 2013 [info] process id is 9036, written to /var/lib/jabberd/pid/c2s.pid Tue Jan 8 02:37:14 2013 [notice] modules search path: /usr/lib64/jabberd Tue Jan 8 02:37:14 2013 [info] loading 'db' authreg module Tue Jan 8 02:37:14 2013 authreg.c:73 preloaded module 'db' (not initialized yet) Tue Jan 8 02:37:14 2013 [notice] initialized auth module 'db' Tue Jan 8 02:37:14 2013 ack.c:104 initialising stanza acknowledgements sx plugin sx (env.c:75) plugin initialised (index 0) Tue Jan 8 02:37:14 2013 address.c:43 initialising address sx plugin All the hint I can offer... # rpm -V jabberd # ldd /usr/lib64/jabberd/authreg_db.so # ldd /usr/lib64/jabberd/storage_db.so # rpm -V db4 I'm closing this as notabug, as this seems to be a jabberd problem. This BZ closed some time during 2.5, 2.6 or 2.7. Adding to 2.7 tracking bug. |
Description of problem: I have installed a fresh copy of fedora 17, and created a fresh install of spacewalk 1.8 as per the postgresql instructions on the wiki. After installing, my logs are filled with the following: 2012/12/20 23:59:05 +10:30 592 0.0.0.0: osad/jabber_lib.__init__ 2012/12/20 23:59:05 +10:30 592 0.0.0.0: osad/jabber_lib.print_message('socket error',) 2012/12/20 23:59:05 +10:30 592 0.0.0.0: osad/jabber_lib.print_message('Could not connect to jabber server', 'spacewalk.fy.id.au') 2012/12/20 23:59:05 +10:30 592 0.0.0.0: osad/jabber_lib.setup_connection('ERROR', 'Traceback (most recent call last):\n File "/usr/share/rhn/osad/jabber_lib.py", line 252, in setup_connection\n c = self._get_jabber_client(js)\n File "/usr/share/rhn/osad/jabber_lib.py", line 309, in _get_jabber_client\n c.connect()\n File "/usr/share/rhn/osad/jabber_lib.py", line 567, in connect\n jabber.Client.connect(self)\n File "/usr/lib/python2.7/site-packages/jabber/xmlstream.py", line 488, in connect\n raise socket.error("Unable to connect to the host and port specified")\nerror: Unable to connect to the host and port specified\n') 2012/12/20 23:59:05 +10:30 592 0.0.0.0: osad/jabber_lib.setup_connection('Could not connect to any jabber server',) 2012/12/20 23:59:05 +10:30 592 0.0.0.0: osad/jabber_lib.main('Unable to connect to jabber servers, sleeping 10 seconds',) For the record, my systems hostname is resolveable.