MCSXAP 3.0.0.57

[Steve Q]

Michael, looking at the mcsXap HS3 plugin debug log, I noticed 2 things.

1. The "VirtualXP" device appears to be a heartbeat from another machine on my network. That machine has mcsXaphub running. But the message is occurring much more frequently than I would expect.

2. There appear to be messages from non-xAP devices. 014CDF43-028-Q38 is a z-wave device (Aeon energy meter). I don't understand this.

Perhaps all this extraneous information is causing the plugin to get confused?

Steve Q



Sent from my iPad using Tapatalk

[Michael McSharry]

3.0.0.58 is the last version posted so you start with using the same version that match that source. I do not recall when I added debug line numbers for ProcessMessage, but your first screenshot showed Line 0 which only exists before logic of the module is processed and the debug information was much more limited than what is now in the current source.

   Public Sub New(ByVal sMessage As String) 'ReadMessage(ByVal sMessage As String)

        Dim iMessageType As Short
        Dim iLine As Integer = 0

        Try

            If Not gDisconnect Then
                iLine = 1
:
:
        Catch ex As Exception
            Dim s As String = ""
            If ValueChangeDictionary Is Nothing Then
                Dim jLine As Integer
                Try
                    s = "is Nothing"
                    jLine = 1
                    ValueChangeDictionary = New System.Collections.Generic.Dictionary(Of Integer, Date)
                    jLine = 2
                    ValueChangeDictionary.Add(iRef, Now)
                    jLine = 3
                    hs.SetDeviceValueByRef(iRef, nValue, True)
                    jLine = 4
                Catch ex2 As Exception
                    s = "is Nothing Line " & jLine.ToString & " " & ex2.Message
                End Try

            Else
                Try
                    s = ValueChangeDictionary.Count.ToString
                Catch ex2 As Exception
                    s = "Count Undefined " & ex2.Message
                End Try
            End If
            hsWritelogEx(PLUGIN_NAME, "ProcessMessage New Line=" & iLine.ToString & ", ValueChangeDictionary=" & s & ", Type=" & iMessageType.ToString & " " & Replace(Replace(sMessage, vbLf, "|"), vbCr, "~"), ex.Message)
        End Try

I also do not see where your zwave device was in the screenshots.

Once difference between mcsXap between HS2 and HS3 is the heartbeat is allowed to be mapped to HS devices in HS3 while it was not in HS2.

The observation you made about the frequency of the heartbeat is also of concern. I have had network hardware in the past where received xAP messages would be delivered multiple times. Don't know if it was the NIC on the PC or the way the OS managed it. Back then I put a software filter to ignore the same message if there was not sufficient time between its receipt. I likely have that filter on xapmcsHub, but probably not on mcsXap. You should also take advantage of xFX xAP Message Viewer as a debug aid. It can be run on the same computer and on a different computer to help assess if replication is PC-dependent. I doubt if Edward put filter logic into it.

[Steve Q]

I am using plugin ver 3.0.0.42.

The Line 0 message is from the HS3 log not the debug log. These line appeared when the plugin stopped working. Sorry for the confusion.

I found the source of the "VirtualXP" debug messages. It was a leftover from my HS2 machine. I shutdown mcsXaphub running on my HS2 computer. The messages have disappeared.

The mcsXap debug log still shows lots of messages from device 014CDF43-028-Q38. This is NOT an XAP device. It is a z-wave(Aeon energy meter) device. There are no other non-xAP devices in the log.

See below:





Sent from my iPad using Tapatalk

[Michael McSharry]

mcsXap is called by HS3 every time any HS3 device changes. mcsXap looks to see if this device has been setup to have the device status reported via xAP message. The lines in your output that contain "source=" are the xAP messages received that mcsXap looks to see if the message has been setup to report back to HS3 as a device status change.

The ProcessMessage error will show up in both the debug and HS log as it is an error condition and not just information.

Same first step. Update to current version of mcsXap and then we can continue if you still have issues.

[Steve Q]

Michael, I am back home. I updated to plugin version 3.0.0.58 this morning. I had to restart the computer to get everything working. But it looks like everything is working.

