OnDisconnect is not called sometimes ?

Options
BesoC
BesoC ✭✭
edited November 2013 in Photon Server
Hi all

I have a problem with OnDisconnect() not raising, maybe i have some misunderstanding in photon execution logic. Here is my code:
BasePeer:
[code2=csharp]public abstract class BasePeer : PeerBase
{
public Guid SessionID { get; protected set; }
public PeerStates PeerState { get; protected set; }
public int AccountID { get; protected set; }
public DateTime JoinDate { get; private set; }


protected SendParameters PeerSendParameters;

protected static readonly ILogger Logger = LogManager.GetCurrentClassLogger();

protected BasePeer(IRpcProtocol protocol, IPhotonPeer unmanagedPeer) : base(protocol, unmanagedPeer)
{
SessionID = Guid.Empty;
JoinDate = DateTime.Now;
PeerState = PeerStates.Connected;
DoLogDebug(
string.Format("Created peer. IP: {0}, LoggedIn: {1}, PeerState: {2}, ConnectionID: {3}", RemoteIP,
PeerState, JoinDate, ConnectionId), DebugTypes.Info);
}

public void SendEvent(EventData eventData)
{
RequestFiber.Enqueue(() =>
{
try
{
SendEvent(eventData, PeerSendParameters);
}
catch (Exception exception)
{
DoLogDebug(
string.Format(
"SendEvent Exception:{0}, AccountID: {1}, Event: {2}, LocalPort: {3}, Stack: {4}",
exception.Message, AccountID, (EventCodes) eventData.Code, LocalPort,
exception.StackTrace), DebugTypes.Error);
}
});
}

private void SendOperationResponse(OperationResponse operationResponse)
{
RequestFiber.Enqueue(() =>
{
try
{
SendOperationResponse(operationResponse, PeerSendParameters);

}
catch (Exception exception)
{
DoLogDebug(
string.Format(
"SendOperationResponse Exception:{0}, AccountID: {1}, Operation: {2}, LocalPort: {3}, Stack: {4}",
exception.Message, AccountID,
(OperationCodes) operationResponse.OperationCode, LocalPort, exception.StackTrace),
DebugTypes.Error);
}
});
}

public void EnqueueDisconnect()
{
RequestFiber.Enqueue(Disconnect);
}

protected override void OnOperationRequest(OperationRequest operationRequest, SendParameters sendParameters)
{
SendOperationResponse(new OperationResponse
{
OperationCode = operationRequest.OperationCode,
ReturnCode = 0
});
}

protected override void OnDisconnect(DisconnectReason reasonCode, string reasonDetail)
{
PeerState = PeerStates.Disconnecting;
DoLogDebug(string.Format(
"Peer disconnected. Reason: {0}, ReasonDetail: {1}", reasonCode, reasonDetail), DebugTypes.Info);
}

}[/code2]

