parisbutterfield / restswitchmate

Control Switchmate devices via REST
MIT License
10 stars 2 forks source link

newFirmware + 3 Bluetooth Radios -> Lots of failed connections still #5

Open kianrafiee opened 6 years ago

kianrafiee commented 6 years ago

Hi again @parisbutterfield

So both of my switchmate brights are on the new 2.9.15 firmware. Even so, I decided to put in 2 buetooth adapters on the Pi3 making a total of 3 bt radios because I was getting a lot of failed connections through alexa/hass.

Even with 3 bt radios, there are a lot of failed connections. And moreso at one point it quede 5 commands and therefore about 2 minutes later the switchmate was toggling on and off multiple times in a row.

I'm wondering if this has to do with how often it polls the switchmates? Specifically since there on the new firmware and you said it has to connect to the devices for each polling?

I'm wondering if it is something that can be fixed or would I see better connection quality if I downgrade my brights to older firmware that requires authorization?

Log:

pi@raspberrypi:~/restswitchmate $ sudo docker-compose logs --tail="100" switchserver
Attaching to restswitchmate_switchserver_1
switchserver_1  | Switchmate SwitchServer Running
switchserver_1  |  * Running on http://0.0.0.0:5002/ (Press CTRL+C to quit)
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 08:55:49] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
switchserver_1  | Switchmate SwitchServer Running
switchserver_1  |  * Running on http://0.0.0.0:5002/ (Press CTRL+C to quit)
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 09:03:49] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 09:08:03] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 09:08:12] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Failed to connect to peripheral f1:ab:e8:2e:ed:df, addr type: random
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 09:08:22] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 09:08:59] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 09:09:15] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 09:15:30] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 09:15:54] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 09:17:02] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 19:03:08] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Failed to connect to peripheral f1:ab:e8:2e:ed:df, addr type: random
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 19:03:24] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 19:03:35] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 19:03:46] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 19:03:58] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 19:04:12] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 19:14:14] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 19:14:23] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 19:15:23] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 19:15:49] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 19:16:01] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 19:16:57] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 19:17:38] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 19:17:56] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 19:20:21] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 19:20:21] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 19:20:21] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 19:20:21] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 19:20:22] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 19:20:22] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 19:20:22] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
pi@raspberrypi:~/restswitchmate $ 
kianrafiee commented 6 years ago

I downgraded one of the brights to 2.9.0. Tried authorizing it. But it keeps failing:

statusserver_1  | Starting Scan Process
authserver_1    | Status Background Thread has stopped
authserver_1    | Auth Background Thread has stopped
authserver_1    | Status Background Thread Listening
authserver_1    | Auth Background Thread Listening
authserver_1    | Got auth request for: D01CCB9A9E82
authserver_1    | Sending item Starting auth for D01CCB9A9E82
authserver_1    | Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
statusserver_1  | ('F1ABE82EEDDF', True, datetime.datetime(2018, 3, 11, 20, 4, 1, 940893))
statusserver_1  | ('D01CCB9A9E82', False, datetime.datetime(2018, 3, 11, 20, 4, 3, 756041))
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 20:04:05] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 20:04:05] "GET /device/D01CCB9A9E82 HTTP/1.1" 200 -
statusserver_1  | Starting Scan Process
statusserver_1  | ('F1ABE82EEDDF', True, datetime.datetime(2018, 3, 11, 20, 4, 12, 133763))
statusserver_1  | ('D01CCB9A9E82', False, datetime.datetime(2018, 3, 11, 20, 4, 14, 826482))
statusserver_1  | Starting Scan Process
authserver_1    | Status Background Thread has stopped
authserver_1    | Auth Background Thread has stopped
authserver_1    | Status Background Thread Listening
authserver_1    | Auth Background Thread Listening
authserver_1    | Got auth request for: D01CCB9A9E82
authserver_1    | Sending item Starting auth for D01CCB9A9E82
authserver_1    | Error from Bluetooth stack (comerr)
statusserver_1  | ('F1ABE82EEDDF', True, datetime.datetime(2018, 3, 11, 20, 4, 23, 534294))
statusserver_1  | ('D01CCB9A9E82', False, datetime.datetime(2018, 3, 11, 20, 4, 24, 81897))
statusserver_1  | Starting Scan Process
statusserver_1  | WARNING: Could not read status of f1:ab:e8:2e:ed:df. Failed to connect to peripheral f1:ab:e8:2e:ed:df, addr type: random
statusserver_1  | WARNING: Could not read status of d0:1c:cb:9a:9e:82. Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
statusserver_1  | Starting Scan Process
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 20:04:36] "GET /device/D01CCB9A9E82 HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 20:04:36] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
kianrafiee commented 6 years ago

