[SOLVED]debug server on runtime with log4net

sebako
edited June 2011 in Photon Server
Hey guys,

I am trying to get the log4net logging working, I've added all references to Log4Net in visual studion and build the project, put it on the server and the server is running fine. In my Unity client I get the "connected" message as well. But for some reason it is not creating any logfiles on the Server (Windows 2008 r2 with iis 7 + unity webplayer).

So what I tried to log is:
using System;
using System.Collections.Generic;
using System.Linq;
using System.Text;

namespace AmberServer
{
    #region using directives

    using LiteLobby;
    using ExitGames.Logging;
    using Photon.SocketServer;

    #endregion

    public class AmberPeer : LiteLobbyPeer
    {
        /// <summary>
        /// An <see cref="ILogger"/> instance used to log messages to the logging framework.
        /// </summary>
        private static readonly ILogger log = LogManager.GetCurrentClassLogger();

        #region IPeer Members

        public override void OnDisconnect()
        {
            log.Debug("CLIENT DISCONNECTED");
            //throw new NotImplementedException();
        }

        /// <summary>
        /// Initializes a new instance of the <see cref="LiteLobbyPeer"/> class.
        /// </summary>
        /// <param name="photonPeer">
        /// The photon peer.
        /// </param>
        public AmberPeer(PhotonPeer photonPeer)
            : base(photonPeer)
        {
        }

        /// <summary>
        /// The on operation request.
        /// </summary>
        /// <param name="operationRequest">
        /// The operation request.
        /// </param>
        public override void OnOperationRequest(OperationRequest operationRequest)
        {
            log.Debug("Received OperationRequest. Code: " + operationRequest.OperationCode);
        }

        #endregion
    }
}