And GamblerPeer:
[code2=csharp]public class GamblerPeer: BasePeer
{
public GamblerPeer(IRpcProtocol protocol, IPhotonPeer unmanagedPeer)
: base(protocol, unmanagedPeer)
{
// init some variables, not important
}

protected override void OnOperationRequest(OperationRequest operationRequest, SendParameters sendParameters)
{
if (PeerState == PeerStates.Disconnecting)
return;
RequestFiber.Enqueue(() =>
{
try
{
if (PeerState < PeerStates.JoinedLobby && (OperationCodes)operationRequest.OperationCode != OperationCodes.JoinLobby)
{
DoLogDebug(string.Format("Gambler invalid operation. PeerState: {0}, Operation: {1} ",
PeerState, (OperationCodes)operationRequest.OperationCode), DebugTypes.Error);
Disconnect();
return;
}

PeerSendParameters = sendParameters;
switch ((OperationCodes) operationRequest.OperationCode)
{
case OperationCodes.JoinLobby:
HandleJoinLobbyRequest(
Convert.ToString(operationRequest.Parameters[(byte) OperationParameters.SessionID]));
break;
}

base.OnOperationRequest(operationRequest, sendParameters);
}
catch (Exception exception)
{
// log exception
Disconnect();
}

});
}


private void HandleJoinLobbyRequest(string sessionID)
{
try
{
if (PeerState != PeerStates.Connected)
{
SendEvent(new EventData((byte) EventCodes.JoinLobby,
new Dictionary<byte, object>
{
{(byte) EventParameters.Result, (int) ErrorCodes.AlreadyLoggedIn}
}));
DoLogDebug(
string.Format( "JoinLobby error. PeerState: {0}, IP: {1}, Session: {2}",
PeerState, RemoteIP, sessionID, ), DebugTypes.Error);
EnqueueDisconnect();
return;
}

DAL dal = new DAL();
JoinLobbyResult joinLobbyResult = dal.JoinLobby(Guid.Parse(sessionID));
if (joinLobbyResult.ErrorCode != ErrorCodes.NoError)
{
SendEvent(new EventData((byte) EventCodes.JoinLobby,
new Dictionary<byte, object>
{
{(byte) EventParameters.Result, (int) joinLobbyResult.ErrorCode}
}));
DoLogDebug(
string.Format("JoinLobby error: {0}, Session: {1}, ConectionID: {2}",
joinLobbyResult.ErrorCode, sessionID, ConnectionId),
DebugTypes.Error);
EnqueueDisconnect();
return;
}


PersonName = joinLobbyResult.PersonName;
SessionID = joinLobbyResult.NewSessionID.Value;
AccountID = joinLobbyResult.AccountID;

bool success;
IReply<bool> reply = Lobby.AddPeerChannel.SendRequest(this);
if (!reply.Receive(RouletteParameters.LobbyTimeout, out success))
{
DoLogDebug(string.Format("AddGambler Timeout! GamblerName: {0}", PersonName), DebugTypes.Error);
Disconnect();
return;
}

if (!success)
{
SendEvent(new EventData((byte)EventCodes.DuplicatePerson, new Dictionary<byte, object>()));
DoLogDebug(string.Format("AddGambler - Duplicate person! PersonName: {0}", PersonName), DebugTypes.Error);
EnqueueDisconnect();
return;
}

PeerState = PeerStates.JoinedLobby;
SendEvent(new EventData((byte)EventCodes.JoinLobby,
new Dictionary<byte, object>
{
{(byte) EventParameters.Result, (int) ErrorCodes.NoError},
{(byte) EventParameters.Balance, joinLobbyResult.Balance},
{(byte) EventParameters.PersonName, joinLobbyResult.PersonName},
{(byte) EventParameters.SessionID, joinLobbyResult.NewSessionID.Value.ToString()}
}));

DoLogDebug(string.Format(
"Joined {0}, AccountID: {1}, IP: {2}, Session: {3}, ConnectionID: {4}",
PersonName, AccountID, RemoteIP, SessionID, ConnectionId), DebugTypes.Info);

}
catch (Exception exception)
{
DoLogDebug(
string.Format(
"HandleJoinLobbyRequest exception: {0}, Stack: {1}, ConectionID: {2}",
exception.Message, exception.StackTrace, ConnectionId),
DebugTypes.Error);
}
}

protected override void OnDisconnect(DisconnectReason reasonCode, string reasonDetail)
{
if (PeerState != PeerStates.Connected)
{
bool success;
IReply<bool> reply = Lobby.RemovePeerChannel.SendRequest(this);
if (!reply.Receive(RouletteParameters.LobbyTimeout, out success))
{
DoLogDebug(string.Format("RemoveGambler Timeout! GamblerName: {0}", PersonName), DebugTypes.Error);
}

if (!success)
{
DoLogDebug(string.Format("RemoveGambler returned false! GamblerName: {0}", PersonName), DebugTypes.Error);
}
PeerState = PeerStates.Disconnecting;
}
base.OnDisconnect(reasonCode, reasonDetail);
}
}[/code2]

Now let's imagine, that peer is trying to connect, while another peer with the same AccountID already exists in Lobby.
The log should look like
Created peer
AddGambler - Duplicate person!
Peer disconnected

