Agent Reconnecting to Broker repeatedly

[neildes2]

Agent V 2.3.0.7

Agent disconnects and reconnects repeatedly. Is this by design. I think not.

This works fine with v2.3.0.2.

[wsobel]

Need to reproduce. Can You give more context?

[neildes2]

Running agent on desktop connecting to Mosquitto broker with user/pwd only. Running in debug/console mode.

cfg

Devices = Devices.xml AgentDeviceUUID = "3519a48b-814b-3425-a12d-ef250947ab3d" PreserveUUID = true Port = 5000 ReconnectInterval = 1000 BufferSize = 17 MaxAssets = 1024 SchemaVersion = 2.2 ShdrVersion = 1 SuppressIPAddress = false DisableAgentDevice = ture MonitorConfigFiles = false WorkerThreads = 2 JsonVersion = 1 ConversionRequired = true IgnoreTimestamps = true Pretty = true

Adapters {

device {

	Url = mqtt://mydomainname.com/
    MqttPort = 1883
    MqttUserName = userid
    MqttPassword = pwd
    Topics = "test/ingest/testmachine/#"
    MqttClientId = test
	

}

}

Logger Configuration

logger_config {

logging_level = trace

}

[wsobel]

I'm having trouble reproducing. Have your configuration and the connection is remaining solid.

Can you upload the entire log? I need to see what happened before to reproduce. Also, the MQTT feed would be helpful to see if something caused the disconnect cycle.

Here's my log. All looks good.

