WaitForCommunicationFilterRegistration never returns

Hi

I have the following simple code to initialize a Milestone connection and register a communication filter:

VideoOS.Platform.SDK.Environment.Initialize();
VideoOS.Platform.SDK.Media.Environment.Initialize();
var credential = Util.BuildCredentialCache(serverUri, username, password, "Negotiate");
VideoOS.Platform.SDK.Environment.AddServer(false, serverUri, credential, false);
VideoOS.Platform.SDK.Environment.Login(serverUri, false);
if (VideoOS.Platform.SDK.Environment.IsLoggedIn(server))
    Log("Logged in.", EventLogEntryType.Information);
else
    throw new Exception("not connected");
MessageCommunicationManager.Start(EnvironmentManager.Instance.MasterSite.ServerId);
msgCom = MessageCommunicationManager.Get(EnvironmentManager.Instance.MasterSite.ServerId);
var filter = new CommunicationIdFilter(MessageCommunication.NewEndPointIndication);
var obj = msgCom.RegisterCommunicationFilter(messageReceiver, filter);
msgCom.WaitForCommunicationFilterRegistration(filter);

It never gets past the last line. What could be the reason for this? There is one particular Milestone installation where this problem happens, on other servers it works fine.

It seems like the registration for some reason never goes through with the server, which is quite weird unless the client for some reason cannot connect to the message communication interface.

Could you please try check the MIP logs on both the client machine under ProgramData\Milestone\MipSdk and the Event Server machine under ProgramData\Milestone\XProtect Event Server\logs and see if there is any indication of something going wrong? If nothing is found you can try set the following right after the 2 Initialize calls in your code:

EnvironmentManager.Instance.TraceMessageCommunication = true;

and then check the logs on the client again.

Finally, you can of course change your code to use the version of WaitForCommunicationFilterRegistration that takes a timeout parameter so your code won’t block forever, but that will of course most likely also mean that the message communication is not working.

Thanks for the reply.

Every time I run the code I get this in the MIPSDK logs:

