[SOLVED] Reactor Error After Room Left (u44) Message Received

[sean]

I think I am able to reproduce the error successfully so if you stay tuned I should have an updated log output for you...

[sean]

Hey Colin,

I am now able to successfully reproduce the error and have done so a few times. I have emailed you the output log while in DEBUG mode. Toward the end of the file, you will notice the error message.

I notice that this error is triggered by the RoomStopObserve event but now I am puzzled as to how to recreate the situation where the RoomLeft event triggers the same error based on the first stack trace I posted. Maybe you'll have more insight into what's happening in both scenarios, so far the RoomStopObserve scenario is the one that makes sense to me..

Let me know if you need anything else..

[sean]

Oh, at line 2252 in the debug output file, I notice the second rendition of the error triggered by the ROOM_LEFT event so looks like both scenarios are there for you to see. It would be nice to know the reasoning behind the ROOM_LEFT rendition of the error or the steps that trigger it I guess.

I had to connect to the server with multiple clients in order to reproduce the error so I'm not sure if the messages are confusing to you or if you are able to decipher which client is which..

[sean]

After a bit of review of the output, my educated guess is that after calling stopWatchingForRooms(), that what the roomManager does is remove each known room from its list of rooms which I thought it would just stop subscribing to updates about Rooms being added or removed.

So it seems that while its removing ALL rooms from its internal list that if the room is currently being watched or occupied, it then forces the client to leave or stop observing the room, hence the errors?

[colin]

hi sean,
thanks for sending me your log. using it i was able to reproduce the error you reported. here are the exact steps to reproduce:

1. Client watches for rooms.
2. Client is informed of the existence of a given room (let's call it "Room N")
3. Client observes "Room N".
4. Client stops watching for rooms.
5. "Room N" is removed from the server.
6. Client receives a u62 (STOPPED_OBSERVING_ROOM) UPC.
7. RoomManager removes "Room N" from its observed room list. No other references to the room remain, so RoomManager invokes the internal shutdown() method on "Room N".
8. In response to the u62 UPC, the internal doStopObserving() method is invoked on "Room N".
9. The doStopObserving() method notices that the current client is neither in nor observing the room, so it invokes the purgeRoomData() method.
10. The purgeRoomData() method tries to add a log message (line 2099), but "Room N" has already been shutdown/disposed (Step 7), so its log reference is null.
11. TypeError: Cannot access a property or method of a null object reference. The null object is the missing log.

in most applications, this error does not occur during room observation/stop observation because the current client typically has a remaining cached reference to the room being observed, so shutdown() is not called in Step 7. in your case, however, the client gains knowledge of the room via watchForRooms(), which does not cache rooms. in the current design, rooms are added to the room cache only when they are presently unknown to the current client but expected to become known in the future (e.g., during a "createRoom()" call).

there are two ways to address this bug in Reactor:

1. Cache rooms that become known in response to a watchForRooms() call.
2. Make rooms that have already been shutdown ignore subsequent shutdown requests.

i favour a smaller cache/memory footprint over occasional redundant shutdown() calls, so i chose option 2 (as described at http://factory.user1.net/issues/show/568).

in your use case, the caching system is an internal detail that you doesn't affect your code, but after all your help in the bug hunt, i thought you might be interested in the internals.

in my tests, the error is gone as of staging build Reactor_1.1.1.1176_dev (http://www.unionplatform.com/staging/re ... or/latest/). if you have time, please let me know whether the errors are also gone in your application.

colin

[sean]

Hi Colin,

Thanks for taking the time to explain the internals behind the bug. I really appreciate the insight since this bug caused a lot of curiosity and uncertainty for me.

I also agree with your approach in favouring a small memory footprint by default. It naturally seems way simpler and efficient to just do a quick check to see if the room had already been disposed of.

It was definitely a bug hunt indeed and it took me a while to even figure out the series of events to reproduce it. Luckily I did and I'm glad that those efforts were not in vain since you were able to test your hypothesis. This has got to be debugging at its best!

Oh and yes, the error is gone for me as well in the latest staging build: 1.1.1.1176