Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

It would be nice to support Device Discovery - Commissionable Node Discovery using MDNS #8

Closed
jdesai61 opened this issue Jul 11, 2022 · 8 comments

Comments

@jdesai61
Copy link
Collaborator

jdesai61 commented Jul 11, 2022

It would be nice to support Device Discovery - Commissionable Node Discovery using MDNS, so that one could use a command like

chip-tool pairing onnetwork 222 20202021

rather than using device IP address/port ("chip-tool pairing ethernet 222 20202021 3840 192.168.1.28 5540")

@jdesai61
Copy link
Collaborator Author

jdesai61 commented Jul 13, 2022

I have added the required support for basic discovery. With the attached change, I can now discover device using "chip-tool pairing onnetwork 222 20202021".
MdnsServer.ts.txt

@jdesai61
Copy link
Collaborator Author

Using above code, I tried to pair the device with Home Assistant matter add-on. However, I am getting following error:

/home/DadAdmin/node-matter-multiif/node-matter/build/codec/TlvObjectCodec.js:75
                    throw new Error(`Missing mandatory field ${key}`);
                          ^

Error: Missing mandatory field clusterId
    at TlvObjectCodec.decodeObject (/home/DadAdmin/node-matter-multiif/node-matter/build/codec/TlvObjectCodec.js:75:27)
    at TlvObjectCodec.decodeInternal (/home/DadAdmin/node-matter-multiif/node-matter/build/codec/TlvObjectCodec.js:58:29)
    at TlvObjectCodec.decodeElement (/home/DadAdmin/node-matter-multiif/node-matter/build/codec/TlvObjectCodec.js:25:21)
    at /home/DadAdmin/node-matter-multiif/node-matter/build/codec/TlvObjectCodec.js:64:45
    at Array.map (<anonymous>)
    at TlvObjectCodec.decodeArray (/home/DadAdmin/node-matter-multiif/node-matter/build/codec/TlvObjectCodec.js:64:25)
    at TlvObjectCodec.decodeInternal (/home/DadAdmin/node-matter-multiif/node-matter/build/codec/TlvObjectCodec.js:55:29)
    at TlvObjectCodec.decodeObject (/home/DadAdmin/node-matter-multiif/node-matter/build/codec/TlvObjectCodec.js:72:32)
    at TlvObjectCodec.decodeInternal (/home/DadAdmin/node-matter-multiif/node-matter/build/codec/TlvObjectCodec.js:58:29)
    at TlvObjectCodec.decodeElement (/home/DadAdmin/node-matter-multiif/node-matter/build/codec/TlvObjectCodec.js:25:21)

If I try to make clusterId optional, then I am getting following error at compile time with tsc:

tsc && node build/Main.js
src/interaction/InteractionProtocol.ts:32:79 - error TS2345: Argument of type 'TypeFromFieldTemplates<{ endpointId: OptionalField<number>; clusterId: OptionalField<number>; attributeId: Field<number>; }>' is not assignable to parameter of type 'AttributePath'.
  Types of property 'clusterId' are incompatible.
    Type 'number | undefined' is not assignable to type 'number'.
      Type 'undefined' is not assignable to type 'number'.

32             values: attributes.flatMap(path => this.device.getAttributeValues(path)).map(value => ({value})),
                                                                                 ~~~~

src/interaction/InteractionProtocol.ts:39:111 - error TS2345: Argument of type 'TypeFromFieldTemplates<{ endpointId: Field<number>; clusterId: OptionalField<number>; commandId: Field<number>; }>' is not assignable to parameter of type 'CommandPath'.
  Types of property 'clusterId' are incompatible.
    Type 'number | undefined' is not assignable to type 'number'.
      Type 'undefined' is not assignable to type 'number'.

39         const results = (await Promise.all(invokes.map(({path, args}) => this.device.invoke(exchange.session, path, args)))).flat();
                                                                                                                 ~~~~


Found 2 errors in the same file, starting at: src/interaction/InteractionProtocol.ts:32

@jdesai61
Copy link
Collaborator Author

