Any Verbose Logging?

Posted on
Tue Dec 27, 2016 1:48 am
AndyVirus offline
Posts: 257
Joined: Mar 18, 2014
Location: Newport Pagnell, UK

Any Verbose Logging?

Hello,

Is there anyway to get verbose logging/debug logging for the EasyDaq plugin?

For years this plugin has been rock solid but in the last few days the only time i can get the plugin to control a relay is to restart the plugin then fire the action.
If i try again an hour later (maybe minutes later, i don't know the exact time period) the action does nothing, no errors just nothing happens on the relays.

I have tried putting the easydaq usb connection on a powered switch to eliminate any power issues, same behaviour.
Different USB port,same behaviour.
Disabled as many plugins as possible incase of some conflict/resource drain, same behaviour.

I have no idea if its the plugin or the board which is at fault at this point so additional logging would be great as the plugin is not reporting disconnections or any errors, its jst isnt doing anything until i restart the easydaq plugin THEN it works for a while.

Any troubleshooting advice would be appreciated.
Last edited by AndyVirus on Tue Dec 27, 2016 10:28 am, edited 1 time in total.

Posted on
Tue Dec 27, 2016 6:30 am
DaveL17 offline
User avatar
Posts: 6742
Joined: Aug 20, 2013
Location: Chicago, IL, USA

Re: Any Verbose Logging?

I don't use the easyDaq plugin, but this may work for you. It will require adding one line to the plugin code. In plugin.py, add the following line to the plugin's __init__ method:
Code: Select all
self.debug = True

Be sure that it is indented to the same level as the other lines in the method (if the other lines are indented with tabs or spaces, you should match that). Of course, if you want to turn it back off again, just set this line to False. It will look something like this:

Screen Shot 2016-12-27 at 6.28.05 AM.png
Screen Shot 2016-12-27 at 6.28.05 AM.png (28.99 KiB) Viewed 4736 times

If you need more help to make this happen, feel free to post back.
Dave

I came here to drink milk and kick ass....and I've just finished my milk.

[My Plugins] - [My Forums]

Posted on
Tue Dec 27, 2016 10:27 am
AndyVirus offline
Posts: 257
Joined: Mar 18, 2014
Location: Newport Pagnell, UK

Re: Any Verbose Logging?

Excellent, thank you!

There was a commented out self.debug = true so i was able to just uncomment it and i can now see debug messages.
I will see if that reports anything so i know where to look to resolve this.

Thanks Again!

Posted on
Tue Dec 27, 2016 10:35 am
DaveL17 offline
User avatar
Posts: 6742
Joined: Aug 20, 2013
Location: Chicago, IL, USA

Re: Any Verbose Logging?

Even better. Glad that worked for you.

Cheers!
Dave

I came here to drink milk and kick ass....and I've just finished my milk.

[My Plugins] - [My Forums]

Posted on
Wed Dec 28, 2016 3:42 am
AndyVirus offline
Posts: 257
Joined: Mar 18, 2014
Location: Newport Pagnell, UK

Re: Any Verbose Logging?

OK Damn.

Debug logging does not log the issue. It looks like the plugin at some point "goes to sleep" and never wakes up until i reload it.

So with debug on, when it works it displays:

Code: Select all
2016-12-27 21:37:01.629   Action Group   All Blinds Close
2016-12-27 21:37:01.689   EasyDAQ Relay Card   sending "Blinds Relay Board - Master Bed All Down" on
2016-12-27 21:37:01.690   EasyDAQ Relay Card Debug   SENDING: 46 04 (set outputs)
2016-12-27 21:37:01.708   EasyDAQ Relay Card   received "Blinds Relay Board - Master Bed All Down" update to on
2016-12-27 21:37:02.157   EasyDAQ Relay Card   sending "Blinds Relay Board - Master Bed All Down" off
2016-12-27 21:37:02.158   EasyDAQ Relay Card Debug   SENDING: 46 00 (set outputs)
2016-12-27 21:37:02.176   EasyDAQ Relay Card   received "Blinds Relay Board - Master Bed All Down" update to off


Try the same thing this morning to open the blinds and it does nothing:

Code: Select all
2016-12-28 07:55:18.253   Action Group   All Blinds Open
2016-12-28 07:55:20.027   Schedule   Master Bedroom Blinds Open (Light Switch) (delayed action)
2016-12-28 07:55:22.114   Action Group   All Blinds Close
2016-12-28 07:55:24.028   Schedule   Master Bedroom Blinds Close (Light Switch) (delayed action)


So at some point it seems the plugin goes down the pub and fails to come back as it does not seem to attempt to communicate to the easydaq relay board.
If comms with the relay board was the issue i would have expected the plugin to report this or die like it does when you whip out the usb cable.
I have searched through the logs from the point it did work last to the point it did not and no EasyDAQ messages at all so nothing to go on other that it does not want to work.

Any idea where I can go from here to get this back to working/diagnose further?

On restart of plugin:

Code: Select all
28 Dec 2016, 10:53:26
   Error                           process (pid 7525) failed to quit after polite request -- forcing it to quit now
   Stopped plugin "EasyDAQ Relay Card 2.0.2"
   Starting plugin "EasyDAQ Relay Card 2.0.2" (pid 62414)
   Started plugin "EasyDAQ Relay Card 2.0.2"
   EasyDAQ Relay Card Debug        startup called
   EasyDAQ Relay Card Debug        <<-- entering deviceStartComm: Blinds Relay Board (1967663012 - easyDaq24r)
   EasyDAQ Relay Card Debug        SENDING: 42 00 (config bank)
   EasyDAQ Relay Card Debug        exiting deviceStartComm1 -->>
   EasyDAQ Relay Card Debug        <<-- entering deviceStartComm: Close Master Bedroom Blinds (946795252 - easyDaqOutputRelay)
   EasyDAQ Relay Card Debug        added mirror of "Blinds Relay Board" channel 11 to "Close Master Bedroom Blinds"
   EasyDAQ Relay Card Debug        exiting deviceStartComm1 -->>
   EasyDAQ Relay Card Debug        <<-- entering deviceStartComm: MasterBedBlind1 Down (250860958 - easyDaqOutputRelay)
   EasyDAQ Relay Card Debug        added mirror of "Blinds Relay Board" channel 2 to "MasterBedBlind1 Down"
   EasyDAQ Relay Card Debug        exiting deviceStartComm1 -->>
   EasyDAQ Relay Card Debug        <<-- entering deviceStartComm: MasterBedBlind1 Up (867196319 - easyDaqOutputRelay)
   EasyDAQ Relay Card Debug        added mirror of "Blinds Relay Board" channel 1 to "MasterBedBlind1 Up"
   EasyDAQ Relay Card Debug        exiting deviceStartComm1 -->>
   EasyDAQ Relay Card Debug        <<-- entering deviceStartComm: MasterBedBlind2 Down (1808294713 - easyDaqOutputRelay)
   EasyDAQ Relay Card Debug        added mirror of "Blinds Relay Board" channel 4 to "MasterBedBlind2 Down"
   EasyDAQ Relay Card Debug        exiting deviceStartComm1 -->>
   EasyDAQ Relay Card Debug        <<-- entering deviceStartComm: MasterBedBlind2Up (1165065192 - easyDaqOutputRelay)
   EasyDAQ Relay Card Debug        added mirror of "Blinds Relay Board" channel 3 to "MasterBedBlind2Up"
   EasyDAQ Relay Card Debug        exiting deviceStartComm1 -->>
   EasyDAQ Relay Card Debug        <<-- entering deviceStartComm: MasterBedBlind3 Down (1522018846 - easyDaqOutputRelay)
   EasyDAQ Relay Card Debug        added mirror of "Blinds Relay Board" channel 7 to "MasterBedBlind3 Down"
   EasyDAQ Relay Card Debug        exiting deviceStartComm1 -->>
   EasyDAQ Relay Card Debug        <<-- entering deviceStartComm: MasterBedBlind3 Up (96285935 - easyDaqOutputRelay)
   EasyDAQ Relay Card Debug        added mirror of "Blinds Relay Board" channel 8 to "MasterBedBlind3 Up"
   EasyDAQ Relay Card Debug        exiting deviceStartComm1 -->>
   EasyDAQ Relay Card Debug        <<-- entering deviceStartComm: MasterBedBlind4 Down (906498398 - easyDaqOutputRelay)
   EasyDAQ Relay Card Debug        added mirror of "Blinds Relay Board" channel 9 to "MasterBedBlind4 Down"
   EasyDAQ Relay Card Debug        exiting deviceStartComm1 -->>
   EasyDAQ Relay Card Debug        <<-- entering deviceStartComm: MasterBedBlind4 Up (3535946 - easyDaqOutputRelay)
   EasyDAQ Relay Card Debug        added mirror of "Blinds Relay Board" channel 10 to "MasterBedBlind4 Up"
   EasyDAQ Relay Card Debug        exiting deviceStartComm1 -->>
   EasyDAQ Relay Card Debug        <<-- entering deviceStartComm: MasterBedBlind5 Down (1643879633 - easyDaqOutputRelay)
   EasyDAQ Relay Card Debug        added mirror of "Blinds Relay Board" channel 6 to "MasterBedBlind5 Down"
   EasyDAQ Relay Card Debug        exiting deviceStartComm1 -->>
   EasyDAQ Relay Card Debug        <<-- entering deviceStartComm: MasterBedBlind5 Up (1658614185 - easyDaqOutputRelay)
   EasyDAQ Relay Card Debug        added mirror of "Blinds Relay Board" channel 5 to "MasterBedBlind5 Up"
   EasyDAQ Relay Card Debug        exiting deviceStartComm1 -->>
   EasyDAQ Relay Card Debug        <<-- entering deviceStartComm: Nursey Blind Down (337509677 - easyDaqOutputRelay)
   EasyDAQ Relay Card Debug        added mirror of "Blinds Relay Board" channel 14 to "Nursey Blind Down"
   EasyDAQ Relay Card Debug        exiting deviceStartComm1 -->>
   EasyDAQ Relay Card Debug        <<-- entering deviceStartComm: Nursey Blind Up (764478774 - easyDaqOutputRelay)
   EasyDAQ Relay Card Debug        added mirror of "Blinds Relay Board" channel 13 to "Nursey Blind Up"
   EasyDAQ Relay Card Debug        exiting deviceStartComm1 -->>
   EasyDAQ Relay Card Debug        <<-- entering deviceStartComm: Open Master Bededroom Blinds (653166852 - easyDaqOutputRelay)
   EasyDAQ Relay Card Debug        added mirror of "Blinds Relay Board" channel 12 to "Open Master Bededroom Blinds"
   EasyDAQ Relay Card Debug        exiting deviceStartComm1 -->>
   EasyDAQ Relay Card Debug        SENDING: 45 00 (config bank)
   EasyDAQ Relay Card Debug        SENDING: 48 00 (config bank)
   EasyDAQ Relay Card              connected to device "Blinds Relay Board" on /dev/cu.usbserial-00002226
   EasyDAQ Relay Card              channel status polling disable for device "Blinds Relay Board"

Posted on
Wed Dec 28, 2016 2:31 pm
matt (support) offline
Site Admin
User avatar
Posts: 21411
Joined: Jan 27, 2003
Location: Texas

Re: Any Verbose Logging?

My guess is the hardware (or driver) is having a problem and not responding to Indigo's request when it tries to poll the current state from the module.

When the problem occurs does it fix itself if you unplug the EasyDAQ USB cable for a few seconds and plug it back in? If a plugin restart gets it working, then I think that will also get it working. Not a solution obviously, I'm just curious.

Also try turning on the Disable channel status polling checkbox in the device settings. Indigo will then no longer poll out the states and will just blindly assume commands sent work. That might or might not work for you but give it a try. Actually, based on your Event Log you already have that option enabled (so disabling is ON)?

Image

Posted on
Wed Dec 28, 2016 4:01 pm
AndyVirus offline
Posts: 257
Joined: Mar 18, 2014
Location: Newport Pagnell, UK

Re: Any Verbose Logging?

Just tried unplugging and plugging in the usb cable to the EasyDAQ relay board and it lost the serial connection (prob as i had it in a usb hub as a test) so will re-test this direct attached again.
Code: Select all
EasyDAQ Relay Card Debug        trying to reconnect to failed devices
   EasyDAQ Relay Card Debug        <<-- entering deviceStartComm: Blinds Relay Board (1967663012 - easyDaq24r)
   EasyDAQ Relay Card Debug        "Blinds Relay Board" serial port open error: [Errno 2] could not open port /dev/cu.usbserial-00002226: [Errno 2] No such file or directory: '/dev/cu.usbserial-00002226'
   EasyDAQ Relay Card Debug        make sure the USB virtual serial port driver (ex: FTDI driver) is installed and correct port is selected
   EasyDAQ Relay Card Debug        silently retrying serial connection every 5 seconds
   EasyDAQ Relay Card Debug        exiting deviceStartComm2 -->>

Before when direct attached when i did this, the plugin restarted so it started working again because the plugin restarted (it seemed), but will test this again while in debug.

"Disable channel status poling" is disabled (see attachment). Will try enabling it to see if it makes a difference.

As you can see in the image the deviceid/port has changed since plugin it in direct again... just to point that out
Attachments
2016-12-28_21-59-06.jpg
2016-12-28_21-59-06.jpg (132.78 KiB) Viewed 4607 times

Posted on
Fri Dec 30, 2016 8:59 am
AndyVirus offline
Posts: 257
Joined: Mar 18, 2014
Location: Newport Pagnell, UK

Re: Any Verbose Logging?

OK I went extreme and wiped my mac mini and built fresh.... Sounds over the top but i have had the occasional issue where things would not work right in Indigo such as inbuilt plugins (action collector?) sometimes starting, sometimes not after a reboot mainly. With this issue i started to dig deeper, found my filesystem had issues so backed up everything and dropped to recovery partition to run the fix errors on the disk and.... pop goes my filesystem. So had not choice in the end.

Good news is, it all now works again. Bad news is my mac is to old for Sierra but oh well.

Thanks for all your help and sorry there is not a nice resolution to this one for the forum :-).

Posted on
Fri Dec 30, 2016 11:46 am
matt (support) offline
Site Admin
User avatar
Posts: 21411
Joined: Jan 27, 2003
Location: Texas

Re: Any Verbose Logging?

Great – glad it is up and working again. Sometimes a clean OS install is a good cure...

Image

Page 1 of 1

Who is online

Users browsing this forum: No registered users and 1 guest