I should see the "CLIENT DISCONNECTED" message, should I ? I have setup the log4net.config to debug as well but it is not even creating the file :(
Any Ideas what could be wrong?

Cheers

Seb

Comments

  • We recently had a similar log4net issue when we forgot to put the application binaries into a "bin" subfolder. The PhotonServer.config does not name this folder but it's expected. For some reason, the server still starts and runs without the "bin" folder but: There is no logging, as the log4net config is not found.

    Can you please verify this. If it's not the case, please attach your log files. These would be the next place to check.
  • hey Tobias,

    I've created a bin folder within the bin_Win64 directory and put the log4net.config into it, but the file is still not created. I've found another thread in the forums here so I tried that first ;) Where would the line go to tell the photon.config to use this bin folder as well and how would it look like?

    The logs "photon instance":

    1992: 16:55:20.307 - Server Starting...
    1992: 16:55:20.307 - Not using performance counters as they are not currently installed. Run the service with /InstallCounters to install them.
    1992: 16:55:20.323 - About to load runtime: PhotonHostRuntime.PhotonDomainManager from PhotonHostRuntime, Version=2.0.0.0, Culture=neutral, PublicKeyToken=02C301B61B060C4D
    1992: 16:55:20.323 - About to load CLR - versions available:
    1992: 16:55:20.323 - v2.0.50727
    1992: 16:55:20.323 - v4.0.30319
    1992: 16:55:20.323 - No preference in configuration file, will load latest.
    1992: 16:55:20.323 - About to load version: "v4.0.30319"
    1992: 16:55:20.323 - Loaded version: "v4.0.30319"
    1992: 16:55:23.716 - Photon host runtime loaded
    1992: 16:55:23.732 - License is valid.
    1992: 16:55:23.732 - Licensed for 100 concurrent connections.
    1992: 16:55:23.732 - Max Reliable Data In Transit (awaiting ACKs) per peer : 16384 bytes
    1992: 16:55:23.732 - Per peer bandwidth limit
    1992: 16:55:23.732 - Transmit Rate Limit: 128 KB/Sec
    1992: 16:55:23.732 - Limit period: 250ms
    1992: 16:55:23.732 - Limit per period: 32768 bytes
    1992: 16:55:23.732 - Max queued data for transmission per peer: 65536 bytes
    1992: 16:55:23.732 - Minimum retransmit timeout: 200
    1992: 16:55:23.732 - Minimum ENet timeout: 5000ms
    1992: 16:55:23.732 - Maximum ENet timeout: 30000ms
    1992: 16:55:23.747 - ENetHost: Using Timer Wheel
    1992: 16:55:23.747 - About to load application: Amber from AmberServer
    1992: 16:55:23.747 - Auto restart is enabled for application
    1992: 16:55:23.747 - Application will restart 10000ms after the last change detected
    1992: 16:55:23.747 - Application will restart if files matching the following are changed: "dll;config"
    1992: 16:55:23.747 - Application will NOT restart if files matching the following are changed: "log4net.config"
    1992: 16:55:27.689 - Application: "Amber" started in app domain: 2
    1992: 16:55:27.689 - About to load application: Policy from Policy.Application
    1992: 16:55:30.801 - Application: "Policy" started in app domain: 3
    1992: 16:55:30.801 - Adding TCP listener on :0.0.0.0: 4530 with a listen backlog of: 150
    1992: 16:55:30.801 - Nagle disabled
    1992: 16:55:30.801 - TCP inactivity timeout: 5000ms
    1992: 16:55:30.801 - UDP address specified as:0.0.0.0 adding listener to each available IPv4 address
    1992: 16:55:30.816 - Adding UDP listener on :88.198.117.82: 5055 with a listen backlog of: 500
    1992: 16:55:30.816 - Adding UDP listener on :127.0.0.1: 5055 with a listen backlog of: 500
    1992: 16:55:30.816 - Adding TCP Policy listener on :0.0.0.0: 843 with a listen backlog of: 150 and routing to application: "Policy"
    1992: 16:55:30.816 - TCP inactivity timeout: 5000ms
    1992: 16:55:30.816 - Adding TCP Policy listener on :0.0.0.0: 943 with a listen backlog of: 150 and routing to application: "Policy"
    1992: 16:55:30.816 - TCP inactivity timeout: 5000ms
    1992: 16:55:30.863 - Service is running...

    and the "PhotonCLR"

    2011-06-06 16:55:23,685 [ 1] DEBUG PhotonHostRuntime.PhotonDomainManager - PhotonDomainManager created
    2011-06-06 16:55:23,716 [ 1] DEBUG PhotonHostRuntime.PhotonDomainManager - PhotonDomainManager created
    2011-06-06 16:55:23,716 [ 1] DEBUG PhotonHostRuntime.PhotonDomainManager - InitializeNewDomain PhotonSocketServer.exe
    2011-06-06 16:55:23,732 [ 1] INFO eRMymtkIis3IE6Ijwv.epGUTlMZNm84XrNili - ### PhotonHostRuntime.Licensing: Getting license information...
    2011-06-06 16:55:23,732 [ 1] INFO eRMymtkIis3IE6Ijwv.epGUTlMZNm84XrNili - LICENSE: Expiration: 7/4/2011; floating license: no; max connections: 100; valid IPs: any
    2011-06-06 16:55:23,747 [ 1] INFO PhotonHostRuntime.PhotonDomainManager - CreateAppDomain Amber , AmberServer
    2011-06-06 16:55:24,576 [ 1] DEBUG PhotonHostRuntime.PhotonDomainManager - CreateAppDomain: ApplicationBase = C:\Users\Administrator\ExitGames-Photon-Server-SDK_v2-6-0\deploy
    2011-06-06 16:55:24,576 [ 1] DEBUG PhotonHostRuntime.PhotonDomainManager - CreateAppDomain: PrivateBinPath = Amber\AmberServer;Amber\AmberServer\bin;bin_Win64;Shared
    2011-06-06 16:55:24,576 [ 1] DEBUG PhotonHostRuntime.PhotonDomainManager - CreateAppDomain: ConfigurationFile = C:\Users\Administrator\ExitGames-Photon-Server-SDK_v2-6-0\deploy\Amber\AmberServer\bin\AmberServer.dll.config
    2011-06-06 16:55:27,689 [ 1] INFO PhotonHostRuntime.PhotonDomainManager - CreateAppDomain Policy , Policy.Application
    2011-06-06 16:55:27,689 [ 1] DEBUG PhotonHostRuntime.PhotonDomainManager - CreateAppDomain: ApplicationBase = C:\Users\Administrator\ExitGames-Photon-Server-SDK_v2-6-0\deploy
    2011-06-06 16:55:27,689 [ 1] DEBUG PhotonHostRuntime.PhotonDomainManager - CreateAppDomain: PrivateBinPath = Policy\Policy.Application;Policy\Policy.Application\bin;bin_Win64;Shared
    2011-06-06 16:55:27,689 [ 1] DEBUG PhotonHostRuntime.PhotonDomainManager - CreateAppDomain: ConfigurationFile = C:\Users\Administrator\ExitGames-Photon-Server-SDK_v2-6-0\deploy\Policy\Policy.Application\bin\Policy.Application.dll.config

    Thanks for help.

    Greetings,

    Seb
  • Please make sure the log4net config is in your deploy\Amber\AmberServer\bin folder.
  • okay I've put it in there, but its still the same.

    maybe anything in the config itself?
    <?xml version="1.0" encoding="utf-8" ?>
    <log4net debug="true">
    
      <appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender">
        <layout type="log4net.Layout.PatternLayout">
          <param name="ConversionPattern" value="%d{ABSOLUTE} %-5p %-30.30c{2} %m% [%t] [%x]%n" />
        </layout>
      </appender>
      
    	<!-- "normal" log file appender -->
    	<appender name="LogFileAppender" type="log4net.Appender.RollingFileAppender">
    		<param name="File" value="log\Amber.log" />
    		<param name="AppendToFile" value="true" />
    		<param name="MaxSizeRollBackups" value="1" />
    		<param name="MaximumFileSize" value="250MB" />
    		<param name="RollingStyle" value="Size" />
        <param name="LockingModel" type="log4net.Appender.FileAppender+MinimalLock" />
    		<layout type="log4net.Layout.PatternLayout">
    			<param name="ConversionPattern" value="%d [%t] %-5p %c [%x] - %m%n" />
    		</layout>
    	</appender>
    
      <!-- performance counter log file appender -->
      <appender name="CounterAppender" type="log4net.Appender.RollingFileAppender">
        <param name="File" value="log\AmberCounter.log" />
        <param name="AppendToFile" value="true" />
        <param name="MaxSizeRollBackups" value="1" />
        <param name="MaximumFileSize" value="1MB" />
        <param name="RollingStyle" value="Size" />
        <param name="StaticLogFileName" value="true" />
        <param name="LockingModel" type="log4net.Appender.FileAppender+MinimalLock" />
        <layout type="log4net.Layout.PatternLayout">
          <param name="ConversionPattern" value="%d{ABSOLUTE} %m%n" />
        </layout>
      </appender>
    
      <!-- logger -->
      <root>
        <level value="DEBUG" />
        <appender-ref ref="LogFileAppender" /> 
        <appender-ref ref="ConsoleAppender" />
    	</root>
    
      <!-- operation data logger -->
      <!-- set level to DEBUG to enable operation data logging-->
      <logger name="OperationData" additivity="false">
        <level value="DEBUG" />
        <appender-ref ref="LogFileAppender" />
      </logger>
      
      <!-- performance counter logger -->
      <!-- set level to DEBUG to enable performance counter logging-->
      <logger name="PerformanceCounter" additivity="false">
        <level value="DEBUG" />
        <appender-ref ref="CounterAppender" />
      </logger>
      
    </log4net>
    
    
    
  • The Amber.log file should be in the deploy\log folder (not deploy\bin_Win64\log).
    If not, did you overwrite LiteApplication.Setup() by any chance?
  • indeed it was the Setup override, I commented it and now it runs :)
    Thank a lot!

    Any chance you can explain the reason for it? Is the logging initialized somewhere in the Lite app? I've build my app on top of LiteLobby to use some of its
    functions.
  • The LiteApplication.Setup method initializes the logging - you got the source.
    If you override it don't forget to call base.Setup() first!
  • got it now, thank you Boris.
    gonna setup redis now! Take care! ;)
  • nice, happy coding.