QueueIncomingReliableWarning on the same computer

Sergiy

Hi

Not sure where to post this question, so I'll put it here

I'm monitoring my game server - total number of clients, games, etc. So every time a peer connects/disconnects, game started/finished my monitoring app gets an event with all necessary information. Monitoring app is running on the same computer where game server is working. Quite often i have QueueIncomingReliableWarning in PhotonPeer status. What can cause this? Events are not even leaving the physical computer. I'm using ExitGames-Photon-Server-SDK_v3-2-10-4248 and Photon-DotNet_v3-2-0-1_SDK.

zeppelinisgod

its prolly caused by queuing too many messages esp when they are huge in size. look into your log and see if you are sending messages that are too big or too frequently. What happens when you queue too many messages, the server still queues all the messages to be processed but this causes messages to be slow and often cause disconnect(if it is too big that the time it takes to send the actual message is longer than the disconnect timeout). if you have massive loads in your server(that's what see said :P) try splitting the server into sub-servers to handle different tasks or perhaps another thread pool/background thread to queue tasks. Also, try using message channels.

Sergiy

hmmm, each event should be no more than 150-250 bytes. Timeout is set to 5 secs. Let's say there were 10 events (should be much fewer) queued and sent at once. That gives 2.5Kbytes. Is it too much?

zeppelinisgod

Are you calling DispatchIncommingCommands()? or is the service getting called regularly?

Sergiy

Service() is getting called 10 times per second.

I changed the code so it calls VitalStatsToString(true) every time when status is changed. Here is the log:
[code2=plain]2/28/2013 12:53:36 PM QueueIncomingReliableWarning
2/28/2013 12:53:36 PM Rtt(variance): 3(3). Ms since last receive: 63. Stats elapsed: 0sec.
Longest delta between Send: 0ms Dispatch: 0ms. Longest callback OnEv: 0=0ms OnResp: 0=0ms. Calls of Send: 0 Dispatch: 0.
TotalPacketBytes: 0 TotalCommandBytes: 0 TotalPacketCount: 0 TotalCommandsInPackets: 0
TotalPacketBytes: 0 TotalCommandBytes: 0 TotalPacketCount: 0 TotalCommandsInPackets: 0

2/28/2013 12:53:37 PM QueueIncomingReliableWarning
2/28/2013 12:53:37 PM Rtt(variance): 3(3). Ms since last receive: 47. Stats elapsed: 0sec.
Longest delta between Send: 0ms Dispatch: 0ms. Longest callback OnEv: 0=0ms OnResp: 0=0ms. Calls of Send: 0 Dispatch: 0.
TotalPacketBytes: 0 TotalCommandBytes: 0 TotalPacketCount: 0 TotalCommandsInPackets: 0
TotalPacketBytes: 0 TotalCommandBytes: 0 TotalPacketCount: 0 TotalCommandsInPackets: 0[/code2]

please note that they appeared in 1 second interval. Logging was started at 2/28/2013 11:54:48 AM. Till now - 1:10PM - only these 2 warnings

Tobias

QueueIncomingReliableCommandsWarnings are warnings only: The client obviously gets quite some reliable messages and is not dispatching them before 100 are queued (for dispatch). If the warning happens a long while, it gets more and more likely your client gets more commands than it consumes (dispatches) and that (!) would be an issue over time.
You could throw in some DispatchIncomingCommands calls in-between calling Service. This will reduce the warning.

The stats you print are not telling much. Maybe you're resetting them before they get printed? Are they enabled?
Let them collect data a fews seconds.

Sergiy

So client receives info faster then it can process? pretty strange.... Can you please tell me what stats to enable and how? thanks

Tobias

> pretty strange
Nope. The client will already accept all incoming data. That's not the problem. However, the messages get queued until you dispatch them and handle them in your game loop. The alternative would be that the event and operation-result callbacks would get called any time, no matter what your code currently does.
The warning is only about the queues getting long. Nothing more.

Enable:
PhotonPeer.TrafficStatsEnabled = true;

Sergiy

Hi

Below is the part of log. What can I do to improve situation?
[code2=csharp]3/4/2013 3:36:31 PM: 127.0.0.1:21319 : Connect
3/4/2013 3:36:31 PM Rtt(variance): 0(0). Ms since last receive: 0. Stats elapsed: 0sec.
Longest delta between Send: 0ms Dispatch: 0ms. Longest callback OnEv: 0=0ms OnResp: 0=0ms. Calls of Send: 0 Dispatch: 1.
TotalPacketBytes: 19 TotalCommandBytes: 19 TotalPacketCount: 2 TotalCommandsInPackets: 2
TotalPacketBytes: 113 TotalCommandBytes: 113 TotalPacketCount: 3 TotalCommandsInPackets: 2

3/4/2013 3:41:34 PM: 127.0.0.1:21319 : QueueIncomingReliableWarning
3/4/2013 3:41:34 PM Rtt(variance): 0(0). Ms since last receive: 0. Stats elapsed: 303sec.
Longest delta between Send: 515ms Dispatch: 110ms. Longest callback OnEv: 0=0ms OnResp: 2=172ms. Calls of Send: 2776 Dispatch: 24155.
TotalPacketBytes: 5154741 TotalCommandBytes: 5154741 TotalPacketCount: 21784 TotalCommandsInPackets: 21784
TotalPacketBytes: 1534 TotalCommandBytes: 1534 TotalPacketCount: 283 TotalCommandsInPackets: 6

3/4/2013 3:41:44 PM: 127.0.0.1:21319 : QueueIncomingReliableWarning
3/4/2013 3:41:44 PM Rtt(variance): 0(0). Ms since last receive: 31. Stats elapsed: 312sec.
Longest delta between Send: 515ms Dispatch: 110ms. Longest callback OnEv: 0=0ms OnResp: 2=172ms. Calls of Send: 2865 Dispatch: 24905.
TotalPacketBytes: 5319196 TotalCommandBytes: 5319196 TotalPacketCount: 22488 TotalCommandsInPackets: 22488
TotalPacketBytes: 1579 TotalCommandBytes: 1579 TotalPacketCount: 292 TotalCommandsInPackets: 6

3/4/2013 4:08:14 PM: 127.0.0.1:21319 : QueueIncomingReliableWarning
3/4/2013 4:08:14 PM Rtt(variance): 0(0). Ms since last receive: 47. Stats elapsed: 1903sec.
Longest delta between Send: 717ms Dispatch: 141ms. Longest callback OnEv: 0=0ms OnResp: 2=172ms. Calls of Send: 17429 Dispatch: 144682.
TotalPacketBytes: 30342233 TotalCommandBytes: 30342233 TotalPacketCount: 129098 TotalCommandsInPackets: 129098
TotalPacketBytes: 8869 TotalCommandBytes: 8869 TotalPacketCount: 1750 TotalCommandsInPackets: 6

3/4/2013 4:08:14 PM: 127.0.0.1:21319 : QueueIncomingReliableWarning
3/4/2013 4:08:14 PM Rtt(variance): 0(0). Ms since last receive: 16. Stats elapsed: 1903sec.
Longest delta between Send: 717ms Dispatch: 141ms. Longest callback OnEv: 0=0ms OnResp: 2=172ms. Calls of Send: 17429 Dispatch: 144686.
TotalPacketBytes: 30344361 TotalCommandBytes: 30344361 TotalPacketCount: 129107 TotalCommandsInPackets: 129107
TotalPacketBytes: 8869 TotalCommandBytes: 8869 TotalPacketCount: 1750 TotalCommandsInPackets: 6

3/4/2013 4:43:05 PM: 127.0.0.1:21319 : QueueIncomingReliableWarning
3/4/2013 4:43:05 PM Rtt(variance): 3(3). Ms since last receive: 62. Stats elapsed: 3994sec.
Longest delta between Send: 717ms Dispatch: 156ms. Longest callback OnEv: 0=0ms OnResp: 2=172ms. Calls of Send: 36568 Dispatch: 307007.
TotalPacketBytes: 64404274 TotalCommandBytes: 64404274 TotalPacketCount: 274202 TotalCommandsInPackets: 274202
TotalPacketBytes: 18449 TotalCommandBytes: 18449 TotalPacketCount: 3666 TotalCommandsInPackets: 6

3/4/2013 7:02:44 PM: 127.0.0.1:21319 : QueueIncomingReliableWarning
3/4/2013 7:02:44 PM Rtt(variance): 3(3). Ms since last receive: 32. Stats elapsed: 12373sec.
Longest delta between Send: 717ms Dispatch: 156ms. Longest callback OnEv: 0=0ms OnResp: 2=172ms. Calls of Send: 113263 Dispatch: 1034282.
TotalPacketBytes: 219472433 TotalCommandBytes: 219472433 TotalPacketCount: 932475 TotalCommandsInPackets: 932475
TotalPacketBytes: 56839 TotalCommandBytes: 56839 TotalPacketCount: 11344 TotalCommandsInPackets: 6

3/4/2013 9:25:59 PM: 127.0.0.1:21319 : QueueIncomingReliableWarning
3/4/2013 9:25:59 PM Rtt(variance): 7(7). Ms since last receive: 0. Stats elapsed: 20968sec.
Longest delta between Send: 765ms Dispatch: 156ms. Longest callback OnEv: 0=0ms OnResp: 2=172ms. Calls of Send: 191972 Dispatch: 1817697.
TotalPacketBytes: 387695594 TotalCommandBytes: 387695594 TotalPacketCount: 1645089 TotalCommandsInPackets: 1645089
TotalPacketBytes: 96279 TotalCommandBytes: 96279 TotalPacketCount: 19232 TotalCommandsInPackets: 6

3/4/2013 9:30:13 PM: 127.0.0.1:21319 : QueueIncomingReliableWarning
3/4/2013 9:30:13 PM Rtt(variance): 7(7). Ms since last receive: 16. Stats elapsed: 21221sec.
Longest delta between Send: 765ms Dispatch: 156ms. Longest callback OnEv: 0=0ms OnResp: 2=172ms. Calls of Send: 194292 Dispatch: 1842014.
TotalPacketBytes: 392957590 TotalCommandBytes: 392957590 TotalPacketCount: 1667373 TotalCommandsInPackets: 1667373
TotalPacketBytes: 97444 TotalCommandBytes: 97444 TotalPacketCount: 19465 TotalCommandsInPackets: 6[/code2]
Thanks