jdesai61 commented Jul 13, 2022

I modified the code to make clusterId optional and then got similar error about attributeId requred field missing. I tried to fix that as well (by returning zero when either of the fields are not present). This allows home assistant commissioning to progress further and from node-matter it seems like the device paired - but somehow HA add-on gives up after receiving response from last read... Here is how it looks from the node-matter side:

node build/Main.js
Matter server listening
Pase: Received pairing request from udp://192.168.1.57:60161
Pase: Paired succesfully with udp://192.168.1.57:60161
Received read request from udp://192.168.1.57:60161 on session secure/20610: */49/65532, 0/48/0, 0/48/1, 0/48/2, 0/48/3, 0/40/2, 0/40/4, */49/3
Received invoke request from udp://192.168.1.57:60161 on session secure/20610: 0/48/0
Received invoke request from udp://192.168.1.57:60161 on session secure/20610: 0/48/2
Received invoke request from udp://192.168.1.57:60161 on session secure/20610: 0/62/2
Received invoke request from udp://192.168.1.57:60161 on session secure/20610: 0/62/2
Received invoke request from udp://192.168.1.57:60161 on session secure/20610: 0/62/0
Received invoke request from udp://192.168.1.57:60161 on session secure/20610: 0/62/4
Received invoke request from udp://192.168.1.57:60161 on session secure/20610: 0/62/11
Received invoke request from udp://192.168.1.57:60161 on session secure/20610: 0/62/6
Case: Received pairing request from udp://192.168.1.57:60161
Case: Paired succesfully with udp://192.168.1.57:60161
Received invoke request from udp://192.168.1.57:60161 on session secure/20611: 0/48/4
Received read request from udp://192.168.1.57:60161 on session secure/20611: */undefined/undefined

No further communication from HA to node-matter after this read request. However, HA doesn't complete the full commissioning process. Not sure what is going on, but here are some HA logs...