2023-08-15 13:05:36.054 Error: ConnectionCheck:IsOAuthServerOnline (): Error(s): No authorization server found at: https://10.31.158.1/idp/.well-known/openid-configuration: The remote certificate is invalid according to the validation procedure.
2023-08-15 13:05:36.201 Debug: FindBestAddress (): Address was found: http://10.31.158.1/. Is OAuth server: True
2023-08-15 13:05:36.247 Debug: LoginServerOauth.CreateClient (): Creating an HTTP client using uri: http://10.31.158.1/ManagementServer/ServerCommandServiceOAuth.svc
2023-08-15 13:05:36.816 Debug: ProxyClientBase (): Creating an HTTP client using uri: http://10.31.158.1/
2023-08-15 13:05:36.847 Debug: LoginServerbase (): New token posted - Server: 10.31.158.1
2023-08-15 13:05:36.868 Debug: MessageCommunicationManager (): Start - e5d5fa94-c780-452b-9f1c-8630cd30d1b7
2023-08-15 13:05:36.871 Debug: MessageCommunication (): Init - e5d5fa94-c780-452b-9f1c-8630cd30d1b7
2023-08-15 13:05:36.874 Debug: CommunicationClient (): Init - e5d5fa94-c780-452b-9f1c-8630cd30d1b7
2023-08-15 13:05:36.880 Debug: MessageCommunication (): RegisterCommunicationFilter - MessageCommunication.NewEndPointIndication
2023-08-15 13:05:36.883 Debug: CommunicationClient background thread (): Now starting...
2023-08-15 13:05:36.888 Debug: CommunicationClient (): InitSession - e5d5fa94-c780-452b-9f1c-8630cd30d1b7
2023-08-15 13:05:38.224 Debug: CommunicationClient (): Thread - Received Message Try ..... e915f624-8916-4b52-a173-9be0a74be5ad
2023-08-15 13:05:40.246 Debug: CommunicationClient (): Thread EndpointNotFoundException
2023-08-15 13:05:40.246 Debug: CommunicationClient (): ClientClose start - e5d5fa94-c780-452b-9f1c-8630cd30d1b7
2023-08-15 13:05:40.247 Debug: CommunicationClient (): ClientClose end - e5d5fa94-c780-452b-9f1c-8630cd30d1b7
2023-08-15 13:05:45.248 Debug: CommunicationClient (): InitSession - e5d5fa94-c780-452b-9f1c-8630cd30d1b7
2023-08-15 13:05:45.250 Debug: CommunicationClient (): Thread - Received Message Try ..... e915f624-8916-4b52-a173-9be0a74be5ad
2023-08-15 13:05:47.263 Debug: CommunicationClient (): Thread EndpointNotFoundException
2023-08-15 13:05:47.264 Debug: CommunicationClient (): ClientClose start - e5d5fa94-c780-452b-9f1c-8630cd30d1b7
2023-08-15 13:05:47.264 Debug: CommunicationClient (): ClientClose end - e5d5fa94-c780-452b-9f1c-8630cd30d1b7
2023-08-15 13:05:52.265 Debug: CommunicationClient (): InitSession - e5d5fa94-c780-452b-9f1c-8630cd30d1b7
2023-08-15 13:05:52.266 Debug: CommunicationClient (): Thread - Received Message Try ..... e915f624-8916-4b52-a173-9be0a74be5ad
2023-08-15 13:05:54.280 Debug: CommunicationClient (): Thread EndpointNotFoundException
2023-08-15 13:05:54.280 Debug: CommunicationClient (): ClientClose start - e5d5fa94-c780-452b-9f1c-8630cd30d1b7
2023-08-15 13:05:54.281 Debug: CommunicationClient (): ClientClose end - e5d5fa94-c780-452b-9f1c-8630cd30d1b7
2023-08-15 13:05:59.282 Debug: CommunicationClient (): InitSession - e5d5fa94-c780-452b-9f1c-8630cd30d1b7
2023-08-15 13:05:59.283 Debug: CommunicationClient (): Thread - Received Message Try ..... e915f624-8916-4b52-a173-9be0a74be5ad
2023-08-15 13:06:01.297 Debug: CommunicationClient (): Thread EndpointNotFoundException
2023-08-15 13:06:01.298 Debug: CommunicationClient (): ClientClose start - e5d5fa94-c780-452b-9f1c-8630cd30d1b7
2023-08-15 13:06:01.298 Debug: CommunicationClient (): ClientClose end - e5d5fa94-c780-452b-9f1c-8630cd30d1b7
2023-08-15 13:06:06.299 Debug: CommunicationClient (): InitSession - e5d5fa94-c780-452b-9f1c-8630cd30d1b7
2023-08-15 13:06:06.300 Debug: CommunicationClient (): Thread - Received Message Try ..... e915f624-8916-4b52-a173-9be0a74be5ad
2023-08-15 13:06:08.310 Debug: CommunicationClient (): Thread EndpointNotFoundException
2023-08-15 13:06:08.311 Debug: CommunicationClient (): ClientClose start - e5d5fa94-c780-452b-9f1c-8630cd30d1b7
2023-08-15 13:06:08.311 Debug: CommunicationClient (): ClientClose end - e5d5fa94-c780-452b-9f1c-8630cd30d1b7

The initial cert error is the same on other servers, so that’s probably fine. However, the EndpointNotFoundException does not happen on other servers.

The event server mip log is completely empty for some reason.

What about the other log for event server (named C***.log)? Does that contain something? It seems like the client can for some reason not connect to the Event Server. Whether that is due to the Event Server being in a faulty state, a firewall is blocking or something 3rd is hard to say. What version is the VMS?

Yes it has some entries. This is the entire file for today:

