Why is it disconnected?

Hi,

first of all one comment:

Sorry for the massive post, but I thoughts it’'s better to post all information I have.

And now my problem.

I’‘m running my jabber-server on a local webserver beeing accessable by a dynamic nameservername (dyndns.org). I have the server2server-connection enabled, so others may connect to me and I’'m able to send messages.

This works fine for most of the time. But about once every two days the connection gets strange.

I receive “Error 404” when sending a message to a friend of mine. He has his account at jabber.ccc.de.

It really happens, that I could send him 5 entences, he answers everyone and the 6th doesn’'t reach him -> Error 404.

So it doesn’'t look like timeouts, but take a look at the log :confused:

Here are two logextracts, both are from the activated debug.log, the first contains EVERY information around this timestamp the error occured. The second one contains only the messages from jabber, so no im-gateway-transport-messages.

I cannot say if the gateway may cause the problem, I don’‘t think so, but to be shure, I’'m posting both logs.

complete debug-log WITH im-gateway-entries:

2007.05.23 20:26:33 icq: Sending packet: <iq type="result" id="aabaa" from="12345678@icq.mydomain.dyndns.org" to="wareagle@mydomain.dyndns.org/sim"><query xmlns="jabber:iq:version"><name>Openfire ICQ Transport</name><version>3.4.0 Alpha 1 - 1.0.2</version><os>Linux</os></query></iq>
2007.05.23 20:26:33 OSCAR bos snac packet received: SnacPacketEvent: snacProcessor=ClientSnacProcessor: lastreqid=15, requests: 15, paused=false, snacPacket=SnacPacket type 0x3/0xb: 217 bytes (id=2480652076), snacCommand=BuddyStatusCmd: userinfo=UserInfo for 12345678: flags=0x70 (MASK_AWAY | MASK_FREE | 0x40), ICQ status=ICQSTATUS_AWAY | 0x10010000, memberSince=Sun Oct 15 19:37:49 CEST 2006, sessLenAim=0min, onSince=Wed May 23 20:30:17 CEST 2007, away, extraInfos=[ExtraInfoBlock: type=0x1 (TYPE_ICONHASH), extraData=<ExtraInfoData: flags=0x1 (FLAG_HASH_PRESENT), data=ab ca c5 aa 9e 6e 7a aa 58 8a 0e dd 7d 31 4c 4b>], extraTlvs=[TLV: type=0xc, length=37 - hex: 00 00 00 00 00 00 00 00 04 00 09 d5 47 cd 01 00 00 6c 00 00 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00, TLV: type=0xa, length=4, ascii value="[null][null][null][null]", uint value=0: 00 00 00 00, TLV: type=0x27, length=4, uint value=1179945018: 46 54 88 3a], longcaps: [] - FlapPacketEvent: flapProcessor=FlapProcessor: seqNum=SeqNum: min=0, max=65535, last(current)=16, flapCommand=SnacFlapCmd: packet=SnacPacket type 0x3/0xb: 217 bytes (id=2480652076), flapPacket=FlapPacket (channel=2, seq=36795)
2007.05.23 20:26:33 OSCAR snac packet received: SnacPacketEvent: snacProcessor=ClientSnacProcessor: lastreqid=15, requests: 15, paused=false, snacPacket=SnacPacket type 0x3/0xb: 217 bytes (id=2480652076), snacCommand=BuddyStatusCmd: userinfo=UserInfo for 12345678: flags=0x70 (MASK_AWAY | MASK_FREE | 0x40), ICQ status=ICQSTATUS_AWAY | 0x10010000, memberSince=Sun Oct 15 19:37:49 CEST 2006, sessLenAim=0min, onSince=Wed May 23 20:30:17 CEST 2007, away, extraInfos=[ExtraInfoBlock: type=0x1 (TYPE_ICONHASH), extraData=<ExtraInfoData: flags=0x1 (FLAG_HASH_PRESENT), data=ab ca c5 aa 9e 6e 7a aa 58 8a 0e dd 7d 31 4c 4b>], extraTlvs=[TLV: type=0xc, length=37 - hex: 00 00 00 00 00 00 00 00 04 00 09 d5 47 cd 01 00 00 6c 00 00 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00, TLV: type=0xa, length=4, ascii value="[null][null][null][null]", uint value=0: 00 00 00 00, TLV: type=0x27, length=4, uint value=1179945018: 46 54 88 3a], longcaps: [] - FlapPacketEvent: flapProcessor=FlapProcessor: seqNum=SeqNum: min=0, max=65535, last(current)=16, flapCommand=SnacFlapCmd: packet=SnacPacket type 0x3/0xb: 217 bytes (id=2480652076), flapPacket=FlapPacket (channel=2, seq=36795)
2007.05.23 20:26:33 icq: Sending packet: <presence to="wareagle@mydomain.dyndns.org" from="12345678@icq.mydomain.dyndns.org"><show>away</show></presence>
2007.05.23 20:28:32 OSCAR bos snac packet received: SnacPacketEvent: snacProcessor=ClientSnacProcessor: lastreqid=15, requests: 15, paused=false, snacPacket=SnacPacket type 0x3/0xb: 193 bytes (id=2480780096), snacCommand=BuddyStatusCmd: userinfo=UserInfo for 12345678: flags=0x70 (MASK_AWAY | MASK_FREE | 0x40), ICQ status=ICQSTATUS_AWAY | 0x10010000, memberSince=Sun Oct 15 19:37:49 CEST 2006, sessLenAim=2min, onSince=Wed May 23 20:30:17 CEST 2007, away, extraTlvs=[TLV: type=0xc, length=37 - hex: 00 00 00 00 00 00 00 00 04 00 09 d5 47 cd 01 00 00 6c 00 00 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00, TLV: type=0xa, length=4, ascii value="[null][null][null][null]", uint value=0: 00 00 00 00, TLV: type=0x27, length=4, uint value=1179945137: 46 54 88 b1], longcaps: [] - FlapPacketEvent: flapProcessor=FlapProcessor: seqNum=SeqNum: min=0, max=65535, last(current)=16, flapCommand=SnacFlapCmd: packet=SnacPacket type 0x3/0xb: 193 bytes (id=2480780096), flapPacket=FlapPacket (channel=2, seq=36796)
2007.05.23 20:28:32 OSCAR snac packet received: SnacPacketEvent: snacProcessor=ClientSnacProcessor: lastreqid=15, requests: 15, paused=false, snacPacket=SnacPacket type 0x3/0xb: 193 bytes (id=2480780096), snacCommand=BuddyStatusCmd: userinfo=UserInfo for 12345678: flags=0x70 (MASK_AWAY | MASK_FREE | 0x40), ICQ status=ICQSTATUS_AWAY | 0x10010000, memberSince=Sun Oct 15 19:37:49 CEST 2006, sessLenAim=2min, onSince=Wed May 23 20:30:17 CEST 2007, away, extraTlvs=[TLV: type=0xc, length=37 - hex: 00 00 00 00 00 00 00 00 04 00 09 d5 47 cd 01 00 00 6c 00 00 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00, TLV: type=0xa, length=4, ascii value="[null][null][null][null]", uint value=0: 00 00 00 00, TLV: type=0x27, length=4, uint value=1179945137: 46 54 88 b1], longcaps: [] - FlapPacketEvent: flapProcessor=FlapProcessor: seqNum=SeqNum: min=0, max=65535, last(current)=16, flapCommand=SnacFlapCmd: packet=SnacPacket type 0x3/0xb: 193 bytes (id=2480780096), flapPacket=FlapPacket (channel=2, seq=36796)
2007.05.23 20:28:32 icq: Sending packet: <presence to="wareagle@mydomain.dyndns.org" from="12345678@icq.mydomain.dyndns.org"><show>away</show></presence>
2007.05.23 20:29:07 OSCAR bos snac packet received: SnacPacketEvent: snacProcessor=ClientSnacProcessor: lastreqid=15, requests: 15, paused=false, snacPacket=SnacPacket type 0x3/0xc: 24 bytes (id=2480818491), snacCommand=BuddyOfflineCmd for 12345678 - FlapPacketEvent: flapProcessor=FlapProcessor: seqNum=SeqNum: min=0, max=65535, last(current)=16, flapCommand=SnacFlapCmd: packet=SnacPacket type 0x3/0xc: 24 bytes (id=2480818491), flapPacket=FlapPacket (channel=2, seq=36797)
2007.05.23 20:29:07 OSCAR snac packet received: SnacPacketEvent: snacProcessor=ClientSnacProcessor: lastreqid=15, requests: 15, paused=false, snacPacket=SnacPacket type 0x3/0xc: 24 bytes (id=2480818491), snacCommand=BuddyOfflineCmd for 12345678 - FlapPacketEvent: flapProcessor=FlapProcessor: seqNum=SeqNum: min=0, max=65535, last(current)=16, flapCommand=SnacFlapCmd: packet=SnacPacket type 0x3/0xc: 24 bytes (id=2480818491), flapPacket=FlapPacket (channel=2, seq=36797)
2007.05.23 20:29:07 icq: Sending packet: <presence type="unavailable" to="wareagle@mydomain.dyndns.org" from="12345678@icq.mydomain.dyndns.org"></presence>
2007.05.23 20:30:28 OSCAR bos snac packet received: SnacPacketEvent: snacProcessor=ClientSnacProcessor: lastreqid=15, requests: 15, paused=false, snacPacket=SnacPacket type 0x3/0xb: 172 bytes (id=2480905982), snacCommand=BuddyStatusCmd: userinfo=UserInfo for 1234567: flags=0x51 (MASK_FREE | MASK_UNCONFIRMED | 0x40), ICQ status=, memberSince=Sun Dec 02 21:27:39 CET 2001, sessLenAim=30min, onSince=Wed May 23 20:04:12 CEST 2007, extraInfos=[ExtraInfoBlock: type=0x1 (TYPE_ICONHASH), extraData=<ExtraInfoData: flags=0x0 (), data=02 01 d2 04 72>], extraTlvs=[TLV: type=0xc, length=37 - hex: 00 00 00 00 00 00 00 00 04 00 09 6b 0f f9 e0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00, TLV: type=0xa, length=4, ascii value="[null][null][null][null]", uint value=0: 00 00 00 00, TLV: type=0x8, length=2, ascii value="
[ACK]", ushort value=2566: 0a 06], longcaps: [] - FlapPacketEvent: flapProcessor=FlapProcessor: seqNum=SeqNum: min=0, max=65535, last(current)=16, flapCommand=SnacFlapCmd: packet=SnacPacket type 0x3/0xb: 172 bytes (id=2480905982), flapPacket=FlapPacket (channel=2, seq=36798)
2007.05.23 20:30:28 OSCAR snac packet received: SnacPacketEvent: snacProcessor=ClientSnacProcessor: lastreqid=15, requests: 15, paused=false, snacPacket=SnacPacket type 0x3/0xb: 172 bytes (id=2480905982), snacCommand=BuddyStatusCmd: userinfo=UserInfo for 1234567: flags=0x51 (MASK_FREE | MASK_UNCONFIRMED | 0x40), ICQ status=, memberSince=Sun Dec 02 21:27:39 CET 2001, sessLenAim=30min, onSince=Wed May 23 20:04:12 CEST 2007, extraInfos=[ExtraInfoBlock: type=0x1 (TYPE_ICONHASH), extraData=<ExtraInfoData: flags=0x0 (), data=02 01 d2 04 72>], extraTlvs=[TLV: type=0xc, length=37 - hex: 00 00 00 00 00 00 00 00 04 00 09 6b 0f f9 e0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00, TLV: type=0xa, length=4, ascii value="[null][null][null][null]", uint value=0: 00 00 00 00, TLV: type=0x8, length=2, ascii value="
[ACK]", ushort value=2566: 0a 06], longcaps: [] - FlapPacketEvent: flapProcessor=FlapProcessor: seqNum=SeqNum: min=0, max=65535, last(current)=16, flapCommand=SnacFlapCmd: packet=SnacPacket type 0x3/0xb: 172 bytes (id=2480905982), flapPacket=FlapPacket (channel=2, seq=36798)
2007.05.23 20:30:28 icq: Sending packet: <presence to="wareagle@mydomain.dyndns.org" from="1234567@icq.mydomain.dyndns.org"></presence>
2007.05.23 20:34:27 OS - Trying to connect to jabber.ccc.de:5269(DNS lookup: jabberd.jabber.ccc.de:5266)
2007.05.23 20:34:27 OS - Plain connection to jabber.ccc.de:5269 successful
2007.05.23 20:34:27 OS - Going to try connecting using server dialback with: jabber.ccc.de
2007.05.23 20:34:27 OS - Trying to connect to jabber.ccc.de:5269(DNS lookup: jabberd.jabber.ccc.de:5267)
2007.05.23 20:34:28 OS - Connection to jabber.ccc.de:5269 successful
2007.05.23 20:34:28 OS - Sent dialback key to host: jabber.ccc.de id: 89e2f4e4c5eb4492153a9968671f901b2b73c30b from domain: mydomain.dyndns.org
2007.05.23 20:34:32 Connect Socket[addr=/217.10.9.40,port=47430,localport=5269]
2007.05.23 20:34:32 AS - Verifying key for host: jabber.ccc.de id: 89e2f4e4c5eb4492153a9968671f901b2b73c30b
2007.05.23 20:34:32 AS - Key was: VALID for host: jabber.ccc.de id: 89e2f4e4c5eb4492153a9968671f901b2b73c30b
2007.05.23 20:34:32 AS - Connection closed for host: jabber.ccc.de id: 89e2f4e4c5eb4492153a9968671f901b2b73c30b
2007.05.23 20:34:32 Connection closed before session established
Socket[addr=/217.10.9.40,port=47430,localport=5269]
2007.05.23 20:34:32 OS - Validation GRANTED from: jabber.ccc.de id: 89e2f4e4c5eb4492153a9968671f901b2b73c30b for domain: mydomain.dyndns.org
2007.05.23 20:43:39 OSCAR bos snac packet received: SnacPacketEvent: snacProcessor=ClientSnacProcessor: lastreqid=15, requests: 15, paused=false, snacPacket=SnacPacket type 0x3/0xb: 158 bytes (id=2481767728), snacCommand=BuddyStatusCmd: userinfo=UserInfo for 15942370: flags=0x70 (MASK_AWAY | MASK_FREE | 0x40), ICQ status=ICQSTATUS_AWAY | 0x20000000, memberSince=Tue Jul 21 20:23:44 CEST 1998, sessLenAim=195min, onSince=Wed May 23 17:31:43 CEST 2007, away, extraTlvs=[TLV: type=0xc, length=37 - hex: c0 a8 4c 01 00 00 0d cc 02 00 09 57 b5 03 da 00 00 00 50 00 00 00 03 45 29 47 12 46 54 5e 63 45 29 47 12 00 00, TLV: type=0xa, length=4, uint value=1417831409: 54 82 63 f1], longcaps: [] - FlapPacketEvent: flapProcessor=FlapProcessor: seqNum=SeqNum: min=0, max=65535, last(current)=16, flapCommand=SnacFlapCmd: packet=SnacPacket type 0x3/0xb: 158 bytes (id=2481767728), flapPacket=FlapPacket (channel=2, seq=36799)
2007.05.23 20:43:39 OSCAR snac packet received: SnacPacketEvent: snacProcessor=ClientSnacProcessor: lastreqid=15, requests: 15, paused=false, snacPacket=SnacPacket type 0x3/0xb: 158 bytes (id=2481767728), snacCommand=BuddyStatusCmd: userinfo=UserInfo for 15942370: flags=0x70 (MASK_AWAY | MASK_FREE | 0x40), ICQ status=ICQSTATUS_AWAY | 0x20000000, memberSince=Tue Jul 21 20:23:44 CEST 1998, sessLenAim=195min, onSince=Wed May 23 17:31:43 CEST 2007, away, extraTlvs=[TLV: type=0xc, length=37 - hex: c0 a8 4c 01 00 00 0d cc 02 00 09 57 b5 03 da 00 00 00 50 00 00 00 03 45 29 47 12 46 54 5e 63 45 29 47 12 00 00, TLV: type=0xa, length=4, uint value=1417831409: 54 82 63 f1], longcaps: [] - FlapPacketEvent: flapProcessor=FlapProcessor: seqNum=SeqNum: min=0, max=65535, last(current)=16, flapCommand=SnacFlapCmd: packet=SnacPacket type 0x3/0xb: 158 bytes (id=2481767728), flapPacket=FlapPacket (channel=2, seq=36799)
2007.05.23 20:43:39 icq: Sending packet: <presence to="wareagle@mydomain.dyndns.org" from="15942370@icq.mydomain.dyndns.org"><show>away</show></presence>
2007.05.23 20:45:27 OSCAR bos snac packet received: SnacPacketEvent: snacProcessor=ClientSnacProcessor: lastreqid=15, requests: 15, paused=false, snacPacket=SnacPacket type 0x3/0xb: 172 bytes (id=2481885369), snacCommand=BuddyStatusCmd: userinfo=UserInfo for 1234567: flags=0x51 (MASK_FREE | MASK_UNCONFIRMED | 0x40), ICQ status=, memberSince=Sun Dec 02 21:27:39 CET 2001, sessLenAim=45min, onSince=Wed May 23 20:04:12 CEST 2007, extraInfos=[ExtraInfoBlock: type=0x1 (TYPE_ICONHASH), extraData=<ExtraInfoData: flags=0x0 (), data=02 01 d2 04 72>], extraTlvs=[TLV: type=0xc, length=37 - hex: 00 00 00 00 00 00 00 00 04 00 09 6b 0f f9 e0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00, TLV: type=0xa, length=4, ascii value="[null][null][null][null]", uint value=0: 00 00 00 00, TLV: type=0x8, length=2, ascii value="
[ACK]", ushort value=2566: 0a 06], longcaps: [] - FlapPacketEvent: flapProcessor=FlapProcessor: seqNum=SeqNum: min=0, max=65535, last(current)=16, flapCommand=SnacFlapCmd: packet=SnacPacket type 0x3/0xb: 172 bytes (id=2481885369), flapPacket=FlapPacket (channel=2, seq=36800)
2007.05.23 20:45:27 OSCAR snac packet received: SnacPacketEvent: snacProcessor=ClientSnacProcessor: lastreqid=15, requests: 15, paused=false, snacPacket=SnacPacket type 0x3/0xb: 172 bytes (id=2481885369), snacCommand=BuddyStatusCmd: userinfo=UserInfo for 1234567: flags=0x51 (MASK_FREE | MASK_UNCONFIRMED | 0x40), ICQ status=, memberSince=Sun Dec 02 21:27:39 CET 2001, sessLenAim=45min, onSince=Wed May 23 20:04:12 CEST 2007, extraInfos=[ExtraInfoBlock: type=0x1 (TYPE_ICONHASH), extraData=<ExtraInfoData: flags=0x0 (), data=02 01 d2 04 72>], extraTlvs=[TLV: type=0xc, length=37 - hex: 00 00 00 00 00 00 00 00 04 00 09 6b 0f f9 e0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00, TLV: type=0xa, length=4, ascii value="[null][null][null][null]", uint value=0: 00 00 00 00, TLV: type=0x8, length=2, ascii value="
[ACK]", ushort value=2566: 0a 06], longcaps: [] - FlapPacketEvent: flapProcessor=FlapProcessor: seqNum=SeqNum: min=0, max=65535, last(current)=16, flapCommand=SnacFlapCmd: packet=SnacPacket type 0x3/0xb: 172 bytes (id=2481885369), flapPacket=FlapPacket (channel=2, seq=36800)
2007.05.23 20:45:27 icq: Sending packet: <presence to="wareagle@mydomain.dyndns.org" from="1234567@icq.mydomain.dyndns.org"></presence>

And now it starts toget strange:

2007.05.23 20:48:27 Finishing Outgoing Server Reader. Closing session: org.jivesoftware.openfire.session.OutgoingServerSession@c441bf status: -1 address: jabber.ccc.de id: 89e2f4e4c5eb4492153a9968671f901b2b73c30b
java.net.SocketException: Socket closed
     at java.net.SocketInputStream.socketRead0(Native Method)
     at java.net.SocketInputStream.read(SocketInputStream.java:129)
     at org.jivesoftware.openfire.net.ServerTrafficCounter$InputStreamWrapper.read(ServerTrafficCounter.java:201)
     at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:264)
     at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:306)
     at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:158)
     at java.io.InputStreamReader.read(InputStreamReader.java:167)
     at org.xmlpull.mxp1.MXParser.fillBuf(MXParser.java:2992)
     at org.xmlpull.mxp1.MXParser.more(MXParser.java:3046)
     at org.jivesoftware.openfire.net.MXParser.nextImpl(MXParser.java:75)
     at org.xmlpull.mxp1.MXParser.nextToken(MXParser.java:1100)
     at org.dom4j.io.XMPPPacketReader.parseDocument(XMPPPacketReader.java:317)
     at org.jivesoftware.openfire.server.OutgoingServerSocketReader$1.run(OutgoingServerSocketReader.java:92)
2007.05.23 20:49:07 OSCAR bos snac packet received: SnacPacketEvent: snacProcessor=ClientSnacProcessor: lastreqid=15, requests: 15, paused=false, snacPacket=SnacPacket type 0x3/0xc: 24 bytes (id=2482127676), snacCommand=BuddyOfflineCmd for 199372733 - FlapPacketEvent: flapProcessor=FlapProcessor: seqNum=SeqNum: min=0, max=65535, last(current)=16, flapCommand=SnacFlapCmd: packet=SnacPacket type 0x3/0xc: 24 bytes (id=2482127676), flapPacket=FlapPacket (channel=2, seq=36801)
2007.05.23 20:49:07 OSCAR snac packet received: SnacPacketEvent: snacProcessor=ClientSnacProcessor: lastreqid=15, requests: 15, paused=false, snacPacket=SnacPacket type 0x3/0xc: 24 bytes (id=2482127676), snacCommand=BuddyOfflineCmd for 199372733 - FlapPacketEvent: flapProcessor=FlapProcessor: seqNum=SeqNum: min=0, max=65535, last(current)=16, flapCommand=SnacFlapCmd: packet=SnacPacket type 0x3/0xc: 24 bytes (id=2482127676), flapPacket=FlapPacket (channel=2, seq=36801)
2007.05.23 20:49:07 icq: Sending packet: <presence type="unavailable" to="wareagle@mydomain.dyndns.org" from="199372733@icq.mydomain.dyndns.org"/>
2007.05.23 20:49:47 OSCAR bos snac packet received: SnacPacketEvent: snacProcessor=ClientSnacProcessor: lastreqid=15, requests: 15, paused=false, snacPacket=SnacPacket type 0x3/0xc: 24 bytes (id=2482172293), snacCommand=BuddyOfflineCmd for 1234567 - FlapPacketEvent: flapProcessor=FlapProcessor: seqNum=SeqNum: min=0, max=65535, last(current)=16, flapCommand=SnacFlapCmd: packet=SnacPacket type 0x3/0xc: 24 bytes (id=2482172293), flapPacket=FlapPacket (channel=2, seq=36802)
2007.05.23 20:49:47 OSCAR snac packet received: SnacPacketEvent: snacProcessor=ClientSnacProcessor: lastreqid=15, requests: 15, paused=false, snacPacket=SnacPacket type 0x3/0xc: 24 bytes (id=2482172293), snacCommand=BuddyOfflineCmd for 1234567 - FlapPacketEvent: flapProcessor=FlapProcessor: seqNum=SeqNum: min=0, max=65535, last(current)=16, flapCommand=SnacFlapCmd: packet=SnacPacket type 0x3/0xc: 24 bytes (id=2482172293), flapPacket=FlapPacket (channel=2, seq=36802)
2007.05.23 20:49:47 icq: Sending packet: <presence type="unavailable" to="wareagle@mydomain.dyndns.org" from="1234567@icq.mydomain.dyndns.org"></presence>
2007.05.23 20:49:48 OSCAR bos snac packet received: SnacPacketEvent: snacProcessor=ClientSnacProcessor: lastreqid=15, requests: 15, paused=false, snacPacket=SnacPacket type 0x3/0xb: 172 bytes (id=2482173934), snacCommand=BuddyStatusCmd: userinfo=UserInfo for 1234567: flags=0x51 (MASK_FREE | MASK_UNCONFIRMED | 0x40), ICQ status=, memberSince=Sun Dec 02 21:27:39 CET 2001, sessLenAim=0min, onSince=Wed May 23 20:53:33 CEST 2007, extraInfos=[ExtraInfoBlock: type=0x1 (TYPE_ICONHASH), extraData=<ExtraInfoData: flags=0x0 (), data=02 01 d2 04 72>], extraTlvs=[TLV: type=0xc, length=37 - hex: 00 00 00 00 00 00 00 00 04 00 09 2f 32 d9 07 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00, TLV: type=0xa, length=4, ascii value="[null][null][null][null]", uint value=0: 00 00 00 00, TLV: type=0x8, length=2, ascii value="
[ACK]", ushort value=2566: 0a 06], longcaps: [] - FlapPacketEvent: flapProcessor=FlapProcessor: seqNum=SeqNum: min=0, max=65535, last(current)=16, flapCommand=SnacFlapCmd: packet=SnacPacket type 0x3/0xb: 172 bytes (id=2482173934), flapPacket=FlapPacket (channel=2, seq=36803)
2007.05.23 20:49:48 OSCAR snac packet received: SnacPacketEvent: snacProcessor=ClientSnacProcessor: lastreqid=15, requests: 15, paused=false, snacPacket=SnacPacket type 0x3/0xb: 172 bytes (id=2482173934), snacCommand=BuddyStatusCmd: userinfo=UserInfo for 1234567: flags=0x51 (MASK_FREE | MASK_UNCONFIRMED | 0x40), ICQ status=, memberSince=Sun Dec 02 21:27:39 CET 2001, sessLenAim=0min, onSince=Wed May 23 20:53:33 CEST 2007, extraInfos=[ExtraInfoBlock: type=0x1 (TYPE_ICONHASH), extraData=<ExtraInfoData: flags=0x0 (), data=02 01 d2 04 72>], extraTlvs=[TLV: type=0xc, length=37 - hex: 00 00 00 00 00 00 00 00 04 00 09 2f 32 d9 07 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00, TLV: type=0xa, length=4, ascii value="[null][null][null][null]", uint value=0: 00 00 00 00, TLV: type=0x8, length=2, ascii value="
[ACK]", ushort value=2566: 0a 06], longcaps: [] - FlapPacketEvent: flapProcessor=FlapProcessor: seqNum=SeqNum: min=0, max=65535, last(current)=16, flapCommand=SnacFlapCmd: packet=SnacPacket type 0x3/0xb: 172 bytes (id=2482173934), flapPacket=FlapPacket (channel=2, seq=36803)
2007.05.23 20:49:48 icq: Sending packet: <presence to="wareagle@mydomain.dyndns.org" from="1234567@icq.mydomain.dyndns.org"></presence>
2007.05.23 20:49:48 Received iq packet: <iq type="get" id="aabba" to="1234567@icq.mydomain.dyndns.org" from="wareagle@mydomain.dyndns.org/sim">
<query xmlns="jabber:iq:version"></query>
</iq>
2007.05.23 20:49:48 icq: Sending packet: <iq type="result" id="aabba" from="1234567@icq.mydomain.dyndns.org" to="wareagle@mydomain.dyndns.org/sim"><query xmlns="jabber:iq:version"><name>Openfire ICQ Transport</name><version>3.4.0 Alpha 1 - 1.0.2</version><os>Linux</os></query></iq>
2007.05.23 20:50:39 OSCAR bos snac packet received: SnacPacketEvent: snacProcessor=ClientSnacProcessor: lastreqid=15, requests: 15, paused=false, snacPacket=SnacPacket type 0x3/0xb: 158 bytes (id=2482232046), snacCommand=BuddyStatusCmd: userinfo=UserInfo for 15942370: flags=0x70 (MASK_AWAY | MASK_FREE | 0x40), ICQ status=ICQSTATUS_NA | ICQSTATUS_AWAY | 0x20000000, memberSince=Tue Jul 21 20:23:44 CEST 1998, sessLenAim=202min, onSince=Wed May 23 17:31:43 CEST 2007, idleMins=7, away, extraTlvs=[TLV: type=0xc, length=37 - hex: c0 a8 4c 01 00 00 0d cc 02 00 09 57 b5 03 da 00 00 00 50 00 00 00 03 45 29 47 12 46 54 5e 63 45 29 47 12 00 00, TLV: type=0xa, length=4, uint value=1417831409: 54 82 63 f1], longcaps: [] - FlapPacketEvent: flapProcessor=FlapProcessor: seqNum=SeqNum: min=0, max=65535, last(current)=16, flapCommand=SnacFlapCmd: packet=SnacPacket type 0x3/0xb: 158 bytes (id=2482232046), flapPacket=FlapPacket (channel=2, seq=36804)
2007.05.23 20:50:39 OSCAR snac packet received: SnacPacketEvent: snacProcessor=ClientSnacProcessor: lastreqid=15, requests: 15, paused=false, snacPacket=SnacPacket type 0x3/0xb: 158 bytes (id=2482232046), snacCommand=BuddyStatusCmd: userinfo=UserInfo for 15942370: flags=0x70 (MASK_AWAY | MASK_FREE | 0x40), ICQ status=ICQSTATUS_NA | ICQSTATUS_AWAY | 0x20000000, memberSince=Tue Jul 21 20:23:44 CEST 1998, sessLenAim=202min, onSince=Wed May 23 17:31:43 CEST 2007, idleMins=7, away, extraTlvs=[TLV: type=0xc, length=37 - hex: c0 a8 4c 01 00 00 0d cc 02 00 09 57 b5 03 da 00 00 00 50 00 00 00 03 45 29 47 12 46 54 5e 63 45 29 47 12 00 00, TLV: type=0xa, length=4, uint value=1417831409: 54 82 63 f1], longcaps: [] - FlapPacketEvent: flapProcessor=FlapProcessor: seqNum=SeqNum: min=0, max=65535, last(current)=16, flapCommand=SnacFlapCmd: packet=SnacPacket type 0x3/0xb: 158 bytes (id=2482232046), flapPacket=FlapPacket (channel=2, seq=36804)
2007.05.23 20:50:39 icq: Sending packet: <presence to="wareagle@mydomain.dyndns.org" from="15942370@icq.mydomain.dyndns.org"><show>away</show></presence>
2007.05.23 20:55:19 OSCAR bos snac packet received: SnacPacketEvent: snacProcessor=ClientSnacProcessor: lastreqid=15, requests: 15, paused=false, snacPacket=SnacPacket type 0x3/0xb: 158 bytes (id=2482559761), snacCommand=BuddyStatusCmd: userinfo=UserInfo for 15942370: flags=0x50 (MASK_FREE | 0x40), ICQ status=, memberSince=Tue Jul 21 20:23:44 CEST 1998, sessLenAim=207min, onSince=Wed May 23 17:31:43 CEST 2007, idleMins=11, extraTlvs=[TLV: type=0xc, length=37 - hex: c0 a8 4c 01 00 00 0d cc 02 00 09 57 b5 03 da 00 00 00 50 00 00 00 03 45 29 47 12 46 54 5e 63 45 29 47 12 00 00, TLV: type=0xa, length=4, uint value=1417831409: 54 82 63 f1], longcaps: [] - FlapPacketEvent: flapProcessor=FlapProcessor: seqNum=SeqNum: min=0, max=65535, last(current)=16, flapCommand=SnacFlapCmd: packet=SnacPacket type 0x3/0xb: 158 bytes (id=2482559761), flapPacket=FlapPacket (channel=2, seq=36805)
2007.05.23 20:55:19 OSCAR snac packet received: SnacPacketEvent: snacProcessor=ClientSnacProcessor: lastreqid=15, requests: 15, paused=false, snacPacket=SnacPacket type 0x3/0xb: 158 bytes (id=2482559761), snacCommand=BuddyStatusCmd: userinfo=UserInfo for 15942370: flags=0x50 (MASK_FREE | 0x40), ICQ status=, memberSince=Tue Jul 21 20:23:44 CEST 1998, sessLenAim=207min, onSince=Wed May 23 17:31:43 CEST 2007, idleMins=11, extraTlvs=[TLV: type=0xc, length=37 - hex: c0 a8 4c 01 00 00 0d cc 02 00 09 57 b5 03 da 00 00 00 50 00 00 00 03 45 29 47 12 46 54 5e 63 45 29 47 12 00 00, TLV: type=0xa, length=4, uint value=1417831409: 54 82 63 f1], longcaps: [] - FlapPacketEvent: flapProcessor=FlapProcessor: seqNum=SeqNum: min=0, max=65535, last(current)=16, flapCommand=SnacFlapCmd: packet=SnacPacket type 0x3/0xb: 158 bytes (id=2482559761), flapPacket=FlapPacket (channel=2, seq=36805)
2007.05.23 20:55:19 icq: Sending packet: <presence to="wareagle@mydomain.dyndns.org" from="15942370@icq.mydomain.dyndns.org"></presence>
2007.05.23 21:04:33 OS - Trying to connect to jabber.ccc.de:5269(DNS lookup: jabberd.jabber.ccc.de:5269)
2007.05.23 21:04:33 OS - Plain connection to jabber.ccc.de:5269 successful
2007.05.23 21:04:33 OS - Going to try connecting using server dialback with: jabber.ccc.de
2007.05.23 21:04:33 OS - Trying to connect to jabber.ccc.de:5269(DNS lookup: jabberd.jabber.ccc.de:5262)
2007.05.23 21:04:33 OS - Connection to jabber.ccc.de:5269 successful
2007.05.23 21:04:36 OS - Sent dialback key to host: jabber.ccc.de id: 30511d5bbb7e144fbc6a83a04f9d6af3be8d75d4 from domain: mydomain.dyndns.org
2007.05.23 21:04:48 OSCAR bos snac packet received: SnacPacketEvent: snacProcessor=ClientSnacProcessor: lastreqid=15, requests: 15, paused=false, snacPacket=SnacPacket type 0x3/0xb: 172 bytes (id=2483224216), snacCommand=BuddyStatusCmd: userinfo=UserInfo for 1234567: flags=0x51 (MASK_FREE | MASK_UNCONFIRMED | 0x40), ICQ status=, memberSince=Sun Dec 02 21:27:39 CET 2001, sessLenAim=15min, onSince=Wed May 23 20:53:33 CEST 2007, extraInfos=[ExtraInfoBlock: type=0x1 (TYPE_ICONHASH), extraData=<ExtraInfoData: flags=0x0 (), data=02 01 d2 04 72>], extraTlvs=[TLV: type=0xc, length=37 - hex: 00 00 00 00 00 00 00 00 04 00 09 2f 32 d9 07 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00, TLV: type=0xa, length=4, ascii value="[null][null][null][null]", uint value=0: 00 00 00 00, TLV: type=0x8, length=2, ascii value="
[ACK]", ushort value=2566: 0a 06], longcaps: [] - FlapPacketEvent: flapProcessor=FlapProcessor: seqNum=SeqNum: min=0, max=65535, last(current)=16, flapCommand=SnacFlapCmd: packet=SnacPacket type 0x3/0xb: 172 bytes (id=2483224216), flapPacket=FlapPacket (channel=2, seq=36806)
2007.05.23 21:04:48 OSCAR snac packet received: SnacPacketEvent: snacProcessor=ClientSnacProcessor: lastreqid=15, requests: 15, paused=false, snacPacket=SnacPacket type 0x3/0xb: 172 bytes (id=2483224216), snacCommand=BuddyStatusCmd: userinfo=UserInfo for 1234567: flags=0x51 (MASK_FREE | MASK_UNCONFIRMED | 0x40), ICQ status=, memberSince=Sun Dec 02 21:27:39 CET 2001, sessLenAim=15min, onSince=Wed May 23 20:53:33 CEST 2007, extraInfos=[ExtraInfoBlock: type=0x1 (TYPE_ICONHASH), extraData=<ExtraInfoData: flags=0x0 (), data=02 01 d2 04 72>], extraTlvs=[TLV: type=0xc, length=37 - hex: 00 00 00 00 00 00 00 00 04 00 09 2f 32 d9 07 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00, TLV: type=0xa, length=4, ascii value="[null][null][null][null]", uint value=0: 00 00 00 00, TLV: type=0x8, length=2, ascii value="
[ACK]", ushort value=2566: 0a 06], longcaps: [] - FlapPacketEvent: flapProcessor=FlapProcessor: seqNum=SeqNum: min=0, max=65535, last(current)=16, flapCommand=SnacFlapCmd: packet=SnacPacket type 0x3/0xb: 172 bytes (id=2483224216), flapPacket=FlapPacket (channel=2, seq=36806)
2007.05.23 21:04:48 icq: Sending packet: <presence to="wareagle@mydomain.dyndns.org" from="1234567@icq.mydomain.dyndns.org"></presence>
2007.05.23 21:04:56 OS - Time out waiting for answer in validation from: jabber.ccc.de id: 30511d5bbb7e144fbc6a83a04f9d6af3be8d75d4 for domain: mydomain.dyndns.org
2007.05.23 21:04:56 Finishing Outgoing Server Reader. No session to close.
java.net.SocketException: Socket closed
     at java.net.SocketInputStream.socketRead0(Native Method)
     at java.net.SocketInputStream.read(SocketInputStream.java:129)
     at org.jivesoftware.openfire.net.ServerTrafficCounter$InputStreamWrapper.read(ServerTrafficCounter.java:201)
     at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:264)
     at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:306)
     at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:158)
     at java.io.InputStreamReader.read(InputStreamReader.java:167)
     at org.xmlpull.mxp1.MXParser.fillBuf(MXParser.java:2992)
     at org.xmlpull.mxp1.MXParser.more(MXParser.java:3046)
     at org.jivesoftware.openfire.net.MXParser.nextImpl(MXParser.java:75)
     at org.xmlpull.mxp1.MXParser.nextToken(MXParser.java:1100)
     at org.dom4j.io.XMPPPacketReader.parseDocument(XMPPPacketReader.java:317)
     at org.jivesoftware.openfire.server.OutgoingServerSocketReader$1.run(OutgoingServerSocketReader.java:92)
2007.05.23 21:04:56 OS - Trying to connect to ccc.de:5269(DNS lookup: ccc.de:5269)
2007.05.23 21:04:56 OS - Trying to connect to de:5269(DNS lookup: de:5269)
2007.05.23 21:04:56 Error sending packet to remote server: <message to="aFriendOfMine1976@jabber.ccc.de" from="wareagle@mydomain.dyndns.org/sim">
  <x xmlns="jabber:x:event">
    <composing></composing>
    <id>msg18</id>
  </x>
</message>
java.lang.Exception: Failed to create connection to remote server
     at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.sendPacket(OutgoingSessionPromise.java:212)
     at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.run(OutgoingSessionPromise.java:184)
     at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
     at java.lang.Thread.run(Thread.java:619)
2007.05.23 21:04:56 OS - Trying to connect to jabber.ccc.de:5269(DNS lookup: jabberd.jabber.ccc.de:5262)
2007.05.23 21:04:56 OS - Plain connection to jabber.ccc.de:5269 successful
2007.05.23 21:04:57 OS - Going to try connecting using server dialback with: jabber.ccc.de
2007.05.23 21:04:57 OS - Trying to connect to jabber.ccc.de:5269(DNS lookup: jabberd.jabber.ccc.de:5263)
2007.05.23 21:04:57 OS - Connection to jabber.ccc.de:5269 successful
2007.05.23 21:04:57 OS - Sent dialback key to host: jabber.ccc.de id: e5d3fa305e5042af84210ca69ee519a88f18c313 from domain: mydomain.dyndns.org
2007.05.23 21:05:05 Received message packet: <message to="15942370@icq.mydomain.dyndns.org" from="wareagle@mydomain.dyndns.org/sim"><x xmlns="jabber:x:event"><composing></composing><id></id></x></message>
2007.05.23 21:05:05 Received message packet: <message to="15942370@icq.mydomain.dyndns.org" from="wareagle@mydomain.dyndns.org/sim"><x xmlns="jabber:x:event"><id></id></x></message>
2007.05.23 21:05:05 Received message packet: <message type="chat" to="15942370@icq.mydomain.dyndns.org" id="msg40" from="wareagle@mydomain.dyndns.org/sim"><body>aFriendOfMine1976 Mi Mai 23 2007 21:08:10
ist text drucken aus java heraus schwierig?
??? Mi Mai 23 2007 21:08:27
weiß ich nicht, es gibt eine druck-api, aber habe ich nie benutzt
aFriendOfMine1976 Mi Mai 23 2007 21:08:41
Fehler 404
Originalnachricht:</body><html xmlns="http://jabber.org/protocol/xhtml-im"><body><span style="font-size:8pt;font-family:''MS Shell Dlg'';background-color:#FFFFFF"><span style="color:#000000">aFriendOfMine1976 Mi Mai 23 2007 21:08:10</span><br/><span style="color:#000000">ist text drucken aus java heraus schwierig?</span><br/><span style="color:#000000">??? Mi Mai 23 2007 21:08:27</span><br/><span style="color:#000000">weiß ich nicht, es gibt eine druck-api, aber habe ich nie benutzt</span><br/><span style="color:#000000">aFriendOfMine1976 Mi Mai 23 2007 21:08:41</span><br/><span style="color:#000000">Fehler 404</span><br/><span style="color:#000000">Originalnachricht:</span></span></body></html><x xmlns="jabber:x:event"><composing></composing></x></message>
2007.05.23 21:05:06 OSCAR bos snac response received: SnacResponseEvent: request=SnacRequest for SendImIcbm to 15942370 (id=0, ackreq=true): IM: aFriendOfMine1976 Mi Mai 23 2007 21:08:10
ist text drucken aus java heraus schwierig?
??? Mi Mai 23 2007 21:08:27
weiß ich nicht, es gibt eine druck-api, aber habe ich nie benutzt
aFriendOfMine1976 Mi Mai 23 2007 21:08:41
Fehler 404
Originalnachricht:: listeners: [org.jivesoftware.openfire.gateway.protocols.oscar.BaseFlapConnection$5@10cc039, net.kano.joscar.ratelim.RateQueue$1@1abd36b], responses: null - SnacPacketEvent: snacProcessor=ClientSnacProcessor: lastreqid=18, requests: 3, paused=false, snacPacket=SnacPacket type 0x4/0xc: 19 bytes (id=18), snacCommand=MessageAck - FlapPacketEvent: flapProcessor=FlapProcessor: seqNum=SeqNum: min=0, max=65535, last(current)=19, flapCommand=SnacFlapCmd: packet=SnacPacket type 0x4/0xc: 19 bytes (id=18), flapPacket=FlapPacket (channel=2, seq=36807)
2007.05.23 21:05:06 Connect Socket[addr=/217.10.9.40,port=52612,localport=5269]
2007.05.23 21:05:07 AS - Verifying key for host: jabber.ccc.de id: 30511d5bbb7e144fbc6a83a04f9d6af3be8d75d4
2007.05.23 21:05:07 AS - Key was: VALID for host: jabber.ccc.de id: 30511d5bbb7e144fbc6a83a04f9d6af3be8d75d4
2007.05.23 21:05:07 AS - Connection closed for host: jabber.ccc.de id: 30511d5bbb7e144fbc6a83a04f9d6af3be8d75d4
2007.05.23 21:05:07 Connection closed before session established
Socket[addr=/217.10.9.40,port=52612,localport=5269]
2007.05.23 21:05:11 Connect Socket[addr=/217.10.9.40,port=52621,localport=5269]
2007.05.23 21:05:12 AS - Verifying key for host: jabber.ccc.de id: e5d3fa305e5042af84210ca69ee519a88f18c313
2007.05.23 21:05:12 AS - Key was: VALID for host: jabber.ccc.de id: e5d3fa305e5042af84210ca69ee519a88f18c313
2007.05.23 21:05:12 AS - Connection closed for host: jabber.ccc.de id: e5d3fa305e5042af84210ca69ee519a88f18c313
2007.05.23 21:05:12 Connection closed before session established
Socket[addr=/217.10.9.40,port=52621,localport=5269]
2007.05.23 21:05:12 OS - Validation GRANTED from: jabber.ccc.de id: e5d3fa305e5042af84210ca69ee519a88f18c313 for domain: mydomain.dyndns.org

log only with jabber-entries:

2007.05.23 20:34:27 OS - Trying to connect to jabber.ccc.de:5269(DNS lookup: jabberd.jabber.ccc.de:5266)
2007.05.23 20:34:27 OS - Plain connection to jabber.ccc.de:5269 successful
2007.05.23 20:34:27 OS - Going to try connecting using server dialback with: jabber.ccc.de
2007.05.23 20:34:27 OS - Trying to connect to jabber.ccc.de:5269(DNS lookup: jabberd.jabber.ccc.de:5267)
2007.05.23 20:34:28 OS - Connection to jabber.ccc.de:5269 successful
2007.05.23 20:34:28 OS - Sent dialback key to host: jabber.ccc.de id: 89e2f4e4c5eb4492153a9968671f901b2b73c30b from domain: mydomain.dyndns.org
2007.05.23 20:34:32 Connect Socket[addr=/217.10.9.40,port=47430,localport=5269]
2007.05.23 20:34:32 AS - Verifying key for host: jabber.ccc.de id: 89e2f4e4c5eb4492153a9968671f901b2b73c30b
2007.05.23 20:34:32 AS - Key was: VALID for host: jabber.ccc.de id: 89e2f4e4c5eb4492153a9968671f901b2b73c30b
2007.05.23 20:34:32 AS - Connection closed for host: jabber.ccc.de id: 89e2f4e4c5eb4492153a9968671f901b2b73c30b
2007.05.23 20:34:32 Connection closed before session established
Socket[addr=/217.10.9.40,port=47430,localport=5269]
2007.05.23 20:34:32 OS - Validation GRANTED from: jabber.ccc.de id: 89e2f4e4c5eb4492153a9968671f901b2b73c30b for domain: mydomain.dyndns.org

And now it starts to get strange:

2007.05.23 20:48:27 Finishing Outgoing Server Reader. Closing session: org.jivesoftware.openfire.session.OutgoingServerSession@c441bf status: -1 address: jabber.ccc.de id: 89e2f4e4c5eb4492153a9968671f901b2b73c30b
java.net.SocketException: Socket closed
     at java.net.SocketInputStream.socketRead0(Native Method)
     at java.net.SocketInputStream.read(SocketInputStream.java:129)
     at org.jivesoftware.openfire.net.ServerTrafficCounter$InputStreamWrapper.read(ServerTrafficCounter.java:201)
     at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:264)
     at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:306)
     at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:158)
     at java.io.InputStreamReader.read(InputStreamReader.java:167)
     at org.xmlpull.mxp1.MXParser.fillBuf(MXParser.java:2992)
     at org.xmlpull.mxp1.MXParser.more(MXParser.java:3046)
     at org.jivesoftware.openfire.net.MXParser.nextImpl(MXParser.java:75)
     at org.xmlpull.mxp1.MXParser.nextToken(MXParser.java:1100)
     at org.dom4j.io.XMPPPacketReader.parseDocument(XMPPPacketReader.java:317)
     at org.jivesoftware.openfire.server.OutgoingServerSocketReader$1.run(OutgoingServerSocketReader.java:92)