My mistake, 2.9.0 is non-auth firmware. Looks like I cannot downgrade to a firmware that has auth to test connection reliability.

kianrafiee commented 6 years ago

Oh and this may be useful: The switchmate app always gets the toggle requests everytime. So I am sure it's not a matter of distance of the pi and switchmates.

parisbutterfield commented 6 years ago

I'm pretty sure the polling which creates a connection and the switching which also creates a connection is causing an issue.

For the old firmware and classic Switchmate, I don't have this issue. I don't think auth ever worked on the Bright firmwares.

I think there could be a redesign.

Not sure if I'll have time to do this in the immediate future.

Few things I'd like for you try:

Sent with GitHawk

kianrafiee commented 6 years ago

When I disabled status server, nothing would work. I suspect you meant the auth server? When I disabled the authserver, things seem to have gotten a little better. If I wait about 15 seconds in between commands, I can get about 50% of commands to go through now. One caveat: there are more "cannot connect to bluetooth" errors in status server now. I haven't tried increasing sleep time yet though, will do that in a second.

Log:

restswitchmate_authserver_1 exited with code 137
statusserver_1  | ('D01CCB9A9E82', False, datetime.datetime(2018, 3, 11, 22, 27, 42, 996782))
statusserver_1  | Starting Scan Process
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:27:45] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:27:45] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 22:27:50] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:27:50] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:27:50] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | ('F1ABE82EEDDF', False, datetime.datetime(2018, 3, 11, 22, 27, 51, 374457))
statusserver_1  | ('D01CCB9A9E82', False, datetime.datetime(2018, 3, 11, 22, 27, 52, 513407))
statusserver_1  | Starting Scan Process
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 22:27:57] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:27:57] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:27:57] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
statusserver_1  | ('F1ABE82EEDDF', True, datetime.datetime(2018, 3, 11, 22, 28, 2, 443717))
statusserver_1  | ('D01CCB9A9E82', False, datetime.datetime(2018, 3, 11, 22, 28, 4, 326337))
statusserver_1  | Starting Scan Process
statusserver_1  | ('F1ABE82EEDDF', True, datetime.datetime(2018, 3, 11, 22, 28, 12, 298996))
statusserver_1  | WARNING: Could not read status of d0:1c:cb:9a:9e:82. Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
statusserver_1  | Starting Scan Process
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:28:16] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:28:16] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | ('F1ABE82EEDDF', True, datetime.datetime(2018, 3, 11, 22, 28, 21, 816358))
statusserver_1  | ('D01CCB9A9E82', False, datetime.datetime(2018, 3, 11, 22, 28, 23, 293894))
statusserver_1  | Starting Scan Process
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 22:28:31] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:28:31] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:28:31] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | ('F1ABE82EEDDF', True, datetime.datetime(2018, 3, 11, 22, 28, 32, 76532))
statusserver_1  | ('D01CCB9A9E82', False, datetime.datetime(2018, 3, 11, 22, 28, 33, 959909))
switchserver_1  | Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
statusserver_1  | Starting Scan Process
statusserver_1  | WARNING: Could not read status of f1:ab:e8:2e:ed:df. Failed to connect to peripheral f1:ab:e8:2e:ed:df, addr type: random
statusserver_1  | ('D01CCB9A9E82', False, datetime.datetime(2018, 3, 11, 22, 28, 44, 294899))
statusserver_1  | Starting Scan Process
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:28:47] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:28:47] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | ('F1ABE82EEDDF', True, datetime.datetime(2018, 3, 11, 22, 28, 53, 2685))
statusserver_1  | ('D01CCB9A9E82', False, datetime.datetime(2018, 3, 11, 22, 28, 55, 290245))
statusserver_1  | Starting Scan Process
statusserver_1  | WARNING: Could not read status of f1:ab:e8:2e:ed:df. Failed to connect to peripheral f1:ab:e8:2e:ed:df, addr type: random
statusserver_1  | ('D01CCB9A9E82', False, datetime.datetime(2018, 3, 11, 22, 29, 5, 85549))
statusserver_1  | Starting Scan Process
statusserver_1  | WARNING: Could not read status of f1:ab:e8:2e:ed:df. Failed to connect to peripheral f1:ab:e8:2e:ed:df, addr type: random
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 22:29:14] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:29:14] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:29:14] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | ('D01CCB9A9E82', False, datetime.datetime(2018, 3, 11, 22, 29, 14, 737053))
statusserver_1  | Starting Scan Process
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:29:18] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:29:18] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | ('F1ABE82EEDDF', True, datetime.datetime(2018, 3, 11, 22, 29, 22, 972356))
statusserver_1  | ('D01CCB9A9E82', True, datetime.datetime(2018, 3, 11, 22, 29, 24, 179506))
statusserver_1  | Starting Scan Process
statusserver_1  | WARNING: Could not read status of f1:ab:e8:2e:ed:df. Failed to connect to peripheral f1:ab:e8:2e:ed:df, addr type: random
statusserver_1  | ('D01CCB9A9E82', True, datetime.datetime(2018, 3, 11, 22, 29, 33, 367693))
statusserver_1  | Starting Scan Process
statusserver_1  | ('F1ABE82EEDDF', True, datetime.datetime(2018, 3, 11, 22, 29, 42, 547956))
statusserver_1  | ('D01CCB9A9E82', True, datetime.datetime(2018, 3, 11, 22, 29, 44, 498018))
statusserver_1  | Starting Scan Process
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:29:49] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:29:49] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | WARNING: Could not read status of f1:ab:e8:2e:ed:df. Failed to connect to peripheral f1:ab:e8:2e:ed:df, addr type: random
statusserver_1  | ('D01CCB9A9E82', True, datetime.datetime(2018, 3, 11, 22, 29, 55, 440771))
statusserver_1  | Starting Scan Process
statusserver_1  | WARNING: Could not read status of f1:ab:e8:2e:ed:df. Failed to connect to peripheral f1:ab:e8:2e:ed:df, addr type: random
statusserver_1  | ('D01CCB9A9E82', True, datetime.datetime(2018, 3, 11, 22, 30, 6, 646069))
statusserver_1  | Starting Scan Process
statusserver_1  | ('F1ABE82EEDDF', True, datetime.datetime(2018, 3, 11, 22, 30, 15, 556194))
statusserver_1  | WARNING: Could not read status of d0:1c:cb:9a:9e:82. Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
statusserver_1  | Starting Scan Process
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:30:20] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:30:20] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | ('F1ABE82EEDDF', True, datetime.datetime(2018, 3, 11, 22, 30, 26, 289028))
statusserver_1  | ('D01CCB9A9E82', True, datetime.datetime(2018, 3, 11, 22, 30, 28, 34698))
statusserver_1  | Starting Scan Process
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 22:30:30] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:30:30] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:30:30] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | ('F1ABE82EEDDF', False, datetime.datetime(2018, 3, 11, 22, 30, 36, 750660))
statusserver_1  | ('D01CCB9A9E82', True, datetime.datetime(2018, 3, 11, 22, 30, 38, 903318))
statusserver_1  | Starting Scan Process
statusserver_1  | ('F1ABE82EEDDF', False, datetime.datetime(2018, 3, 11, 22, 30, 47, 956008))
statusserver_1  | ('D01CCB9A9E82', True, datetime.datetime(2018, 3, 11, 22, 30, 49, 568563))
statusserver_1  | Starting Scan Process
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:30:51] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:30:51] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | ('F1ABE82EEDDF', False, datetime.datetime(2018, 3, 11, 22, 30, 57, 743771))
statusserver_1  | ('D01CCB9A9E82', True, datetime.datetime(2018, 3, 11, 22, 30, 59, 153850))
statusserver_1  | Starting Scan Process
statusserver_1  | ('F1ABE82EEDDF', False, datetime.datetime(2018, 3, 11, 22, 31, 7, 666124))
statusserver_1  | WARNING: Could not read status of d0:1c:cb:9a:9e:82. Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
statusserver_1  | Starting Scan Process
statusserver_1  | ('F1ABE82EEDDF', False, datetime.datetime(2018, 3, 11, 22, 31, 17, 724346))
statusserver_1  | ('D01CCB9A9E82', True, datetime.datetime(2018, 3, 11, 22, 31, 19, 66391))
statusserver_1  | Starting Scan Process
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 22:31:22] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:31:22] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:31:22] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:31:23] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:31:23] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | ('F1ABE82EEDDF', False, datetime.datetime(2018, 3, 11, 22, 31, 28, 389082))
statusserver_1  | WARNING: Could not read status of d0:1c:cb:9a:9e:82. Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
statusserver_1  | Starting Scan Process
statusserver_1  | WARNING: Could not read status of f1:ab:e8:2e:ed:df. Failed to connect to peripheral f1:ab:e8:2e:ed:df, addr type: random
statusserver_1  | WARNING: Could not read status of d0:1c:cb:9a:9e:82. Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
statusserver_1  | Starting Scan Process
statusserver_1  | ('F1ABE82EEDDF', False, datetime.datetime(2018, 3, 11, 22, 31, 49, 448264))
statusserver_1  | ('D01CCB9A9E82', False, datetime.datetime(2018, 3, 11, 22, 31, 52, 343403))
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:31:53] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:31:53] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | Starting Scan Process
statusserver_1  | ('F1ABE82EEDDF', False, datetime.datetime(2018, 3, 11, 22, 32, 0, 790433))
statusserver_1  | WARNING: Could not read status of d0:1c:cb:9a:9e:82. Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
statusserver_1  | Starting Scan Process
statusserver_1  | ('F1ABE82EEDDF', False, datetime.datetime(2018, 3, 11, 22, 32, 10, 306908))
statusserver_1  | WARNING: Could not read status of d0:1c:cb:9a:9e:82. Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
statusserver_1  | Starting Scan Process
statusserver_1  | ('F1ABE82EEDDF', False, datetime.datetime(2018, 3, 11, 22, 32, 20, 27131))
statusserver_1  | ('D01CCB9A9E82', False, datetime.datetime(2018, 3, 11, 22, 32, 21, 842217))
statusserver_1  | Starting Scan Process
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:32:24] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:32:24] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | WARNING: Could not read status of f1:ab:e8:2e:ed:df. Failed to connect to peripheral f1:ab:e8:2e:ed:df, addr type: random
statusserver_1  | WARNING: Could not read status of d0:1c:cb:9a:9e:82. Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
statusserver_1  | Starting Scan Process
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 22:32:36] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:32:36] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:32:36] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | ('F1ABE82EEDDF', True, datetime.datetime(2018, 3, 11, 22, 32, 41, 20092))
statusserver_1  | WARNING: Could not read status of d0:1c:cb:9a:9e:82. Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
statusserver_1  | Starting Scan Process
statusserver_1  | ('F1ABE82EEDDF', True, datetime.datetime(2018, 3, 11, 22, 32, 50, 470343))
statusserver_1  | WARNING: Could not read status of d0:1c:cb:9a:9e:82. Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
statusserver_1  | Starting Scan Process
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:32:55] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:32:55] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | ('F1ABE82EEDDF', True, datetime.datetime(2018, 3, 11, 22, 32, 59, 785535))
statusserver_1  | WARNING: Could not read status of d0:1c:cb:9a:9e:82. Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
statusserver_1  | Starting Scan Process
statusserver_1  | WARNING: Could not read status of f1:ab:e8:2e:ed:df. Failed to connect to peripheral f1:ab:e8:2e:ed:df, addr type: random
statusserver_1  | WARNING: Could not read status of d0:1c:cb:9a:9e:82. Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
statusserver_1  | Starting Scan Process
statusserver_1  | WARNING: Could not read status of f1:ab:e8:2e:ed:df. Failed to connect to peripheral f1:ab:e8:2e:ed:df, addr type: random
statusserver_1  | WARNING: Could not read status of d0:1c:cb:9a:9e:82. Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
statusserver_1  | Starting Scan Process
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:33:26] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:33:26] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | WARNING: Could not read status of f1:ab:e8:2e:ed:df. Failed to connect to peripheral f1:ab:e8:2e:ed:df, addr type: random
statusserver_1  | ('D01CCB9A9E82', False, datetime.datetime(2018, 3, 11, 22, 33, 31, 443598))
statusserver_1  | Starting Scan Process
statusserver_1  | WARNING: Could not read status of f1:ab:e8:2e:ed:df. Failed to connect to peripheral f1:ab:e8:2e:ed:df, addr type: random
statusserver_1  | WARNING: Could not read status of d0:1c:cb:9a:9e:82. Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
statusserver_1  | Starting Scan Process
statusserver_1  | ('F1ABE82EEDDF', True, datetime.datetime(2018, 3, 11, 22, 33, 49, 61265))
statusserver_1  | ('D01CCB9A9E82', False, datetime.datetime(2018, 3, 11, 22, 33, 51, 619020))
statusserver_1  | Starting Scan Process
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:33:57] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:33:57] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | ('F1ABE82EEDDF', True, datetime.datetime(2018, 3, 11, 22, 34, 0, 130646))
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 22:34:01] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:34:01] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:34:01] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | ('D01CCB9A9E82', False, datetime.datetime(2018, 3, 11, 22, 34, 1, 743199))
statusserver_1  | Starting Scan Process
switchserver_1  | Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
statusserver_1  | ('F1ABE82EEDDF', True, datetime.datetime(2018, 3, 11, 22, 34, 10, 593473))
statusserver_1  | ('D01CCB9A9E82', False, datetime.datetime(2018, 3, 11, 22, 34, 13, 488662))
statusserver_1  | Starting Scan Process
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 22:34:18] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:34:18] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:34:18] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | ('F1ABE82EEDDF', True, datetime.datetime(2018, 3, 11, 22, 34, 21, 799018))
statusserver_1  | ('D01CCB9A9E82', True, datetime.datetime(2018, 3, 11, 22, 34, 23, 681608))
statusserver_1  | Starting Scan Process
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:34:28] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:34:28] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | WARNING: Could not read status of f1:ab:e8:2e:ed:df. Failed to connect to peripheral f1:ab:e8:2e:ed:df, addr type: random
statusserver_1  | ('D01CCB9A9E82', True, datetime.datetime(2018, 3, 11, 22, 34, 34, 84265))
statusserver_1  | Starting Scan Process
statusserver_1  | ('F1ABE82EEDDF', True, datetime.datetime(2018, 3, 11, 22, 34, 42, 454245))
statusserver_1  | ('D01CCB9A9E82', True, datetime.datetime(2018, 3, 11, 22, 34, 44, 202066))
statusserver_1  | Starting Scan Process
statusserver_1  | WARNING: Could not read status of f1:ab:e8:2e:ed:df. Failed to connect to peripheral f1:ab:e8:2e:ed:df, addr type: random
statusserver_1  | WARNING: Could not read status of d0:1c:cb:9a:9e:82. Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
statusserver_1  | Starting Scan Process
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:34:59] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:34:59] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | ('F1ABE82EEDDF', True, datetime.datetime(2018, 3, 11, 22, 35, 2, 29755))
statusserver_1  | WARNING: Could not read status of d0:1c:cb:9a:9e:82. Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
statusserver_1  | Starting Scan Process
statusserver_1  | WARNING: Could not read status of f1:ab:e8:2e:ed:df. Failed to connect to peripheral f1:ab:e8:2e:ed:df, addr type: random
statusserver_1  | ('D01CCB9A9E82', True, datetime.datetime(2018, 3, 11, 22, 35, 16, 475006))
statusserver_1  | Starting Scan Process
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 22:35:22] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:35:22] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:35:22] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | WARNING: Could not read status of f1:ab:e8:2e:ed:df. Failed to connect to peripheral f1:ab:e8:2e:ed:df, addr type: random
switchserver_1  | Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
statusserver_1  | WARNING: Could not read status of d0:1c:cb:9a:9e:82. Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
statusserver_1  | Starting Scan Process
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:35:30] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:35:30] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | ('F1ABE82EEDDF', True, datetime.datetime(2018, 3, 11, 22, 35, 33, 686779))
statusserver_1  | ('D01CCB9A9E82', True, datetime.datetime(2018, 3, 11, 22, 35, 35, 434310))
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 22:35:36] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:35:36] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:35:36] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | Starting Scan Process
statusserver_1  | ('F1ABE82EEDDF', True, datetime.datetime(2018, 3, 11, 22, 35, 44, 82069))
statusserver_1  | ('D01CCB9A9E82', False, datetime.datetime(2018, 3, 11, 22, 35, 45, 627473))
statusserver_1  | Starting Scan Process
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 22:35:50] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:35:50] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:35:50] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Failed to connect to peripheral f1:ab:e8:2e:ed:df, addr type: random
statusserver_1  | WARNING: Could not read status of f1:ab:e8:2e:ed:df. Failed to connect to peripheral f1:ab:e8:2e:ed:df, addr type: random
statusserver_1  | WARNING: Could not read status of d0:1c:cb:9a:9e:82. Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
statusserver_1  | Starting Scan Process
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:36:01] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:36:01] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | ('F1ABE82EEDDF', True, datetime.datetime(2018, 3, 11, 22, 36, 3, 590015))
statusserver_1  | WARNING: Could not read status of d0:1c:cb:9a:9e:82. Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [11/Mar/2018 22:36:06] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:36:06] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [11/Mar/2018 22:36:06] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | Starting Scan Process
statusserver_1  | ('F1ABE82EEDDF', False, datetime.datetime(2018, 3, 11, 22, 36, 13, 107817))
statusserver_1  | ('D01CCB9A9E82', False, datetime.datetime(2018, 3, 11, 22, 36, 14, 855297))
statusserver_1  | Starting Scan Process
statusserver_1  | WARNING: Could not read status of f1:ab:e8:2e:ed:df. Failed to connect to peripheral f1:ab:e8:2e:ed:df, addr ty
parisbutterfield commented 6 years ago

