PluginManager initialization failed

Dear Photon Community,

I am getting Plugin errors when creating a room, using default "WebHooksPlugin1.2" and self hosted server.

Here is the Game server log:
2019-06-27 13:22:10,506 [9] ERROR Photon.Hive.HiveHostGame - Game Room 7571 is created with ErrorPlugin. message:PluginManager initialization failed.
2019-06-27 13:22:10,538 [9] WARN Photon.Hive.HiveHostGame - Game 'Room 7571' userId 'b01d3527-9708-4376-8924-0466a4303dc3' failed to create game. msg:Plugin Mismatch requested='WebHooksPlugin1.2' got ErrorPlugin with message:'PluginManager initialization failed.' -- peer:GameClientPeer: PID 1, IsConnected: True, IsDisposed: False, Last Activity: Operation 227 at UTC 6/27/2019 8:22:10 PM in Room , IP 10.0.3.103:53760,

My server version is v4.0.29.11263.

Could this be a pathing issue?
Sifang

Comments

  • Hi, @sifang_jc

    you have to check deploy/log/GSGame.log. It should contain more information, but you might be right. this is either path issue or some other config issue

    best,
    ilya
  • JohnTube
    JohnTube ✭✭✭✭✭
    Hi @sifang_jc,

    Thank you for choosing Photon!

    For more info about plugins paths for self-hosted Photon Server check out these two forum posts:
    - post1
    - post2
  • sifang_jc
    sifang_jc
    edited June 2019
    Hi chvetsov and JohnTube,

    Thank you for the reply.
    Following the two posts, I copied Plugins folder to all places, still no luck.

    I have the folders in following paths:
    deploy/Plugins/WebHooksPlugin1.2
    deploy/bin_Win64/Plugins/WebHooksPlugin1.2
    deploy/Loadbalancing/Master/Plugins/WebHooksPlugin1.2
    deploy/Loadbalancing/Master/bin/Plugins/WebHooksPlugin1.2
    deploy/Loadbalancing/GameServer/Plugins/WebHooksPlugin1.2
    deploy/Loadbalancing/GameServer/bin/Plugins/WebHooksPlugin1.2

    Also, I am watching the GameServer log, but no other error besides failing to initialize Plugin, Here is the full log:
    2019-06-28 14:35:45,464 [1] INFO Photon.LoadBalancing.GameServer.GameApplication - Setup: serverId=07c02028-01d8-4553-9d5a-3fc6d6f352e0
    2019-06-28 14:35:46,183 [1] INFO Photon.SocketServer.Diagnostics.HttpQueuePerformanceCounters - HTTP Queue performance counters successfully initialized
    2019-06-28 14:35:46,183 [1] INFO Photon.SocketServer.Diagnostics.HttpQueuePerformanceCounters - Internal HTTP Queue performance counters successfully created
    2019-06-28 14:35:46,198 [1] INFO Photon.LoadBalancing.GameServer.GameApplication - TokenCreator intialized with an expiration of 02:46:40
    2019-06-28 14:35:46,198 [1] WARN Photon.Common.LoadBalancer.LoadShedding.WorkloadController - Did not find counter Business Logic Queue
    2019-06-28 14:35:46,213 [1] WARN Photon.Common.LoadBalancer.LoadShedding.WorkloadController - Did not find counter ENet Queue
    2019-06-28 14:35:46,214 [1] WARN Photon.Common.LoadBalancer.LoadShedding.WorkloadController - Did not find counter bytes in/sec
    2019-06-28 14:35:46,214 [1] WARN Photon.Common.LoadBalancer.LoadShedding.WorkloadController - Did not find counter bytes out/sec
    2019-06-28 14:35:46,214 [1] WARN Photon.Common.LoadBalancer.LoadShedding.WorkloadController - Did not find counter ENet Threads Processing
    2019-06-28 14:35:46,214 [1] WARN Photon.Common.LoadBalancer.LoadShedding.WorkloadController - Did not find counter ENet Threads Active
    2019-06-28 14:35:46,214 [1] WARN Photon.Common.LoadBalancer.LoadShedding.WorkloadController - Did not find counter Time Spent In Server: In (ms)
    2019-06-28 14:35:46,214 [1] WARN Photon.Common.LoadBalancer.LoadShedding.WorkloadController - Did not find counter Time Spent In Server: Out (ms)
    2019-06-28 14:35:46,214 [1] WARN Photon.Common.LoadBalancer.LoadShedding.WorkloadController - Did not find counter TCP: Disconnected Peers +/sec
    2019-06-28 14:35:46,214 [1] WARN Photon.Common.LoadBalancer.LoadShedding.WorkloadController - Did not find counter TCP: Disconnected Peers (C) +/sec
    2019-06-28 14:35:46,214 [1] WARN Photon.Common.LoadBalancer.LoadShedding.WorkloadController - Did not find counter TCP: Peers
    2019-06-28 14:35:46,214 [1] WARN Photon.Common.LoadBalancer.LoadShedding.WorkloadController - Did not find counter UDP: Disconnected Peers +/sec
    2019-06-28 14:35:46,229 [1] WARN Photon.Common.LoadBalancer.LoadShedding.WorkloadController - Did not find counter UDP: Disconnected Peers (C) +/sec
    2019-06-28 14:35:46,229 [1] WARN Photon.Common.LoadBalancer.LoadShedding.WorkloadController - Did not find counter UDP: Peers
    2019-06-28 14:35:46,229 [1] WARN Photon.Common.LoadBalancer.LoadShedding.FeedbackControlSystem - Could not initialize Feedback Control System from configuration: Invalid configuration file \\vboxsvr\luckstars_backend\Photon_Server\deploy\Workload.config. Using default settings... (Could not find file '\\vboxsvr\luckstars_backend\Photon_Server\deploy\Workload.config'.)
    2019-06-28 14:35:46,248 [1] INFO Photon.Common.LoadBalancer.ServerStateManager - Watching for application state file in \\vboxsvr\luckstars_backend\Photon_Server\deploy\ServerState.txt
    2019-06-28 14:35:46,248 [1] INFO Photon.Common.LoadBalancer.ServerStateManager - Server state is set to online
    2019-06-28 14:35:46,248 [1] INFO Photon.LoadBalancing.GameServer.GameApplication - Initializing master server connection ...
    2019-06-28 14:35:46,278 [1] INFO Photon.LoadBalancing.GameServer.MasterServerConnectionBase - Connecting to master at 127.0.0.1:4520, serverId=07c02028-01d8-4553-9d5a-3fc6d6f352e0
    2019-06-28 14:35:46,308 [1] INFO Photon.SocketServer.ApplicationBase - Application start: AppId=Game; AppPath=\\vboxsvr\luckstars_backend\Photon_Server\deploy\LoadBalancing\GameServer, Type=Photon.LoadBalancing.GameServer.GameApplication
    2019-06-28 14:35:46,308 [1] INFO Photon.SocketServer.Diagnostics.CounterPublisher - CounterPublisher started publishing ExitGames.Diagnostics.Monitoring.CounterSamplePublisher to ExitGames.Diagnostics.Monitoring.CounterSampleSender
    2019-06-28 14:35:47,386 [9] INFO Photon.LoadBalancing.GameServer.MasterServerConnectionBase - Master connection established: address:127.0.0.1
    2019-06-28 14:35:47,386 [9] INFO Photon.Common.LoadBalancer.ServerStateManager - Server state is set to online
    2019-06-28 14:35:47,403 [9] INFO Photon.LoadBalancing.GameServer.OutgoingMasterServerPeer - Registering game server with address 10.0.2.248, TCP 4531, UDP 5056, WebSocket 9091, Secure WebSocket 19091, HTTP 80, ServerID 07c02028-01d8-4553-9d5a-3fc6d6f352e0, Hostname localhost, IPv6Address
    2019-06-28 14:35:47,464 [10] INFO Photon.LoadBalancing.GameServer.OutgoingMasterServerPeer - Successfully registered at master server: serverId=07c02028-01d8-4553-9d5a-3fc6d6f352e0



    2019-06-28 14:36:05,995 [10] ERROR Photon.Hive.HiveHostGame - Game Room 9466 is created with ErrorPlugin. message:PluginManager initialization failed.
    2019-06-28 14:36:06,027 [10] WARN Photon.Hive.HiveHostGame - Game 'Room 9466' userId 'b01d3527-9708-4376-8924-0466a4303dc3' failed to create game. msg:Plugin Mismatch requested='WebHooksPlugin1.2' got ErrorPlugin with message:'PluginManager initialization failed.' -- peer:GameClientPeer: PID 1, IsConnected: True, IsDisposed: False, Last Activity: Operation 227 at UTC 6/28/2019 9:36:05 PM in Room , IP 10.0.3.103:59161


    Please kindly advice!
    Sifang
  • Hi, @sifang_jc

    Try different plugin name 'Webhooks'. there is no plugins name 'WebHooksPlugin1.2'

    best,
    ilya
  • Hi, @chvetsov ,

    Thank you for the reply.

    The server came with the plugin as "deploy/Plugins/WebHooksPlugin1.2".
    Isn't the folder name "WebHooksPlugin1.2" also the plugin name?

    I tried using the name "Webhooks", but still not working.

    Sifang
  • @sifang_jc
    please remove all logs in deploy/log folder. Activate DEBUG logging and start your application and try to join.

    After that collect logs and share it with us

    best,
    ilya
  • @chvetsov

    Thank you for the suggestion.
    This is part of the Game Server log:

    2019-07-02 13:55:47,905 [11] DEBUG OperationData - OnInit - ConnID=1, data=(41 bytes) F3 00 01 06 1E 41 02 09 00 4C 6F 61 64 42 61 6C 61 6E 63 69 6E 67 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
    2019-07-02 13:55:47,905 [11] DEBUG Photon.SocketServer.ApplicationBase - OnInit - ConnID=1, IP 10.0.3.103 on port 5056, type = ENetListener
    2019-07-02 13:55:47,905 [11] DEBUG Photon.SocketServer.Protocol - Parsed init message for application LoadBalancing, client version 4.1.2.9, protocol GpBinaryV2 version 1.6 sdk 7680 using IPv6 False
    2019-07-02 13:55:47,920 [9] DEBUG Photon.SocketServer.PeerBase - OnInit - response sent to ConnId 1 with SendResult Ok
    2019-07-02 13:55:47,920 [9] DEBUG OperationData - OnInit - response sent to ConnID=1, send data=(20 bytes) F3-01-00-73-00-0E-52-65-73-70-6F-6E-73-65-4F-62-6A-65-63-74
    2019-07-02 13:55:47,936 [9] DEBUG Photon.SocketServer.PeerBase - Connection state changed from Initializing to Connected: peer=GameClientPeer: PID 1, IsConnected: False, IsDisposed: False, Last Activity: Operation 0 at UTC 1/1/0001 12:00:00 AM in Room , IP 10.0.3.103:51074,
    2019-07-02 13:55:47,936 [9] DEBUG OperationData - PBase.OnReceive - ConnID=1, data=(107 bytes) F3-06-00-00-01-01-78-00-00-00-60-9F-85-DA-3F-FE-7A-A5-68-E4-4D-CA-B8-3B-0E-DE-E6-97-24-FC-4B-0D-BF-7D-7C-97-68-AE-7D-7E-B3-20-55-3B-AA-0D-4B-1D-C4-72-64-F6-AA-88-B1-C0-DB-E9-AD-55-18-6C-D7-F0-81-FA-BF-3C-3B-88-89-18-83-CC-BB-71-09-BF-F0-B7-1F-71-88-46-BC-5C-A0-10-54-3A-83-98-82-95-7B-1B-EE-DB-F5-97-40-F2-85-20-7A-8A-C3
    2019-07-02 13:55:47,967 [9] DEBUG Photon.SocketServer.PeerBase - InitializeEncryption: conId=1, HashMode=SHA256, Paddin=PKCS7
    2019-07-02 13:55:47,967 [9] DEBUG OperationData - SentOpResponse: Peer=GameClientPeer: PID 1, IsConnected: True, IsDisposed: False, Last Activity: Operation 0 at UTC 1/1/0001 12:00:00 AM in Room , IP 10.0.3.103:51074, , opCode=0, return=0, ChannelId=0, result=Ok, data=(110 bytes) F3-07-00-00-00-2A-00-01-01-78-00-00-00-60-41-37-84-8E-4F-D1-BD-51-5C-27-DE-31-99-58-79-B2-DD-1E-D9-61-A3-54-97-A4-A0-78-FF-A8-30-AA-39-BD-29-C2-D6-4C-3D-90-3C-07-CB-B0-77-B5-AD-7E-5F-48-50-3C-E7-9E-F0-8B-6E-3F-B0-E1-94-AD-6E-0E-79-62-79-F9-21-37-1B-30-98-0F-06-81-E9-C2-82-4E-2A-AB-F3-93-D8-BC-D3-FE-99-3E-4C-79-E3-B9-34-F8-98-57
    2019-07-02 13:55:47,983 [9] DEBUG OperationData - PBase.OnReceive - ConnID=1, data=(66 bytes) F3-82-85-D4-FB-62-0C-CE-03-EA-82-C8-C7-01-3F-63-40-45-9A-35-A6-CD-30-AB-8C-1C-DB-59-83-42-CD-DC-A6-CE-45-15-73-16-5E-FA-57-58-5C-CC-D1-53-58-58-6D-21-92-9C-EE-B8-08-92-06-30-83-A6-A4-6C-04-7B-90-89
    2019-07-02 13:55:47,983 [9] DEBUG OperationData - Decrypted data: data=(55 bytes) E6-00-03-DC-73-00-04-5F-32-2E-37-E0-73-00-00-E1-73-00-24-62-30-31-64-33-35-32-37-2D-39-37-30-38-2D-34-33-37-36-2D-38-39-32-34-2D-30-34-36-36-61-34-33-30-33-64-63-33
    2019-07-02 13:55:48,014 [9] DEBUG OperationData - SentOpResponse: Peer=GameClientPeer: PID 1, IsConnected: True, IsDisposed: False, Last Activity: Operation 230 at UTC 7/2/2019 8:55:47 PM in Room , IP 10.0.3.103:51074, , opCode=230, return=0, ChannelId=0, result=Ok, data=(18 bytes) F3-83-6B-64-E1-81-0C-4D-26-01-A9-7D-F5-8B-A6-E8-6A-38
    2019-07-02 13:55:48,092 [9] DEBUG OperationData - PBase.OnReceive - ConnID=1, data=(205 bytes) F3-02-E3-00-09-FF-73-00-09-52-6F-6F-6D-20-32-39-38-31-F9-68-00-04-73-00-0C-50-6C-61-79-65-72-41-76-61-74-61-72-73-00-08-61-76-61-74-61-72-30-30-73-00-0C-50-6C-61-79-65-72-55-73-65-72-49-64-73-00-24-62-30-31-64-33-35-32-37-2D-39-37-30-38-2D-34-33-37-36-2D-38-39-32-34-2D-30-34-36-36-61-34-33-30-33-64-63-33-73-00-1A-50-75-6E-53-65-6C-66-48-6F-73-74-65-64-43-41-53-57-6F-72-6B-61-72-6F-75-6E-64-6F-01-62-FF-73-00-03-31-31-31-FA-6F-01-F8-68-00-04-62-FD-6F-01-62-FE-6F-01-62-FA-79-00-00-73-62-FF-62-14-F1-6F-01-E8-6F-01-CC-79-00-01-73-00-11-57-65-62-48-6F-6F-6B-73-50-6C-75-67-69-6E-31-2E-32-EF-6F-01-BF-69-00-00-00-2B
    2019-07-02 13:55:48,374 [9] ERROR Photon.Hive.HiveHostGame - Game Room 2981 is created with ErrorPlugin. message:PluginManager initialization failed.
    2019-07-02 13:55:48,390 [9] DEBUG OperationData - SentOpResponse: Peer=GameClientPeer: PID 1, IsConnected: True, IsDisposed: False, Last Activity: Operation 227 at UTC 7/2/2019 8:55:48 PM in Room Room 2981, IP 10.0.3.103:51074, , opCode=227, return=32751(Plugin Mismatch requested='WebHooksPlugin1.2' got ErrorPlugin with message:'PluginManager initialization failed.'), ChannelId=0, result=Ok, data=(123 bytes) F3-03-E3-7F-EF-73-00-71-50-6C-75-67-69-6E-20-4D-69-73-6D-61-74-63-68-20-72-65-71-75-65-73-74-65-64-3D-27-57-65-62-48-6F-6F-6B-73-50-6C-75-67-69-6E-31-2E-32-27-20-67-6F-74-20-45-72-72-6F-72-50-6C-75-67-69-6E-20-77-69-74-68-20-6D-65-73-73-61-67-65-3A-27-50-6C-75-67-69-6E-4D-61-6E-61-67-65-72-20-69-6E-69-74-69-61-6C-69-7A-61-74-69-6F-6E-20-66-61-69-6C-65-64-2E-27-00-00
    2019-07-02 13:55:48,405 [9] DEBUG OperationData - SentEvent: Peer=T:OutgoingMasterServerPeer,ConnId:2,ip:127.0.0.1:4520, evCode=3, ChannelId=0, result=Ok, data=(76 bytes) F3-04-03-00-07-E5-62-00-FF-73-00-09-52-6F-6F-6D-20-32-39-38-31-D4-62-00-2E-79-00-01-73-00-24-62-30-31-64-33-35-32-37-2D-39-37-30-38-2D-34-33-37-36-2D-38-39-32-34-2D-30-34-36-36-61-34-33-30-33-64-63-33-2A-6F-00-1C-62-00-1D-6F-00
    2019-07-02 13:55:48,405 [9] WARN Photon.Hive.HiveHostGame - Game 'Room 2981' userId 'b01d3527-9708-4376-8924-0466a4303dc3' failed to create game. msg:Plugin Mismatch requested='WebHooksPlugin1.2' got ErrorPlugin with message:'PluginManager initialization failed.' -- peer:GameClientPeer: PID 1, IsConnected: True, IsDisposed: False, Last Activity: Operation 227 at UTC 7/2/2019 8:55:48 PM in Room Room 2981, IP 10.0.3.103:51074,
    2019-07-02 13:55:48,437 [9] DEBUG OperationData - SentEvent: Peer=T:OutgoingMasterServerPeer,ConnId:2,ip:127.0.0.1:4520, evCode=4, ChannelId=0, result=Ok, data=(18 bytes) F3-04-04-00-01-FF-73-00-09-52-6F-6F-6D-20-32-39-38-31
    2019-07-02 13:55:48,452 [9] DEBUG OperationData - SentEvent: Peer=T:OutgoingMasterServerPeer,ConnId:2,ip:127.0.0.1:4520, evCode=1, ChannelId=0, result=Ok, data=(26 bytes) F3-04-01-00-04-16-62-00-17-69-00-00-00-00-14-69-00-00-00-01-15-69-00-00-00-00
    2019-07-02 13:55:48,452 [11] DEBUG Photon.SocketServer.ApplicationBase - OnDisconnect - ConnID=1 reasonCode=ClientDisconnect
    2019-07-02 13:55:48,452 [9] DEBUG Photon.SocketServer.PeerBase - Connection state changed from Connected to Disconnected: peer=GameClientPeer: PID 1, IsConnected: True, IsDisposed: False, Last Activity: Operation 227 at UTC 7/2/2019 8:55:48 PM in Room , IP 10.0.3.103:0,
    2019-07-02 13:55:48,452 [9] DEBUG Photon.SocketServer.PeerBase - Connection state changed from Disconnected to Disposed: peer=GameClientPeer: PID 1, IsConnected: False, IsDisposed: False, Last Activity: Operation 227 at UTC 7/2/2019 8:55:48 PM in Room , IP 10.0.3.103:0,
    2019-07-02 13:55:48,952 [10] DEBUG OperationData - SentEvent: Peer=T:OutgoingMasterServerPeer,ConnId:2,ip:127.0.0.1:4520, evCode=2, ChannelId=0, result=Ok, data=(17 bytes) F3-04-02-00-02-00-69-00-00-00-00-01-69-00-00-00-00
    2019-07-02 13:55:49,452 [10] DEBUG OperationData - SentEvent: Peer=T:OutgoingMasterServerPeer,ConnId:2,ip:127.0.0.1:4520, evCode=1, ChannelId=0, result=Ok, data=(26 bytes) F3-04-01-00-04-16-62-00-17-69-00-00-00-00-14-69-00-00-00-00-15-69-00-00-00-00
  • @sifang_jc

    Please switch debug log for 'OperationData' logger off. And send me entire log zipped to address developers@photonengine.com

    best,
    ilya
  • JohnTube
    JohnTube ✭✭✭✭✭
    Problem solved.
    We now have a "Step by Step Guide" for starting with Photon Server Plugins.
    We will also update the Configuration section for self-hosted server on the Plugins Manual page.