2007.05.23 21:04:33 OS - Trying to connect to jabber.ccc.de:5269(DNS lookup: jabberd.jabber.ccc.de:5269)
2007.05.23 21:04:33 OS - Plain connection to jabber.ccc.de:5269 successful
2007.05.23 21:04:33 OS - Going to try connecting using server dialback with: jabber.ccc.de
2007.05.23 21:04:33 OS - Trying to connect to jabber.ccc.de:5269(DNS lookup: jabberd.jabber.ccc.de:5262)
2007.05.23 21:04:33 OS - Connection to jabber.ccc.de:5269 successful
2007.05.23 21:04:36 OS - Sent dialback key to host: jabber.ccc.de id: 30511d5bbb7e144fbc6a83a04f9d6af3be8d75d4 from domain: mydomain.dyndns.org
2007.05.23 21:04:56 OS - Time out waiting for answer in validation from: jabber.ccc.de id: 30511d5bbb7e144fbc6a83a04f9d6af3be8d75d4 for domain: mydomain.dyndns.org
2007.05.23 21:04:56 Finishing Outgoing Server Reader. No session to close.
java.net.SocketException: Socket closed
     at java.net.SocketInputStream.socketRead0(Native Method)
     at java.net.SocketInputStream.read(SocketInputStream.java:129)
     at org.jivesoftware.openfire.net.ServerTrafficCounter$InputStreamWrapper.read(ServerTrafficCounter.java:201)
     at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:264)
     at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:306)
     at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:158)
     at java.io.InputStreamReader.read(InputStreamReader.java:167)
     at org.xmlpull.mxp1.MXParser.fillBuf(MXParser.java:2992)
     at org.xmlpull.mxp1.MXParser.more(MXParser.java:3046)
     at org.jivesoftware.openfire.net.MXParser.nextImpl(MXParser.java:75)
     at org.xmlpull.mxp1.MXParser.nextToken(MXParser.java:1100)
     at org.dom4j.io.XMPPPacketReader.parseDocument(XMPPPacketReader.java:317)
     at org.jivesoftware.openfire.server.OutgoingServerSocketReader$1.run(OutgoingServerSocketReader.java:92)