2024-04-16T14:24:11.945996Z (0x000000016ff13000) [debug] : topic_name: test/ingest/testmachine/topic
2024-04-16T14:24:11.946399Z (0x000000016ff13000) [debug] : contents: {
  "timestamp": "2023-11-06T12:12:44Z",
  "avail": "AVAILABLE"
}
2024-04-16T14:24:16.695047Z (0x000000016ff9f000) [debug] AgentConfiguration::monitorThread: Monitoring files: "/Users/will/projects/MTConnect/agent/issues/441_broker_reconnection/agent.cfg" and /Users/will/projects/MTConnect/agent/issues/441_broker_reconnection/Devices.xml, will warm start if they change.
2024-04-16T14:24:21.884092Z (0x000000016ff13000) [info] SessionImpl::requested: ReST Request: From [127.0.0.1:63255]: GET /
2024-04-16T14:24:22.067695Z (0x000000016ff13000) [info] SessionImpl::requested: ReST Request: From [127.0.0.1:63257]: GET /apple-touch-icon-precomposed.png
2024-04-16T14:24:22.069634Z (0x000000016ff13000) [warning] SessionImpl::requested: Cannot find file: /apple-touch-icon-precomposed.png
2024-04-16T14:24:22.069700Z (0x000000016ff13000) [warning] SessionImpl::requested: Cannot find file: /apple-touch-icon-precomposed.png
2024-04-16T14:24:22.069747Z (0x000000016ff13000) [warning] SessionImpl::requested->Session::fail: Operation failed: 127.0.0.1: Cannot find handler for: GET /apple-touch-icon-precomposed.png
2024-04-16T14:24:22.069787Z (0x000000016ff13000) [debug] SessionImpl::requested->Session::fail: Returning error INVALID_REQUEST: 127.0.0.1: Cannot find handler for: GET /apple-touch-icon-precomposed.png
2024-04-16T14:24:22.071779Z (0x000000016ff9f000) [info] SessionImpl::requested: ReST Request: From [127.0.0.1:63257]: GET /apple-touch-icon.png
2024-04-16T14:24:22.072731Z (0x000000016ff9f000) [warning] SessionImpl::requested: Cannot find file: /apple-touch-icon.png
2024-04-16T14:24:22.072783Z (0x000000016ff9f000) [warning] SessionImpl::requested: Cannot find file: /apple-touch-icon.png
2024-04-16T14:24:22.072828Z (0x000000016ff9f000) [warning] SessionImpl::requested->Session::fail: Operation failed: 127.0.0.1: Cannot find handler for: GET /apple-touch-icon.png
2024-04-16T14:24:22.072868Z (0x000000016ff9f000) [debug] SessionImpl::requested->Session::fail: Returning error INVALID_REQUEST: 127.0.0.1: Cannot find handler for: GET /apple-touch-icon.png
2024-04-16T14:24:26.696584Z (0x000000016ff13000) [debug] AgentConfiguration::monitorThread: Monitoring files: "/Users/will/projects/MTConnect/agent/issues/441_broker_reconnection/agent.cfg" and /Users/will/projects/MTConnect/agent/issues/441_broker_reconnection/Devices.xml, will warm start if they change.
2024-04-16T14:24:31.388915Z (0x000000016ff9f000) [info] SessionImpl::requested: ReST Request: From [127.0.0.1:63255]: GET /current
2024-04-16T14:24:36.698056Z (0x000000016ff13000) [debug] AgentConfiguration::monitorThread: Monitoring files: "/Users/will/projects/MTConnect/agent/issues/441_broker_reconnection/agent.cfg" and /Users/will/projects/MTConnect/agent/issues/441_broker_reconnection/Devices.xml, will warm start if they change.
2024-04-16T14:24:46.699794Z (0x000000016ff9f000) [debug] AgentConfiguration::monitorThread: Monitoring files: "/Users/will/projects/MTConnect/agent/issues/441_broker_reconnection/agent.cfg" and /Users/will/projects/MTConnect/agent/issues/441_broker_reconnection/Devices.xml, will warm start if they change.
2024-04-16T14:24:52.085882Z (0x000000016ff13000) [warning] SessionImpl::requested->Session::fail: Operation failed: Could not read request
2024-04-16T14:24:52.085988Z (0x000000016ff13000) [warning] SessionImpl::requested->Session::fail: Closing: The socket was closed due to a timeout - The socket was closed due to a timeout
2024-04-16T14:24:56.700958Z (0x000000016ff9f000) [debug] AgentConfiguration::monitorThread: Monitoring files: "/Users/will/projects/MTConnect/agent/issues/441_broker_reconnection/agent.cfg" and /Users/will/projects/MTConnect/agent/issues/441_broker_reconnection/Devices.xml, will warm start if they change.
2024-04-16T14:25:01.395441Z (0x000000016ff9f000) [warning] SessionImpl::requested->Session::fail: Operation failed: Could not read request
2024-04-16T14:25:01.395557Z (0x000000016ff9f000) [warning] SessionImpl::requested->Session::fail: Closing: The socket was closed due to a timeout - The socket was closed due to a timeout
2024-04-16T14:25:06.702751Z (0x000000016ff9f000) [debug] AgentConfiguration::monitorThread: Monitoring files: "/Users/will/projects/MTConnect/agent/issues/441_broker_reconnection/agent.cfg" and /Users/will/projects/MTConnect/agent/issues/441_broker_reconnection/Devices.xml, will warm start if they change.
2024-04-16T14:25:16.704579Z (0x000000016ff9f000) [debug] AgentConfiguration::monitorThread: Monitoring files: "/Users/will/projects/MTConnect/agent/issues/441_broker_reconnection/agent.cfg" and /Users/will/projects/MTConnect/agent/issues/441_broker_reconnection/Devices.xml, will warm start if they change.
2024-04-16T14:25:26.706772Z (0x000000016ff13000) [debug] AgentConfiguration::monitorThread: Monitoring files: "/Users/will/projects/MTConnect/agent/issues/441_broker_reconnection/agent.cfg" and /Users/will/projects/MTConnect/agent/issues/441_broker_reconnection/Devices.xml, will warm start if they change.
2024-04-16T14:25:36.708356Z (0x000000016ff9f000) [debug] AgentConfiguration::monitorThread: Monitoring files: "/Users/will/projects/MTConnect/agent/issues/441_broker_reconnection/agent.cfg" and /Users/will/projects/MTConnect/agent/issues/441_broker_reconnection/Devices.xml, will warm start if they change.
2024-04-16T14:25:46.709658Z (0x000000016ff13000) [debug] AgentConfiguration::monitorThread: Monitoring files: "/Users/will/projects/MTConnect/agent/issues/441_broker_reconnection/agent.cfg" and /Users/will/projects/MTConnect/agent/issues/441_broker_reconnection/Devices.xml, will warm start if they change.
2024-04-16T14:25:56.711903Z (0x000000016ff13000) [debug] AgentConfiguration::monitorThread: Monitoring files: "/Users/will/projects/MTConnect/agent/issues/441_broker_reconnection/agent.cfg" and /Users/will/projects/MTConnect/agent/issues/441_broker_reconnection/Devices.xml, will warm start if they change.
2024-04-16T14:26:06.712951Z (0x000000016ff9f000) [debug] AgentConfiguration::monitorThread: Monitoring files: "/Users/will/projects/MTConnect/agent/issues/441_broker_reconnection/agent.cfg" and /Users/will/projects/MTConnect/agent/issues/441_broker_reconnection/Devices.xml, will warm start if they change.
2024-04-16T14:26:16.715587Z (0x000000016ff9f000) [debug] AgentConfiguration::monitorThread: Monitoring files: "/Users/will/projects/MTConnect/agent/issues/441_broker_reconnection/agent.cfg" and /Users/will/projects/MTConnect/agent/issues/441_broker_reconnection/Devices.xml, will warm start if they change.
2024-04-16T14:26:26.717303Z (0x000000016ff9f000) [debug] AgentConfiguration::monitorThread: Monitoring files: "/Users/will/projects/MTConnect/agent/issues/441_broker_reconnection/agent.cfg" and /Users/will/projects/MTConnect/agent/issues/441_broker_reconnection/Devices.xml, will warm start if they change.