Yeah I meant the StatusServer and then connect directly to the Switch server with :5002. I'm wondering if the scanning is causing an issue.

Sent with GitHawk

kianrafiee commented 6 years ago

Ah ok, let me do that real quick. I will use postman I assume, will report back shortly. Your right, it could be the scanning. But I cant really tell you how, just that maybe the bluetooth connection during scanning(and failing) is causing it to not have enough time to make another connection to the switch when I issue a command.

kianrafiee commented 6 years ago

Alright more progress. So I disabled both auth and status server. I used postman to send both true on and true off to both switchmates, total of 4 put requests inside postman.

I'm getting an even higher success rate with toggles. I'd say about 60-70% accuracy.

I noticed an anomaly: When I make a put request to one switchmate, and immediately(well about 3-5 seconds) after make a put request to another switchmate, they both work about 90-100%. Subsequent put requests are still at 60-70% accuracy.

If I make a put request to one switchmate, and immediately after make a put request of true off to the same switchmate, it usually fails.

Also, I think the status server really doesn't need 2-3 second polling. I'd say even 10 seconds is too much. Reason being: How often are you going to turn the lights on and then immediately back off again? If increasing the sleep timer could increase accuracy so much, then I'd say it's for the better. But I do understand that there are users who wouldnt like this. But then again if that user has a switchmate bright then she probably wont like failed connections like they are now anyway.

