로깅

프레임워크 로깅

Photon은 프레임워크 로깅을 위해 log4net을 사용합니다.

문서:
https://logging.apache.org/log4net/

로그 파일과 위치

로그 파일에는 3가지의 유형이 있습니다:

관리되지 않는\ Photon 소켓 서버 로그

• 내용: 관리되지 않는 "PhotonSocketServer.exe" 코어가 쓰게 됩니다.
  Photon의 시작/중지 시퀀스의 모든 상태 메시지와 네이티브 코어의 예외(예: Photon 자체의 버그, 유효하지 않은 클라이언트 데이터의 직렬화 오류 등)가 여기에 기록됩니다.
• 이름: "Photon-{InstanceName}-Timestamp.log"
• 로그 수준 환경 구성: n/a
• 위치: 기본 값은 "/bin_WinXXX/log" 입니다. 로그 파일 위치를 바꾸시려면 "PhotonServer.config"에 있는 각각의 인스턴스 노드의 "LogFileLocation" 속성을 설정합니다.
  "LogFileLocation"은 절대 경로 또는 "PhotonSocketServer.exe"에 대한 상대 경로가 될 수 있습니다.

예제:

XML

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

관리되는 CLR 로그

• 내용: 애플리케이션을 호스팅하고 있는 관리되는 .NET 런타임에 의해서 작성됩니다.
  CLR의 모든 상태 메시지(예: 로드된 .NET 애플리케이션 & 어셈블리에 대한 정보)와 사용자 정의 .NET 애플리케이션에서 처리되지 않은 모든 예외가 기록됩니다.
• 이름: "PhotonCLR.log"
• 로그 수준 환경 구성: "/deploy/bin_WinXXX/Photon.local.log4net"에서 적절한 log4net appender를 구성합니다.
• 위치: 기본값은 "/bin_WinXXX/log"입니다.
  로그 파일 위치를 변경하시려면 "/deploy/bin_WinXXX/Photon.local.log4net"에서 적절한 log4net appender를 구성하세요.
  "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 appender를 구성할 수 있습니다.
• 위치: 기본값은 "/deploy/log"입니다.
  로그 파일 위치를 구성하려면 "/deploy/{MyApplication}/bin/log4net.config"에서 적절한 log4net appender를 구성하세요.
  애플리케이션의 Setup() 메소드 내에서 변경할 수 있는 기본값 별로 "/deploy/log"로 설정하는 "Photon:ApplicationLogPath" 속성을 사용할 수 있습니다.

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>

자주 문의하는 질문

클라이언트가 연결하거나 연결을 끊을 때마다 로그는 어떻게 생성하나요?

어플리케이션의 "log4net.config"에 아래 내용을 추가합니다:

XML

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

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

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

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

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>

Peer 클래스(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=

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

각 라인은 다음들의 값으로 구성되어 있습니다:

• 인덱스 (0...49, 0이 가장 최신이고 49는 가장 오래된 것입니다. 최신의 50개 항목만 보여집니다.)
• 시퀀스 - 증가하는 일련번호
• rtt (RoundTripTime - ms로 현재 RTT - ACK 또는 타임아웃이 발생 처리된 이후 사용가능)
• variance (ms 로 현재 Variance)
• sentTime (명령이 전송된 시간)
• recvTime (ACK가 수신된 시간)
• cmd_rtt (ms 단위로 명령이 전송되고 ACK가 수신된 시간 사이의 간격)

위의 예에서 클라이언트는 62ms에서 124ms 사이에 cmd_rtt를 가지고 있었습니다. 마지막 명령에 대해 11초 동안 ACK를 수신하지 않은 후 연결이 끊어졌습니다.