Announcement
Collapse
No announcement yet.
SSL Support for mcsMQTT
Collapse
X
-
Debug was enabled, and the logs are posted above. Nothing was being written while CPU use was high.
If i do a trace on the process I see this:
Code:clock_gettime(CLOCK_MONOTONIC, {tv_sec=92741, tv_nsec=274027787}) = 0 clock_gettime(CLOCK_MONOTONIC, {tv_sec=92741, tv_nsec=274181874}) = 0 clock_gettime(CLOCK_MONOTONIC, {tv_sec=92741, tv_nsec=274320752}) = 0 clock_gettime(CLOCK_MONOTONIC, {tv_sec=92741, tv_nsec=274458589}) = 0 futex(0x73f918, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9862163}) = -1 ETIMEDOUT (Connection timed out) clock_gettime(CLOCK_MONOTONIC, {tv_sec=92741, tv_nsec=284757537}) = 0 futex(0x73f8d4, FUTEX_WAKE_PRIVATE, 1) = 0
As for SSL. I do not have a 'background' persay, just an avid System Administrator. I'll look around the forum, I did not realize the source was available, maybe that will give some clues.
Comment
-
For SSL, vasrc looks to have a solution using callback approach to authentication of the certificate. He is now trying to integrate it into the mcsMQTT source.
Can you provide some insight into the environment you are running mcsMQTT? Based upon your debug it looks like you have nothing selected for publication so no callbacks for device changes from HS and you indicated no connection the broker was setup.
The main is in a 10 ms loop monitoring the HS connection. This is boilerplate from the HS3 SDK.
There is a MQTT thread that wakes up on 10 second intervals to assess the broker connection. This does update the Statistics tab so you can see if it is being refreshed with at least elapsed time.
There are many synchronization wait loops. In each case the reason for waiting is written to the debug log. Since you have none of these in the log we should be able to rule them out.
There is a thread that wakes up on HS event callbacks. Since you have no callbacks in the log we can rule out this thread.
There is a thread to run GNUPlot on Linux on chart requests. Since no data exists for charting and I doubt if you tried to generate a chart this one can be ruled out too.
There is MQTT callback thread from broker message received. No broker connection and nothing in the log so this is not a candidate.
There is Browser ajax postback at 2 second intervals. In some versions I have this in the debug. I can add it back on the next iteration.
Give me a little background on your setup and I will put together some debug in the candidate loops. The Statistics tab updating will mean that the ajax postbacks are being processed.
Comment
-
Originally posted by Michael McSharry View PostCan you provide some insight into the environment you are running mcsMQTT? Based upon your debug it looks like you have nothing selected for publication so no callbacks for device changes from HS and you indicated no connection the broker was setup.
Give me a little background on your setup and I will put together some debug in the candidate loops. The Statistics tab updating will mean that the ajax postbacks are being processed.
Both of the environments I've installed mcsMQTT in experienced this after installation.
Currently: Ubuntu 18.04, Mono 5.12, the broker is on the same device (localhost), Broker using TLS 1.2.
Prevously: Debian 8.10, Mono 5.12, the broker is on the same device (localhost), no TLS.
Currently: I have nothing selected for publish and the plugin is minimally configured, it has been uninstalled and reinstalled to test. The connection to the broker is configured, but it cannot be reached because the broker is behind TLS1.2 and mcsMQTT cannot talk to it.
Previously: The plugin ran for a week before over port 1833 with several associations from the broker from other devices. After installation the device started rebooting frequently prompting the move (high CPU load seemed to be the cause). Nothing from HS3 was being published or controlled at that point.
I've just installed plugin v3.4.0.0, CPU spiked and the trace seems to show the same, although I'm not sure it's really useful:
Code:[pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=341022}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=341243}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=341375}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=341495}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=341648}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=341838}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=341993}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=342145}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=342269}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=342420}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=342578}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=342884}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=343142}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=343260}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=343418}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=343636}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=343755}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=343908}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=344064}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=344189}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=344345}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=344500}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=344659}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=344855}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=344999}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=345220}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=345376}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=345593}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=345735}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=345874}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=346009}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=346166}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=346339}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=346546}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=346790}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=347172}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=347506}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=347882}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=348094}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=348259}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=348477}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=348688}, NULL) = 0 [pid 3897] <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=348811}, NULL) = 0 [pid 3897] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 3913] gettimeofday( <unfinished ...> [pid 3897] <... clock_gettime resumed> {tv_sec=101372, tv_nsec=971166930}) = 0 [pid 3913] <... gettimeofday resumed> {tv_sec=1526792189, tv_usec=348946}, NULL) = 0 [pid 3897] futex(0x7718d4, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 3913] gettimeofday( <unfinished ...> [pid 3897] <... futex resumed> ) = 0 [pid 3913] <... gettimeofday resumed> {tv_sec=1526792189, tv_usec=349140}, NULL) = 0 [pid 3897] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 3913] gettimeofday( <unfinished ...> [pid 3897] <... clock_gettime resumed> {tv_sec=101372, tv_nsec=971631108}) = 0 [pid 3913] <... gettimeofday resumed> {tv_sec=1526792189, tv_usec=349396}, NULL) = 0 [pid 3897] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 3913] gettimeofday( <unfinished ...> [pid 3897] <... clock_gettime resumed> {tv_sec=101372, tv_nsec=971811779}) = 0 [pid 3913] <... gettimeofday resumed> {tv_sec=1526792189, tv_usec=349575}, NULL) = 0 [pid 3897] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 3913] gettimeofday( <unfinished ...> [pid 3897] <... clock_gettime resumed> {tv_sec=101372, tv_nsec=972004534}) = 0 [pid 3913] <... gettimeofday resumed> {tv_sec=1526792189, tv_usec=349780}, NULL) = 0 [pid 3897] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 3913] gettimeofday( <unfinished ...> [pid 3897] <... clock_gettime resumed> {tv_sec=101372, tv_nsec=972194455}) = 0 [pid 3913] <... gettimeofday resumed> {tv_sec=1526792189, tv_usec=350035}, NULL) = 0 [pid 3897] futex(0x771918, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=9810079} <unfinished ...> [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=350242}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=350402}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=350556}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=350752}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=350989}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=351121}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=351237}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=351385}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=351519}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=351657}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=351783}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=351941}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=352056}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=352327}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=352585}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=352820}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=353186}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=353648}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=353774}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=353922}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=354076}, NULL) = 0 [pid 3913] gettimeofday({tv_sec=1526792189, tv_usec=354233}, NULL) = 0
Code:[0xb6f35010: 50.06988 4] ENTER: HSCF.Communication.ScsServices.Client.ScsServiceClient`1<T_REF>:get_CommunicationState ()() ip: (nil) [0xb6f35010: 50.06990 5] ENTER: HSCF.Communication.Scs.Client.ScsClientBase:get_CommunicationState ()() ip: (nil) [0xb6f35010: 50.06991 6] ENTER: HSCF.Communication.Scs.Communication.Channels.CommunicationChannelBase:get_CommunicationState ()() ip: (nil) [0xb6f35010: 50.06992 6] LEAVE: HSCF.Communication.Scs.Communication.Channels.CommunicationChannelBase:get_CommunicationState ()result=0 [0xb6f35010: 50.06995 5] LEAVE: HSCF.Communication.Scs.Client.ScsClientBase:get_CommunicationState ()result=0 [0xb6f35010: 50.06997 4] LEAVE: HSCF.Communication.ScsServices.Client.ScsServiceClient`1<T_REF>:get_CommunicationState ()result=0 [0xb6f35010: 50.07001 4] ENTER: (wrapper managed-to-native) System.Threading.Thread:SleepInternal (int)() ip: (nil) [0xb6f35010: 50.08011 4] LEAVE: (wrapper managed-to-native) System.Threading.Thread:SleepInternal (int) [0xb6f35010: 50.08016 4] ENTER: HSCF.Communication.ScsServices.Client.ScsServiceClient`1<T_REF>:get_CommunicationState ()() ip: (nil) [0xb6f35010: 50.08018 5] ENTER: HSCF.Communication.Scs.Client.ScsClientBase:get_CommunicationState ()() ip: (nil) [0xb6f35010: 50.08019 6] ENTER: HSCF.Communication.Scs.Communication.Channels.CommunicationChannelBase:get_CommunicationState ()() ip: (nil) [0xb6f35010: 50.08020 6] LEAVE: HSCF.Communication.Scs.Communication.Channels.CommunicationChannelBase:get_CommunicationState ()result=0 [0xb6f35010: 50.08025 5] LEAVE: HSCF.Communication.Scs.Client.ScsClientBase:get_CommunicationState ()result=0 [0xb6f35010: 50.08028 4] LEAVE: HSCF.Communication.ScsServices.Client.ScsServiceClient`1<T_REF>:get_CommunicationState ()result=0 [0xb6f35010: 50.08030 4] ENTER: (wrapper managed-to-native) System.Threading.Thread:SleepInternal (int)() ip: (nil) [0xb6f35010: 50.09041 4] LEAVE: (wrapper managed-to-native) System.Threading.Thread:SleepInternal (int) [0xb6f35010: 50.09046 4] ENTER: HSCF.Communication.ScsServices.Client.ScsServiceClient`1<T_REF>:get_CommunicationState ()() ip: (nil) [0xb6f35010: 50.09047 5] ENTER: HSCF.Communication.Scs.Client.ScsClientBase:get_CommunicationState ()() ip: (nil) [0xb6f35010: 50.09048 6] ENTER: HSCF.Communication.Scs.Communication.Channels.CommunicationChannelBase:get_CommunicationState ()() ip: (nil) [0xb6f35010: 50.09050 6] LEAVE: HSCF.Communication.Scs.Communication.Channels.CommunicationChannelBase:get_CommunicationState ()result=0 [0xb6f35010: 50.09053 5] LEAVE: HSCF.Communication.Scs.Client.ScsClientBase:get_CommunicationState ()result=0 [0xb6f35010: 50.09055 4] LEAVE: HSCF.Communication.ScsServices.Client.ScsServiceClient`1<T_REF>:get_CommunicationState ()result=0 [0xb6f35010: 50.09058 4] ENTER: (wrapper managed-to-native) System.Threading.Thread:SleepInternal (int)() ip: (nil) [0xb6f35010: 50.10068 4] LEAVE: (wrapper managed-to-native) System.Threading.Thread:SleepInternal (int) [0xb6f35010: 50.10073 4] ENTER: HSCF.Communication.ScsServices.Client.ScsServiceClient`1<T_REF>:get_CommunicationState ()() ip: (nil) [0xb6f35010: 50.10074 5] ENTER: HSCF.Communication.Scs.Client.ScsClientBase:get_CommunicationState ()() ip: (nil) [0xb6f35010: 50.10076 6] ENTER: HSCF.Communication.Scs.Communication.Channels.CommunicationChannelBase:get_CommunicationState ()() ip: (nil) [0xb6f35010: 50.10076 6] LEAVE: HSCF.Communication.Scs.Communication.Channels.CommunicationChannelBase:get_CommunicationState ()result=0 [0xb6f35010: 50.10078 5] LEAVE: HSCF.Communication.Scs.Client.ScsClientBase:get_CommunicationState ()result=0 [0xb6f35010: 50.10081 4] LEAVE: HSCF.Communication.ScsServices.Client.ScsServiceClient`1<T_REF>:get_CommunicationState ()result=0 [0xb6f35010: 50.10083 4] ENTER: (wrapper managed-to-native) System.Threading.Thread:SleepInternal (int)() ip: (nil) [0xb6f35010: 50.11093 4] LEAVE: (wrapper managed-to-native) System.Threading.Thread:SleepInternal (int) [0xb6f35010: 50.11098 4] ENTER: HSCF.Communication.ScsServices.Client.ScsServiceClient`1<T_REF>:get_CommunicationState ()() ip: (nil) [0xb6f35010: 50.11099 5] ENTER: HSCF.Communication.Scs.Client.ScsClientBase:get_CommunicationState ()() ip: (nil) [0xb6f35010: 50.11100 6] ENTER: HSCF.Communication.Scs.Communication.Channels.CommunicationChannelBase:get_CommunicationState ()() ip: (nil) [0xb6f35010: 50.11100 6] LEAVE: HSCF.Communication.Scs.Communication.Channels.CommunicationChannelBase:get_CommunicationState ()result=0 [0xb6f35010: 50.11103 5] LEAVE: HSCF.Communication.Scs.Client.ScsClientBase:get_CommunicationState ()result=0
Last edited by Jeeves; May 20, 2018, 12:22 AM.
Comment
-
I moved the thread to https://forums.homeseer.com/showthre...53#post1366753
The mono trace shows the main thread that is simply maintaining a socket connection with HS.
The OS level debug does not give me much insight as there are multple layers between the application and the OS. The mcsMQTT_Debug.txt is most helpful for me as we progress in the investigation.
Comment
-
Originally posted by Michael McSharry View PostFor SSL, vasrc looks to have a solution using callback approach to authentication of the certificate. He is now trying to integrate it into the mcsMQTT source.
Comment
-
@Michael and Vasrc,
Should I be posting testing results here for current modified SSL build?- Pete
Auto matorHomeseer 3 Pro - 3.0.0.548 (Linux) - Ubuntu 18.04/W7e 64 bit Intel Haswell CPU 16Gb
Homeseer Zee2 (Lite) - 3.0.0.548 (Linux) - Ubuntu 18.04/W7e - CherryTrail x5-Z8350 BeeLink 4Gb BT3 Pro
HS4 Lite - Ubuntu 22.04 / Lenovo Tiny M900 / 32Gb Ram
HS4 Pro - V4.1.18.1 - Ubuntu 22.04 / Lenova Tiny M900 / 32Gb Ram
HSTouch on Intel tabletop tablets (Jogglers) - Asus AIO - Windows 11X10, UPB, Zigbee, ZWave and Wifi MQTT automation-Tasmota-Espurna. OmniPro 2, Russound zoned audio, Alexa, Cheaper RFID, W800 and Home Assistant
Comment
-
Thank you and will do.- Pete
Auto matorHomeseer 3 Pro - 3.0.0.548 (Linux) - Ubuntu 18.04/W7e 64 bit Intel Haswell CPU 16Gb
Homeseer Zee2 (Lite) - 3.0.0.548 (Linux) - Ubuntu 18.04/W7e - CherryTrail x5-Z8350 BeeLink 4Gb BT3 Pro
HS4 Lite - Ubuntu 22.04 / Lenovo Tiny M900 / 32Gb Ram
HS4 Pro - V4.1.18.1 - Ubuntu 22.04 / Lenova Tiny M900 / 32Gb Ram
HSTouch on Intel tabletop tablets (Jogglers) - Asus AIO - Windows 11X10, UPB, Zigbee, ZWave and Wifi MQTT automation-Tasmota-Espurna. OmniPro 2, Russound zoned audio, Alexa, Cheaper RFID, W800 and Home Assistant
Comment
Comment