Log says "pairing established" but any interaction throws "is no known alias"
cablesandcoffee opened this issue · 4 comments
Hi!
I don't use Home Assistant but I really could use the functionality of this software so I gave it a try tonight.
I've installed it from source. Discovery command works good and I can see the device I would like to pair. It's an Aqara FP2 Sensor.
I use the pair command, get to put in a pin code, log says: Pairing for "aqara" was established.
The device starts flashing and never stops. When doing a discovery again the "unpaired" parameter is gone and it kind of seems like it has worked.
But when trying any of the other commands: accessories, identify, unpair it just says that the alias entered is no known alias so it doesn't seemed to have worked 100%. As soon as it says paired it also says connection lost in the log.
Here's the entire log with log DEBUG:
aiohomekitctl --log DEBUG pair -a aqara -d ce:49:60:c0:b6:16
2023-05-16 00:55:42,162 connection.py:0529 DEBUG Starting reconnect loop to 192.168.32.219:56940
2023-05-16 00:55:42,163 connection.py:0497 DEBUG Attempting connection to 192.168.32.219:56940
2023-05-16 00:55:42,236 __init__.py:0111 DEBUG #1 ios -> accessory: send SRP start request
2023-05-16 00:55:42,236 tlv.py:0192 DEBUG sending [
6 (State): (1 bytes/<class 'bytearray'>) 0x01
0 (Method): (1 bytes/<class 'bytearray'>) 0x00
]
2023-05-16 00:55:42,236 connection.py:0449 DEBUG 192.168.32.219: raw request: b'POST /pair-setup HTTP/1.1\r\nHost: 192.168.32.219\r\nContent-Length: 6\r\nContent-Type: application/pairing+tlv8\r\n\r\n\x06\x01\x01\x00\x01\x00'
2023-05-16 00:55:43,171 connection.py:0459 DEBUG 192.168.32.219: raw response: bytearray(b'\x06\x01\x02\x03\xffe$"\xf1\xbc\xce\xc7\x897O\x87i\x1d\xb2\xfe\xde\xee#\xe9d)\xb6\x00\x11\xfeM$\xad\xd6\xd3\x04k\x9e&[\x07\xda\xd1\xf3iA\xcc\xce\x90v\xf9+\r\x14\x07M\xc9\xc1f\xb7E}\x9f\x80\x00K"\xeb\x9e\xd9\xe0\x02\xe2:\x88\x7fQ\x05\xee\xec5\xf0\xbe\xcfU\x13\xfd\xd6\xac9\xdf]\xba\xc0!\\9.\xd9L\xfd\xfd\xf3\xc1c\x19\x80\xd4\xda-\x8dfi\xea\xbf\xdc\xad;\xfc\xcb\xe3\xc5$\xa5\x13y,\x8c\x9d\x0f\xce\x18(\'\xe3ME"\xd7\x93\xeevTum\xe3\x1ddo\x9c\xc7\x98\xec`\xd0\xd2\xe0\xd1\xe1\xdb\xb6\xc4j\xf9\x82\xfd;\xa6V\xf9\r\x9eN\xbf\x8e.\xcf0\x87$ \x96\x0e\xfc\xc6\xae $g\x14:Tn\xc6~\x8fJW\x03\xe9J\x90\x0f\x8f:\x9c`\xb6b\xce\xaeJ\xc3\xf2\x8eb\xcd\x94\x87\x0f\x01\xef\xe8e\xacn\xd4\xccY\x1c@9W\xb7\x1d\x00\xa3.P[8\xed\xaaB\xd4Te\xa5\xfc\xcdh/sM\x1f\xa5\x9bY]\x89\x03\x81\xfa\x80\xe07\x07\xe00a\x00m\xbcj\xe4)=\xb7\xeb\n\xa9\xea\xeaF\xdcKU\x1dl\xe3\x18w\x04\xbfe\xa1\xa3\xba\x82l+f\x7ft\x91^\xdc\xb5$\x0c\xc9n^\xa6T\xbf\x85q\xdc\x19\xf4\xf0\x86\'\xc7\xb4:\xe5Ws\x8e\x99\xa4\x18(rn\x7f\xa81\x9d9\xcbgJ\xc2\xe6\x0cU\x15p\xc8mH\x80=\xf1)\x1a\tF\xad\x998WFC\x06\xf7\xae\x88\x81\xc5\x85\xf0\x11\x8a\xd3RR\x88\x95\xe3oZ\x8b\x14\xc0\x1c\x88\xab\x02\x10\x05\xbb\xda\x8a\xf2\x93d\xbe\x83=D\x84<:\x11T')
2023-05-16 00:55:43,171 tlv.py:0175 DEBUG receiving [
6 (State): (1 bytes/<class 'bytearray'>) 0x02
3 (PublicKey): (384 bytes/<class 'bytearray'>) 0x652422f1bccec789374f87691db2fedeee23e96429b60011fe4d24add6d3046b9e265b07dad1f36941ccce9076f92b0d14074dc9c166b7457d9f80004b22eb9ed9e002e23a887f5105eeec35f0becf5513fdd6ac39df5dbac0215c392ed94cfdfdf3c1631980d4da2d8d6669eabfdcad3bfccbe3c524a513792c8c9d0fce182827e34d4522d793ee7654756de31d646f9cc798ec60d0d2e0d1e1dbb6c46af982fd3ba656f90d9e4ebf8e2ecf30872420960efcc6ae202467143a546ec67e8f4a5703e94a900f8f3a9c60b662ceae4ac3f28e62cd94870f01efe865ac6ed4cc591c403957b71d00a32e505b38edaa42d45465a5fccd682f734d1fa59b595d89fa80e03707e03061006dbc6ae4293db7eb0aa9eaea46dc4b551d6ce3187704bf65a1a3ba826c2b667f74915edcb5240cc96e5ea654bf8571dc19f4f08627c7b43ae557738e99a41828726e7fa8319d39cb674ac2e60c551570c86d48803df1291a0946ad993857464306f7ae8881c585f0118ad352528895e36f5a8b14c01c88ab
2 (Salt): (16 bytes/<class 'bytearray'>) 0x05bbda8af29364be833d44843c3a1154
]
2023-05-16 00:55:43,171 __init__.py:0128 DEBUG #3 ios -> accessory: send SRP verify request
Enter device pin (XXX-YY-ZZZ): 911-75-040
2023-05-16 00:55:54,298 tlv.py:0192 DEBUG sending [
6 (State): (1 bytes/<class 'bytearray'>) 0x03
3 (PublicKey): (384 bytes/<class 'bytes'>) b'\x0fGhk\xd3R\xa9\x93\xb2\x07@\xe7m9e\xe83\xe9?\x90\x96>8\xd8\xad\x0fx\xe6eQ\xd2\xd2\x07a~]\xcf\x06\xd80\x8d\xb5\x0e\x82^\xa0~\x98\xa4Y\x07g\x8b\xe8\xb8\x12\x0e\x98s\x89\x9f{\xf8\xa1\xb8\x142P\xdd\x1e\x8b\x87\xfa\x1eY\x13\x10\xc5\xba\xd6\x98v\xc4\xd4@u\xce?\xb1\xd7\n6\x7f\xc6\x1c\x8e\xb6<\xc0\x96\xa6#8\n\xd4{\\\xed\xd5\x15\x87\xed\xdc\x11\x96\xd3[@"\x0328\x88\xa6\xeb\xe0\x91\xf0\xcb\xa5a5\xf1\x90\x10Ev\xf8\xbc\x19\x89\xb7\xc8\xc4\xe2VF\xf4\xfa\x8ca\xc5\xa2\xc4\xf4\x9bx\x08\x16Ys\xfe8\xe8\xa1:\xad\xf6\xef\r6\x87\xa7n4\x8d\xe9%\x9b\xce\x98yzd\xca\xa6_\xbce+A\xb8\xcb\xd1\xab\xb4\xe88)\xcc\xf5^\xc3#F\xb9j\x16s:\xe6\xde\x86u\xe4\xcf\xbe9\xb4\x94p\xdd\x14r*D\x88\xe6F\t\xf7U\x94\x07AD\xf4\xae\x1cj\xe7\xe3\xe4\x84\xd9\xd2\xc2\xa7\x04\xffi\xe62\x13"L\x8fL,`\x8dq\x9d\xf66\xcb\xcb\xfb\x0e\xacm\xa2\x975\x15~\x01\xfe\xe7\x03\xa5mx\xa5\xf3\xd4\xeb\xc5\xb4\xf7`\xc5\x14\x08\xd1I\x86\xdb\xb0\xdd\xb7\xb6uK|\xf0\x93\xb9\xec\xe0\x97NY\xc5$\xa5<\x05\x9a\xb1\x88Jeh\xc5\x85}-\xf6\x86?$+\xe6\x871C\xa1\xc9\xa9\x8d\xba_\xd1`>\'\x05\xb7C\r\xd8\x7f=\xbe\x90\x1cO\'u\xc4\x80\xb3\xd9>\x9d\n\x17\x95o\x8ehV\xf4\xeb"\xe0o\x10\xda\xa3A\xb6I'
4 (Proof): (64 bytes/<class 'bytes'>) b'\xd8\x022\x92\x9a\xce\xb7DS\xe7\xac]\x8a\x84Z\xaa\x004)Z\x11\x07\xf3\xd1\x05Br\xae!s\n\xbcOf\xc18D\x1em\xbe\xc5xb\xba\x9d\xa8\xf8\xd2G\xd2z#\x10\xff@\xf6\xba\xa4R\xce3\x8f\x8du'
]
2023-05-16 00:55:54,298 connection.py:0449 DEBUG 192.168.32.219: raw request: b'POST /pair-setup HTTP/1.1\r\nHost: 192.168.32.219\r\nContent-Length: 457\r\nContent-Type: application/pairing+tlv8\r\n\r\n\x06\x01\x03\x03\xff\x0fGhk\xd3R\xa9\x93\xb2\x07@\xe7m9e\xe83\xe9?\x90\x96>8\xd8\xad\x0fx\xe6eQ\xd2\xd2\x07a~]\xcf\x06\xd80\x8d\xb5\x0e\x82^\xa0~\x98\xa4Y\x07g\x8b\xe8\xb8\x12\x0e\x98s\x89\x9f{\xf8\xa1\xb8\x142P\xdd\x1e\x8b\x87\xfa\x1eY\x13\x10\xc5\xba\xd6\x98v\xc4\xd4@u\xce?\xb1\xd7\n6\x7f\xc6\x1c\x8e\xb6<\xc0\x96\xa6#8\n\xd4{\\\xed\xd5\x15\x87\xed\xdc\x11\x96\xd3[@"\x0328\x88\xa6\xeb\xe0\x91\xf0\xcb\xa5a5\xf1\x90\x10Ev\xf8\xbc\x19\x89\xb7\xc8\xc4\xe2VF\xf4\xfa\x8ca\xc5\xa2\xc4\xf4\x9bx\x08\x16Ys\xfe8\xe8\xa1:\xad\xf6\xef\r6\x87\xa7n4\x8d\xe9%\x9b\xce\x98yzd\xca\xa6_\xbce+A\xb8\xcb\xd1\xab\xb4\xe88)\xcc\xf5^\xc3#F\xb9j\x16s:\xe6\xde\x86u\xe4\xcf\xbe9\xb4\x94p\xdd\x14r*D\x88\xe6F\t\xf7U\x94\x07AD\xf4\xae\x1cj\xe7\xe3\xe4\x84\xd9\xd2\xc2\xa7\x04\xffi\xe62\x13"\x03\x81L\x8fL,`\x8dq\x9d\xf66\xcb\xcb\xfb\x0e\xacm\xa2\x975\x15~\x01\xfe\xe7\x03\xa5mx\xa5\xf3\xd4\xeb\xc5\xb4\xf7`\xc5\x14\x08\xd1I\x86\xdb\xb0\xdd\xb7\xb6uK|\xf0\x93\xb9\xec\xe0\x97NY\xc5$\xa5<\x05\x9a\xb1\x88Jeh\xc5\x85}-\xf6\x86?$+\xe6\x871C\xa1\xc9\xa9\x8d\xba_\xd1`>\'\x05\xb7C\r\xd8\x7f=\xbe\x90\x1cO\'u\xc4\x80\xb3\xd9>\x9d\n\x17\x95o\x8ehV\xf4\xeb"\xe0o\x10\xda\xa3A\xb6I\x04@\xd8\x022\x92\x9a\xce\xb7DS\xe7\xac]\x8a\x84Z\xaa\x004)Z\x11\x07\xf3\xd1\x05Br\xae!s\n\xbcOf\xc18D\x1em\xbe\xc5xb\xba\x9d\xa8\xf8\xd2G\xd2z#\x10\xff@\xf6\xba\xa4R\xce3\x8f\x8du'
2023-05-16 00:55:55,122 connection.py:0459 DEBUG 192.168.32.219: raw response: bytearray(b'\x06\x01\x04\x04@c\xea\x97\xf5%`&\xaa-\x00\x8f\xbf`\xf0\x82\x9fT\x7f\xcb\xd5a\x89ni\xd0\xaa\xc2#Of\x06~s\xee\x02\xb5hS\x10\xa0\xb6\x91Rn6\x06\x16\x8e\x93A\x02\xed:\x0e\xf0\xe4xe\x99\xd0~\x8c\xa4k\x05\x1al:\x12G\xbe\xdd\x11\x1c\xd9\x8d\xa8\xdf\xa1\x18%\xe8\xe0\xaf\x1d\x9ew\x8d=#\x81\xff')
2023-05-16 00:55:55,122 tlv.py:0175 DEBUG receiving [
6 (State): (1 bytes/<class 'bytearray'>) 0x04
4 (Proof): (64 bytes/<class 'bytearray'>) 0x63ea97f5256026aa2d008fbf60f0829f547fcbd561896e69d0aac2234f66067e73ee02b5685310a0b691526e3606168e934102ed3a0ef0e4786599d07e8ca46b
5 (EncryptedData): (26 bytes/<class 'bytearray'>) 0x6c3a1247bedd111cd98da8dfa11825e8e0af1d9e778d3d2381ff
]
2023-05-16 00:55:55,123 __init__.py:0223 DEBUG #5 ios -> accessory: send SRP exchange request
2023-05-16 00:55:55,125 tlv.py:0192 DEBUG sending [
1 (Identifier): (36 bytes/<class 'bytes'>) b'fccaa974-a315-4f5b-b779-c3a21757d072'
3 (PublicKey): (32 bytes/<class 'bytes'>) b'\xd6n\x86\x0bB"\xbb\xcdp#(\x9f\x14\x88\x13\x9b\x86yf\x98F\xb6p#b4\xfd|\xea\xef\x0e\xd2'
10 (Signature): (64 bytes/<class 'bytes'>) b'\xe1y\x92\xad\x9b\x1d\x95\x84\xa9 \xb2\xe2\xd1\xcb\x10\r\xbe\xdb\xb0\x0b\x95xn\xdb\x81\xdfp\xc9\x99ib\xf5S\xe6\x9eX\x06\x87\xf8D\x08\xdaA\xd2ew\x13\x98\x802\x14-\x8d\xa4 /\xb7\xec[\xa33\x91]\x01'
]
2023-05-16 00:55:55,126 tlv.py:0192 DEBUG sending [
6 (State): (1 bytes/<class 'bytearray'>) 0x05
5 (EncryptedData): (154 bytes/<class 'bytes'>) b"{\xca\xd50_\xd7\xa9]\x8e\xcd%:\xd6f[z\xb7\x84iS\xf3h\x10\xcf<\x17\xaf)\xa0\x9e\xb9\xf7\x95\xea\xe8QA\xb1\xa5m;~\xcb\x0e\x1b3\x9eK\xb6\xe6\x1e'\x18\xca\x1b\xaa\xe2\xeb\xf2\x14\r)n\xc6\xb1\x96\xbf\xad\x12Zj\x17303\xc3,*\xd0[\xa07%K\x8ci\x1f\xb6+y;\x01\xbf\x84\x94@\xda\xc9p\x9a~*?g\x14B\x0c\x7f\xae\xb7\xacQ\x98\xbf\x95\xf1\x91\x17A\xderoN\xda\xbf\xc1\xde\xfc<8\xd9\xf8\xf1)\xce\xa1`\x11\xbaEj\xd7\xf2\xa1\xeb\x19\xf5\x1b\x8f\xe906\x9f\x05"
]
2023-05-16 00:55:55,127 connection.py:0449 DEBUG 192.168.32.219: raw request: b"POST /pair-setup HTTP/1.1\r\nHost: 192.168.32.219\r\nContent-Length: 159\r\nContent-Type: application/pairing+tlv8\r\n\r\n\x06\x01\x05\x05\x9a{\xca\xd50_\xd7\xa9]\x8e\xcd%:\xd6f[z\xb7\x84iS\xf3h\x10\xcf<\x17\xaf)\xa0\x9e\xb9\xf7\x95\xea\xe8QA\xb1\xa5m;~\xcb\x0e\x1b3\x9eK\xb6\xe6\x1e'\x18\xca\x1b\xaa\xe2\xeb\xf2\x14\r)n\xc6\xb1\x96\xbf\xad\x12Zj\x17303\xc3,*\xd0[\xa07%K\x8ci\x1f\xb6+y;\x01\xbf\x84\x94@\xda\xc9p\x9a~*?g\x14B\x0c\x7f\xae\xb7\xacQ\x98\xbf\x95\xf1\x91\x17A\xderoN\xda\xbf\xc1\xde\xfc<8\xd9\xf8\xf1)\xce\xa1`\x11\xbaEj\xd7\xf2\xa1\xeb\x19\xf5\x1b\x8f\xe906\x9f\x05"
2023-05-16 00:55:55,470 connection.py:0459 DEBUG 192.168.32.219: raw response: bytearray(b'\x06\x01\x06\x05\x87\xe2\xf2\xb7\x87o3c\x10\xddW8\r\x96X\xde}\xdc\xc5\x8e\xbf\xb9\x1b\x12\xda\x03\xcd\x1d@\xe9\xe3\x11\x9f\x17\xcb%\xa1\x84\xfbL\x0e\xb1/\xb8g\xd9\xdd\xe2L]\xbbRy\x18\xa73\xe6\x8d\xfcj\x17dE\x88V\xd3d\x03^_V\x84\xca\x84\xff\x9b<U\x98\xd4\xea\xb5l\xbe\x1b\xaf\x97\x8c\x14\xec\x9c\xfd\xd6\x9f`E\xfa\xa94B:\xc4\xe8\x9b\x12\xc7\x1e\xe2\xc7\xfe%\xa3\x1e\x8b\x12\x11\xf8\x01\x0f\xa2\x91Z\x0c\x1e\xa9\x85\xa9\xe0\xcc\xb6m\xe1\x98h\xa9\x84')
2023-05-16 00:55:55,470 tlv.py:0175 DEBUG receiving [
6 (State): (1 bytes/<class 'bytearray'>) 0x06
5 (EncryptedData): (135 bytes/<class 'bytearray'>) 0xe2f2b7876f336310dd57380d9658de7ddcc58ebfb91b12da03cd1d40e9e3119f17cb25a184fb4c0eb12fb867d9dde24c5dbb527918a733e68dfc6a1764458856d364035e5f5684ca84ff9b3c5598d4eab56cbe1baf978c14ec9cfdd69f6045faa934423ac4e89b12c71ee2c7fe25a31e8b1211f8010fa2915a0c1ea985a9e0ccb66de19868a984
]
2023-05-16 00:55:55,471 tlv.py:0175 DEBUG receiving [
1 (Identifier): (17 bytes/<class 'bytearray'>) 0x43453a34393a36303a43303a42363a3136
3 (PublicKey): (32 bytes/<class 'bytearray'>) 0x029910f067a205fcb0a16b3cf23669d36f727da6c45789d58e351dd8157060b0
10 (Signature): (64 bytes/<class 'bytearray'>) 0xa27281314bf7fa82932cb252af214ee4d5b25f8054828c3269384022ede5bbe7888f44cd861a33cb04f95ede00ee5c97f5e090fd6af74d49c3f123509bf5fd0f
]
2023-05-16 00:55:55,473 abstract.py:0219 DEBUG [192.168.32.219:56940] (id=CE:49:60:C0:B6:16): No accessories cache available for this device
Pairing for "aqara" was established.
2023-05-16 00:55:55,499 connection.py:0482 DEBUG Connection HomeKitConnection(host='192.168.32.219', port=56940) lost.
Is this supposed to work all though not used with Home Assistant? Thankful for any guidance.
Hi, sorry it's a known problem outside of home assistant. Pairing works but the encryption keys aren't saved.
I'd love to make the cli fully functional again but short of time.
Iirc it's a result of the refactoring to add ble and thread support. That added a controller for each protocol, then a meta controller that started all 3 backends. Pairing is I think creating the record in IpController but the "save pairings" code is saving data from the meta controller. (Before there was just one controller object, so it worked fine).
There are a bunch of refactors planned, one of which would have fixed this by replacing how saving and loading pairings work. I wanted to add a PairingStorage abstraction so in HA we could read the keys directly out of HAs config abstraction, and in the CLI we just read them off disk.
Right now HA ignores the aiohomekit saving/loading. When it gets a pairing object from finish_pairing it saves the pairing record itself manually. Then it loads it back into a controller itself as well.
There is probably a temporary fix for the cli controller to have the save function iterate through all the transport controllers maybe. I think it just persists self.pairings. But needs to gather self.pairings from its children?
Love the fast and interesting answer! Sounds like I'll just have to be patient and hope that you can use the client on it's own in the future. It would be a great tool for non HA-setups, I've been digging around the internet for days for something that can do what this does and was so happy when I found it. Started with the HomeKit Python which I think you were involved with as well but no luck with pairing there either. Imagine how happy I was when the log said "pairing for "device" was established". :D
Your last sentence: Don't know what you are talking about but it sounds great and super smart! :) I would use it and I would do a Youtube video about it cause people need to here about this awesome software!
But anyways, it clearly stated proceed with caution and that your focus is Home Assistant. Great work and thank you for taking the time to answer!
Oh, just realized one thing. Does this mean I could use an older version of your software where this still worked?
In theory, versions < 2 should work as the split to enable multiple backend transports hadn't happened. There might be other problems of course.
Okay worth a try for now. I will check it out when I have time. Thank you!