2007.05.23 21:04:56 OS - Trying to connect to ccc.de:5269(DNS lookup: ccc.de:5269)
2007.05.23 21:04:56 OS - Trying to connect to de:5269(DNS lookup: de:5269)
2007.05.23 21:04:56 Error sending packet to remote server: <message to="aFriendOfMine1976@jabber.ccc.de" from="wareagle@mydomain.dyndns.org/sim">
  <x xmlns="jabber:x:event">
    <composing></composing>
    <id>msg18</id>
  </x>
</message>
java.lang.Exception: Failed to create connection to remote server
     at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.sendPacket(OutgoingSessionPromise.java:212)
     at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.run(OutgoingSessionPromise.java:184)
     at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
     at java.lang.Thread.run(Thread.java:619)
2007.05.23 21:04:56 OS - Trying to connect to jabber.ccc.de:5269(DNS lookup: jabberd.jabber.ccc.de:5262)
2007.05.23 21:04:56 OS - Plain connection to jabber.ccc.de:5269 successful
2007.05.23 21:04:57 OS - Going to try connecting using server dialback with: jabber.ccc.de
2007.05.23 21:04:57 OS - Trying to connect to jabber.ccc.de:5269(DNS lookup: jabberd.jabber.ccc.de:5263)
2007.05.23 21:04:57 OS - Connection to jabber.ccc.de:5269 successful
2007.05.23 21:04:57 OS - Sent dialback key to host: jabber.ccc.de id: e5d3fa305e5042af84210ca69ee519a88f18c313 from domain: mydomain.dyndns.org
2007.05.23 21:05:06 Connect Socket[addr=/217.10.9.40,port=52612,localport=5269]
2007.05.23 21:05:07 AS - Verifying key for host: jabber.ccc.de id: 30511d5bbb7e144fbc6a83a04f9d6af3be8d75d4
2007.05.23 21:05:07 AS - Key was: VALID for host: jabber.ccc.de id: 30511d5bbb7e144fbc6a83a04f9d6af3be8d75d4
2007.05.23 21:05:07 AS - Connection closed for host: jabber.ccc.de id: 30511d5bbb7e144fbc6a83a04f9d6af3be8d75d4
2007.05.23 21:05:07 Connection closed before session established
Socket[addr=/217.10.9.40,port=52612,localport=5269]
2007.05.23 21:05:11 Connect Socket[addr=/217.10.9.40,port=52621,localport=5269]
2007.05.23 21:05:12 AS - Verifying key for host: jabber.ccc.de id: e5d3fa305e5042af84210ca69ee519a88f18c313
2007.05.23 21:05:12 AS - Key was: VALID for host: jabber.ccc.de id: e5d3fa305e5042af84210ca69ee519a88f18c313
2007.05.23 21:05:12 AS - Connection closed for host: jabber.ccc.de id: e5d3fa305e5042af84210ca69ee519a88f18c313
2007.05.23 21:05:12 Connection closed before session established
Socket[addr=/217.10.9.40,port=52621,localport=5269]
2007.05.23 21:05:12 OS - Validation GRANTED from: jabber.ccc.de id: e5d3fa305e5042af84210ca69ee519a88f18c313 for domain: mydomain.dyndns.org