[neildes2]

No logs just trace output on debug console. Never sent payload. just started up and got the reconnects. V2.3.7.zip

[neildes2]

if I exchange the exe to 2.3.0.2 it works just fine

[wsobel]

I've been testing on MacOS. I'll test on windows and see if I get the same behavior. I don't have a windows machine to test with aside from my VM, so milage may vary.

[wsobel]

What version of Windows?

[wsobel]

tested on windows and can't reproduce

2024-04-16T14:59:41.875382Z (0x00000998) [warning] MAIN->Agent::start->pipeline.deliver: Could not find data item: mqtt://10.211.55.2:1883_observation_update_rate, exiting metrics
2024-04-16T14:59:41.891031Z (0x00000998) [warning] MAIN->Agent::start->pipeline.deliver: Could not find data item: mqtt://10.211.55.2:1883_asset_update_rate, exiting metrics
2024-04-16T14:59:41.891031Z (0x00000998) [warning] MAIN->Agent::start->pipeline.deliver: Could not find data item: mqtt://10.211.55.2:1883_observation_update_rate, exiting metrics
2024-04-16T14:59:41.891031Z (0x00000998) [warning] MAIN->Agent::start->pipeline.deliver: Could not find data item: mqtt://10.211.55.2:1883_asset_update_rate, exiting metrics
2024-04-16T14:59:41.891031Z (0x00000998) [warning] MAIN->Agent::start->pipeline.deliver: Could not find data item: mqtt://10.211.55.2:1883_observation_update_rate, exiting metrics
2024-04-16T14:59:41.891031Z (0x00003378) [info] : MqttClientImpl::connect: connected
2024-04-16T14:59:41.891031Z (0x00001230) [info] : MQTT ConnAck: MQTT Connected
2024-04-16T14:59:41.891031Z (0x00001230) [info] : MqttClientImpl::connect: subscribing to topics
2024-04-16T14:59:41.891031Z (0x00001230) [debug] MqttClientImpl::subscribe: Subscribing to topic: test/ingest/testmachine/#
2024-04-16T14:59:41.906664Z (0x00001230) [debug] : Subscribed to: test/ingest/testmachine/#
2024-04-16T15:01:07.408800Z (0x00003378) [debug] : topic_name: test/ingest/testmachine/topic
2024-04-16T15:01:07.409823Z (0x00003378) [debug] : contents: {
  "avail": "AVAILABLE"
}

Stable using your exec and configured to point at external broker on my mac.

[wsobel]

Configuration:

 device {
        
        Url = mqtt://10.211.55.2/
        MqttPort = 1883
        MqttUserName = testuser
        MqttPassword = testpasswd
        Topics = "test/ingest/testmachine/#"
        MqttClientId = Neil
 }

[wsobel]

Also, I'm testing with mosquitto. What broker are you working with?

[neildes2]

Mosquitto

[wsobel]

Are you using TLS or websockets?

[neildes2]

no

[wsobel]

Is the broker local or remote?

Any other info you can send me? Broker config? More logging?

[neildes2]

Mosquitto Broker is remote (aws). Could this be some sort of a timeout issue? Do the Heatbeat param etc effect broker connections?

[wsobel]

No idea. I'm trying to reproduce and have had no luck. It could be heartbeat or some other param. Do you have the aws mosquitto config? I could try to replicate.

[wsobel]

Or could you give me access to the aws broker or a similar instance?

[neildes2]

Not able to provide access to this or duplicate broker. But the cfg file is attached. It uses a pwd file for you will need to modify to use. mosquitto.txt

[robot-ranger]

posting in hopes this is a clue... we had this problem before when the agent was creating a unique client connection to the broker for the sink as well as any adapters using mqtt. iirc, both connections were using the same id and the broker was kicking one off immediately.

[wsobel]

I thought we had addressed this by changing the client id. Neil can you test with a specific client id for each connection?

[neildes2]

Unable to reproduce with agent v2.3.0.16 unless I forcibly set same clientID for both adapter connections. I believe this issue to be resolved.