Attached is my debug file. It took me quite a while to find it because it has a different name and location than the one for version 42.

I looked at the file and it appears to contain all kinds of information from multiple computers and both HS2 and HS3 devices. Most of it seems to be not necessary for my current HS3 configuration?

Also, the debug file does not contain the most recent information. Is there some periodic interval that is used to write the data to the file?

When I use device manager to turn on a XAP controlled LED, device ref 189, it does not showup in the debug log? It does however turn ON.

Steve Q

[Michael McSharry]

The debug file tends for focus on certain types of investigation based upon recent user needs. This one shows string changes, but not value changes so that explains why you can change values successfully but does not show up in debug. I did find the following for your Ref 189 which is the command from HS to send the new value via xAP Message.

1/25/2016 3:24:35 PM	742005	| mcsXap SetIOMulti Device Ref 189=0  
1/25/2016 3:24:35 PM	742011	| SendXap Ready=True, SendCollection=0, Target=mcs.OneWire.HSLaptop2015:xapmcs1Wire_YellowLED.510000002C854905.Relay, Sub=, class=xapBSC.Cmd, Data=ID
0068 state
Off

Most of what is showing is receipt of xAP messages on your LAN. Most likely do not get beyond the first level filter of being Accepted as being mapped into HS devices. There are some X10 changes in HS that have been setup to deliver as xap-x10.request xAP schema. I use this schema with my xapmcsCM11A.exe to control my X10, but I did not think anybody else used it, especially HS users that more typically use X10 plugins.

For your continued investigation I think you are waiting for high CPU utilization and what exists in the HS log for error information from mcsXap and in the debug as to what may be going on internally.

[Steve Q]

Thanks for the explanation. I will be watching HS3 for increased CPU usage. I am thinking the problem might be a hardware issue because I am periodically losing one or more COM ports on the laptop. They quit working for some unknown reason. I suspect the comport buffer is getting clogged. I saw this happening on HS2 with my cheaper RFID device com port. I found a way to flush the port periodically which solved the problem.

Overall, I think HS3 is working pretty well for me now.


Sent from my iPad using Tapatalk

[Steve Q]

Michael, the mcsxAP plugin caused HS3 to crash today at 2:12 PM. Attached are 2 screen shots showing the HS3 log. I discovered the crash around 3:40PM. The HS3 log had stopped but HS3 was still executing some events. I disabled then enabled the xAP plugin, but nothing changed in HS3. I checked mcsxap1wire; it was still running and contained up to date info. The HS3 computer CPU was at 50%, normally it is around 20%.

Attached is the plugin debug file.

I restarted HS3. Everything was fine, no errors in the startup log.

I have been having lots of Z-wave and x10 issues with HS3 lately. You had mentioned that you were looking at X10 commands with the plugin. Could an x10 failure cause the plugin to crash?

Please have a look at the debug file.

Steve Q



Sent from my iPad using Tapatalk

[Steve Q]

The zipped debug file would not upload. I am trying to make it smaller (original file is 300,000 lines).

[Steve Q]

Here is the debug file. I stripped out the middle 200,000 lines of the file to make it smaller.

[Steve Q]

Michael, have you had a chance to look at this?


Sent from my iPad using Tapatalk

[Michael McSharry]

There is really nothing unusual in debug output. It shows continued receipt of xAP LAN traffic and a pretty busy HS3 will multiple calls to mcsXap for string change every second. There are likely value change calls to mcsXap during this same time, but I did not capture those in the debug. I don't know what you have producing this frequency of changes in the device strings but I can see where it could load the system.

The messages in the debug log come from the same code where the string debug is occurring. More likely in section with value changes or other type of event. It is only a guess, but I suspect that the reference to the object (device) that had changed disappeared before mcsXap was able to process the event.

Additional debug could be put in this code area to better follow what object was missing, but it does seem that once is occurred, it repeats. Since string events are still handled as expected I do not see a general relationship with the event change calls to mcsXap.

I am not aware of a programmatic way to restart a plugin. There is not API for it, but I believe Jon has a script to do it so there is a way. I just do not know it. I do not know what to suggest for the next step. I am open to suggestions.

