ICQ: Contacts not showing up the first login [debuglog]

Ok, I did some research in my debuglog (daniel, if you whant to have it, please say so, because it contains all icqnumbers of all friends and other information I didn’'t whant to post it publically).

First of all, there are no errormessages relevant to icq (only one because of googletalk-xmpp), first some information:

  1. is my icq-number of a second testaccount

myhost.mydomain.mytdl is my server, accessable from the internet

I saw this:

----- Start ----------
--- gooing online ---
2007.04.14 00:01:10 AIM got buddy item BuddyItem for ####### (buddy 0x1 in group 0x6344): alias=#######, comment="null", alerts: 2007.04.14 00:01:10 Found buddy item: BuddyItem for ####### (buddy 0x1 in group 0x6344): alias=#######, comment="null", alerts:  at id 1
2007.04.14 00:01:11 OSCAR bos snac packet received: SnacPacketEvent: snacProcessor=ClientSnacProcessor: lastreqid=13, requests: 13, paused=false, snacPacket=SnacPacket type 0x3/0xb: 169 bytes (id=2308436991), snacCommand=BuddyStatusCmd: userinfo=UserInfo for #######: flags=0x51 (MASK_FREE | MASK_UNCONFIRMED | 0x40), ICQ status=, memberSince=Wed Apr 11 15:55:19 CEST 2007, sessLenAim=6min, onSince=Sat Apr 14 00:00:08 CEST 2007, extraTlvs=[TLV: type=0xc, length=37 - hex: c0 a8 49 64 00 00 09 1d 04 00 08 00 00 00 00 00 00 00 50 00 00 00 03 ff ff ff ff 00 03 07 06 00 00 00 00 00 00, TLV: type=0xa, length=4, uint value=1418062325: 54 85 e9 f5], longcaps: [] - FlapPacketEvent: flapProcessor=FlapProcessor: seqNum=SeqNum: min=0, max=65535, last(current)=14, flapCommand=SnacFlapCmd: packet=SnacPacket type 0x3/0xb: 169 bytes (id=2308436991), flapPacket=FlapPacket (channel=2, seq=29468)
2007.04.14 00:01:11 OSCAR snac packet received: SnacPacketEvent: snacProcessor=ClientSnacProcessor: lastreqid=13, requests: 13, paused=false, snacPacket=SnacPacket type 0x3/0xb: 169 bytes (id=2308436991), snacCommand=BuddyStatusCmd: userinfo=UserInfo for #######: flags=0x51 (MASK_FREE | MASK_UNCONFIRMED | 0x40), ICQ status=, memberSince=Wed Apr 11 15:55:19 CEST 2007, sessLenAim=6min, onSince=Sat Apr 14 00:00:08 CEST 2007, extraTlvs=[TLV: type=0xc, length=37 - hex: c0 a8 49 64 00 00 09 1d 04 00 08 00 00 00 00 00 00 00 50 00 00 00 03 ff ff ff ff 00 03 07 06 00 00 00 00 00 00, TLV: type=0xa, length=4, uint value=1418062325: 54 85 e9 f5], longcaps: [] - FlapPacketEvent: flapProcessor=FlapProcessor: seqNum=SeqNum: min=0, max=65535, last(current)=14, flapCommand=SnacFlapCmd: packet=SnacPacket type 0x3/0xb: 169 bytes (id=2308436991), flapPacket=FlapPacket (channel=2, seq=29468)
2007.04.14 00:01:11 icq: Sending packet: <presence to="wareagle@myhost.mydomain.mytdl" from="#######@icq.myhost.mydomain.mytdl"/>
--- going offline ----
2007.04.14 00:01:31 icq: Sending packet: <presence type="unavailable" to="wareagle@myhost.mydomain.mytdl/sim" from="#######@icq.myhost.mydomain.mytdl"></presence>
2007.04.14 00:01:31 Received presence packet: <presence type="unavailable" from="wareagle@myhost.mydomain.mytdl/sim" to="#######@icq.myhost.mydomain.mytdl"></presence>
--- being offline /gooing online again ---
2007.04.14 00:02:24 Received presence packet: <presence from="wareagle@myhost.mydomain.mytdl/sim" to="#######@icq.myhost.mydomain.mytdl">
<status>I am there.</status>
<priority>5</priority>
</presence>
2007.04.14 00:02:24 Received presence packet: <presence type="probe" from="wareagle@myhost.mydomain.mytdl/sim" to="#######@icq.myhost.mydomain.mytdl"></presence>
2007.04.14 00:02:24 Received iq packet: <iq type="get" id="aacba" to="#######@icq.myhost.mydomain.mytdl" from="wareagle@myhost.mydomain.mytdl/sim">
<vCard xmlns="vcard-temp" prodid="-//HandGen//NONSGML vGen v1.0//EN" version="2.0"></vCard>
</iq>
2007.04.14 00:02:24 Unable to handle iq request: vcard-temp
2007.04.14 00:02:24 icq: Sending packet: <iq type="error" id="aacba" from="#######@icq.myhost.mydomain.mytdl" to="wareagle@myhost.mydomain.mytdl/sim"><error code="503" type="cancel"><service-unavailable xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"></service-unavailable></error></iq>
2007.04.14 00:02:24 icq: contactUpdated wareagle:#######@icq.myhost.mydomain.mytdl
2007.04.14 00:02:24 contact = #######, grouplist = [General]
-
2007.04.14 00:02:26 AIM got buddy item BuddyItem for ####### (buddy 0x1 in group 0x6344): alias=#######, comment="null", alerts: 2007.04.14 00:02:26 Found buddy item: BuddyItem for ####### (buddy 0x1 in group 0x6344): alias=#######, comment="null", alerts:  at id 1
2007.04.14 00:02:27 OSCAR bos snac packet received: SnacPacketEvent: snacProcessor=ClientSnacProcessor: lastreqid=13, requests: 13, paused=false, snacPacket=SnacPacket type 0x3/0xb: 169 bytes (id=2308496103), snacCommand=BuddyStatusCmd: userinfo=UserInfo for #######: flags=0x51 (MASK_FREE | MASK_UNCONFIRMED | 0x40), ICQ status=, memberSince=Wed Apr 11 15:55:19 CEST 2007, sessLenAim=7min, onSince=Sat Apr 14 00:00:08 CEST 2007, extraTlvs=[TLV: type=0xc, length=37 - hex: c0 a8 49 64 00 00 09 1d 04 00 08 00 00 00 00 00 00 00 50 00 00 00 03 ff ff ff ff 00 03 07 06 00 00 00 00 00 00, TLV: type=0xa, length=4, uint value=1418062325: 54 85 e9 f5], longcaps: [] - FlapPacketEvent: flapProcessor=FlapProcessor: seqNum=SeqNum: min=0, max=65535, last(current)=14, flapCommand=SnacFlapCmd: packet=SnacPacket type 0x3/0xb: 169 bytes (id=2308496103), flapPacket=FlapPacket (channel=2, seq=17056)
2007.04.14 00:02:27 OSCAR snac packet received: SnacPacketEvent: snacProcessor=ClientSnacProcessor: lastreqid=13, requests: 13, paused=false, snacPacket=SnacPacket type 0x3/0xb: 169 bytes (id=2308496103), snacCommand=BuddyStatusCmd: userinfo=UserInfo for #######: flags=0x51 (MASK_FREE | MASK_UNCONFIRMED | 0x40), ICQ status=, memberSince=Wed Apr 11 15:55:19 CEST 2007, sessLenAim=7min, onSince=Sat Apr 14 00:00:08 CEST 2007, extraTlvs=[TLV: type=0xc, length=37 - hex: c0 a8 49 64 00 00 09 1d 04 00 08 00 00 00 00 00 00 00 50 00 00 00 03 ff ff ff ff 00 03 07 06 00 00 00 00 00 00, TLV: type=0xa, length=4, uint value=1418062325: 54 85 e9 f5], longcaps: [] - FlapPacketEvent: flapProcessor=FlapProcessor: seqNum=SeqNum: min=0, max=65535, last(current)=14, flapCommand=SnacFlapCmd: packet=SnacPacket type 0x3/0xb: 169 bytes (id=2308496103), flapPacket=FlapPacket (channel=2, seq=17056)
2007.04.14 00:02:27 icq: Sending packet: <presence to="wareagle@myhost.mydomain.mytdl" from="#######@icq.myhost.mydomain.mytdl"></presence>
-
2007.04.14 00:02:27 Received iq packet: <iq type="get" id="ab17a" to="#######@icq.myhost.mydomain.mytdl" from="wareagle@myhost.mydomain.mytdl/sim">
<query xmlns="jabber:iq:version"></query>
</iq>
2007.04.14 00:02:27 icq: Sending packet: <iq type="result" id="ab17a" from="#######@icq.myhost.mydomain.mytdl" to="wareagle@myhost.mydomain.mytdl/sim"><query xmlns="jabber:iq:version"><name>Openfire ICQ Transport</name><version>3.3.0 Beta 1 - 1.0.1-tk(without offline messages)</version><os>Linux</os></query></iq>
----- END ----------

Maybe I’'m wrong, but it looks like at the second try the contactlist is present, because the server requests/sends an presence-packet from the contact in the list.

When going online the first time, this resence-packet could not be requested, because during the gooing-online-process, the contactlist is empty.

Is there a way to trigger this request when an icq-contact is added to the list?

Just a stupid idea

WarEagle

That log seems to indicate the contact list both times. Nothing in this log looks unreasonable to me.