ok…

  • this is printed as the ascii-chat ACK in my editor (hex 0x06)

  • this is printed as the ascii-chat NULL in my editor (hex 0x0)

both aren’'t the String “ACK” or “null”, but the ascii-char

the error.log says:

[org.jivesoftware.openfire.session.OutgoingServerSession.createOutgoingSession(OutgoingServerSession.java:338)] Error creating secured outgoing session to remote server: jabber.ccc.de(DNS lookup: jabberd.jabber.ccc.de:5262)
java.net.SocketTimeoutException: Read timed out
     at java.net.SocketInputStream.socketRead0(Native Method)
     at java.net.SocketInputStream.read(SocketInputStream.java:129)
     at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:264)
     at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:306)
     at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:158)
     at java.io.InputStreamReader.read(InputStreamReader.java:167)
     at org.xmlpull.mxp1.MXParser.fillBuf(MXParser.java:2992)
     at org.xmlpull.mxp1.MXParser.more(MXParser.java:3046)
     at org.xmlpull.mxp1.MXParser.parseProlog(MXParser.java:1410)
     at org.jivesoftware.openfire.net.MXParser.nextImpl(MXParser.java:331)
     at org.xmlpull.mxp1.MXParser.next(MXParser.java:1093)
     at org.jivesoftware.openfire.session.OutgoingServerSession.createOutgoingSession(OutgoingServerSession.java:287)
     at org.jivesoftware.openfire.session.OutgoingServerSession.authenticateDomain(OutgoingServerSession.java:142)
     at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.sendPacket(OutgoingSessionPromise.java:199)
     at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.run(OutgoingSessionPromise.java:184)
     at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
     at java.lang.Thread.run(Thread.java:619)

My guess would be, there is a disconnect from the jabber.ccc.de-server.

I had no reconnect (I have a reconnect every 24h because of the dialin-connection, but this is at about 3 am not at 10 pm.

Now, has anyone an idea what is going wrong?

Greetings

Torsten