[Spacewalk-list] osa-dispatcher not running or not connecting

Tue Oct 20 12:00:40 UTC 2009

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

- -------- Original Message --------
Subject: [Spacewalk-list] osa-dispatcher not running or not connecting
From: Joshua Roys <joshua.roys at gtri.gatech.edu>
To: spacewalk-list at redhat.com <spacewalk-list at redhat.com>
Date: 10/20/2009 01:51 PM

> Hello,

Hi! :)
> 
> On 10/20/2009 01:47 AM, Michiel van Es wrote:
>> 2009/10/20 07:43:00 +02:00 3866 0.0.0.0: osad/jabber_lib.__init__
>> 2009/10/20 07:43:00 +02:00 3866 0.0.0.0:
>> osad/jabber_lib.print_message('socket error',)
>> 2009/10/20 07:43:00 +02:00 3866 0.0.0.0:
>> osad/jabber_lib.print_message('Could not connect to jabber server',
>> 'devmx01.buro.info.nl')
>> 2009/10/20 07:43:00 +02:00 3866 0.0.0.0:
>> osad/jabber_lib.setup_connection('Could not connect to any jabber server',)
>> 2009/10/20 07:43:00 +02:00 3866 0.0.0.0: osad/jabber_lib.main('Unable to
>> connect to jabber servers, sleeping 10 seconds',)
>>
>> But when I run nc -vv devmx01 5222 it is working
>>
>> [root at devmx01 ~]# nc -vv devmx01 5222
>> Connection to devmx01 5222 port [tcp/xmpp-client] succeeded!
>>
>> All the logfiles in /var/lib/jabberd/log show no errors.
>>
>> How can I check what is going wrong?
>>
> 
> I think you had a similar problem about a month ago?  Has anything 
> significant changed between then and now?  (the thread name is "error 
> jabber after upgrade 0.5 => 0.6")  You could grep /var/log/yum.log for 
> osa and jabber, etc.
> 
> I would do something like:
> 
> # kill $(pidof c2s)
> # c2s -D

There is my problem: (a lot of errors)

[root at devmx01 rhn]# c2s -D
Tue Oct 20 13:58:33 2009 [notice] starting up
Tue Oct 20 13:58:33 2009 [info] process id is 16525, written to
/var/lib/jabberd/pid/c2s.pid
Tue Oct 20 13:58:33 2009 [notice] modules search path: /usr/lib/jabberd/
Tue Oct 20 13:58:33 2009 [info] loading 'db' authreg module
Tue Oct 20 13:58:33 2009 authreg.c:73 preloaded module 'db' (not
initialized yet)
Tue Oct 20 13:58:33 2009 [notice] initialized auth module 'db'
sx (sasl_gsasl.c:860) initialising sasl plugin
sx (sasl_gsasl.c:887) sasl context initialised
sx (env.c:75) plugin initialised (index 0)
Tue Oct 20 13:58:33 2009 bind.c:70 initialising resource bind sx plugin
sx (env.c:75) plugin initialised (index 1)
sx (ssl.c:683) initialising ssl plugin
sx (ssl.c:784) setting ssl context '' verify mode to 00
sx (ssl.c:784) setting ssl context '*' verify mode to 00
sx (ssl.c:805) ssl context '*' initialised; certificate and key loaded
from /etc/pki/spacewalk/jabberd/server.pem
sx (ssl.c:805) ssl context '' initialised; certificate and key loaded
from /etc/pki/spacewalk/jabberd/server.pem
sx (env.c:75) plugin initialised (index 2)
Tue Oct 20 13:58:33 2009 [notice] [devmx01.buro.info.nl] configured;
realm=, registration enabled
Tue Oct 20 13:58:33 2009 [notice] attempting connection to router at
127.0.0.1, port=5347
sx (sx.c:51) allocated new sx for 5
sx (client.c:122) doing client init for sx 5
sx (client.c:138) stream request: ns (null) to (null) from (null)
version 1.0
sx (client.c:168) prepared stream header: <?xml
version='1.0'?><stream:stream
xmlns:stream='http://etherx.jabber.org/streams' version='1.0'>
sx (client.c:175) tag 5 event 1 data 0x0
Tue Oct 20 13:58:33 2009 c2s.c:694 want write
Tue Oct 20 13:58:33 2009 c2s.c:1312 write action on fd 5
sx (io.c:328) 5 ready for writing
sx (io.c:286) encoding 98 bytes for writing: <?xml
version='1.0'?><stream:stream
xmlns:stream='http://etherx.jabber.org/streams' version='1.0'>
sx (chain.c:79) calling io write chain
sx (io.c:349) handing app 98 bytes to write
sx (io.c:350) tag 5 event 3 data 0x9dc61b0
Tue Oct 20 13:58:33 2009 c2s.c:731 writing to 5
Tue Oct 20 13:58:33 2009 c2s.c:735 98 bytes written
sx (client.c:103) 5 state change from 0 to 2
sx (client.c:105) stream header sent, waiting for reply
sx (io.c:383) tag 5 event 0 data 0x0
Tue Oct 20 13:58:33 2009 c2s.c:689 want read
Tue Oct 20 13:58:33 2009 c2s.c:1301 read action on fd 5
sx (io.c:191) 5 ready for reading
sx (io.c:197) tag 5 event 2 data 0x9dc61b0
Tue Oct 20 13:58:33 2009 c2s.c:699 reading from 5
Tue Oct 20 13:58:33 2009 c2s.c:724 read 326 bytes
sx (io.c:216) passed 326 read bytes
sx (chain.c:93) calling io read chain
sx (io.c:240) decoded read data (326 bytes): <?xml
version='1.0'?><stream:stream
xmlns:stream='http://etherx.jabber.org/streams' version='1.0'
id='edaljssrxx04faixwdlmo8l5r5dagdbvqmgae91b'><stream:features
xmlns:stream='http://etherx.jabber.org/streams'><mechanisms
xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>DIGEST-MD5</mechanism></mechanisms></stream:features>
sx (client.c:70) stream response: to (null) from (null) version 1.0 id
edaljssrxx04faixwdlmo8l5r5dagdbvqmgae91b
sx (client.c:85) 5 state change from 2 to 3
sx (client.c:86) tag 5 event 4 data 0x0
sx (io.c:92) completed nad: <stream:features
xmlns:stream='http://etherx.jabber.org/streams'><mechanisms
xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>DIGEST-MD5</mechanism></mechanisms></stream:features>
sx (chain.c:119) calling nad read chain
sx (io.c:156) tag 5 event 6 data 0x9dc6f28
sx (sasl_gsasl.c:960) sending auth request to server, mech 'DIGEST-MD5':
sx (chain.c:106) calling nad write chain
sx (io.c:406) queueing for write: <auth
xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='DIGEST-MD5'/>
sx (io.c:429) tag 5 event 1 data 0x0
Tue Oct 20 13:58:33 2009 c2s.c:694 want write
Tue Oct 20 13:58:33 2009 c2s.c:1312 write action on fd 5
sx (io.c:328) 5 ready for writing
sx (io.c:286) encoding 71 bytes for writing: <auth
xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='DIGEST-MD5'/>
sx (chain.c:79) calling io write chain
sx (io.c:349) handing app 71 bytes to write
sx (io.c:350) tag 5 event 3 data 0x9dc7048
Tue Oct 20 13:58:33 2009 c2s.c:731 writing to 5
Tue Oct 20 13:58:33 2009 c2s.c:735 71 bytes written
sx (io.c:383) tag 5 event 0 data 0x0
Tue Oct 20 13:58:33 2009 c2s.c:689 want read
sx (io.c:431) tag 5 event 0 data 0x0
Tue Oct 20 13:58:33 2009 c2s.c:689 want read
Tue Oct 20 13:58:33 2009 c2s.c:1301 read action on fd 5
sx (io.c:191) 5 ready for reading
sx (io.c:197) tag 5 event 2 data 0x9dc6708
Tue Oct 20 13:58:33 2009 c2s.c:699 reading from 5
Tue Oct 20 13:58:33 2009 c2s.c:724 read 204 bytes
sx (io.c:216) passed 204 read bytes
sx (chain.c:93) calling io read chain
sx (io.c:240) decoded read data (204 bytes): <challenge
xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cmVhbG09ImphYmJlcmQtcm91dGVyIiwgbm9uY2U9Ik8zalZrTVliT0tvaWRmdVNSMjhPdWc9PSIsIHFvcD0iYXV0aCIsIGNoYXJzZXQ9dXRmLTgsIGFsZ29yaXRobT1tZDUtc2Vzcw==</challenge>
sx (io.c:92) completed nad: <challenge
xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cmVhbG09ImphYmJlcmQtcm91dGVyIiwgbm9uY2U9Ik8zalZrTVliT0tvaWRmdVNSMjhPdWc9PSIsIHFvcD0iYXV0aCIsIGNoYXJzZXQ9dXRmLTgsIGFsZ29yaXRobT1tZDUtc2Vzcw==</challenge>
sx (chain.c:119) calling nad read chain
sx (sasl_gsasl.c:564) data from client
sx (sasl_gsasl.c:570) decoded data: realm="jabberd-router",
nonce="O3jVkMYbOKoidfuSR28Oug==", qop="auth", charset=utf-8,
algorithm=md5-sess
sx (sasl_gsasl.c:766) in _sx_sasl_gsasl_callback, property: 2
sx (sasl_gsasl.c:766) in _sx_sasl_gsasl_callback, property: 11
sx (sasl_gsasl.c:578) sasl handshake in progress (response:
username="jabberd", realm="jabberd-router",
nonce="O3jVkMYbOKoidfuSR28Oug==", cnonce="zbLxvQEhl2baTc9+jPfspg==",
nc=00000001, qop=auth, digest-uri="jabberd-router/devmx01.buro.info.nl",
response=c2807265e5c4c86262678d3f8afec204, charset=utf-8)
sx (chain.c:106) calling nad write chain
sx (io.c:406) queueing for write: <response
xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>dXNlcm5hbWU9ImphYmJlcmQiLCByZWFsbT0iamFiYmVyZC1yb3V0ZXIiLCBub25jZT0iTzNqVmtNWWJPS29pZGZ1U1IyOE91Zz09IiwgY25vbmNlPSJ6Ykx4dlFFaGwyYmFUYzkralBmc3BnPT0iLCBuYz0wMDAwMDAwMSwgcW9wPWF1dGgsIGRpZ2VzdC11cmk9ImphYmJlcmQtcm91dGVyL2Rldm14MDEuYnVyby5pbmZvLm5sIiwgcmVzcG9uc2U9YzI4MDcyNjVlNWM0Yzg2MjYyNjc4ZDNmOGFmZWMyMDQsIGNoYXJzZXQ9dXRmLTg=</response>
sx (io.c:256) tag 5 event 1 data 0x0
Tue Oct 20 13:58:33 2009 c2s.c:694 want write
Tue Oct 20 13:58:33 2009 c2s.c:1312 write action on fd 5
sx (io.c:328) 5 ready for writing
sx (io.c:286) encoding 386 bytes for writing: <response
xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>dXNlcm5hbWU9ImphYmJlcmQiLCByZWFsbT0iamFiYmVyZC1yb3V0ZXIiLCBub25jZT0iTzNqVmtNWWJPS29pZGZ1U1IyOE91Zz09IiwgY25vbmNlPSJ6Ykx4dlFFaGwyYmFUYzkralBmc3BnPT0iLCBuYz0wMDAwMDAwMSwgcW9wPWF1dGgsIGRpZ2VzdC11cmk9ImphYmJlcmQtcm91dGVyL2Rldm14MDEuYnVyby5pbmZvLm5sIiwgcmVzcG9uc2U9YzI4MDcyNjVlNWM0Yzg2MjYyNjc4ZDNmOGFmZWMyMDQsIGNoYXJzZXQ9dXRmLTg=</response>
sx (chain.c:79) calling io write chain
sx (io.c:349) handing app 386 bytes to write
sx (io.c:350) tag 5 event 3 data 0x9dc7170
Tue Oct 20 13:58:33 2009 c2s.c:731 writing to 5
Tue Oct 20 13:58:33 2009 c2s.c:735 386 bytes written
sx (io.c:383) tag 5 event 0 data 0x0
Tue Oct 20 13:58:33 2009 c2s.c:689 want read
Tue Oct 20 13:58:33 2009 c2s.c:1301 read action on fd 5
sx (io.c:191) 5 ready for reading
sx (io.c:197) tag 5 event 2 data 0x9dc78b8
Tue Oct 20 13:58:33 2009 c2s.c:699 reading from 5
Tue Oct 20 13:58:33 2009 c2s.c:724 read 120 bytes
sx (io.c:216) passed 120 read bytes
sx (chain.c:93) calling io read chain
sx (io.c:240) decoded read data (120 bytes): <challenge
xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cnNwYXV0aD1hMGU4YWM4NGU0MzkzNDdmMTMxM2Y0NTlhYjQ0ZmVkNw==</challenge>
sx (io.c:92) completed nad: <challenge
xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cnNwYXV0aD1hMGU4YWM4NGU0MzkzNDdmMTMxM2Y0NTlhYjQ0ZmVkNw==</challenge>
sx (chain.c:119) calling nad read chain
sx (sasl_gsasl.c:564) data from client
sx (sasl_gsasl.c:570) decoded data: rspauth=a0e8ac84e439347f1313f459ab44fed7
sx (sasl_gsasl.c:578) sasl handshake in progress (response: )
sx (chain.c:106) calling nad write chain
sx (io.c:406) queueing for write: <response
xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
sx (io.c:256) tag 5 event 1 data 0x0
Tue Oct 20 13:58:33 2009 c2s.c:694 want write
Tue Oct 20 13:58:33 2009 c2s.c:1312 write action on fd 5
sx (io.c:328) 5 ready for writing
sx (io.c:286) encoding 52 bytes for writing: <response
xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
sx (chain.c:79) calling io write chain
sx (io.c:349) handing app 52 bytes to write
sx (io.c:350) tag 5 event 3 data 0x9dc7858
Tue Oct 20 13:58:33 2009 c2s.c:731 writing to 5
Tue Oct 20 13:58:33 2009 c2s.c:735 52 bytes written
sx (io.c:383) tag 5 event 0 data 0x0
Tue Oct 20 13:58:33 2009 c2s.c:689 want read
Tue Oct 20 13:58:33 2009 c2s.c:1301 read action on fd 5
sx (io.c:191) 5 ready for reading
sx (io.c:197) tag 5 event 2 data 0x9dc7858
Tue Oct 20 13:58:33 2009 c2s.c:699 reading from 5
Tue Oct 20 13:58:33 2009 c2s.c:724 read 51 bytes
sx (io.c:216) passed 51 read bytes
sx (chain.c:93) calling io read chain
sx (io.c:240) decoded read data (51 bytes): <success
xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
sx (io.c:92) completed nad: <success
xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
sx (chain.c:119) calling nad read chain
sx (sasl_gsasl.c:696) sasl handshake completed, resetting
sx (sx.c:144) resetting stream state
sx (sx.c:68) freeing sx for 5
sx (sx.c:51) allocated new sx for 5
sx (sx.c:199) finished resetting stream state
sx (sasl_gsasl.c:711) restarting stream with sasl layer established
sx (client.c:122) doing client init for sx 5
sx (client.c:138) stream request: ns (null) to (null) from (null)
version 1.0
sx (client.c:168) prepared stream header: <?xml
version='1.0'?><stream:stream
xmlns:stream='http://etherx.jabber.org/streams' version='1.0'>
sx (client.c:175) tag 5 event 1 data 0x0
Tue Oct 20 13:58:33 2009 c2s.c:694 want write
Tue Oct 20 13:58:33 2009 c2s.c:1312 write action on fd 5
sx (io.c:328) 5 ready for writing
sx (io.c:286) encoding 98 bytes for writing: <?xml
version='1.0'?><stream:stream
xmlns:stream='http://etherx.jabber.org/streams' version='1.0'>
sx (chain.c:79) calling io write chain
sx (io.c:349) handing app 98 bytes to write
sx (io.c:350) tag 5 event 3 data 0x9dc6f50
Tue Oct 20 13:58:33 2009 c2s.c:731 writing to 5
Tue Oct 20 13:58:33 2009 c2s.c:735 98 bytes written
sx (client.c:103) 5 state change from 0 to 2
sx (client.c:105) stream header sent, waiting for reply
sx (io.c:383) tag 5 event 0 data 0x0
Tue Oct 20 13:58:33 2009 c2s.c:689 want read
Tue Oct 20 13:58:33 2009 c2s.c:1301 read action on fd 5
sx (io.c:191) 5 ready for reading
sx (io.c:197) tag 5 event 2 data 0x9dc6f50
Tue Oct 20 13:58:33 2009 c2s.c:699 reading from 5
Tue Oct 20 13:58:33 2009 c2s.c:724 read 144 bytes
sx (io.c:216) passed 144 read bytes
sx (chain.c:93) calling io read chain
sx (io.c:240) decoded read data (144 bytes): <?xml
version='1.0'?><stream:stream
xmlns:stream='http://etherx.jabber.org/streams' version='1.0'
id='62glcyj8b5v0dg55mig2wrxmeextnz4t1lfdjzmv'>
sx (client.c:70) stream response: to (null) from (null) version 1.0 id
62glcyj8b5v0dg55mig2wrxmeextnz4t1lfdjzmv
sx (sx.c:130) authenticating stream (method=SASL/DIGEST-MD5;
id=jabberd at jabberd-router)
sx (sx.c:135) 5 state change from 2 to 4
sx (sx.c:136) tag 5 event 5 data 0x0
Tue Oct 20 13:58:33 2009 [notice] connection to router established
Tue Oct 20 13:58:33 2009 c2s.c:771 requesting component bind for 'c2s'
sx (chain.c:106) calling nad write chain
sx (io.c:406) queueing for write: <bind
xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' name='c2s'/>
sx (io.c:429) tag 5 event 1 data 0x0
Tue Oct 20 13:58:33 2009 c2s.c:694 want write
Tue Oct 20 13:58:33 2009 c2s.c:1312 write action on fd 5
sx (io.c:328) 5 ready for writing
sx (io.c:286) encoding 75 bytes for writing: <bind
xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' name='c2s'/>
sx (chain.c:79) calling io write chain
sx (io.c:349) handing app 75 bytes to write
sx (io.c:350) tag 5 event 3 data 0x9dc65b8
Tue Oct 20 13:58:33 2009 c2s.c:731 writing to 5
Tue Oct 20 13:58:33 2009 c2s.c:735 75 bytes written
sx (io.c:383) tag 5 event 0 data 0x0
Tue Oct 20 13:58:33 2009 c2s.c:689 want read
sx (io.c:431) tag 5 event 0 data 0x0
Tue Oct 20 13:58:33 2009 c2s.c:689 want read
Tue Oct 20 13:58:33 2009 c2s.c:1301 read action on fd 5
sx (io.c:191) 5 ready for reading
sx (io.c:197) tag 5 event 2 data 0x9dc6f38
Tue Oct 20 13:58:33 2009 c2s.c:699 reading from 5
Tue Oct 20 13:58:33 2009 c2s.c:724 read 66 bytes
sx (io.c:216) passed 66 read bytes
sx (chain.c:93) calling io read chain
sx (io.c:240) decoded read data (66 bytes): <stream:features
xmlns:stream='http://etherx.jabber.org/streams'/>
sx (io.c:92) completed nad: <stream:features
xmlns:stream='http://etherx.jabber.org/streams'/>
sx (chain.c:119) calling nad read chain
sx (io.c:156) tag 5 event 6 data 0x9dc64c0
Tue Oct 20 13:58:33 2009 c2s.c:824 got a packet from router, but we're
not online, dropping
Tue Oct 20 13:58:33 2009 c2s.c:1301 read action on fd 5
sx (io.c:191) 5 ready for reading
sx (io.c:197) tag 5 event 2 data 0x9dc6410
Tue Oct 20 13:58:33 2009 c2s.c:699 reading from 5
Tue Oct 20 13:58:33 2009 c2s.c:724 read 76 bytes
sx (io.c:216) passed 76 read bytes
sx (chain.c:93) calling io read chain
sx (io.c:240) decoded read data (76 bytes): <bind
xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' error='409'/>
sx (io.c:92) completed nad: <bind
xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' error='409'/>
sx (chain.c:119) calling nad read chain
sx (io.c:156) tag 5 event 6 data 0x9dbd468
Tue Oct 20 13:58:33 2009 [error] router refused bind request (409)

> 
> and then see what
> # service osa-dispatcher stop
> # osa-dispatcher -N -vvvvvvvvvvvv
> ...gives you.
> 

I can not even start the c2s, I fixed it by movening an creating a new
db folder in /var/lib/jabberd

> Hope to help,

You sure did!
Now I have to find out what is wrong with my c2s..

> 
> Josh

Michiel

> 
> _______________________________________________
> Spacewalk-list mailing list
> Spacewalk-list at redhat.com
> https://www.redhat.com/mailman/listinfo/spacewalk-list
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.9 (GNU/Linux)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org

iEYEARECAAYFAkrdpmgACgkQSU+5fmlaNkNdNwCguYMb2T1IVgxTYZ6ARkBamI9O
MykAniTzosJJ8jnKHByMoRGUpfvSiSkk
=OyIP
-----END PGP SIGNATURE-----