Shoutbox

Hey,
This has started recently (I've made no changes in hardware/software) and is really bugging me.
As the title suggests, my WLM keeps randomally logging off. I've tried isolating the problem with the help of the connection log file but it left me baffled.
I've also tried to upgrade to the WLM 9 latest beta and the problem still exists.

Here's a (relevant - i think) copy-paste from the log:

code:

---

[23:41:13.01] 1934            Messenger:       Zone_StoreAdapter CStoreAdapter::Uninitialize
[23:41:13.01] 1934            Messenger:       Zone_StoreAdapter CStoreAdapterEventSink::SetStoreAdapter
[23:41:13.02] 1934            Messenger:         Zone_ConfigInfo CProductProviderMgr::_Free - UNHOOK_ALL_EVENTS for CConfigServerClientEvents
[23:41:13.02] 1934            Messenger:     Zone_HotmailService CHotmailService::DisconnectAndCleanupInternal@0281A418: Firing OnLogoff()
[23:41:13.03] 1934            Messenger:            Zone_Circles CCircleConversationManager::OnServiceLogoff@036CDB60: throwing away all helpers
[23:41:13.03] 1934            Messenger:         Zone_P2PSession CP2PMasterSession::FreeSlaveInternal@0756D158: caller attempting to free master session -- ignoring
[23:41:13.03] 1934            Messenger:         Zone_P2PSession CP2PMasterSession::FreeSlaveInternal@074E1FF8: caller attempting to free master session -- ignoring
[23:41:13.03] 1934            Messenger:         Zone_P2PSession CP2PMasterSession::FreeSlaveInternal@074E5D60: caller attempting to free master session -- ignoring
[23:41:13.03] 1934      LiveNatTrav.dll:       Zone_NatTraversal CP2PNatTraversal::Shutdown@05EA87D8:enter
[23:41:13.03] 1934      LiveNatTrav.dll:       Zone_NatTraversal CP2PNatTraversal::Shutdown@05EA87D8:enter
[23:41:13.03] 1934            Messenger:         Zone_P2PSession CP2PMasterSession::FreeSlaveInternal@0756D158: caller attempting to free master session -- ignoring
[23:41:13.03] 1934            Messenger:       Zone_P2PTransport CP2PTransport::RemoveSessionHandler@0756D158:>> removing session handler for slave session id = 0
[23:41:13.03] 1934      LiveNatTrav.dll:       Zone_NatTraversal CP2PNatTraversal::Shutdown@05E635A8:enter
[23:41:13.03] 1934      LiveNatTrav.dll:       Zone_NatTraversal CP2PNatTraversal::Shutdown@05E635A8:enter
[23:41:13.03] 1934            Messenger:         Zone_P2PSession CP2PMasterSession::FreeSlaveInternal@074E1FF8: caller attempting to free master session -- ignoring
[23:41:13.03] 1934            Messenger:       Zone_P2PTransport CP2PTransport::RemoveSessionHandler@074E1FF8:>> removing session handler for slave session id = 0
[23:41:13.03] 1934      LiveNatTrav.dll:       Zone_NatTraversal CP2PNatTraversal::Shutdown@05E65A90:enter
[23:41:13.03] 1934      LiveNatTrav.dll:       Zone_NatTraversal CP2PNatTraversal::Shutdown@05E65A90:enter
[23:41:13.03] 1934            Messenger:         Zone_P2PSession CP2PMasterSession::FreeSlaveInternal@074E5D60: caller attempting to free master session -- ignoring
[23:41:13.03] 1934            Messenger:       Zone_P2PTransport CP2PTransport::RemoveSessionHandler@074E5D60:>> removing session handler for slave session id = 0
[23:41:13.06] 1934            Messenger:              Zone_Voice CActivityManagerInstance::LogOff - Entering
[23:41:13.08] 1934            Messenger:        Zone_IM_Messages CSessionManagerInstance<class CWinSessionManagerDisp<struct IMsgrSessionManager>,struct IMsgrLock,struct DMsgrSessionManagerEvents,class CSessionInstance<class CWinSessionInstanceDisp,struct IMsgrSession,struct IMsgrLock,struct DMsgrSessionEvents>,0>::FireEvent ln 484 Firing Session Manager event directly: 12288
[23:41:13.08] 1934            Messenger:              Zone_Voice CRtcActivityMetaDataManager::OnPlatformLogoff - LOG OFF called
[23:41:13.08] 1934            Messenger:              Zone_Voice CTunneledRtcActivityProvider::OnPlatformLogoff - hrLogoff = 81000395
[23:41:13.08] 1934            Messenger:              Zone_Voice CRtcEndpointManager::CleanupEndpoints [0x36d74c0] > Cleaning up endpoints (mode=0).
[23:41:13.08] 1934            Messenger:              Zone_Voice CRtcEndpointInternal::Disable [0x37aef60] > Disabling endpoint (pIUccEndpoint=0x5745280, state=1
[23:41:13.08] 1934            Messenger:              Zone_Voice CMessengerCSTunnel::SetEventSink > Setting event sink.
[23:41:13.08] 1934      LiveNatTrav.dll:       Zone_NatTraversal CEchoClient::Shutdown:Shutting down echo client.
[23:41:13.08] 1934      LiveNatTrav.dll:       Zone_NatTraversal CEchoClient::CleanupForRestartingNatDetection:enter
[23:41:13.08] 1934      LiveNatTrav.dll:       Zone_NatTraversal CEchoClient::SetTCPNatType:nat type = 0
[23:41:13.08] 1934      LiveNatTrav.dll:       Zone_NatTraversal CEchoClient::SetUDPNatType:nat type = 0
[23:41:13.08] 1934      LiveNatTrav.dll:       Zone_NatTraversal CEchoClient::SetTCPNatType:nat type = 0
[23:41:13.08] 1934      LiveNatTrav.dll:       Zone_NatTraversal CEchoClient::SetCachedUDPNatType:nat type = 0
[23:41:13.08] 1934      LiveNatTrav.dll:       Zone_NatTraversal CEchoClient::SetCachedTCPNatType:nat type = 0
[23:41:13.08] 1934            Messenger:         Zone_ConfigInfo CSMsgrConfigLogOff
[23:52:36.03] 1934            Messenger:         Zone_ConfigInfo CStatusMenu::CStatusMenu - HOOK_EVENT for CConfigServerClientEvents and calling GetConfigInfo
[23:52:36.03] 1934            Messenger:         Zone_ConfigInfo CSMsgrGetConfigInfo - with with fRefresh=false
[23:52:36.03] 1934            Messenger:         Zone_ConfigInfo CSMsgrGetConfigInfo - not online.

---

Thanks for any help!

---

:/

I think I found an alerting entry that might have to do with the issue,
I seem to get these lines:

[20:31:10.96] 0fb4            Messenger:       Zone_P2PTransport CP2PTransport::FindBestBridge@02AE8F48: trying to find the best bridge
[20:31:10.96] 0fb4            Messenger:       Zone_P2PTransport CP2PTransport::FindBestBridge@02AE8F48:no bridge found

Every time my MSN disconnects.. any clues?

This too:

[15:29:13.21] 05b8      LiveNatTrav.dll:       Zone_NatTraversal CEchoClient::OnNatDetectionCompleted: NAT detection not DONE yet, phase = 16.
[15:29:13.21] 05b8      LiveNatTrav.dll:       Zone_NatTraversal CEchoClient::OnMessage:Received NAT detection select message (socket=1660, error=10048, event=16).
[15:29:13.21] 05b8      LiveNatTrav.dll:       Zone_NatTraversal CEchoClient::ProcessNATDetection > Phase 16
[15:29:13.21] 05b8      LiveNatTrav.dll:       Zone_NatTraversal CEchoClient::ProcessNATDetection:Failure in NAT detection, hr=0x80072740, Phase = 16
[15:29:13.21] 05b8      LiveNatTrav.dll:       Zone_NatTraversal CEchoClient::ProcessNATDetection:Aborting NAT detection hr = 0x80072740.
[15:29:13.21] 05b8      LiveNatTrav.dll:       Zone_NatTraversal CEchoClient::OnNatDetectionCompleted: NAT detection completed, phase = 19.
[15:29:13.21] 05b8      LiveNatTrav.dll:       Zone_NatTraversal CEchoClient::CloseSendSocket:closing socket 1660.
[15:29:13.21] 05b8      LiveNatTrav.dll:       Zone_NatTraversal CEchoClient::SetCachedUDPNatType:nat type = 5
[15:29:13.21] 05b8      LiveNatTrav.dll:       Zone_NatTraversal CEchoClient::SetCachedTCPNatType:nat type = 5

Finally I was able to determine the relevant lines in the log:

[16:48:44.07]     Zone_HotmailProtocol CMNSConnection::OnPNGTimer@03A07070: PNG timer fired for 1th time
[16:48:44.07]                 Zone_Net CTCPNetworkLayer::Send (03A07C58) >> sent 5 bytes on socket 2708
[16:48:44.07]     Zone_HotmailProtocol CMNSConnection::SendNetMsg@03A07070: Sent >PNG<
[16:48:59.08]     Zone_HotmailProtocol CMNSConnection::OnPNGTimer@03A07070: PNG timer fired for 1th time
[16:48:59.08]                 Zone_Net CTCPNetworkLayer::Send (03A07C58) >> sent 5 bytes on socket 2708
[16:48:59.08]     Zone_HotmailProtocol CMNSConnection::SendNetMsg@03A07070: Sent >PNG<
[16:49:14.08]     Zone_HotmailProtocol CMNSConnection::OnPNGTimer@03A07070: PNG timer fired for 1th time
[16:49:14.08]                 Zone_Net CTCPNetworkLayer::Send (03A07C58) >> sent 5 bytes on socket 2708
[16:49:14.08]     Zone_HotmailProtocol CMNSConnection::SendNetMsg@03A07070: Sent >PNG<
[16:49:16.13]                 Zone_Net CTCPNetworkLayer::OnMessage (03A07C58) (2) >> Got WM_WSASELECT_MESSAGE(1055) from WSAAsyncSelect for socket = 2708, error = 10053, event = FD_CLOS

What's happening is that sometimes my client doesn't reply to the server PNG (ping) commands. usually it returns a QNG command to acknowledge connectivity, but when it fails to do so the socket is regarded to as closed (error 10053) and the log off procedure kicks in.

I'm in contact with the WLM escalation team but with no success.
Any gurus out there who can try to troubleshoot this issue?

Certain messages may be beingblocked from your firewall (It may, for example, prevent people from pinging your IP address). Seeing as you logon to begin with, we can safely assume port 1863 to be working ok as otherwise you would not have been given the address to the login server. Now, the server does not send a PNG command, the client send it to the server. The server should respond with QNG.

I would check to see if you are able to SEND information past your firewall in this case. It may also be worth getting a packet sniffer that actually shows the data in an easy to understand way.

Thanks for the reply!

The weird thing is - I don't use any (not even Vista's) software firewall, and I already tried disabling my router's firewall. it still happened.

I'll try running a packet sniffer, do you have any recommendations on a specific one?

EDIT:
I ran CurrPorts and when disconnected it showed:

01/10/2008 07:36:36 PM Removed         msnmsgr.exe          TCP 192.168.2.100:56061    79.180.10.24:4450     
01/10/2008 07:36:36 PM Removed         msnmsgr.exe          TCP 192.168.2.100:56052    79.182.100.82:1174   
01/10/2008 07:36:49 PM Removed         msnmsgr.exe          TCP 192.168.2.100:55719    207.46.107.62:1863   
01/10/2008 07:36:49 PM Removed         msnmsgr.exe          UDP 192.168.2.100:9        *:*   

Last msnmsgr.exe ports removed only when application closed (manually by me)

01/10/2008 07:40:09 PM Removed         msnmsgr.exe          UDP 192.168.2.100:11858    *:*                   
01/10/2008 07:40:09 PM Removed         msnmsgr.exe          UDP 127.0.0.1:55069        *:*     

192.168.2.100 being my IP.

I carried on reading on the MSN protocol and now I understand the PNG commands are actually being sent in order to keep the socket alive even if idle.
So basically what's happening to me is that the commands are repeatedly being sent but do not get acknowledged by the server, causing the socket to close down and in order shuts down the connection and logs me off.

Reference: http://www.ezonate.co.uk/messenger/MSNP15:Pings

Any advice on that? :|