Logging

Content

If you are running a local Photon Server and noticed a bad event rate then this is most likely caused by logging. For instance, we noticed that enabling both Photon Server logging and Windows Defender may cause the event rate to slow down considerably. That is why we recommend disabling all virus scanners and firewalls when enabling Photon logging so you can have the expected events rate. You can enable back the virus scanners and firewalls once you stop logging on Photon Servers.

Logging Framework

Photon uses log4net as a logging framework.

Documentation: http://logging.apache.org/log4net/

Log files and locations

There are 3 types of log files:

1. The unmananged Photon Socket Server log:

  • Content: Written by the unmanaged PhotonSocketServer.exe core. All status messages from Photon's start / stop sequence are logged here, as well as exceptions from the native core (like: bugs in Photon itself, serialization errors from invalid client data and so on).
  • Name: Photon-(InstanceName)-Timestamp.log
  • Location: /bin_WinXXX/log
  • Log level configuration: n/a
  • Change the log file location: set the "LogFileLocation" attribute on each Instance node in PhotonServer.config. The "LogFileLocation" can be either an absolute path or relative to PhotonSocketServer.exe.

Example:

2. The managed CLR log:

  • Content: Written by the managed .NET runtime that hosts your application. All status messages from the CLR are logged here (for example: information about loaded .NET applications & assemblys), and ALL unhandled exceptions from your custom .NET applications.

  • Name: PhotonCLR.log

  • Location: /bin_WinXXX/log
  • Log level configuration: configure the appropriate log4net appender in /deploy/bin_WinXXX/Photon.local.log4net.
  • Change the log file location: configure the appropriate log4net appender in /deploy/bin_WinXXX/Photon.local.log4net - you can use the "Photon:UnmanagedLogDirectory" property, which contains the value of the "LogFileLocation" attribute from PhotonServer.config.

Example:

3. The application logs:

  • Content: each .NET application that is hosted by Photon writes its own application log file. It contains all debug output from the application.
  • Name: {MyApplication}.log
  • Location: /deploy/log

  • Change the log file location: configure the appropriate log4net appender in /deploy/{MyApplication}/bin/log4net.config. You can use the "Photon:ApplicationLogPath" property, which is set to /deploy/log per default which can be changed in the Setup() method of your application.

  • Log level configuration: configure the appropriate log4net appender in /deploy/{MyApplication}/bin/log4net.config.

Example:

FAQ

How to write a log entry each time a client connects / disconnects.

Add this to your application's log4net.config:

Output from {MyApplication}.log: Successful connect:

Disconnect:

How to write a log entry when Photon sends an operation response to a client.

Add this to your application's log4net.config:

Output from (MyApplication).log:

How to write a log entry when Photon receives an operation request from a client.

This kind of logging is best done in your application's Peer class (which inherits from PeerBase).

Example for Lite:

Output from (MyApplication).log:

You can modify the contents of the log entry in OnOperationRequest method.

Example of Lite.LitePeer:

Why are my clients disconnecting? How can I debug timeouts?

There are 4 types of disconnects:

  • ClientDisconnect: the client closed the connection
  • ManagedDisconnect: the managed .NET application called PeerBase.Disconnect()
  • ServerDisconnect: an exception in Photon caused the client to disconnect. You should see exception details in the unmanaged Photon Socket Server log.
  • TimeoutDisconnect: Photon closed the connection because it did not receive some expected data after a certain timeout.

To see why your client disconnects, configure your application to write a debug log entry when OnDisconnect is called on your Peer.

Example for Lite:

In your Peer class (which inherits from PeerBase), your OnDisconnect() method should look like this:

Output from (MyApplication).log:

If you are using UDP: in case of "TimeoutDisconnect", the "reasonDetail" will contain the RoundTripTime history, like this:

index - sequence - rtt - variance - sentTime - recvTime - cmd_rtt

Each line consist of these values:

  • Index (0...49, where 0 is latest and 49 is oldest. Only the last 50 entries are shown.)
  • Sequence - an increasing sequence number
  • rtt (RoundTripTime - the current RTT in ms - available after processing the an ACK or a Timeout occurred)
  • variance (current Variance in ms)
  • sentTime (Time when command was sent)
  • recvTime (Time when ACK was recieved)
  • cmd_rtt (Timespan between the time when the command was sent and the ACK was received, in ms)

In the example above, the client had a cmd_rtt between 62ms and 124ms; it was disconnected after no ACK was received for the last command for 11 seconds.

 To Document Top