Now the real log:
[code2=plain]2013-06-04 13:37:32,227 [35] INFO Created peer. IP: 46.49.120.250, LoggedIn: Connected, PeerState: 6/4/2013 1:37:32 PM, ConnectionID: 5731, ConnectionID: 5731, RemoteIP: 46.49.120.250, JoinDate: 6/4/2013 1:37:32 PM
2013-06-04 13:37:32,242 [63] ERROR AddGambler - Duplicate person! ConnectionID: 5731, RemoteIP: 46.49.120.250, JoinDate: 6/4/2013 1:37:32 PM
2013-06-04 13:37:32,242 [29] ERROR Gambler invalid operation. PeerState: Connected, Operation: LeaveLobby , ConnectionID: 5731, RemoteIP: 46.49.120.250, JoinDate: 6/4/2013 1:37:32 PM[/code2]

As you can see, there is no "Peer disconnected" entry. OnDisconnected() was not called and the peer remains in memory, though it's IsConnected property is false. I can see it with my debug utility.
Perhaps, the problem is caused by peer requested LeaveLobby operation without joining Lobby. It's not allowed and peer was forcibly disconnected by server. But i guess that OnDisconnect should be called anyways

P.S. Sorry for long post, I did my best to cut out the code :)

Comments

  • Philip
    Options
    Re "I have a problem with OnDisconnect() not raising"
    Are you using the latest Photon Server & Client SDK?

    What client sdk are you using? dotnet, flash, javascript, ...?
  • BesoC
    BesoC ✭✭
    Options
    Photon Server SDK v3.2.10.4248
    Photon Flash client. Don't remember version, but definitely not the latest one.

    Maybe I'm wrong, but as far as i can see, my issue is entirely server-side
  • BesoC
    BesoC ✭✭
    Options
    Perhaps OnDisconnect() is not raised when server explicitly calls Disconnect() on client peer??

    Disconnect() kills peer's RequestFiber immediately, so OnDisconnect() that is executing in RequstFiber, has no chance to be called?
  • BesoC
    BesoC ✭✭
    Options
    I'm almost positive that peer's OnDisconnect() is not raised when server calls Disconnect(). At least that's what i see form my logs. I need somebody from ExitGames' staff to confirm it, but looks like they don't care :(
  • chvetsov
    Options
    Well, i checked code, and should admit, that you are not right.
    I do not understand why OnDisconnect is not raised on your side.
    I do not see any errors in your code
  • BesoC
    BesoC ✭✭
    Options
    I do not understand it either, that's why i asked for your help. :) I was trying to find an error several days before posting here
    My only guess is - GamblerPeer inherits abstract class BasePeer. GamblerPeer's OnDisconnect eventually calls base.OnDisconnect. Looks like this call is not performed?
    I'm really confused and need some help and support
  • Please update to the latest Flash SDK, if possible.
    We had a problem where TCP connections were not shut down correctly in previous client/server versions, and OnDisconnect() was not called.

    Please have a look at your PhotonCLR.log as well, are there any (unhandled) exceptions?

    If you still see the error after you've updated the Flash SDK, let us know. We can either set up a debugging session, or it would be really helpful if you could create a simple test case with which we can reproduce the problem.

    Your issue sounds a lot like viewtopic.php?f=5&t=2479 - so we are definitely interested to solve this issue with Flash disconnects.
  • BesoC
    BesoC ✭✭
    Options
    Hi Nicole

    Thanks for quick reply. The topic you mentioned was created by one of my colleague, who doesn't work on this project anymore :)

    There are no unhandled exceptions in PhotonCLR, except on server shutdown:
    [code2=plain]2013-06-07 11:56:52,805 [68] ERROR PhotonHostRuntime.PhotonDomainManager - UnhandledException:
    System.AppDomainUnloadedException: Attempted to access an unloaded AppDomain.[/code2]
    this is repeated several times (22 last on last restart). Not sure if this is the number of "hanging" peers, but it may very well be

    We are using Flash SDK version 3.0.1.0. We'll update our client on Monday and I'll let you know.
  • BesoC
    BesoC ✭✭
    Options
    Hi Nicole

    We have updated to latest flash sdk. However, the problem still persists. I'm almost positive that it appears under considerable load when peer leaves with ManagedDisconnect reason. Why under load? because on test server for 3-4 connected peers everything works as it should - Disconnect() makes peer leave and closes the connection. On production server the PeerCount property in ApplicationBase is growing steadily while connected peers count is more or less the same.

    And - when shutting down test server (only 2 peers connected):

    [code2=plain]1296: 12:30:38.232 - WARNING: ***************************************************************
    1296: 12:30:38.232 - WARNING: CPhotonPeer leaks detected
    1296: 12:30:38.232 - WARNING: ***************************************************************
    1296: 12:30:38.232 -
    1296: 12:30:38.232 - Shutdown complete...
    1296: 12:30:38.232 - Service shutting down: leaks detected. Errorcode: 106
    1296: 12:30:38.233 - Service shut down complete[/code2]
  • Hi BesoC, thanks for the update. That's definitely interesting and a valuable information. We'll need to have a closer look - it's probably not easy to track down, so please give us a few days. I'll let you know when we find something.

    Thanks again for your help!
  • BesoC
    BesoC ✭✭
    Options
    Thanks, Nicole. I'll wait for your update :)
  • BesoC
    BesoC ✭✭
    Options
    Hi Nicole

    Any news regarding my case?
  • Hi!

    Yes, in a way - we have reproduced a very similar case, that is very likely related to (or the same as) your issue. Unfortunately we have not yet found the time to investigate it in detail, but it's on top of our stack for the next days.
  • BesoC
    BesoC ✭✭
    Options
    WOW!! Great news :) Looking forward for new SDK. It's vital for me :)
  • Hi! It's been some time, but I have good news (hopefully): We've found & fixed a bug around the TCP disconnects in Photon Server - I hope that it fixes your issue as well.

    I'll send a download link for a "pre-release" per PM, so that you can give it a try.
  • BesoC
    BesoC ✭✭
    Options
    Thanks Nicole.
    Downloading it right now.... What do you think - can it also fix a 'Timeout disconnect' issue - http://forum.exitgames.com/viewtopic.php?f=9&t=2902 ?
  • There was no explicit fix for timeouts, but there have been lots of improvements & general fixes for the network layer. We have not been able to reproduce any TCP timeout bugs yet, so please let us know if you find that it got better or worse. :)
  • BesoC
    BesoC ✭✭
    Options
    WOW!! I'm jumping keeping my fingers crossed even on my legs :D
  • BesoC
    Options
    Well after a week of hard testing i can say that Disconnect() now is called every time it should be called. This issue seems to be gone. Great job!! Hooray 8-) :D 8-) !!!

    Just one thing... TimeoutDisconnect issue still persists, if only you could do something about it too...... then Photon server would be absolutely perfect :)
  • Hi Besoc,

    thanks for your feedback! I'm really glad to hear that the OnDisconnect() issue is finally resolved. :)

    We'll see if we can do anything about the timeouts, but it's not so simple and I can't promise anything yet.
  • qaz
    Options
    OnDisconnect is not called sometimes when i disconnect peer from server-side code manually.
    Does this bug still exist in this version?

    == Core ==
    PhotonSocketServer.2010
    x64 Unicode Release
    BuildDate: 2013-02-08 15:03:18
    Version: 3.2.6.2037
    SVN repository: photon-socketserver
    SVN revisions of...
    ... this project: 2037
    == SDK ==
    BuildDate: 2013-02-08 15:19:51
    Version: 3.2.10.4248
    SVN repository: photon-socketserver-sdk
    SVN revisions of...
    ... this project: 4248
  • Yes.

    A new version of the Photon Server SDK will be available in the next days, which will also contain a bug fix for this issue.
  • qaz
    Options
    Thanks :)
  • BesoC
    Options
    Hi Nicole

    Any news about new version?