[Spacewalk-list] OSAD, Jabberd and OpenSSL errors

[Nikhil Anand]

Greetings,

As a followup, I enabled separate logging of sm, c2s, s2s and router in their respective XML configs. That being done, these events on the server:

------------------
(in sm.log)
Sep 13 01:48:10 sauron jabberd/sm[3768]: session replaced: jid=osad-995efdeb4f@<FQDN>/osad

(in c2s.log)
Tue Sep 13 01:48:10 2011 [notice] [9] [128.255.22.35, port=49643] connect
Tue Sep 13 01:48:10 2011 [notice] [9] legacy authentication succeeded: host=, username=osad-995efdeb4f, resource=osad, TLS negotiated
Tue Sep 13 01:48:10 2011 [notice] [9] requesting session: jid=osad-995efdeb4f@<FQDN>/osad
Tue Sep 13 01:48:10 2011 [notice] [10] [128.255.22.35, port=59930] disconnect jid=osad-995efdeb4f@<FQDN>/osad, packets: 7
Tue Sep 13 01:48:10 2011 [notice] [10] [128.255.22.35, port=59925] disconnect jid=osad-995efdeb4f@<FQDN>/osad, packets: 10
------------------

Coincide with the error on the client:

------------------
2011-09-13 01:48:10 jabber_lib.process: Reading 1024 bytes from ssl socket
2011-09-13 01:48:10 jabber_lib.process: Read 132 bytes
2011-09-13 01:48:10 jabber_lib._orig_dispatch: <error><conflict xmlns = 'urn:ietf:params:xml:ns:xmpp-streams'  /></error>
<-- <error><conflict xmlns = 'urn:ietf:params:xml:ns:xmpp-streams'  /></error>
2011-09-13 01:48:10 jabber_lib.process: None
2011-09-13 01:48:10 jabber_lib.process: before select(); timeout None
2011-09-13 01:48:10 jabber_lib.process: select() returned
2011-09-13 01:48:10 jabber_lib.process: Reading 1024 bytes from ssl socket
2011-09-13 01:48:10 jabber_lib.process: Read 16 bytes
2011-09-13 01:48:10 jabber_lib.process: None
2011-09-13 01:48:10 jabber_lib.process: before select(); timeout None
2011-09-13 01:48:10 jabber_lib.process: select() returned
2011-09-13 01:48:10 jabber_lib.process: Reading 1024 bytes from ssl socket
2011-09-13 01:48:10 jabber_lib.process: Closing socket
Error caught:
Traceback (most recent call last):
  File "/usr/share/rhn/osad/jabber_lib.py", line 121, in main
    self.process_forever(c)
  File "/usr/share/rhn/osad/jabber_lib.py", line 179, in process_forever
    self.process_once(client)
  File "/usr/share/rhn/osad/osad.py", line 242, in process_once
    client.process(timeout=None)
  File "/usr/share/rhn/osad/jabber_lib.py", line 1038, in process
    raise SSLError("OpenSSL error; will retry", str(e))
SSLError: ('OpenSSL error; will retry', "(-1, 'Unexpected EOF')")
------------------

A few notes:

+ Whenever I see OpenSSL errors, I _always_ see "session replaced" in sm.log (same timestamps)

+ I felt a little silly and modified stanza variables in c2s.xml. Nothing happened.

+ I see something like the below in the logs all the time. The "urn:xmpp:delay" part worried me;  I thought actions wouldn't be pushed until many hours later, but this doesn't seem to happen.
------------------
<presence to='osad-c94e1c9a90@<FQDN>/osad' from='rhn-dispatcher-sat@<FQDN>/superclient'>
    <delay xmlns = 'urn:xmpp:delay'  stamp='2011-09-13T21:57:41Z' from='rhn-dispatcher-sat@<FQDN>/superclient' />
    <x xmlns = 'jabber:x:delay'  stamp='20110913T21:57:41' from='rhn-dispatcher-sat@<FQDN>/superclient' />
</presence>
------------------

+ The XMPP RFC (http://xmpp.org/rfcs/rfc3921.html#session) seemed to (somewhat) explain this error in my output earlier.
------------------
2011-09-13 01:48:10 jabber_lib._orig_dispatch: <error><conflict xmlns = 'urn:ietf:params:xml:ns:xmpp-streams'  /></error>
<-- <error><conflict xmlns = 'urn:ietf:params:xml:ns:xmpp-streams'  /></error>
------------------
  This apparently happens when 'active resources with the same name' compete with each other. Two session requests from the same jabber ID's on the client, perhaps?

+ I am at least able to push something (albeit sporadically) thanks to the timeout values on this page:
https://fedorahosted.org/spacewalk/wiki/JabberAndOSAD


So what's going on with c2s and sm that cause these errors? Is it possible to tweak the timeout after which a session is "replaced"? More importantly, is the error I have considered normal?

The bottom-line is that I really love using Spacewalk and have gotten to a point where actions are pushed after a half hour max. Even if this issue's inscrutable, that's okay with me.

Thank you for all the work! :)
Nikhil