I doubt if X10 processing is causing an issue since xAP traffic seems to be working normally in the debug.

Source=mcs.onewire.hslaptop2015:xapmcs1wire_mainlegsideavoltb.070000011aa3aa26.voltage.3,Exists=True  
2/5/2016 2:16:03 PM	80392126	| mcsXap Debug DoHSEVENT String , Current= 16:03,  New= 16:03  
2/5/2016 2:16:03 PM	80392127	| mcsXap Debug DoHSEVENT String , Current= 10:16:03,  New= 10:16:03  
2/5/2016 2:16:03 PM	80392127	| mcsXap Debug DoHSEVENT String , Current= 77:06:20:35,  New= 77:06:20:35  
2/5/2016 2:16:03 PM	80392128	| mcsXap Debug DoHSEVENT String , Current= 16:03,  New= 16:03  
2/5/2016 2:16:03 PM	80392128	| mcsXap Debug DoHSEVENT String , Current= 16:03,  New= 15:48  
2/5/2016 2:16:04 PM	80393129	| mcsXap Debug DoHSEVENT String , Current= 16:04,  New= 16:04  
2/5/2016 2:16:04 PM	80393129	| mcsXap Debug DoHSEVENT String , Current= 10:16:04,  New= 10:16:04  
2/5/2016 2:16:04 PM	80393130	| mcsXap Debug DoHSEVENT String , Current= 77:06:20:36,  New= 77:06:20:36  
2/5/2016 2:16:05 PM	80394132	| mcsXap Debug DoHSEVENT String , Current= 16:05,  New= 16:05  
2/5/2016 2:16:05 PM	80394133	| mcsXap Debug DoHSEVENT String , Current= 10:16:05,  New= 10:16:05  
2/5/2016 2:16:05 PM	80394134	| mcsXap Debug DoHSEVENT String , Current= 77:06:20:37,  New= 77:06:20:37  
2/5/2016 2:16:06 PM	80395135	| mcsXap Debug DoHSEVENT String , Current= 16:06,  New= 16:06  
2/5/2016 2:16:06 PM	80395136	| mcsXap Debug DoHSEVENT String , Current= 10:16:06,  New= 10:16:06  
2/5/2016 2:16:06 PM	80395136	| mcsXap Debug DoHSEVENT String , Current= 77:06:20:38,  New= 77:06:20:38  
2/5/2016 2:16:07 PM	80396138	| mcsXap Debug DoHSEVENT String , Current= 16:07,  New= 16:07  
2/5/2016 2:16:07 PM	80396139	| mcsXap Debug DoHSEVENT String , Current= 10:16:07,  New= 10:16:07  
2/5/2016 2:16:07 PM	80396140	| mcsXap Debug DoHSEVENT String , Current= 77:06:20:39,  New= 77:06:20:39  
2/5/2016 2:16:08 PM	80397142	| mcsXap Debug DoHSEVENT String , Current= 16:08,  New= 16:08  
2/5/2016 2:16:08 PM	80397142	| mcsXap Debug DoHSEVENT String , Current= 10:16:08,  New= 10:16:08  
2/5/2016 2:16:08 PM	80397143	| mcsXap Debug DoHSEVENT String , Current= 77:06:20:40,  New= 77:06:20:40  
2/5/2016 2:16:09 PM	80398144	| mcsXap Debug DoHSEVENT String , Current= 16:09,  New= 16:09  
2/5/2016 2:16:09 PM	80398145	| mcsXap Debug DoHSEVENT String , Current= 10:16:09,  New= 10:16:09  
2/5/2016 2:16:09 PM	80398145	| mcsXap Debug DoHSEVENT String , Current= 77:06:20:41,  New= 77:06:20:41  
2/5/2016 2:16:10 PM	80399146	| mcsXap Debug DoHSEVENT String , Current= 16:10,  New= 16:10  
2/5/2016 2:16:10 PM	80399146	| mcsXap Debug DoHSEVENT String , Current= 10:16:10,  New= 10:16:10  
2/5/2016 2:16:10 PM	80399147	| mcsXap Debug DoHSEVENT String , Current= 77:06:20:42,  New= 77:06:20:42  
2/5/2016 2:16:11 PM	80400152	| mcsXap Debug DoHSEVENT String , Current= 16:11,  New= 16:11  
2/5/2016 2:16:11 PM	80400152	| mcsXap Debug DoHSEVENT String , Current= 10:16:11,  New= 10:16:11  
2/5/2016 2:16:11 PM	80400153	| mcsXap Debug DoHSEVENT String , Current= 77:06:20:43,  New= 77:06:20:43  
2/5/2016 2:16:11 PM	80400569	| mcsXap Debug Message Source=mcs.onewire.hslaptop2015:xapmcs1wire_circuit21temp.e5000000a93d5b26.temperature.1,Exists=True