If you could somehow do this with python/html, you could add a setting to the status server web page that allows the user to change timer setting from whatever the default is. If not, I dont mind changing it myself in the future. I dont think Id have to update restswitchmate so much that it would become a pain.

And here is the much better looking log:

switchserver_1  | Request added to queue locally
switchserver_1  | 192.168.1.77 - - [11/Mar/2018 22:50:04] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 192.168.1.77 - - [11/Mar/2018 22:50:20] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 192.168.1.77 - - [11/Mar/2018 22:52:11] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 192.168.1.77 - - [11/Mar/2018 22:52:16] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 192.168.1.77 - - [11/Mar/2018 22:52:24] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 192.168.1.77 - - [11/Mar/2018 22:52:29] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 192.168.1.77 - - [11/Mar/2018 22:52:46] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 192.168.1.77 - - [11/Mar/2018 22:52:53] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
switchserver_1  | Request added to queue locally
switchserver_1  | 192.168.1.77 - - [11/Mar/2018 22:53:01] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
switchserver_1  | Request added to queue locally
switchserver_1  | 192.168.1.77 - - [11/Mar/2018 22:53:10] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 192.168.1.77 - - [11/Mar/2018 22:53:21] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 192.168.1.77 - - [11/Mar/2018 22:53:26] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | 192.168.1.77 - - [11/Mar/2018 22:53:37] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | Request added to queue locally
switchserver_1  | 192.168.1.77 - - [11/Mar/2018 22:53:41] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
switchserver_1  | Request added to queue locally
switchserver_1  | 192.168.1.77 - - [11/Mar/2018 22:53:44] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 192.168.1.77 - - [11/Mar/2018 22:53:57] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
switchserver_1  | Request added to queue locally
switchserver_1  | 192.168.1.77 - - [11/Mar/2018 22:54:03] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Failed to connect to peripheral f1:ab:e8:2e:ed:df, addr type: random
switchserver_1  | Request added to queue locally
switchserver_1  | 192.168.1.77 - - [11/Mar/2018 22:54:10] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 192.168.1.77 - - [11/Mar/2018 22:54:14] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 192.168.1.77 - - [11/Mar/2018 22:54:56] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
switchserver_1  | Request added to queue locally
switchserver_1  | 192.168.1.77 - - [11/Mar/2018 22:55:01] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 192.168.1.77 - - [11/Mar/2018 22:55:05] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | 192.168.1.77 - - [11/Mar/2018 22:55:23] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | Request added to queue locally
switchserver_1  | 192.168.1.77 - - [11/Mar/2018 22:55:28] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 192.168.1.77 - - [11/Mar/2018 22:55:42] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 192.168.1.77 - - [11/Mar/2018 22:55:46] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
parisbutterfield commented 6 years ago

