Every so often when sispmctl exits, it hasn't actually set the output to the desired state. To solve this issue I created a small bash wrapper to test the state after it has been set and retry when required.
Over a week's log, 35900 times a socket was switched. I logged one event that required a retry.
I would like to see two improvements to the main binary:
1. Exit code represents the result of testing the intended state. ) for successful, 1 for failed.
2. Automatic retry (possibly with a max number of attempts).
Here is an improvised log, where the number after the _ underscore is the attempt counter. Normally this should be 0. My bash script tests and retries after 3 seconds. Timestamps are relative to the start of the bash script.
Wed Mar 16 19:58:33 CET 2016
00:00:02.351059587_0 I: Started sispmctl -D 01:01:4b:54:e5 -f3
00:00:02.552495026_0 E: now comparing 01:01:4b:54:e5 and 01:01:4b:54:e5
00:00:02.562626094_0 O: Accessing Gembird #0 USB device 003
00:00:02.563975171_0 O: Switched outlet 3 off
00:00:02.565453876_0 I: Finished with exitcode 0
00:00:05.148134543_1 I: Started sispmctl -D 01:01:4b:54:e5 -f3
00:00:05.357473914_1 E: now comparing 01:01:4b:54:e5 and 01:01:4b:54:e5
00:00:05.366290268_1 O: Accessing Gembird #0 USB device 003
00:00:05.367574251_1 O: Switched outlet 3 off
00:00:05.369716180_1 I: Finished with exitcode 0
At the exact time of this event I noticed an entry in syslog:
Mar 16 19:58:38 diablo kernel: [49365.566257] usb 7-2: usbfs: interface 0 claimed by usbfs while 'sispmctl' sets config #1
But not every occurence of this syslog entry has failed sispmctl event, even if it seems(?) to be at the exact same moment.
This is the bash wrapper script used:
#!/bin/bash
echo >> /tmp/sispmctl.log
date >> /tmp/sispmctl.log
n=0
export TZ=$( TZ="UTC" date -d "now" "+UTC+%H:%M:%S" )
until [ `sispmctl -D 01:01:4b:54:e5 -qg3` = 'on' ]; do
annotate-output +"%T.%N_$n" sispmctl -D 01:01:4b:54:e5 -o3 >> /tmp/sispmctl.log
$n=$(( $n + 1 ))
sleep .1
done
Makes sense. Patches welcome.