2023-08-15 12:00:00 AM UTC+02:00  Info     Log                           -------------------------- Version: 22.3.29.2
2023-08-15 12:00:00 AM UTC+02:00  Info     Log                           Available MAC address:B8:CB:29:FB:04:2F
2023-08-15 12:00:00 AM UTC+02:00  Info     Log                           Available MAC address:B8:CB:29:FB:04:30
2023-08-15 12:00:00 AM UTC+02:00  Info     Log                           Local time is now: 12:00:00 AM
2023-08-15 12:00:00 AM UTC+02:00  Info     Log                           UTC time is now: 10:00:00 PM
2023-08-15 9:23:44 AM UTC+02:00  Info     StatusSessionServer           Finished loading updated VMS configuration
2023-08-15 9:24:44 AM UTC+02:00  Info     StatusSessionServer           Finished loading updated VMS configuration
2023-08-15 10:15:25 AM UTC+02:00  Info     StatusSessionServer           Finished loading updated VMS configuration
2023-08-15 10:16:25 AM UTC+02:00  Info     StatusSessionServer           Finished loading updated VMS configuration
2023-08-15 10:24:05 AM UTC+02:00  Info     StatusSessionServer           Finished loading updated VMS configuration
2023-08-15 10:25:05 AM UTC+02:00  Info     XPCORuleSystemManager         Updating 0 event types and 0 event groups from AxisEventServerPlugin.
2023-08-15 10:25:05 AM UTC+02:00  Info     XPCORuleSystemManager         Done updating event types from AxisEventServerPlugin.
2023-08-15 10:25:05 AM UTC+02:00  Info     XPCORuleSystemManager         Updating 6 event sources from AxisEventServerPlugin.
2023-08-15 10:25:05 AM UTC+02:00  Info     XPCORuleSystemManager         Done updating event sources from AxisEventServerPlugin.
2023-08-15 10:36:46 AM UTC+02:00  Info     StatusSessionServer           Finished loading updated VMS configuration
2023-08-15 10:37:46 AM UTC+02:00  Info     StatusSessionServer           Finished loading updated VMS configuration
2023-08-15 10:38:46 AM UTC+02:00  Info     XPCORuleSystemManager         Updating 0 event types and 0 event groups from AxisEventServerPlugin.
2023-08-15 10:38:46 AM UTC+02:00  Info     XPCORuleSystemManager         Done updating event types from AxisEventServerPlugin.
2023-08-15 10:38:46 AM UTC+02:00  Info     XPCORuleSystemManager         Updating 6 event sources from AxisEventServerPlugin.
2023-08-15 10:38:46 AM UTC+02:00  Info     XPCORuleSystemManager         Done updating event sources from AxisEventServerPlugin.
2023-08-15 10:38:47 AM UTC+02:00  Info     StatusSessionServer           Finished loading updated VMS configuration
2023-08-15 10:39:47 AM UTC+02:00  Info     StatusSessionServer           Finished loading updated VMS configuration
2023-08-15 10:40:48 AM UTC+02:00  Info     StatusSessionServer           Finished loading updated VMS configuration
2023-08-15 10:41:48 AM UTC+02:00  Info     StatusSessionServer           Finished loading updated VMS configuration
2023-08-15 10:42:48 AM UTC+02:00  Info     StatusSessionServer           Finished loading updated VMS configuration
2023-08-15 10:45:27 AM UTC+02:00  Info     StatusSessionServer           Finished loading updated VMS configuration
2023-08-15 10:46:27 AM UTC+02:00  Info     StatusSessionServer           Finished loading updated VMS configuration
2023-08-15 10:47:28 AM UTC+02:00  Info     StatusSessionServer           Finished loading updated VMS configuration
2023-08-15 10:48:28 AM UTC+02:00  Info     StatusSessionServer           Finished loading updated VMS configuration
2023-08-15 1:39:13 PM UTC+02:00  Info     StatusSessionServer           Finished loading updated VMS configuration
2023-08-15 1:40:13 PM UTC+02:00  Info     StatusSessionServer           Finished loading updated VMS configuration
2023-08-15 1:41:17 PM UTC+02:00  Info     StatusSessionServer           Finished loading updated VMS configuration
2023-08-15 1:44:32 PM UTC+02:00  Info     StatusSessionServer           Finished loading updated VMS configuration

VMS version is XProtect Expert 2022 R3.

Seems to be okay, so hard to say what the problem could be. Could there be a firewall blocking access maybe?

There was traffic on port 22333 so they opened it in the firewall. Supposedly it’s used for mip plugins and applications so that makes sense. The problem is the port is still not responding, even when telneting from the same machine.

Turned out I just had to restart the event server. :slight_smile: Now the port is responding and the code works.