I added the sleep for the scanning as an environment variable. You can edit the docker-compose or use one of the methods listed here.

The parameter is called SCAN_INTERVAL the default is 30 seconds. Note this will cause the HASS.io UI to show a delay in status.

    environment:
      - SCAN_HCI=0
      - SCAN_INTERVAL=30

Also for the failed to connect error. Try changing the position of your Pi. Elevation/Vertical wise. I had similar issues and you'd be surprised about the range of the bluetooth dongles. It's not great.

kianrafiee commented 6 years ago

That's great! Are you still planning on eventually reworking the status/switch server into one with priority queuing? No rush, just wondering if there is anything other than placement that will help the script out. Thank you so much.

kianrafiee commented 6 years ago

Also I updated my local repo, restarted docker-compose, but the scanning still occurs every few seconds. I'm wondering if you meant I still have to edit on my end? I thought you meant if I want to change it from 30 seconds. I tried doing sudo docker-compose up -e SCAN_INTERVAL=30 and that didnt work. I'll look into it more later but I guess I'm suppose to make an .env file?

kianrafiee commented 6 years ago

Log:

authserver_1    |  * Restarting with stat
authserver_1    |  * Debugger is active!
authserver_1    |  * Debugger PIN: 116-678-648
statusserver_1  | Starting Scan Process
statusserver_1  | Switchmate Scan Running
statusserver_1  |  * Running on http://0.0.0.0:5000/ (Press CTRL+C to quit)
switchserver_1  | Switchmate SwitchServer Running
switchserver_1  |  * Running on http://0.0.0.0:5002/ (Press CTRL+C to quit)
statusserver_1  | WARNING: Could not read status of f1:ab:e8:2e:ed:df. Failed to connect to peripheral f1:ab:e8:2e:ed:df, addr type: random
statusserver_1  | ('D01CCB9A9E82', False, datetime.datetime(2018, 3, 12, 7, 49, 26, 986870))
statusserver_1  | Starting Scan Process
statusserver_1  | WARNING: Could not read status of f1:ab:e8:2e:ed:df. Failed to connect to peripheral f1:ab:e8:2e:ed:df, addr type: random
statusserver_1  | ('D01CCB9A9E82', False, datetime.datetime(2018, 3, 12, 7, 49, 38, 460567))
statusserver_1  | 192.168.1.67 - - [12/Mar/2018 07:49:44] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [12/Mar/2018 07:49:44] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | Starting Scan Process
statusserver_1  | ('F1ABE82EEDDF', False, datetime.datetime(2018, 3, 12, 7, 49, 52, 636602))
statusserver_1  | ('D01CCB9A9E82', False, datetime.datetime(2018, 3, 12, 7, 49, 56, 274344))
statusserver_1  | Starting Scan Process
statusserver_1  | WARNING: Could not read status of f1:ab:e8:2e:ed:df. Failed to connect to peripheral f1:ab:e8:2e:ed:df, addr type: random
statusserver_1  | WARNING: Could not read status of d0:1c:cb:9a:9e:82. Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
statusserver_1  | Starting Scan Process
statusserver_1  | 192.168.1.67 - - [12/Mar/2018 07:50:10] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [12/Mar/2018 07:50:10] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | ('F1ABE82EEDDF', False, datetime.datetime(2018, 3, 12, 7, 50, 15, 249553))
statusserver_1  | WARNING: Could not read status of d0:1c:cb:9a:9e:82. Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
statusserver_1  | Starting Scan Process
statusserver_1  | WARNING: Could not read status of f1:ab:e8:2e:ed:df. Failed to connect to peripheral f1:ab:e8:2e:ed:df, addr type: random
statusserver_1  | ('D01CCB9A9E82', False, datetime.datetime(2018, 3, 12, 7, 50, 27, 669184))
statusserver_1  | Starting Scan Process
statusserver_1  | ('F1ABE82EEDDF', False, datetime.datetime(2018, 3, 12, 7, 50, 36, 445063))
statusserver_1  | ('D01CCB9A9E82', False, datetime.datetime(2018, 3, 12, 7, 50, 38, 665222))
statusserver_1  | Starting Scan Process
statusserver_1  | 192.168.1.67 - - [12/Mar/2018 07:50:41] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [12/Mar/2018 07:50:41] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | ('F1ABE82EEDDF', False, datetime.datetime(2018, 3, 12, 7, 50, 47, 42827))
statusserver_1  | ('D01CCB9A9E82', False, datetime.datetime(2018, 3, 12, 7, 50, 49, 195698))
statusserver_1  | Starting Scan Process
statusserver_1  | ('F1ABE82EEDDF', False, datetime.datetime(2018, 3, 12, 7, 50, 57, 301939))
statusserver_1  | ('D01CCB9A9E82', False, datetime.datetime(2018, 3, 12, 7, 50, 59, 319562))
statusserver_1  | Starting Scan Process
statusserver_1  | ('F1ABE82EEDDF', False, datetime.datetime(2018, 3, 12, 7, 51, 8, 102173))
statusserver_1  | WARNING: Could not read status of d0:1c:cb:9a:9e:82. Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
statusserver_1  | Starting Scan Process
statusserver_1  | 192.168.1.67 - - [12/Mar/2018 07:51:12] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [12/Mar/2018 07:51:12] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [12/Mar/2018 07:51:14] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [12/Mar/2018 07:51:14] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [12/Mar/2018 07:51:14] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | ('F1ABE82EEDDF', False, datetime.datetime(2018, 3, 12, 7, 51, 17, 890586))
statusserver_1  | ('D01CCB9A9E82', True, datetime.datetime(2018, 3, 12, 7, 51, 19, 435063))
statusserver_1  | Starting Scan Process
statusserver_1  | ('F1ABE82EEDDF', False, datetime.datetime(2018, 3, 12, 7, 51, 28, 82831))
statusserver_1  | WARNING: Could not read status of d0:1c:cb:9a:9e:82. Failed to connect to peripheral d0:1c:cb:9a:9e:82, addr type: random
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [12/Mar/2018 07:51:29] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [12/Mar/2018 07:51:29] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [12/Mar/2018 07:51:29] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
switchserver_1  | Failed to connect to peripheral f1:ab:e8:2e:ed:df, addr type: random
statusserver_1  | Starting Scan Process
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [12/Mar/2018 07:51:37] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [12/Mar/2018 07:51:37] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [12/Mar/2018 07:51:37] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | ('F1ABE82EEDDF', False, datetime.datetime(2018, 3, 12, 7, 51, 38, 4991))
statusserver_1  | ('D01CCB9A9E82', True, datetime.datetime(2018, 3, 12, 7, 51, 40, 428456))
statusserver_1  | Starting Scan Process
statusserver_1  | 192.168.1.67 - - [12/Mar/2018 07:51:43] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [12/Mar/2018 07:51:43] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | ('F1ABE82EEDDF', True, datetime.datetime(2018, 3, 12, 7, 51, 49, 8722))
statusserver_1  | ('D01CCB9A9E82', True, datetime.datetime(2018, 3, 12, 7, 51, 50, 957572))
statusserver_1  | Starting Scan Process
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [12/Mar/2018 07:51:59] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [12/Mar/2018 07:51:59] "PUT /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [12/Mar/2018 07:51:59] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | ('F1ABE82EEDDF', True, datetime.datetime(2018, 3, 12, 7, 52, 1, 22716))
statusserver_1  | ('D01CCB9A9E82', False, datetime.datetime(2018, 3, 12, 7, 52, 6, 625704))
switchserver_1  | Request added to queue locally
switchserver_1  | 127.0.0.1 - - [12/Mar/2018 07:52:07] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [12/Mar/2018 07:52:07] "PUT /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [12/Mar/2018 07:52:07] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | Starting Scan Process
statusserver_1  | 192.168.1.67 - - [12/Mar/2018 07:52:14] "GET /device/D01CCB9A9E82?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | 192.168.1.67 - - [12/Mar/2018 07:52:14] "GET /device/F1ABE82EEDDF?newFirmware=true HTTP/1.1" 200 -
statusserver_1  | ('F1ABE82EEDDF', False, datetime.datetime(2018, 3, 12, 7, 52, 15, 670975))
s
kianrafiee commented 6 years ago

