Ok, here's another weird one. My subscriber agent plugs away for hours without errors, and then spontenously shuts down (without calling shut down handler) and it's not clear why. After examining the logs, we notice that SIF_Unregister message is sent by our agent, and it's all downhill from there. There are two issues:
1) Why is SIF_Unregister sent? It's not originating directly from code; my agent never explicitly sends this. I never call zone.disconnect with UNSUBSCRIBE flag, only:
zone.disconnect(ADKFlags.PROV_NONE);
The Unregister message is NOT being sent as a result of Agent.shutdown -- it happens BEFORE that.
2) Even if a zone unregisters, my agent should not shut down. My guess is that there is some error condition that occurs after the zone is disconnected that isn't handled well by my agent and causes it to abort...although it's not clear from the logs what this is or why any error would cause the agent to abort without going thru the regular shut down code.
What would cause an agent to send a SIF_Unregister message implicitly?
Here is the log info regarding the message:
2010-03-10 13:48:10,270 DEBUG [ADK.Agent$LexiaReadingAgentZoneD2552E30EFF411DE9AB7D970C65D5D99] Send SIF_Unregister2010-03-10 13:48:10,270 DEBUG [ADK.Agent$LexiaReadingAgentZoneD2552E30EFF411DE9AB7D970C65D5D99] MsgId: C7A8A262B2BC4B2E84BD138349C23DF42010-03-10 13:48:10,271 DEBUG [ADK.Agent$LexiaReadingAgentZoneD2552E30EFF411DE9AB7D970C65D5D99] Sending message (618 bytes) 2010-03-10 13:48:10,271 DEBUG [ADK.Agent$LexiaReadingAgentZoneD2552E30EFF411DE9AB7D970C65D5D99] <SIF_Message xmlns="http://www.sifinfo.org/infrastructure/2.x" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" Version="2.2"> <SIF_Unregister> <SIF_Header> <SIF_MsgId>C7A8A262B2BC4B2E84BD138349C23DF4</SIF_MsgId> <SIF_Timestamp>2010-03-10T13:48:10-05:00</SIF_Timestamp> <SIF_Security> <SIF_SecureChannel> <SIF_AuthenticationLevel>0</SIF_AuthenticationLevel> <SIF_EncryptionLevel>0</SIF_EncryptionLevel> </SIF_SecureChannel> </SIF_Security> <SIF_SourceId>LexiaReadingAgent</SIF_SourceId> </SIF_Header> </SIF_Unregister></SIF_Message>
Normal 0 false false false MicrosoftInternetExplorer4 This has been solved by installing the ADK 2.3. I think the problem was actually due to the fact that jar files for the trial version of the ADK were on our server originally.
Hi Miriam,
I would tend to agree with you that some error condition is happening in the agent to cause it to send the SIF_Unregister. Do you see anything happening in the log file before the SIF_Unregister occurs? For instance, do you see any sign of getting a SIF_Event or a SIF_Response to a SIF_Request that your subscriber has sent? Do you see any stack traces or exceptions in the log file before or after?
-Jared
Hi Jared,
I don't see any unusual activity in the logs before the Unregister -- just a whole lot of polling and typically no messages in queue. Here's a snippet of the log file leading up to it:
2010-03-10 13:48:09,737 DEBUG [ADK.Agent$CES] Polling for next message...2010-03-10 13:48:09,737 DEBUG [ADK.Agent$CES] Send SIF_SystemControl2010-03-10 13:48:09,737 DEBUG [ADK.Agent$CES] MsgId: 8AC4C60BCEBE4B748E9E808CC2051BB22010-03-10 13:48:09,738 DEBUG [ADK.Agent$CES] Sending message (705 bytes)2010-03-10 13:48:09,738 DEBUG [ADK.Agent$CES] <SIF_Message xmlns="http://www.sifinfo.org/infrastructure/2.x" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" Version="2.2"> <SIF_SystemControl> <SIF_Header> <SIF_MsgId>8AC4C60BCEBE4B748E9E808CC2051BB2</SIF_MsgId> <SIF_Timestamp>2010-03-10T13:48:09-05:00</SIF_Timestamp> <SIF_Security> <SIF_SecureChannel> <SIF_AuthenticationLevel>0</SIF_AuthenticationLevel> <SIF_EncryptionLevel>0</SIF_EncryptionLevel> </SIF_SecureChannel> </SIF_Security> <SIF_SourceId>LexiaReadingAgent</SIF_SourceId> </SIF_Header> <SIF_SystemControlData> <SIF_GetMessage/> </SIF_SystemControlData> </SIF_SystemControl></SIF_Message>2010-03-10 13:48:09,780 DEBUG [ADK.Agent$CES] Expecting reply (458 bytes)2010-03-10 13:48:09,781 DEBUG [ADK.Agent$CES] Received reply (458 chars)2010-03-10 13:48:09,781 DEBUG [ADK.Agent$CES] <SIF_Message xmlns="http://www.sifinfo.org/infrastructure/2.x" Version="2.2"><SIF_Ack><SIF_Header><SIF_MsgId>0270EDBBBB617F184064D918BFFF1895</SIF_MsgId><SIF_Timestamp>2010-03-10T13:46:10-05:00</SIF_Timestamp><SIF_SourceId>CES</SIF_SourceId></SIF_Header><SIF_OriginalSourceId>LexiaReadingAgent</SIF_OriginalSourceId><SIF_OriginalMsgId>8AC4C60BCEBE4B748E9E808CC2051BB2</SIF_OriginalMsgId><SIF_Status><SIF_Code>9</SIF_Code></SIF_Status></SIF_Ack></SIF_Message>2010-03-10 13:48:09,782 DEBUG [ADK.Agent$CES] Receive SIF_Ack (Status = 9)2010-03-10 13:48:09,782 DEBUG [ADK.Agent$CES] MsgId: 0270EDBBBB617F184064D918BFFF18952010-03-10 13:48:09,782 DEBUG [ADK.Agent$CES] OrgId: 8AC4C60BCEBE4B748E9E808CC2051BB22010-03-10 13:48:09,782 DEBUG [ADK.Agent$CES] No messages waiting in agent queue2010-03-10 13:48:10,197 DEBUG [ADK.Agent$CES] Send SIF_Unregister2010-03-10 13:48:10,197 DEBUG [ADK.Agent$CES] MsgId: B65BCDDF9431476D9F23BB2C4C67C32D2010-03-10 13:48:10,199 DEBUG [ADK.Agent$CES] Sending message (618 bytes)2010-03-10 13:48:10,199 DEBUG [ADK.Agent$CES] <SIF_Message xmlns="http://www.sifinfo.org/infrastructure/2.x" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" Version="2.2"> <SIF_Unregister> <SIF_Header> <SIF_MsgId>B65BCDDF9431476D9F23BB2C4C67C32D</SIF_MsgId> <SIF_Timestamp>2010-03-10T13:48:10-05:00</SIF_Timestamp> <SIF_Security> <SIF_SecureChannel> <SIF_AuthenticationLevel>0</SIF_AuthenticationLevel> <SIF_EncryptionLevel>0</SIF_EncryptionLevel> </SIF_SecureChannel> </SIF_Security> <SIF_SourceId>LexiaReadingAgent</SIF_SourceId> </SIF_Header> </SIF_Unregister></SIF_Message>