ログ

ログのフレームワーク

Photonはログのフレームワークとしてlog4netを使用します。

以下のドキュメントを参照してください：
https://logging.apache.org/log4net/

ログファイルと場所

ログファイルには以下の3つの種類があります：

管理されていないPhoton Socket Serverログ

• 内容: 管理されていない「PhotonSocketServer.exe」コアにより書き込まれます。Photonの開始／停止シーケンスによるすべてのステータスメッセージはここにログされます。これにはネイティブコアの例外も含まれます（例えば：Photon自体のバグ、無効なクライアントデータに起因する直列化エラー、など）。
• 名前: 「Photon-{InstanceName}-Timestamp.log」
• ログレベルの設定: なし
• 場所
  デフォルトは「/bin_WinXXX/log」です。ログファイルの場所を変更するには、「PhotonServer.config」内の各インスタンスノードの「LogFileLocation」属性を設定します。
  「LogFileLocation」は絶対パス、または「PhotonSocketServer.exe」への相対パスのいずれも可能です。

例:

XML

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

管理されたCRLログ

• 内容: アプリケーションをホスティングする、管理された.NETランタイムによって書き込まれます。CLRからのステータスメッセージはすべてここにログされます（例：読み込まれた .NETアプリケーションおよびアセンブリ）。またカスタムの .NET アプリケーションからの、すべての未処理の例外もここにログされます。

• 名前: "PhotonCLR.log"

• ログレベルの設定: 「/deploy/bin_WinXXX/Photon.local.log4net」内で適切なlog4netアペンダーを設定してください。

• 場所: デフォルトでは「/bin_WinXXX/log」です。
  ログファイルの場所を変更するには、「/deploy/bin_WinXXX/Photon.local.log4net」内で適切なlog4netアペンダーを設定してください。「PhotonServer.config」からの「LogFileLocation」属性の値を含む「Photon:UnmanagedLogDirectory」プロパティを使用可能です。

例：

XML

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

アプリケーションログ

• 内容: Photonでホスティングされる各.NETアプリケーションは独自のアプリケーションログファイルを書きます。これにはアプリケーションのすべてのデバッグ出力が含まれます。
• 名前: "{MyApplication}.log"
• ログレベルの設定: 「/deploy/{MyApplication}/bin/log4net.config」内で適切なlog4netアペンダーを設定してください。
• 場所: デフォルトでは「/deploy/log」です。
  ログファイルの場所を変更するには、「/deploy/{MyApplication}/bin/log4net.config」内で適切なlog4netアペンダーを設定してください。
  「Photon:ApplicationLogPath" property」プロパティを使用できます。このプロパティはデフォルトでは「/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>

FAQ

クライアントが接続または切断する度にログエントリーを書く方法は？

アプリケーションのlog4net.configに以下を追加してください：

XML

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

「{MyApplication}.log」からの出力:

正常な接続:

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

切断:

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

Photonがクライアントに作業レスポンスを送信する際にログエントリーを書く方法は？

アプリケーションの「log4net.config」に以下を追加してください：

XML

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

「{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

Photonがクライアントから作業リクエストを受信した際にログエントリーを書く方法は？

この様なログは、アプリケーションのPeerクラス（HivePeerから継承します)でおこなうのが最適です。

XML

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

「{MyApplication}.log」からの出力:

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

OnOperationRequestメソッドで、ログエントリーの内容を修正可能です。

C#

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

クライアントが切断する理由は？タイムアウトのデバッグ方法は？

クライアントが切断する理由を確認するには、ピアでOnDisconnectが呼び出された場合のデバッグログエントリーを書くようにしてください。

XML

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

ピアクラス(HivePeerから継承します)では、OnDisconnect()メソッドは以下のようになります：

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);
    }
    //     
}

「{MyApplication}.log」からの出力:

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

UDPを使用している場合：「TimeoutDisconnect」の際は、以下のように「reasonDetail」にRoundTripTime履歴が含まれます。

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

各行は以下の値から成ります:

• Index -（0から49の範囲の値をとり、0は最新で49は最も古いです。直近の50個のエントリーのみが表示されます。）
• Sequence - 増加するシーケンス番号
• rtt (RoundTripTime - 最新のRTT、ミリ秒単位 - ACKの処理後、またはタイムアウトの発生後から利用可能です)
• variance (最新の偏差、ミリ秒単位)
• sentTime (コマンドが送信された時刻)
• recvTime (ACKが受信された時刻)
• cmd_rtt ( コマンドが送信されてからACKを受信するまでのタイムスパン、ミリ秒単位)

上記の例では、クライアントのcmd_rttは62ミリ秒から124ミリ秒でした。最後のコマンドに対してACKを受信しなかった後、11秒間にわたって切断しました。