Announcement

Collapse
No announcement yet.

MCSMqtt Crashes often and restarts

Collapse
X
 
  • Filter
  • Time
  • Show
Clear All
new posts

    MCSMqtt Crashes often and restarts

    I wouldn't worry about this much, except that it takes ~15 seconds to start, so the crash causes missed events/changes.


    Code:
    May 26 17:32:56 HS4 mono[1943]: Unhandled Exception
    May 26 17:32:56 HS4 mono[1943]: Exception of type 'uPLibrary.Networking.M2Mqtt.Exceptions.MqttClientException' was thrown. : at uPLibrary.Networking.M2Mqtt.Messages.MqttMsgPublish.GetBytes (System.Byte protocolVersion) [0x0003c] in <b97736681d874115a5b41552b43c6e7f>:0
    May 26 17:32:56 HS4 mono[1943]: at uPLibrary.Networking.M2Mqtt.MqttClient.Send (uPLibrary.Networking.M2Mqtt.Messages.MqttMsgBase msg) [0x00017] in <b97736681d874115a5b41552b43c6e7f>:0
    May 26 17:32:56 HS4 mono[1943]: at uPLibrary.Networking.M2Mqtt.MqttClient.ProcessInflightThread () [0x001eb] in <b97736681d874115a5b41552b43c6e7f>:0
    May 26 17:32:56 HS4 mono[1943]: at System.Threading.ThreadHelper.ThreadStart_Context (System.Object state) [0x00014] in <162bccb5b7ae4c18b9c0cff8fdc3dfbc>:0
    May 26 17:32:56 HS4 mono[1943]: at System.Threading.ExecutionContext.RunInternal (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x00071] in <162bccb5b7ae4c18b9c0cff8fdc3dfbc>:0
    May 26 17:32:56 HS4 mono[1943]: at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x00000] in <162bccb5b7ae4c18b9c0cff8fdc3dfbc>:0
    May 26 17:32:56 HS4 mono[1943]: at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state) [0x0002b] in <162bccb5b7ae4c18b9c0cff8fdc3dfbc>:0
    May 26 17:32:56 HS4 mono[1943]: at System.Threading.ThreadHelper.ThreadStart () [0x00008] in <162bccb5b7ae4c18b9c0cff8fdc3dfbc>:0
    May 26 17:32:56 HS4 mono[1943]: [ERROR] FATAL UNHANDLED EXCEPTION: uPLibrary.Networking.M2Mqtt.Exceptions.MqttClientException: Exception of type 'uPLibrary.Networking.M2Mqtt.Exceptions.MqttClientException' was thrown.
    May 26 17:32:56 HS4 mono[1943]: at uPLibrary.Networking.M2Mqtt.Messages.MqttMsgPublish.GetBytes (System.Byte protocolVersion) [0x0003c] in <b97736681d874115a5b41552b43c6e7f>:0
    May 26 17:32:56 HS4 mono[1943]: at uPLibrary.Networking.M2Mqtt.MqttClient.Send (uPLibrary.Networking.M2Mqtt.Messages.MqttMsgBase msg) [0x00017] in <b97736681d874115a5b41552b43c6e7f>:0
    May 26 17:32:56 HS4 mono[1943]: at uPLibrary.Networking.M2Mqtt.MqttClient.ProcessInflightThread () [0x001eb] in <b97736681d874115a5b41552b43c6e7f>:0
    May 26 17:32:56 HS4 mono[1943]: at System.Threading.ThreadHelper.ThreadStart_Context (System.Object state) [0x00014] in <162bccb5b7ae4c18b9c0cff8fdc3dfbc>:0
    May 26 17:32:56 HS4 mono[1943]: at System.Threading.ExecutionContext.RunInternal (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x00071] in <162bccb5b7ae4c18b9c0cff8fdc3dfbc>:0
    May 26 17:32:56 HS4 mono[1943]: at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x00000] in <162bccb5b7ae4c18b9c0cff8fdc3dfbc>:0
    May 26 17:32:56 HS4 mono[1943]: at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state) [0x0002b] in <162bccb5b7ae4c18b9c0cff8fdc3dfbc>:0
    May 26 17:32:56 HS4 mono[1943]: at System.Threading.ThreadHelper.ThreadStart () [0x00008] in <162bccb5b7ae4c18b9c0cff8fdc3dfbc>:0
    May 26 17:33:04 HS4 mono[1157]: 05:33:04:4939:[Warning]->I/O interface mcsMQTT is down, executable is not running, restarting ...
    May 26 17:33:04 HS4 mono[2090]: Connecting to HomeSeer...
    May 26 17:33:04 HS4 mono[2090]: Connected to HomeSeer
    May 26 17:33:04 HS4 mono[2090]: Waiting for initialization...
    May 26 17:33:04 HS4 mono[1157]: 05:33:04:6081:[Info]->Plugin mcsMQTT with instance mcsMQTT has connected. IP:127.0.0.1:42766

    #2
    It means there was an issue with mcsMQTT MQTT client connecting to the IP of the Broker that as setup on the MQTT Page, General tab. Does this help with diagnosis? There may be more info in the mcsMQTT Debug log if it has been enabled from the top of the MQTT Page, General tab. The debug is in \data\mcsMQT\mcsMQTT Debut.txt.

    Comment


      #3
      Originally posted by Michael McSharry View Post
      It means there was an issue with mcsMQTT MQTT client connecting to the IP of the Broker that as setup on the MQTT Page, General tab. Does this help with diagnosis? There may be more info in the mcsMQTT Debug log if it has been enabled from the top of the MQTT Page, General tab. The debug is in \data\mcsMQT\mcsMQTT Debut.txt.
      It's been the same configuration on that page since 2018 or 2019. The IP of MQTT nor the credentials have ever changed. The MQTT host even runs on the same proxmox host.
      I'll watch the debug log and see if I can't catch anything useful.


      Comment


        #4
        Originally posted by Michael McSharry View Post
        It means there was an issue with mcsMQTT MQTT client connecting to the IP of the Broker that as setup on the MQTT Page, General tab. Does this help with diagnosis? There may be more info in the mcsMQTT Debug log if it has been enabled from the top of the MQTT Page, General tab. The debug is in \data\mcsMQT\mcsMQTT Debut.txt.
        Looking through the debug logs, every single one of them is after a device with a "#2" in the name, is published:

        05/26/2022 19:29:46 184478 | ApplyExpression lower("hs4/Hallway/PIR/Motion Forum Home Security") Result=hs4/hallway/pir/motion Forum home security
        05/26/2022 19:29:46 184478 | Publish hs4/hallway/pir/motion Forum home security=8
        05/26/2022 19:29:46 184480 | at uPLibrary.Networking.M2Mqtt.Messages.MqttMsgPublish.GetBytes (System.Byte protocolVersion) [0x0003c] in <b97736681d874115a5b41552b43c6e7f>:0
        at uPLibrary.Networking.M2Mqtt.MqttClient.Send (uPLibrary.Networking.M2Mqtt.Messages.MqttMsgBase msg) [0x00017] in <b97736681d874115a5b41552b43c6e7f>:0
        at uPLibrary.Networking.M2Mqtt.MqttClient.ProcessInflightThread () [0x001eb] in <b97736681d874115a5b41552b43c6e7f>:0
        at System.Threading.ThreadHelper.ThreadStart_Context (System.Object state) [0x00014] in <162bccb5b7ae4c18b9c0cff8fdc3dfbc>:0
        at System.Threading.ExecutionContext.RunInternal (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x00071] in <162bccb5b7ae4c18b9c0cff8fdc3dfbc>:0
        at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x00000] in <162bccb5b7ae4c18b9c0cff8fdc3dfbc>:0
        at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state) [0x0002b] in <162bccb5b7ae4c18b9c0cff8fdc3dfbc>:0

        05/26/2022 19:31:50 83060 | ApplyExpression lower("hs4/Den/PIR/Motion Forum Home Security") Result=hs4/den/pir/motion Forum home security
        05/26/2022 19:31:50 83060 | Publish hs4/den/pir/motion Forum home security=8
        05/26/2022 19:31:50 83064 | at uPLibrary.Networking.M2Mqtt.Messages.MqttMsgPublish.GetBytes (System.Byte protocolVersion) [0x0003c] in <b97736681d874115a5b41552b43c6e7f>:0
        at uPLibrary.Networking.M2Mqtt.MqttClient.Send (uPLibrary.Networking.M2Mqtt.Messages.MqttMsgBase msg) [0x00017] in <b97736681d874115a5b41552b43c6e7f>:0
        at uPLibrary.Networking.M2Mqtt.MqttClient.ProcessInflightThread () [0x001eb] in <b97736681d874115a5b41552b43c6e7f>:0
        at System.Threading.ThreadHelper.ThreadStart_Context (System.Object state) [0x00014] in <162bccb5b7ae4c18b9c0cff8fdc3dfbc>:0
        at System.Threading.ExecutionContext.RunInternal (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x00071] in <162bccb5b7ae4c18b9c0cff8fdc3dfbc>:0
        at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x00000] in <162bccb5b7ae4c18b9c0cff8fdc3dfbc>:0
        at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state) [0x0002b] in <162bccb5b7ae4c18b9c0cff8fdc3dfbc>:0

        05/26/2022 19:32:24 11446 | ApplyExpression lower("hs4/Den/PIR/Motion Forum Home Security") Result=hs4/den/pir/motion Forum home security
        05/26/2022 19:32:24 11447 | Publish hs4/den/pir/motion Forum home security=0
        05/26/2022 19:32:24 11448 | Updating Device from 1 PayloadNumeric=False
        05/26/2022 19:32:24 11448 | Button Value 1, prior value = 1, for VSP of online, bUpdateLastChange=False
        05/26/2022 19:32:24 11449 | ActOnMessageForTrigger QueueSize=54 ,Topic esp8266-vindriktning-particle-sensor-3/VINDRIKTNING-B5CEB4/status,Payload online
        05/26/2022 19:32:24 11450 | at uPLibrary.Networking.M2Mqtt.Messages.MqttMsgPublish.GetBytes (System.Byte protocolVersion) [0x0003c] in <b97736681d874115a5b41552b43c6e7f>:0
        at uPLibrary.Networking.M2Mqtt.MqttClient.Send (uPLibrary.Networking.M2Mqtt.Messages.MqttMsgBase msg) [0x00017] in <b97736681d874115a5b41552b43c6e7f>:0
        at uPLibrary.Networking.M2Mqtt.MqttClient.ProcessInflightThread () [0x001eb] in <b97736681d874115a5b41552b43c6e7f>:0
        at System.Threading.ThreadHelper.ThreadStart_Context (System.Object state) [0x00014] in <162bccb5b7ae4c18b9c0cff8fdc3dfbc>:0
        at System.Threading.ExecutionContext.RunInternal (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x00071] in <162bccb5b7ae4c18b9c0cff8fdc3dfbc>:0
        at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x00000] in <162bccb5b7ae4c18b9c0cff8fdc3dfbc>:0
        at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state) [0x0002b] in <162bccb5b7ae4c18b9c0cff8fdc3dfbc>:0

        Comment


          #5
          The hash and plus symbols are reserved in the MQTT protocol as wildcard and cannot be used in a publish topic. Only as part of the wildcard sequence in the subscribed topic. When mcMQTT creates a publish topic for a non-plugin device it tries to excluded these two characters. The user can later change the publish topic but cannot use these symbols.

          Did mcsMQTT create topics with these symbols? Could it have been as a result of applying HomeAssistant Discovery protocol?

          To correct in your case Edit the publish topic for each case where these symbols are used. The device name does not need to change. Easiest way is from the Association tab of the MQTT Page.

          Comment


            #6
            Originally posted by Michael McSharry View Post
            The hash and plus symbols are reserved in the MQTT protocol as wildcard and cannot be used in a publish topic. Only as part of the wildcard sequence in the subscribed topic. When mcMQTT creates a publish topic for a non-plugin device it tries to excluded these two characters. The user can later change the publish topic but cannot use these symbols.
            I knew as much with the first, and my 'research' is definitely correlation, not causation but it does seem suspicious.

            Did mcsMQTT create topics with these symbols? Could it have been as a result of applying HomeAssistant Discovery protocol?
            Both of the pastes from above are missing from MQTT. hs4/Den/PIR does not exist, nor does hs4/Hallway/PIR. Other items under Den and Hallway exist.
            I do not know how to determine if the Discovery Protocol is related. MQTT has been one of those things that "I need to fix" for months, and am just now digging into it. I couldn't state definitively when the issue began.

            To correct in your case Edit the publish topic for each case where these symbols are used. The device name does not need to change. Easiest way is from the Association tab of the MQTT Page.
            I will modify these and see if the crashes go away, though I would presume sanitation would be the correct approach?

            Is there anything I can do to diagnose if the pound sign is to blame, rather than assume?

            Comment


              #7
              The error is coming from the library used to handle MQTT communications. In particular "uPLibrary.Networking.M2Mqtt.Messages.MqttMsgPublish" so it is happening during the publish event. If seems very reasonable the unexpected characters in the topic are the cause.

              hs4/Den/PIR does not exist, nor does hs4/Hallway/PIR
              The topic being published is "hs4/hallway/pir/motion ... home security" where I expect the message board in using the hash to show Forum. If I was going to research this and other topics I would use the database \data\mcsMQTT\mcsMQTT.db and sort on the Topic column. This will identify the HS Ref number that is associated with the topic. Probably could also use a query looking for the hash in the Topic column. I think it would look something like below. I use "DB Browser for SQLite" to look at the database.

              Code:
              SELECT Ref FROM MQTT_MESSAGE WHERE Topic LIKE '%#%'
              You will need to sanitize of the plugin modified to exclude them at publish time. Now it only does it at topic creation time. I would prefer to reduce CPU load and not do it on every publish event.

              Comment


                #8
                Originally posted by Michael McSharry View Post
                The error is coming from the library used to handle MQTT communications. In particular "uPLibrary.Networking.M2Mqtt.Messages.MqttMsgPublish" so it is happening during the publish event. If seems very reasonable the unexpected characters in the topic are the cause.



                The topic being published is "hs4/hallway/pir/motion ... home security" where I expect the message board in using the hash to show Forum. If I was going to research this and other topics I would use the database \data\mcsMQTT\mcsMQTT.db and sort on the Topic column. This will identify the HS Ref number that is associated with the topic. Probably could also use a query looking for the hash in the Topic column. I think it would look something like below. I use "DB Browser for SQLite" to look at the database.

                Code:
                SELECT Ref FROM MQTT_MESSAGE WHERE Topic LIKE '%#%'
                You will need to sanitize of the plugin modified to exclude them at publish time. Now it only does it at topic creation time. I would prefer to reduce CPU load and not do it on every publish event.
                While I prefer the # sign (simply personal preference), I understand the problems. I went through all of my devices and removed it.
                So far, 5 hours uptime. I'd say that's a good sign.

                Comment

                Working...
                X