1

I have been following the Christian Richards Photon Server Framework tutorial for quite a bit now, fixing errors here and there. I have came across something that doesn't even throw an error, yet it's not doing what it should be. At the end of the tutorial (photon episode 14), Christian shows us that the sub server should be registered and showing in the logs. When i build my project, then open it up with the photon control, the logs show everything but that. The logs throw no errors, but do not display what they should be. For example, the Proxy log SHOULD be saying that it received a register request but it doesn't, as well as the Login saying that 'there is no existing response handler'.

ComplexServer Log:

48068: 19:56:46.598 - Service: "Photon Socket Server" starting 48068: 19:56:46.598 - Config File: C:\Photon\deploy\bin_Win64\PhotonServer.config 48068: 19:56:46.599 - Will produce at most: 10 crash dumps 48068: 19:56:46.599 - Action: run as exe 48068: 19:56:46.600 - Server Starting... 48068: 19:56:46.600 - Tick count: 42761421 (wraps in: 49.2153 days) 48068: 19:56:46.600 - Tick count 64: 42761421 48068: 19:56:46.600 - Photon Version: 3.4.8.2804 48068: 19:56:46.600 - PID: 45344 48068: 19:56:46.600 - Config File: C:\Photon\deploy\bin_Win64\PhotonServer.config 48068: 19:56:46.601 - Will NOT log unimportant exceptions 48068: 19:56:46.604 - Not using performance counters as they are not currently installed. Run the service with /InstallCounters to install them. 48068: 19:56:46.604 - Shutdown timeout enabled: 30000ms 48068: 19:56:46.604 - Starting I/O thread pool with 2 threads 48068: 19:56:46.604 - Using Standard allocator 48068: 19:56:46.604 - Max message size: 512000 48068: 19:56:46.604 - Starting business logic thread pool with the following settings 48068: 19:56:46.604 - InitialThreads: 4 threads 48068: 19:56:46.604 - MinThreads: 4 threads 48068: 19:56:46.604 - Thread pool is fixed size 48068: 19:56:46.604 - Starting ENet thread pool with the following settings 48068: 19:56:46.604 - InitialThreads: 2 threads 48068: 19:56:46.604 - MinThreads: 2 threads 48068: 19:56:46.604 - Thread pool is fixed size 48068: 19:56:46.604 - OnlyDispatchTimers: False 48068: 19:56:46.604 - S2S: flow control: Max pending writes: 50 48068: 19:56:46.604 - S2S: flow control: Max queued buffers: 200 48068: 19:56:46.604 - S2S: flow control: Max pending writes MUX: 500 48068: 19:56:46.604 - S2S: flow control: Max queued buffers MUX: 2000 48068: 19:56:46.604 - S2S: MaxInboundMessageSize: 512000 48068: 19:56:46.604 - S2S: MaxOutboundMessageSize: 512000 48068: 19:56:46.604 - S2S: No inactivity timeout 48068: 19:56:46.607 - WebSocket S2S: MaxInboundMessageSize: 512000 48068: 19:56:46.607 - WebSocket S2S: MaxOutboundMessageSize: 512000 48068: 19:56:46.607 - WebSocket S2S: No inactivity timeout 48068: 19:56:46.607 - Max Reliable Data In Transit (awaiting ACKs) per peer : 51200 bytes 48068: 19:56:46.607 - Per peer bandwidth limit 48068: 19:56:46.607 - Transmit Rate Limit: 256 KB/Sec 48068: 19:56:46.607 - Limit period: 200ms 48068: 19:56:46.607 - Limit per period: 52428 bytes 48068: 19:56:46.607 - Max queued data for transmission per peer: 512000 bytes 48068: 19:56:46.607 - Minimum retransmit timeout: 200 48068: 19:56:46.607 - No Maximum retransmit timeout 48068: 19:56:46.607 - Minimum ENet timeout: 5000ms 48068: 19:56:46.607 - Maximum ENet timeout: 30000ms 48068: 19:56:46.607 - Max Inbound Reliable Data Queued (awaiting resends of earlier sequence numbers) per peer : 163840 bytes 48068: 19:56:46.607 - No RTT ACK adjustment timeout 48068: 19:56:46.607 - Outbound ENet: MaxInboundMessageSize: 512000 48068: 19:56:46.607 - Outbound ENet: MaxOutboundMessageSize: 512000 48068: 19:56:46.609 - GetRuntime - About to load CLR - versions available: 48068: 19:56:46.609 - v2.0.50727 48068: 19:56:46.609 - v4.0.30319 48068: 19:56:46.609 - Configuration requests: "v2.0.50727" 48068: 19:56:46.609 - About to load version: "v2.0.50727" 48068: 19:56:46.611 - About to load runtime: PhotonHostRuntime.PhotonDomainManager from PhotonHostRuntime, Culture=neutral, PublicKeyToken=02C301B61B060C4D 48068: 19:56:46.611 - CLRBaseDirectory set to "C:\Photon\deploy" 48068: 19:56:46.612 - Optimising event broadcast for 20 or more peers 48068: 19:56:46.612 - Start: About to load CLR - versions available: 48068: 19:56:46.612 - v2.0.50727 48068: 19:56:46.612 - v4.0.30319 48068: 19:56:46.612 - No preference in configuration file, will load latest. 48068: 19:56:46.612 - About to load version: "v4.0.30319" 48068: 19:56:46.613 - Loaded version: "v4.0.30319" 48068: 19:56:46.880 - Photon host runtime loaded 48068: 19:56:53.045 - LICENSE: No license file was found. Starting with Bootstrap License. 48068: 19:56:53.045 - License is valid. 48068: 19:56:53.045 - Licensed for 20 concurrent connections. 48068: 19:56:53.045 - ENet: Max Reliable Data In Transit (awaiting ACKs) per peer : 51200 bytes 48068: 19:56:53.045 - ENet: Per peer bandwidth limit 48068: 19:56:53.045 - ENet: Transmit Rate Limit: 256 KB/Sec 48068: 19:56:53.045 - ENet: Limit period: 200ms 48068: 19:56:53.045 - ENet: Limit per period: 52428 bytes 48068: 19:56:53.045 - ENet: Max queued data for transmission per peer: 512000 bytes 48068: 19:56:53.045 - ENet: Minimum retransmit timeout: 200 48068: 19:56:53.045 - ENet: Minimum timeout: 5000ms 48068: 19:56:53.045 - ENet: Maximum timeout: 30000ms 48068: 19:56:53.045 - ENet: Max Inbound Reliable Data Queued (awaiting resends of earlier sequence numbers) per peer : 163840 bytes 48068: 19:56:53.046 - About to load application: Proxy from ComplexServer 48068: 19:56:53.046 - Auto restart is enabled for application, existing connections will be terminated during restart 48068: 19:56:53.046 - Application will restart 1000ms after the last change detected 48068: 19:56:53.046 - Application will restart if files matching the following are changed: "dll;config" 48068: 19:56:53.046 - Application will NOT restart if files matching the following are changed: "log4net.config" 48068: 19:56:53.201 - Taking reference on default app domain 48068: 19:56:53.351 - Application: "Proxy" started in app domain: 2 48068: 19:56:53.351 - About to load application: Login from LoginServer 48068: 19:56:53.351 - Auto restart is enabled for application, existing connections will be terminated during restart 48068: 19:56:53.351 - Application will restart 1000ms after the last change detected 48068: 19:56:53.351 - Application will restart if files matching the following are changed: "dll;config" 48068: 19:56:53.351 - Application will NOT restart if files matching the following are changed: "log4net.config" 48068: 19:56:53.491 - Taking reference on default app domain 48068: 19:56:53.613 - Application: "Login" started in app domain: 3 48068: 19:56:53.613 - About to load application: CounterPublisher from CounterPublisher 48068: 19:56:53.613 - Auto restart is enabled for application, existing connections will be terminated during restart 48068: 19:56:53.613 - Application will restart 1000ms after the last change detected 48068: 19:56:53.613 - Application will restart if files matching the following are changed: "dll;config" 48068: 19:56:53.613 - Application will NOT restart if files matching the following are changed: "log4net.config" 48068: 19:56:53.746 - Taking reference on default app domain 48068: 19:56:53.839 - Application: "CounterPublisher" started in app domain: 4 48068: 19:56:53.839 - Adding TCP listener on :0.0.0.0: 4530 with a listen backlog of: 150 48068: 19:56:53.839 - TCP inactivity timeout: 10000ms 48068: 19:56:53.839 - TCP disconnect timeout: 120000ms 48068: 19:56:53.839 - MaxInboundMessageSize: 512000 48068: 19:56:53.839 - MaxOutboundMessageSize: 512000 48068: 19:56:53.839 - Forcing all applications ids to: "Proxy" 48068: 19:56:53.840 - Serving policy file requests from: "C:\Photon\deploy\Policy\assets\socket-policy.xml" 48068: 19:56:53.840 - Adding TCP listener on :0.0.0.0: 4531 with a listen backlog of: 150 48068: 19:56:53.840 - TCP inactivity timeout: 10000ms 48068: 19:56:53.840 - TCP disconnect timeout: 120000ms 48068: 19:56:53.840 - MaxInboundMessageSize: 512000 48068: 19:56:53.840 - MaxOutboundMessageSize: 512000 48068: 19:56:53.840 - Forcing all applications ids to: "Login" 48068: 19:56:53.840 - Serving policy file requests from: "C:\Photon\deploy\Policy\assets\socket-policy.xml" 48068: 19:56:53.840 - Adding TCP listener on :0.0.0.0: 4520 with a listen backlog of: 150 48068: 19:56:53.840 - TCP inactivity timeout: 5000ms 48068: 19:56:53.840 - TCP disconnect timeout: 120000ms 48068: 19:56:53.840 - MaxInboundMessageSize: 512000 48068: 19:56:53.840 - MaxOutboundMessageSize: 512000 48068: 19:56:53.840 - Forcing all applications ids to: "Proxy" 48068: 19:56:53.840 - MaxInboundMessageSize: 512000 48068: 19:56:53.840 - MaxOutboundMessageSize: 512000 48068: 19:56:53.840 - UDP address specified as:0.0.0.0 adding listener to each available IPv4 address 48068: 19:56:53.840 - Adding UDP listener on :192.168.56.1: 5055 with a listen backlog of: 500 48068: 19:56:53.840 - Adding UDP listener on :192.168.3.103: 5055 with a listen backlog of: 500 48068: 19:56:53.840 - Adding UDP listener on :127.0.0.1: 5055 with a listen backlog of: 500 48068: 19:56:53.840 - Forcing all applications ids to: "Login" 48068: 19:56:53.840 - MaxInboundMessageSize: 512000 48068: 19:56:53.840 - MaxOutboundMessageSize: 512000 48068: 19:56:53.840 - UDP address specified as:0.0.0.0 adding listener to each available IPv4 address 48068: 19:56:53.841 - Adding UDP listener on :192.168.56.1: 5056 with a listen backlog of: 500 48068: 19:56:53.841 - Adding UDP listener on :192.168.3.103: 5056 with a listen backlog of: 500 48068: 19:56:53.841 - Adding UDP listener on :127.0.0.1: 5056 with a listen backlog of: 500 48068: 19:56:53.841 - Adding Policy File listener on :0.0.0.0: 843 with a listen backlog of: 150 and serving Policy File: "C:\Photon\deploy\Policy\assets\socket-policy.xml" 48068: 19:56:53.841 - TCP inactivity timeout: 1000ms 48068: 19:56:53.841 - Adding Policy File listener on :0.0.0.0: 943 with a listen backlog of: 150 and serving Policy File: "C:\Photon\deploy\Policy\assets\socket-policy-silverlight.xml" 48068: 19:56:53.841 - TCP inactivity timeout: 1000ms 48068: 19:56:53.873 - Service is running...