2022-07-13 17:44:01 77f1785d-matter-server chip.IN[122] INFO Sending encrypted msg 0x7fc7dc0197a8 with MessageCounter:167328143 to 0xFFFFFFFB00000000 (0) at monotonic time: 00000000209E1A50 msec
2022-07-13 17:44:01 77f1785d-matter-server chip.CTL[122] INFO Sent operational certificate to the device
2022-07-13 17:44:01 77f1785d-matter-server chip.IN[122] INFO Prepared secure message 0x7fc7f0c23da8 to 0xFFFFFFFB00000000 (0)  of type 0x10 and protocolId (0, 0) on exchange 15703i with MessageCounter:167328144.
2022-07-13 17:44:01 77f1785d-matter-server chip.IN[122] INFO Sending encrypted msg 0x7fc7f0c23da8 with MessageCounter:167328144 to 0xFFFFFFFB00000000 (0) at monotonic time: 00000000209E1A51 msec
2022-07-13 17:44:01 77f1785d-matter-server chip.EM[122] INFO Received message of type 0x9 with protocolId (0, 1) and MessageCounter:4064267261 on exchange 15704i
2022-07-13 17:44:01 77f1785d-matter-server chip.DMG[122] INFO Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0008
2022-07-13 17:44:01 77f1785d-matter-server chip.CTL[122] INFO Device returned status 0 on receiving the NOC
2022-07-13 17:44:01 77f1785d-matter-server chip.CTL[122] INFO Operational credentials provisioned on device 0x7fc7dc02c520
2022-07-13 17:44:01 77f1785d-matter-server chip.CTL[122] INFO Successfully finished commissioning step 'SendNOC'
2022-07-13 17:44:01 77f1785d-matter-server chip.CTL[122] INFO Commissioning stage next step: 'SendNOC' -> 'FindOperational'
2022-07-13 17:44:01 77f1785d-matter-server chip.CTL[122] INFO Performing next commissioning step 'FindOperational'
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO Operational node lookup already in progress. Will NOT start a new one.
2022-07-13 17:44:01 77f1785d-matter-server chip.IN[122] INFO Prepared secure message 0x7fc7f0c23da8 to 0xFFFFFFFB00000000 (0)  of type 0x10 and protocolId (0, 0) on exchange 15704i with MessageCounter:167328145.
2022-07-13 17:44:01 77f1785d-matter-server chip.IN[122] INFO Sending encrypted msg 0x7fc7f0c23da8 with MessageCounter:167328145 to 0xFFFFFFFB00000000 (0) at monotonic time: 00000000209E1A6B msec
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO UDP:192.168.1.28%enp0s18:5540: new best score: 2
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO Checking node lookup status after 8 ms
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO Keeping DNSSD lookup active
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO UDP:192.168.1.28%enp0s18:5540: score has not improved: 2
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO Checking node lookup status after 9 ms
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO Keeping DNSSD lookup active
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO UDP:192.168.1.28%enp0s18:5540: score has not improved: 2
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO Checking node lookup status after 10 ms
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO Keeping DNSSD lookup active
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO UDP:192.168.1.28%hassio:5540: score has not improved: 2
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO Checking node lookup status after 11 ms
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO Keeping DNSSD lookup active
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO UDP:192.168.1.28%hassio:5540: score has not improved: 2
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO Checking node lookup status after 11 ms
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO Keeping DNSSD lookup active
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO UDP:192.168.1.28%hassio:5540: score has not improved: 2
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO Checking node lookup status after 12 ms
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO Keeping DNSSD lookup active
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO UDP:192.168.1.28%enp0s18:5540: score has not improved: 2
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO Checking node lookup status after 18 ms
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO Keeping DNSSD lookup active
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO UDP:192.168.1.28%enp0s18:5540: score has not improved: 2
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO Checking node lookup status after 19 ms
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO Keeping DNSSD lookup active
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO UDP:192.168.1.28%enp0s18:5540: score has not improved: 2
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO Checking node lookup status after 21 ms
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO Keeping DNSSD lookup active
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO UDP:192.168.1.28%hassio:5540: score has not improved: 2
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO Checking node lookup status after 22 ms
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO Keeping DNSSD lookup active
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO UDP:192.168.1.28%hassio:5540: score has not improved: 2
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO Checking node lookup status after 23 ms
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO Keeping DNSSD lookup active
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO UDP:192.168.1.28%hassio:5540: score has not improved: 2
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO Checking node lookup status after 24 ms
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO Keeping DNSSD lookup active
2022-07-13 17:44:01 77f1785d-matter-server chip.DIS[122] INFO Checking node lookup status after 200 ms
2022-07-13 17:44:01 77f1785d-matter-server chip.SC[122] INFO Initiating session on local FabricIndex 1 from 0x0000000000000001 -> 0x00000000000010EF
2022-07-13 17:44:01 77f1785d-matter-server chip.IN[122] INFO Prepared unauthenticated message 0x7fc7dc027818 to 0x0000000000000000 (0)  of type 0x30 and protocolId (0, 0) on exchange 15705i with MessageCounter:12213759.
2022-07-13 17:44:01 77f1785d-matter-server chip.IN[122] INFO Sending unauthenticated msg 0x7fc7dc027818 with MessageCounter:12213759 to 0x0000000000000000 at monotonic time: 00000000209E1B2E msec
2022-07-13 17:44:01 77f1785d-matter-server chip.SC[122] INFO Sent Sigma1 msg
2022-07-13 17:44:01 77f1785d-matter-server chip.EM[122] INFO Received message of type 0x31 with protocolId (0, 0) and MessageCounter:4064267262 on exchange 15705i
2022-07-13 17:44:01 77f1785d-matter-server chip.SC[122] INFO Received Sigma2 msg
2022-07-13 17:44:01 77f1785d-matter-server chip.IN[122] INFO Prepared unauthenticated message 0x7fc7dc02f6b8 to 0x0000000000000000 (0)  of type 0x32 and protocolId (0, 0) on exchange 15705i with MessageCounter:12213760.
2022-07-13 17:44:01 77f1785d-matter-server chip.IN[122] INFO Sending unauthenticated msg 0x7fc7dc02f6b8 with MessageCounter:12213760 to 0x0000000000000000 at monotonic time: 00000000209E1B3F msec
2022-07-13 17:44:01 77f1785d-matter-server chip.SC[122] INFO Sent Sigma3 msg
2022-07-13 17:44:01 77f1785d-matter-server chip.EM[122] INFO Received message of type 0x40 with protocolId (0, 0) and MessageCounter:4064267263 on exchange 15705i
2022-07-13 17:44:01 77f1785d-matter-server chip.SC[122] INFO Success status report received. Session was established
2022-07-13 17:44:01 77f1785d-matter-server root[122] INFO SetSdkKey: f/1/s/00000000000010EF = b'\x150\x03\x10\xbf\x05\x9d\x12W\x97N\xd1}m\xfd\x97\x08\x9c\x87/0\x04 "/\xe0F\xfc\xf8\x9b\xfbEW\xe4\x87\xad)X\xce\x91\xda\x81\x8b\x81<}\xc3\xe2\x13\xe5\xa3\xc7DX\xb90\x05\x0c\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x18'
2022-07-13 17:44:01 77f1785d-matter-server root[122] INFO SetSdkKey: g/s/vwWdEleXTtF9bf2XCJyHLw== = b'\x15$\x01\x01%\x02\xef\x10\x18'
2022-07-13 17:44:01 77f1785d-matter-server root[122] INFO SetSdkKey: g/sri = b'\x16\x15$\x01\x01%\x02\xef\x10\x18\x18'
2022-07-13 17:44:01 77f1785d-matter-server chip.SC[122] INFO SecureSession[0x7fc7dc0279a0]: Moving from state 'kEstablishing' --> 'kActive'
2022-07-13 17:44:01 77f1785d-matter-server chip.CTL[122] INFO Successfully finished commissioning step 'FindOperational'
2022-07-13 17:44:01 77f1785d-matter-server chip.CTL[122] INFO Commissioning stage next step: 'FindOperational' -> 'SendComplete'
2022-07-13 17:44:01 77f1785d-matter-server chip.CTL[122] INFO Performing next commissioning step 'SendComplete'
2022-07-13 17:44:01 77f1785d-matter-server chip.IN[122] INFO Prepared secure message 0x7fc7dc02f6b8 to 0x00000000000010EF (1)  of type 0x8 and protocolId (0, 1) on exchange 15706i with MessageCounter:157404875.
2022-07-13 17:44:01 77f1785d-matter-server chip.IN[122] INFO Sending encrypted msg 0x7fc7dc02f6b8 with MessageCounter:157404875 to 0x00000000000010EF (1) at monotonic time: 00000000209E1B4B msec
2022-07-13 17:44:01 77f1785d-matter-server chip.IN[122] INFO Prepared unauthenticated message 0x7fc7f0c23de8 to 0x0000000000000000 (0)  of type 0x10 and protocolId (0, 0) on exchange 15705i with MessageCounter:12213761.
2022-07-13 17:44:01 77f1785d-matter-server chip.IN[122] INFO Sending unauthenticated msg 0x7fc7f0c23de8 with MessageCounter:12213761 to 0x0000000000000000 at monotonic time: 00000000209E1B4C msec
2022-07-13 17:44:01 77f1785d-matter-server chip.EM[122] INFO Received message of type 0x9 with protocolId (0, 1) and MessageCounter:4064267264 on exchange 15706i
2022-07-13 17:44:01 77f1785d-matter-server chip.DMG[122] INFO Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0005
2022-07-13 17:44:01 77f1785d-matter-server chip.CTL[122] INFO Received CommissioningComplete response, errorCode=0
2022-07-13 17:44:01 77f1785d-matter-server chip.CTL[122] INFO Successfully finished commissioning step 'SendComplete'
2022-07-13 17:44:01 77f1785d-matter-server chip.CTL[122] INFO Commissioning stage next step: 'SendComplete' -> 'Cleanup'
2022-07-13 17:44:01 77f1785d-matter-server chip.CTL[122] INFO Performing next commissioning step 'Cleanup'
2022-07-13 17:44:01 77f1785d-matter-server chip.CTL[122] INFO Successfully finished commissioning step 'Cleanup'
2022-07-13 17:44:01 77f1785d-matter-server chip.IN[122] INFO Prepared secure message 0x7fc7f0c23da8 to 0x00000000000010EF (1)  of type 0x10 and protocolId (0, 0) on exchange 15706i with MessageCounter:157404876.
2022-07-13 17:44:01 77f1785d-matter-server chip.IN[122] INFO Sending encrypted msg 0x7fc7f0c23da8 with MessageCounter:157404876 to 0x00000000000010EF (1) at monotonic time: 00000000209E1B52 msec
2022-07-13 17:44:01 77f1785d-matter-server matter_server.server.server[122] INFO [140496488854960] Deserialized message: CommandMessage(messageId='355dd24ba3044913b6318af120e34980', command='device_controller.ResolveNode', args={'nodeid': 4335})
2022-07-13 17:44:01 77f1785d-matter-server matter_server.server.server[122] INFO [140496488854960] Deserialized message: CommandMessage(messageId='8296edfecec6419499c9ae4db7ced4c7', command='device_controller.Read', args={'nodeid': 4335, 'attributes': '*', 'dataVersionFilters': None, 'events': '*', 'returnClusterObject': True, 'reportInterval': None, 'fabricFiltered': True, 'keepSubscriptions': False})
2022-07-13 17:44:01 77f1785d-matter-server chip.IN[122] INFO Prepared secure message 0x7fc7dc02f6b8 to 0x00000000000010EF (1)  of type 0x2 and protocolId (0, 1) on exchange 15707i with MessageCounter:157404877.
2022-07-13 17:44:01 77f1785d-matter-server chip.IN[122] INFO Sending encrypted msg 0x7fc7dc02f6b8 with MessageCounter:157404877 to 0x00000000000010EF (1) at monotonic time: 00000000209E1B63 msec
2022-07-13 17:44:01 77f1785d-matter-server chip.EM[122] INFO Received message of type 0x5 with protocolId (0, 1) and MessageCounter:4064267265 on exchange 15707i
2022-07-13 17:44:01 77f1785d-matter-server chip.IN[122] INFO Prepared secure message 0x7fc7f0c23da8 to 0x00000000000010EF (1)  of type 0x10 and protocolId (0, 0) on exchange 15707i with MessageCounter:157404878.
2022-07-13 17:44:01 77f1785d-matter-server chip.IN[122] INFO Sending encrypted msg 0x7fc7f0c23da8 with MessageCounter:157404878 to 0x00000000000010EF (1) at monotonic time: 00000000209E1B67 msec

Without specs, it is hard for me to tell what is going on. But HA add-on is also WIP, so will wait till it stabilizes

@mfucci
Copy link
Owner

mfucci commented Jul 14, 2022

Thanks for debugging this!

Can you create separate bugs for the separate issues?
We can keep this bug for the device discovery only and I see two other separate issues: mandatory parameters that should be optional and missing attribute (last read request that fails for HA). The commissioning seems to have succeeded for HA, but it is doing another operation afterwards that is not yet supported...

@jdesai61
Copy link
Collaborator Author

I have created two separate issues - one for optional/required fields and another for HA integration

@mfucci
Copy link
Owner

mfucci commented Jul 28, 2022

Thanks!
I am now back in the US and I have recovered from the jetlag, so I will address those issues this week.

@jdesai61
Copy link
Collaborator Author

jdesai61 commented Aug 4, 2022

The latest refactor code does not seem to include publishing the _matterc._udp.local records (in the MdnsServer constructor from my pull request). Where should that be added? In the new scheme of things, I can't find a proper place.

@mfucci
Copy link
Owner

mfucci commented Aug 9, 2022

This is now fixed with #15

@mfucci mfucci closed this as completed Aug 9, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants