If these are "to be expected" I guess they should be logged as debug rather than warn so users can filter them out with their log4j settings.
When Client.addListener() is called, bisocket stores some information in a static map, keyed on the listener ID, and when Client.removeListener() is called, that information is purged. The "unrecognized listener ID" message comes up when the purge method doesn't find the listener ID among the keys. So it represents an event I didn't expect.
However, I see one way the situation could arise. The client side runs a thread that monitors the health of the control connection, and if the control connection fails, the monitor thread will recreate the control connection. However, it could be that the failed control connection was to a server that died and was restarted (with new connections), in which case there's no point in restarting the old control connection. So the monitor thread keeps a count of the number of times the control connection has been restarted, and when the count maxes out, the thread gives up and purges the static map. If Client.addListener() is called after that, the message will come up.
So I'm thinking
1. I'd like to leave the warning message in, but
2. I could leave a dummy entry in the map (instead of a Thread), just so it's clear that all is well.
But, I'd like to know if this scenario corresponds to what you're seeing, or if there's something else going on that I need to fix.
Ron, at the least change the log level to debug or trace for that. Trace the better. These WARN messages for listener ID are quite annoying.
If this is expected behaviour the exception should be handled and maybe logged at DEBUG or TRACE.
If not, it represents a bug and should be fixed.
According to the link I posted previously this seems to be happening on startup/shutdown of server and every time an MDB receives a message - so I suspect this is a bug.
every time an MDB receives a message
Ah, that's what "each time it fires" means. Yeah, I think it's a bug. I'll look into it.
Ah, that's what "each time it fires" means.
Well, that's my interpretation of the user's posting - I could have it wrong.
Either way we should dig deeper and try and reproduce this.
I'm going to run the remote Messaging tests over night to see if the problem shows up. Maybe that'll shed some light.
Ok, with help from Andrew on the related thread
I see why this message is appearing. When a callback handler is registered, the client side creates a control connection, and when the handler is unregistered, the control connection is destroyed. However, the creation and destruction is somewhat asymmetric: the connection is created when BisocketClientInvoker.transport() sees an ADDLISTENER message go by, and it is destroyed when the callback BisocketServerInvoker.handleInternalInvocation() gets a REMOVECLIENTLISTENER message. Originally, the treatment was symmetric, but in the case of "quick shutdown" with no network i/o, BisocketClientInvoker is bypassed, which caused a leak.
Now, the problem occurs when the Messaging connection is created in a single JVM. Even though the transport is specified as "bisocket", a LocalClientInvoker is used, which makes direct method calls on the server invoker, and so, appropriately, the bisocket control connection isn't created. But the REMOVECLIENTLISTENER message still goes to the callback BisocketServerInvoker, which tries to destroy the non-existent control connection.
I'll reduce the message's log level in Remoting 2.2.0.SP3, which I'll create in time for the Messaging 1_2_0_SP2 release.