This document is about: SERVER 5
SWITCH TO

This page is a work in progress and could be pending updates.

Logging

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 re-enable the virus scanners and firewalls once you stop logging on Photon Servers.

日誌框架

Photon使用log4net作為一個日誌框架。

文檔:
https://logging.apache.org/log4net/

日誌文件和位置

有3種類型的日誌文件:

未管理的Photon套接字伺服器日誌

  • Content: 由無人管理的 "PhotonSocketServer.exe "核心編寫。
    所有來自Photon啟動/停止序列的狀態信息都記錄在這裡,還有來自本地核心的異常(比如:Photon本身的錯誤,來自無效客戶端數據的序列化錯誤等等)。
  • Name: "Photon-{InstanceName}-Timestamp.log"
  • Log Level Configuration: 不適用
  • Location: 默認為"/bin_WinXXX/log"。要改變日誌文件的位置,需要在 "PhotonServer.config "的每個實例節點上設置 "LogFileLocation "屬性。
    "LogFileLocation "可以是絕對路徑或與 "PhotonSocketServer.exe "的相對路徑。

例如:

XML


<Default
    MinimumTimeout="5000"
    MaximumTimeout="30000"
    LogFileLocation="..\MyLogFolder"
>

管理的CLR日誌

  • Content: 由主持您的應用程序的.NET運行時間編寫。
    所有來自CLR的狀態信息都記錄在這裡(例如:關於加載的.NET應用程序和程序集的信息),以及所有來自您的自定義.NET應用程序的未處理的異常。
  • Name: "PhotonCLR.log"
  • Log Level Configuration: 在"/deploy/bin_WinXXX/Photon.local.log4net "中配置適當的log4net附屬程序。
  • Location: 默認為"/bin_WinXXX/log"。
    要改變日誌文件的位置,請在"/deploy/bin_WinXXX/Photon.local.log4net "中配置適當的log4net附屬程序。
    您可以使用 "Photon:UnmanagedLogDirectory "屬性,其中包含 "PhotonServer.config "中 "LogFileLocation "屬性的值。

例如:

XML


<appender name="A1" type="log4net.Appender.RollingFileAppender">
    <file type="log4net.Util.PatternString" value="%property{Photon:UnmanagedLogDirectory}\\PhotonCLR.log" />            
    <!-- snip -->
</appender>

應用程序的日誌

  • Content: 每個由Photon主持的.NET應用程序都會寫下自己的應用程序日誌文件。
    它包含了應用程序的所有除錯輸出。
  • Name: "{MyApplication}.log"。
  • Log Level Configuration: 您可以在"/deploy/{MyApplication}/bin/log4net.config "中配置適當的log4net應用者。
  • Location: 默認為"/deploy/log"。
    要改變日誌文件的位置,請在"/deploy/{MyApplication}/bin/log4net.config "中配置適當的log4net應用程序。
    您可以使用 "Photon:ApplicationLogPath "屬性,該屬性默認設置為"/deploy/log",可以在您的應用程序的Setup()方法中改變。

C#

protected override void Setup()
{
    // log4net
    log4net.GlobalContext.Properties["Photon:ApplicationLogPath"] = Path.Combine(this.ApplicationRootPath, "log");
    var configFileInfo = new FileInfo(Path.Combine(this.BinaryPath, "log4net.config"));
    if (configFileInfo.Exists)
    {
        LogManager.SetLoggerFactory(Log4NetLoggerFactory.Instance);
        XmlConfigurator.ConfigureAndWatch(configFileInfo);
    }
}

XML

<?xml version="1.0" encoding="utf-8" ?>
<log4net debug="true" update="Overwrite"> 
    <appender name="LogFileAppender" type="log4net.Appender.RollingFileAppender">
        <file type="log4net.Util.PatternString" value="%property{Photon:ApplicationLogPath}\\{MyApplication}.log" />    
        <!-- snip --> 
    </appender>
    <root>
        <!-- <level value="INFO" /> -->
        <!-- <level value="DEBUG" /> -->
        <level value="ALL" />
        <appender-ref ref="LogFileAppender" /> 
    </root>
</log4net>

常見問題解答

How to write a log entry each time a client connects or disconnects?

Add this to your application's log4net.config:

XML


<logger name="Photon.SocketServer.ApplicationBase">
    <level value="DEBUG"/>
</logger>

Output from "{MyApplication}.log":

Successful connect:

2013-05-02 11:19:02,506 [23] DEBUG Photon.SocketServer.ApplicationBase [(null)] - OnInit - ConnID=17, IP 127.0.0.1 on port 4530
2013-05-02 11:19:02,506 [23] DEBUG Photon.SocketServer.ApplicationBase [(null)] - OnInit - response sent to ConnId 17 with SendResult Ok

Disconnect:

2013-05-02 11:19:07,608 [24] DEBUG Photon.SocketServer.ApplicationBase [(null)] - OnDisconnect - ConnID=17

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

Add this to your application's "log4net.config":

XML


<logger name="Photon.SocketServer.PeerBase">
    <level value="DEBUG"/>
</logger>

Output from "{MyApplication}.log":

2013-05-02 11:19:02,569 [21] DEBUG Photon.SocketServer.PeerBase [(null)] - SentOpResponse: ConnID=17, opCode=255, return=0, ChannelId=0 result=Ok size=14 bytes

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 HivePeer).

XML


<logger name="Photon.Hive.HivePeer">
    <level value="DEBUG"/>
</logger>

Output from "{MyApplication}.log":

2013-05-02 11:19:02,553 [21] DEBUG Photon.Hive.HivePeer [(null)] - OnOperationRequest. Code=255

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

C#

protected override void OnOperationRequest(OperationRequest operationRequest, SendParameters sendParameters)
{
    if (log.IsDebugEnabled)
    {
        log.DebugFormat("OnOperationRequest. Code={0}", operationRequest.OperationCode);
    }    
    // snip
}

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

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

XML


<logger name="Photon.Hive.HivePeer">
    <level value="DEBUG"/>
</logger>

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

C#

protected override void OnDisconnect(DisconnectReason reasonCode, string reasonDetail)
{
    if (log.IsDebugEnabled)
    {
        log.DebugFormat("OnDisconnect: conId={0}, reason={1}, reasonDetail={2}", this.ConnectionId, reasonCode, reasonDetail);
    }
    //     
}

Output from "{MyApplication}.log":

2013-05-02 11:19:07,639 [12] DEBUG Photon.Hive.HivePeer [(null)] - OnDisconnect: conId=17, reason=ClientDisconnect, reasonDetail=

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

0 - 326 - 0 - 0 - 830717056 - 830728351 - 11295
1 - 325 - 89 - 19 - 830715918 - 830716042 - 124
2 - 324 - 85 - 14 - 830714826 - 830714904 - 78
3 - 323 - 86 - 17 - 830712751 - 830712813 - 62
4 - 322 - 89 - 14 - 830711659 - 830711737 - 78
5 - 321 - 90 - 16 - 830710551 - 830710645 - 94
6 - 320 - 90 - 19 - 830709428 - 830709537 - 109
7 - 319 - 88 - 19 - 830708320 - 830708414 - 94
8 - 318 - 88 - 23 - 830707197 - 830707306 - 109
9 - 317 - 86 - 24 - 830706105 - 830706183 - 78
10 - 316 - 87 - 29 - 830704701 - 830704763 - 62
... etc ... 

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.

Back to top