Room ID not found after Subscribe to Group.

[mmilen]

Hi,

Here is the scanario . A login and subscribe to group Default (all my rooms live there).
1. I join a room and unsubscribe form Default (no need to know what is going on with other rooms)
2.I leave the room and Subscribe for Default (I want to know about rooms now)

3.This is where I get an erro that the Room ID of the room I just left is not found

Bellow is my log file from the moment Leave the room and subscribe to Default. The error is in bold. Looks like some threading issue of sorts where the Room Manager receives a Room Variable Update before it has processed the SubscribeRoomGroup.

11-11 18:05:28.964: I/s*.c*.c*.SFSIOHandler(20315): 73 61 02 01 01 01 01 00 01 01 sa........
11-11 18:05:28.968: I/s*.c*.c*.SFSIOHandler(20315): Handling New Packet of size 634
11-11 18:05:28.971: I/s*.c*.c*.SFSIOHandler(20315): Handling Header Size. Length: 633 (small)
11-11 18:05:28.971: I/s*.c*.c*.SFSIOHandler(20315): Data size is 511
11-11 18:05:28.971: I/s*.c*.c*.SFSIOHandler(20315): Handling Data: 631, previous state: 0/511
11-11 18:05:28.979: I/s*.c*.c*.SFSIOHandler(20315): <<< Packet Complete >>>
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): Message: ResSubscribeRoomGroup { Message id: 15 }
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): { Dump: }
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (utf_string) g: default
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (sfs_array) rl:
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (sfs_array)
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (int) 3
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (utf_string) Table: TheDeveloper
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (utf_string) default
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) false
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) false
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (short) 2
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (short) 4
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (sfs_array)
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (sfs_array)
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (utf_string) nsa
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (byte) 1
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) false
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315):
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (sfs_array)
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (utf_string) owner
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (byte) 2
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (int) 0
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) false
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315):
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (sfs_array)
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (utf_string) nsn
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (byte) 4
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (utf_string) Computer
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) false
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315):
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (sfs_array)
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (utf_string) wsn
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (byte) 4
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (utf_string) Computer
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) false
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315):
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (sfs_array)
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (utf_string) tn
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (byte) 4
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (utf_string) Duplicate scoring
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315):
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (sfs_array)
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (utf_string) ewccfn
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (byte) 4
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (utf_string) SAYC - Basic
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315):
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (sfs_array)
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (utf_string) esn
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (byte) 4
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (utf_string) milen
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) false
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315):
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (sfs_array)
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (utf_string) nsccfn
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (byte) 4
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (utf_string) SAYC - Basic
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315):
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (sfs_array)
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (utf_string) ssa
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (byte) 1
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) false
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) false
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315):
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (sfs_array)
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (utf_string) pr
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (byte) 1
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315):
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (sfs_array)
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (utf_string) ssn
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (byte) 4
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (utf_string) TheDeveloper
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) false
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315):
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (sfs_array)
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (utf_string) esa
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (byte) 1
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) false
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) false
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315):
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (sfs_array)
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (utf_string) dd
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (byte) 1
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) false
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315):
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (sfs_array)
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (utf_string) sl
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (byte) 2
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (int) 1
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315):
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (sfs_array)
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (utf_string) gt
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (byte) 2
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (int) 2
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315):
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (sfs_array)
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (utf_string) slam
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (byte) 1
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315):
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (sfs_array)
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (utf_string) ip
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (byte) 4
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (utf_string) 192.168.80
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315):
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (sfs_array)
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (utf_string) wsa
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (byte) 1
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) false
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315):
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315):
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (short) 0
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315): (short) 10
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315):
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315):
11-11 18:05:29.589: I/s*.c*.c*.SystemControl*(20315):
11-11 18:05:29.636: I/s*.c*.c*.SFSIOHandler(20315): Handling New Packet of size 120
11-11 18:05:29.639: I/s*.c*.c*.SFSIOHandler(20315): Handling Header Size. Length: 119 (small)
11-11 18:05:29.639: I/s*.c*.c*.SFSIOHandler(20315): Data size is 36
11-11 18:05:29.647: I/s*.c*.c*.SFSIOHandler(20315): Handling Data: 117, previous state: 0/36
11-11 18:05:29.647: I/s*.c*.c*.SFSIOHandler(20315): <<< Packet Complete >>>
11-11 18:05:29.710: I/s*.c*.c*.SystemControl*(20315): Message: ResUserExitRoom { Message id: 1004 }
11-11 18:05:29.710: I/s*.c*.c*.SystemControl*(20315): { Dump: }
11-11 18:05:29.710: I/s*.c*.c*.SystemControl*(20315): (int) r: 3
11-11 18:05:29.710: I/s*.c*.c*.SystemControl*(20315): (int) u: 1
11-11 18:05:29.710: I/s*.c*.c*.SystemControl*(20315):
11-11 18:05:29.721: I/s*.c*.c*.EventDispatch*(20315): Dispatching event userExitRoom to 1 listeners
11-11 18:05:29.729: I/s*.c*.c*.SFSIOHandler(20315): Handling New Packet of size 81
11-11 18:05:29.729: I/s*.c*.c*.SFSIOHandler(20315): Handling Header Size. Length: 80 (small)
11-11 18:05:29.729: I/s*.c*.c*.SFSIOHandler(20315): Data size is 78
11-11 18:05:29.729: I/s*.c*.c*.SFSIOHandler(20315): Handling Data: 78, previous state: 0/78
11-11 18:05:29.733: I/s*.c*.c*.SFSIOHandler(20315): <<< Packet Complete >>>
11-11 18:05:29.846: I/s*.c*.c*.SystemControl*(20315): Message: ResSetRoomVariables { Message id: 11 }
11-11 18:05:29.846: I/s*.c*.c*.SystemControl*(20315): { Dump: }
11-11 18:05:29.846: I/s*.c*.c*.SystemControl*(20315): (int) r: 3
11-11 18:05:29.846: I/s*.c*.c*.SystemControl*(20315): (sfs_array) vl:
11-11 18:05:29.846: I/s*.c*.c*.SystemControl*(20315): (sfs_array)
11-11 18:05:29.846: I/s*.c*.c*.SystemControl*(20315): (utf_string) esn
11-11 18:05:29.846: I/s*.c*.c*.SystemControl*(20315): (byte) 4
11-11 18:05:29.846: I/s*.c*.c*.SystemControl*(20315): (utf_string) Computer
11-11 18:05:29.846: I/s*.c*.c*.SystemControl*(20315): (bool) false
11-11 18:05:29.846: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.846: I/s*.c*.c*.SystemControl*(20315):
11-11 18:05:29.846: I/s*.c*.c*.SystemControl*(20315): (sfs_array)
11-11 18:05:29.846: I/s*.c*.c*.SystemControl*(20315): (utf_string) esa
11-11 18:05:29.846: I/s*.c*.c*.SystemControl*(20315): (byte) 1
11-11 18:05:29.846: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.846: I/s*.c*.c*.SystemControl*(20315): (bool) false
11-11 18:05:29.846: I/s*.c*.c*.SystemControl*(20315): (bool) true
11-11 18:05:29.846: I/s*.c*.c*.SystemControl*(20315):
11-11 18:05:29.846: I/s*.c*.c*.SystemControl*(20315):
11-11 18:05:29.846: I/s*.c*.c*.SystemControl*(20315):
11-11 18:05:29.850: W/sfs2x.client.SmartFox(20315): RoomVariablesUpdate, unknown Room id 3
11-11 18:05:31.436: I/s*.c*.c*.EventDispatch*(20315): Dispatching event OnData to 1 listeners
11-11 18:05:31.542: I/s*.c*.c*.SFSIOHandler(20315): Data Read: Binary size: 45
11-11 18:05:31.542: I/s*.c*.c*.SFSIOHandler(20315): 80 00 2A 12 00 03 00 01 61 03 03 E9 00 01 63 02 ..*.....a.....c.
11-11 18:05:31.542: I/s*.c*.c*.SFSIOHandler(20315): 00 00 01 70 12 00 03 00 01 72 04 00 00 00 03 00 ...p.....r......
11-11 18:05:31.542: I/s*.c*.c*.SFSIOHandler(20315): 02 75 63 03 00 01 00 02 73 63 03 00 00 .uc.....sc...
11-11 18:05:31.542: I/s*.c*.c*.SFSIOHandler(20315): Handling New Packet of size 45
11-11 18:05:31.553: I/s*.c*.c*.SFSIOHandler(20315): Handling Header Size. Length: 44 (small)
11-11 18:05:31.557: I/s*.c*.c*.SFSIOHandler(20315): Data size is 42
11-11 18:05:31.565: I/s*.c*.c*.SFSIOHandler(20315): Handling Data: 42, previous state: 0/42
11-11 18:05:31.565: I/s*.c*.c*.SFSIOHandler(20315): <<< Packet Complete >>>
11-11 18:05:31.643: I/s*.c*.c*.SystemControl*(20315): Message: ResUserCountChange { Message id: 1001 }
11-11 18:05:31.643: I/s*.c*.c*.SystemControl*(20315): { Dump: }
11-11 18:05:31.643: I/s*.c*.c*.SystemControl*(20315): (int) r: 3
11-11 18:05:31.643: I/s*.c*.c*.SystemControl*(20315): (short) uc: 1
11-11 18:05:31.643: I/s*.c*.c*.SystemControl*(20315): (short) sc: 0
11-11 18:05:31.643: I/s*.c*.c*.SystemControl*(20315):
11-11 18:05:52.011: I/s*.c*.c*.SFSProtocolCo*(20315): Writing message Binary size: 25
11-11 18:05:52.011: I/s*.c*.c*.SFSProtocolCo*(20315): 12 00 03 00 01 72 04 FF FF FF FF 00 01 63 08 00 .....r.......c..
11-11 18:05:52.011: I/s*.c*.c*.SFSProtocolCo*(20315): 02 6B 61 00 01 70 12 00 00 .ka..p...
11-11 18:05:52.147: I/s*.c*.c*.SFSIOHandler(20315): Data written: Binary size: 42
11-11 18:05:52.147: I/s*.c*.c*.SFSIOHandler(20315): 12 00 03 00 01 61 03 00 0D 00 01 63 02 01 00 01 .....a.....c....
11-11 18:05:52.147: I/s*.c*.c*.SFSIOHandler(20315): 70 12 00 03 00 01 72 04 FF FF FF FF 00 01 63 08 p.....r.......c.
11-11 18:05:52.147: I/s*.c*.c*.SFSIOHandler(20315): 00 02 6B 61 00 01 70 12 00 00 ..ka..p...
11-11 18:06:36.956: I/s*.c*.c*.SFSProtocolCo*(20315): Writing message Binary size: 25
11-11 18:06:36.956: I/s*.c*.c*.SFSProtocolCo*(20315): 12 00 03 00 01 72 04 FF FF FF FF 00 01 63 08 00 .....r.......c..
11-11 18:06:36.956: I/s*.c*.c*.SFSProtocolCo*(20315): 02 6B 61 00 01 70 12 00 00 .ka..p...
11-11 18:06:37.093: I/s*.c*.c*.SFSIOHandler(20315): Data written: Binary size: 42
11-11 18:06:37.093: I/s*.c*.c*.SFSIOHandler(20315): 12 00 03 00 01 61 03 00 0D 00 01 63 02 01 00 01 .....a.....c....
11-11 18:06:37.093: I/s*.c*.c*.SFSIOHandler(20315): 70 12 00 03 00 01 72 04 FF FF FF FF 00 01 63 08 p.....r.......c.
11-11 18:06:37.093: I/s*.c*.c*.SFSIOHandler(20315): 00 02 6B 61 00 01 70 12 00 00 ..ka..p...

[Bax]

Thanks for reporting. Added to our bug tracking system.

[ThomasLund]

Think I know whats wrong!

When you unsubscribe from a room group and you are still logged into that room - then the room is marked "unmanaged".

This means that the room will be removed when you exit - but otherwise not managed by the API anymore.

When you then subscribe to the room group again - the room list is re-populated. But the managed = false flag survives that population.

From your log the order that the code is executed is:

Message: ResSubscribeRoomGroup { Message id: 15 }
Message: ResUserExitRoom { Message id: 1004 }
Message: ResSetRoomVariables { Message id: 11 }

So the list is re-populated - including room 3. Then you exit room 3 (causing room 3 to be deleted due to being unmanaged and now empty). And then set the user variables on room 3.

Interesting

Can you work around this in your code? Meanwhile I'll try to talk to Marco about this. Could be a logical flaw in the API

/Thomas

[mmilen]

Thank you very much for looking into this. I have a work around in place.

Do you have plans releasing the Client code?