Proxy Log:

2015-07-22 19:56:55,596 [1] INFO Photon.SocketServer.ApplicationBase [(null)] - Application start: AppId=Proxy; AppPath=C:\Photon\deploy\ComplexServer, Type=ComplexServer.ComplexProxyServer 2015-07-22 19:56:55,643 [15] DEBUG ExitGames.Diagnostics.Counter.CounterBase [(null)] - Creating AverageCounter: Name='' 2015-07-22 19:56:55,648 [15] DEBUG ExitGames.Diagnostics.Counter.CounterBase [(null)] - Creating NumericCounter: Name='' 2015-07-22 19:56:55,651 [15] DEBUG ExitGames.Diagnostics.Counter.CounterBase [(null)] - Creating CountsPerSecondCounter: Name='' 2015-07-22 19:56:55,654 [15] DEBUG ExitGames.Diagnostics.Counter.CounterBase [(null)] - Creating CountsPerSecondCounter: Name='' 2015-07-22 19:56:55,656 [15] DEBUG ExitGames.Diagnostics.Counter.CounterBase [(null)] - Creating NumericCounter: Name='' 2015-07-22 19:56:55,658 [15] DEBUG ExitGames.Diagnostics.Counter.CounterBase [(null)] - Creating CountsPerSecondCounter: Name='' 2015-07-22 19:56:55,661 [15] DEBUG ExitGames.Diagnostics.Counter.CounterBase [(null)] - Creating NumericCounter: Name='' 2015-07-22 19:56:55,663 [15] DEBUG ExitGames.Diagnostics.Counter.CounterBase [(null)] - Creating CountsPerSecondCounter: Name='' 2015-07-22 19:56:55,666 [15] DEBUG ExitGames.Diagnostics.Counter.CounterBase [(null)] - Creating CountsPerSecondCounter: Name='' 2015-07-22 19:56:55,668 [15] DEBUG ExitGames.Diagnostics.Counter.CounterBase [(null)] - Creating NumericCounter: Name='' 2015-07-22 19:56:55,670 [15] DEBUG ExitGames.Diagnostics.Counter.CounterBase [(null)] - Creating CountsPerSecondCounter: Name='' 2015-07-22 19:56:55,672 [15] DEBUG ExitGames.Diagnostics.Counter.CounterBase [(null)] - Creating CountsPerSecondCounter: Name='' 2015-07-22 19:56:55,674 [15] DEBUG ExitGames.Diagnostics.Counter.CounterBase [(null)] - Creating NumericCounter: Name='' 2015-07-22 19:56:55,686 [15] DEBUG Photon.SocketServer.ApplicationBase [(null)] - OnInit - ConnID=2, IP 127.0.0.1 on port 4520, type = TCPListener 2015-07-22 19:56:55,716 [15] DEBUG Photon.SocketServer.Protocol [(null)] - Parsed init message for application Master, client version 3.0.5, protocol GpBinaryV2 version 1.6 2015-07-22 19:56:55,723 [11] DEBUG MMO.Photon.Application.PhotonConnectionCollection [(null)] - Received init request 127.0.0.1:4520 - Photon.SocketServer.InitRequest 2015-07-22 19:56:55,725 [11] DEBUG MMO.Photon.Application.PhotonApplication [(null)] - Received init request from sub server 2015-07-22 19:56:55,758 [11] DEBUG Photon.SocketServer.ApplicationBase [(null)] - OnInit - response sent to ConnId 2 with SendResult Ok