Oh, now that I looked at the docker-compose.yaml file. I noticed the bluetooth radio used for each server is hard-coded. That leads me to believe that maybe changing the bluetooth radio for the switch server to be the onboard may lead to better connections for the switch server. That's if the onboard bluetooth radio is better than my dongles, which I've actually heard the opposite. And right now one of my dongles(I have two) is being used for nothing since its assigned to the auth server! :) Maybe having both of my dongles be the radios could improve functionality.

Which begs me to ask, can I edit the docker-compose file and change HCI assignments?

parisbutterfield commented 6 years ago

Hey @kianrafiee

You can definitely change the hard coded HCI assignments. I don't know when I'll do a single process based version of this. I will say that it probably won't solve your Failed to Connect errors. If you do a docker-compose build with the latest code it will pickup the new scan interval code.

kianrafiee commented 6 years ago

I was thinking of something the other day. What if you put a if-then logic in your code that if the Bluetooth fails to connect, that it re-trys the command in 1-2 seconds for a total of 3 tries or so? For instance it would be more automated then the user having to Tell Alexa more than once to turn it off in the event theres a failed connection the first try.

kianrafiee commented 6 years ago

Also, what was the scan interval before you made it 30 seconds?

parisbutterfield commented 6 years ago

@kianrafiee That's a possibility. I guess I could catch the Bluetooth exception and have it retry. The scan interval before was every 2 seconds.

kianrafiee commented 6 years ago

Yeah, if there is no downfall to it, I see no reason not to. Other than finding the time to do it, which I am in no rush to get that feature. Just whenever. Might not even need to have the scan interval so long once that feature is built in, could put it back to 2 seconds by default and have user change if needed.