[Steve Q]

Thanks for looking at the debug log. Since I posted it, I have not had a problem with the plugin. I have restarted HS3 and my computer several times for other issues. I think I'm to the point where I will leave HS3 alone. I'll let you know what happens.


Sent from my iPad using Tapatalk

[CouchPotatoe]

Hi Steve,

I just wanted to reassure you - in that I use xAP extensively on HS3 and HS2, albeit with plugin v 050 currently. I have over 1000 xAP BSC endpoints on my system from 42 different devices devices generating a traffic rate of 250+ messages per minute. I also use 1-wire on xAP with 30 mainly temperature or counter sensors, although not via mcs1wire. My HS3 system is stable month after month with no reboots and <5% CPU usage on a 2.2Ghz dual core AMD Turion processor, so Michaels plugin is working well for me. xAP persay is extremely light on network bandwidth and CPU, so something seems awry with your setup but the positive side is that if you can narrow that down then it does all work really well.

I haven't kept up to speed with your implementation but obviously only enabling BSC status reporting from HS devices that you need it from is a good step - as your logs do show very frequently changing device values.

Also, although I don't think this is so in your case, it is possible to put two xAP devices into a loop if they each can set the state of the other - which would use high CPU. Mirroring devices between HS3 and HS2 using xAP and having scripted 'change' actions can also do this. Multiple network cards each receiving and processing xAP can cause issues too - but it's very hard to actually create such a misconfiguration.

xFX Viewer running at the time you encounter high CPU should help in seeing if there are any xAP race conditions.

Keep at it - sporadic issues that you can't reproduce dependably are always the hardest to troubleshoot and really frustrating. You sound to have very intricate system(s) with a lot of potential interactions , both hardware and software but the xAP part should just tick along with minimal overhead.

Michael - does the xAP plugin process xAPBSC.event messages originating from itself ?

K

[Steve Q]

K, thanks for your comments.
Yes, I do have an intricate setup. I'm sure you and Michael would describe it as "a mess". I have 3 xAP instances running. Not because I really need or want them, but because it has evolved from my transition from HS2 to HS3. In HS2, everything was running on a single desktop computer. XAP/1wire was very stable. I also had my security system running on the same computer. It was not very stable and would lockup the HS2 computer about once a week.

When HS3 became available, I decided to implement it on a lower power laptop computer. I quickly discovered that it was going to take a huge amount of time to get HS3 up and running. So I have been working on the transition for 18 months and in January I shutdown HS2 on my desktop computer.

My biggest issue with HS3 and the Laptop has been the management of COM ports and USB ports. I have tried several expansion ports (I have 7 USB devices connected). They all work, but whenever I restarted the Laptop, the COM port assignments would change. It was painful! But I now have a setup that is fairly stable.

During all this, I tried not to change my xAP setup. But I did install a duplicate xAP setup on a netbook computer running HS3. This was a transitional step but it is still running.

So, to answer your question, yes, it is quite possible that I have created some kind of loop feedback between the 2 computers.

This is a complex issue, my intent was to have mcsXaphub keep the 1wire device status in sync across the 2 computers. I never really thought about the impact on the xAP HS3 plugin. I will have to look at how I have it configured.

Steve Q


Sent from my iPad using Tapatalk