Login Log:

2015-07-22 19:56:55,260 [14] DEBUG Photon.SocketServer.ServerToServer.TemporaryServerPeer [(null)] - OnOutboundConnectionEstablished: sending init request 2015-07-22 19:56:55,260 [1] DEBUG MMO.Photon.Application.PhotonApplication [(null)] - Connection to master at 127.0.0.1:4520 2015-07-22 19:56:55,299 [1] INFO Photon.SocketServer.ApplicationBase [(null)] - Application start: AppId=Login; AppPath=C:\Photon\deploy\ComplexServer, Type=LoginServer.LoginServer 2015-07-22 19:56:55,309 [14] DEBUG Photon.SocketServer.ServerToServer.TemporaryServerPeer [(null)] - SentInitRequest: ConnID=2, ChannelId=0, result=Ok size=41 bytes 2015-07-22 19:56:55,762 [15] DEBUG ExitGames.Diagnostics.Counter.CounterBase [(null)] - Creating AverageCounter: Name='' 2015-07-22 19:56:55,765 [15] DEBUG ExitGames.Diagnostics.Counter.CounterBase [(null)] - Creating NumericCounter: Name='' 2015-07-22 19:56:55,769 [15] DEBUG ExitGames.Diagnostics.Counter.CounterBase [(null)] - Creating CountsPerSecondCounter: Name='' 2015-07-22 19:56:55,771 [15] DEBUG ExitGames.Diagnostics.Counter.CounterBase [(null)] - Creating CountsPerSecondCounter: Name='' 2015-07-22 19:56:55,774 [15] DEBUG ExitGames.Diagnostics.Counter.CounterBase [(null)] - Creating NumericCounter: Name='' 2015-07-22 19:56:55,776 [15] DEBUG ExitGames.Diagnostics.Counter.CounterBase [(null)] - Creating CountsPerSecondCounter: Name='' 2015-07-22 19:56:55,783 [15] DEBUG ExitGames.Diagnostics.Counter.CounterBase [(null)] - Creating NumericCounter: Name='' 2015-07-22 19:56:55,785 [15] DEBUG ExitGames.Diagnostics.Counter.CounterBase [(null)] - Creating CountsPerSecondCounter: Name='' 2015-07-22 19:56:55,788 [15] DEBUG ExitGames.Diagnostics.Counter.CounterBase [(null)] - Creating CountsPerSecondCounter: Name='' 2015-07-22 19:56:55,790 [15] DEBUG ExitGames.Diagnostics.Counter.CounterBase [(null)] - Creating NumericCounter: Name='' 2015-07-22 19:56:55,792 [15] DEBUG ExitGames.Diagnostics.Counter.CounterBase [(null)] - Creating CountsPerSecondCounter: Name='' 2015-07-22 19:56:55,795 [15] DEBUG ExitGames.Diagnostics.Counter.CounterBase [(null)] - Creating CountsPerSecondCounter: Name='' 2015-07-22 19:56:55,797 [15] DEBUG ExitGames.Diagnostics.Counter.CounterBase [(null)] - Creating NumericCounter: Name='' 2015-07-22 19:56:55,813 [13] DEBUG MMO.Photon.Application.PhotonApplication [(null)] - Received init request from sub server 2015-07-22 19:56:55,904 [13] DEBUG Photon.SocketServer.ServerToServer.ServerPeerBase [(null)] - SentOpRequest: ConnID=2, opCode=0, ChannelId=0 result=Ok size=439 bytes 2015-07-22 19:56:55,907 [13] DEBUG MMO.Photon.Application.PhotonApplication [(null)] - registering sub server

So it is clearly evident this or more of a logic error in my code, opposed to a syntax. I've tried so many things to try and figure this out but nothing has worked. I had re-watched the video 2-3 times and still nothing. If anyone has any idea or can point me in the right direction that'd be great!

Cheers, Devon.

auth private
  • 1,318
  • 1
  • 9
  • 22
devon t
  • 55
  • 2
  • 8

1 Answers1

0

I wasn't able to respond to your question on the YouTube video, but found your post here.

So the problem you hit is something I didn't realize I did until later in the series. I mystically missed using a duplicate class. The issue is that I created 2 ServerEventCode, ServerParameterCode and ServerOperationCode classes. One is in ComplexServer and the other in SubServerCommon. If you look at the ServerOperationCode file, the one in SubServerCommon is the only one the Login server can use and it is set to OpCode 0. The one in ComplexServer is set to 1.

My recommendation is to go ahead and delete the ones in Complex Server (just delete the whole "Codes" folder), rebuild the project and set all references to the SubServerCommon version so they always match. There is a video later where I do the same thing, you'll just have done it a few videos in advance.

  • Unfortunately I have restarted my project, as I didn't think i'd get any help with this error. I am back at the simple server, client connects properly, the service starts, but, there is no Simple.log file anywhere. I have re-checked my PhotonApplication class, making sure the log setup was correct. I rebuilt the project, made sure all references were correct and still nothing. I made sure to check other folders within the Photon server folder just in case the log was somewhere else, but it wasn't. Right now, I'm not sure if I should continue trying to fix this or wait for your new MMO series. – devon t Jul 28 '15 at 23:30
  • The biggest thing that was tripping up other people with the log is that in the application class definition, the log location must match, case-sensitive, the same name in the log4net.config – CJR Gaming Jul 29 '15 at 16:09
  • Yeah i figured it out. For some reason, when I added the log4net.config into my project then rebuilt it, it wouldn't transfer to the directory in photon, so it wasn't actually even making the logs yet. :) Thanks for getting me back up and running, I have started the login module to hopefully get past the error I posted above. – devon t Jul 29 '15 at 16:19
  • Ok so i finished the login module. Everything is working. I did what you said by removing the codes folder in complex server. It then threw errors saying that all those values were gone, so I re-added them to the enum's in SubServerCommon, and it fixed it all. I am finally receiving the 'no existing handler' message from the logs. I REALLY appreciate you taking the time to help me with this error. I have been struggling with it for almost 2 weeks now, but finally got it. Really appreciate it. – devon t Jul 29 '15 at 18:22