project-chip / connectedhomeip

Matter (formerly Project CHIP) creates more connections between more objects, simplifying development for manufacturers and increasing compatibility for consumers, guided by the Connectivity Standards Alliance.
https://buildwithmatter.com
Apache License 2.0
7.48k stars 2.01k forks source link

Device Attestation fails for linux lightning-app & all-cluster-app #14187

Closed MoeweX closed 1 year ago

MoeweX commented 2 years ago

Problem

Issue validated with this commit.

Currently, it is not possible to commission devices running the linux lightning-app using the chip-tool or the python controller.

Output from chip-tool:

[1643102316864] [44242:8515226] CHIP: [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0001
[1643102316864] [44242:8515226] CHIP: [ZCL] AttestationResponse:
[1643102316864] [44242:8515226] CHIP: [ZCL]   AttestationElements: 278
[1643102316864] [44242:8515226] CHIP: [ZCL]   Signature: 64
[1643102316864] [44242:8515226] CHIP: [CTL] Received Attestation Information from the device
[1643102316864] [44242:8515226] CHIP: [CTL] Verifying attestation
[1643102316868] [44242:8515226] CHIP: [CTL] Failed in verifying 'Attestation Information' command received from the device: err 101. Look at AttestationVerificationResult enum to understand the errors
[1643102316868] [44242:8515226] CHIP: [CTL] Failed to perform commissioning step 7
[1643102316868] [44242:8515226] CHIP: [TOO] Secure Pairing Failed
[1643102316870] [44242:8515226] CHIP: [TOO] Pairing Failure: ../../src/controller/CHIPDeviceController.cpp:1100: CHIP Error 0x000000AC: Internal error

Output from python controller:

[1643101546337] [38361:8482195] CHIP: [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0001
[1643101546337] [38361:8482195] CHIP: [ZCL] AttestationResponse:
[1643101546337] [38361:8482195] CHIP: [ZCL]   AttestationElements: 278
[1643101546337] [38361:8482195] CHIP: [ZCL]   Signature: 64
[1643101546337] [38361:8482195] CHIP: [CTL] Received Attestation Information from the device
[1643101546337] [38361:8482195] CHIP: [CTL] Verifying attestation
[1643101546342] [38361:8482195] CHIP: [CTL] Failed in verifying 'Attestation Information' command received from the device: err 101. Look at AttestationVerificationResult enum to understand the errors
[1643101546342] [38361:8482195] CHIP: [CTL] Failed to perform commissioning step 7
Failed to establish secure session to device: 172

Proposed Solution

Provide app example with certificates that pass the device attestation or add instructions on how to do so.

MoeweX commented 2 years ago

It also fails for the all-cluster-app

woody-apple commented 2 years ago

@emargolis Is this something you can take a look at?

cecille commented 2 years ago

@MoeweX - can you confirm if this is still happening for you? I have not been able to repro this - I am able to commission both of these apps with no issues.

MoeweX commented 2 years ago

HI @cecille, I tried again (commit = 32f41f13a4f2def8ce155b19f387bf86d885655a) and the original error ist gone.

However, chip-tool now prints:

[1646151796991] [2262:6135560] CHIP: [EM] Retransmitting MessageCounter:918817856 on exchange 18401i Send Cnt 0
[1646151796991] [2262:6135560] CHIP: [IN] Sending unauthenticated msg 0x7fe4cf852668 with MessageCounter:918817856 to 0x0000000000000000 at monotonic time: 1156655336 msec
[1646151798992] [2262:6135559] CHIP: [EM] Retransmitting MessageCounter:918817856 on exchange 18401i Send Cnt 1
[1646151798992] [2262:6135559] CHIP: [IN] Sending unauthenticated msg 0x7fe4cf852668 with MessageCounter:918817856 to 0x0000000000000000 at monotonic time: 1156657336 msec
[1646151800992] [2262:6135560] CHIP: [EM] Retransmitting MessageCounter:918817856 on exchange 18401i Send Cnt 2
[1646151800992] [2262:6135560] CHIP: [IN] Sending unauthenticated msg 0x7fe4cf852668 with MessageCounter:918817856 to 0x0000000000000000 at monotonic time: 1156659337 msec
[1646151802992] [2262:6135560] CHIP: [EM] Failed to Send CHIP MessageCounter:918817856 on exchange 18401i sendCount: 3 max retries: 3

The lightning-app just prints [1646151913.337584][2913:2913] CHIP:DIS: Directly sending mDns reply to peer 192.168.50.80 on port 5353

I am trying to commission a device that is connected via ethernet (I started it with the --wifi flag which worked in the past), I use ./chip-tool pairing onnetwork 0x11 20202021 for the commissioning. I deleted all chip files I found in /tmp (on both machines) but this does not seem to help.

TE-N-ElvenWang commented 2 years ago

I also meet this issue on TE8/RC3 tag. Also the issue still exist on latest commit on Mar.8 (1434c5194ac87e2ef30824). Is there any progress on this issue?

Thanks.

cecille commented 2 years ago

I'm not able to repro - my setup works fine. Can you tell me more about how you have these devices set up? is chip-tool linux or darwin or ? Are these running on the same computer? Or are they separate devices? Can you provide full logs?

TE-N-ElvenWang commented 2 years ago

Hi @cecille , Thank you for your reply. I'm using the ARM64 compatible devices similar as RPi4 for both chip-tool controller end and chip-lighting-app end.

With the commit 1434c5194ac87e2ef30824, the chip-tool and chip-lighting-app are built. The controller end running command: $./chip-tool pairing onnetwork 8889 20202021 the output logs are: matter_chip-tool.log

The lighting-app cluster end running command: $./chip-lighting-app --wifi the output logs are: matter_lighting-app.log

The same device has no such issue on TE7.5.

cecille commented 2 years ago

AttestationVerificationResult 300 is kDacExpired.

The logs don't show exactly what's returned from the device (string is too long), so it's hard to tell exactly, but if this is just the example, it should be using the example cert for VID/PID 0xFFF1/0x8001. You can see those values returned from the basic info cluster at the start of commissioning (32769 == 0x8001)

[1616643057.018252][1784:1789] CHIP:DMG:                AttributeReportIB =
[1616643057.018278][1784:1789] CHIP:DMG:                {
[1616643057.018295][1784:1789] CHIP:DMG:                        AttributeDataIB =
[1616643057.018313][1784:1789] CHIP:DMG:                        {
[1616643057.018333][1784:1789] CHIP:DMG:                                DataVersion = 0x2eb8661b,
[1616643057.018352][1784:1789] CHIP:DMG:                                AttributePathIB =
[1616643057.018373][1784:1789] CHIP:DMG:                                {
[1616643057.018394][1784:1789] CHIP:DMG:                                        Endpoint = 0x0,
[1616643057.018416][1784:1789] CHIP:DMG:                                        Cluster = 0x28,
[1616643057.018439][1784:1789] CHIP:DMG:                                        Attribute = 0x0000_0004,
[1616643057.018459][1784:1789] CHIP:DMG:                                }
[1616643057.018481][1784:1789] CHIP:DMG:
[1616643057.018503][1784:1789] CHIP:DMG:                                        Data = 32769,
[1616643057.018522][1784:1789] CHIP:DMG:                        },
[1616643057.018548][1784:1789] CHIP:DMG:
[1616643057.018565][1784:1789] CHIP:DMG:                },
[1616643057.018597][1784:1789] CHIP:DMG:
[1616643057.018614][1784:1789] CHIP:DMG:                AttributeReportIB =
[1616643057.018640][1784:1789] CHIP:DMG:                {
[1616643057.018659][1784:1789] CHIP:DMG:                        AttributeDataIB =
[1616643057.018678][1784:1789] CHIP:DMG:                        {
[1616643057.018697][1784:1789] CHIP:DMG:                                DataVersion = 0x2eb8661b,
[1616643057.018718][1784:1789] CHIP:DMG:                                AttributePathIB =
[1616643057.018739][1784:1789] CHIP:DMG:                                {
[1616643057.018757][1784:1789] CHIP:DMG:                                        Endpoint = 0x0,
[1616643057.018780][1784:1789] CHIP:DMG:                                        Cluster = 0x28,
[1616643057.018802][1784:1789] CHIP:DMG:                                        Attribute = 0x0000_0002,
[1616643057.018820][1784:1789] CHIP:DMG:                                }
[1616643057.018842][1784:1789] CHIP:DMG:
[1616643057.018864][1784:1789] CHIP:DMG:                                        Data = 65521,
[1616643057.018884][1784:1789] CHIP:DMG:                        },
[1616643057.018909][1784:1789] CHIP:DMG:
[1616643057.018924][1784:1789] CHIP:DMG:                

Assuming you're using the example cert, the cert is valid until quite some time in the furture, BUT the initial start time was changed.

Certificate:
    Data:
        Version: 3 (0x2)
        Serial Number: 7624014786269105873 (0x69cdf10de9e54ed1)
        Signature Algorithm: ecdsa-with-SHA256
        Issuer: CN = Matter Dev PAI 0xFFF1 no PID, 1.3.6.1.4.1.37244.2.1 = FFF1
        Validity
            Not Before: Feb  5 00:00:00 2022 GMT
            Not After : Dec 31 23:59:59 9999 GMT
        Subject: CN = Matter Dev DAC 0xFFF1/0x8001, 1.3.6.1.4.1.37244.2.1 = FFF1, 1.3.6.1.4.1.37244.2.2 = 8001
        Subject Public Key Info:
            Public Key Algorithm: id-ecPublicKey
                Public-Key: (256 bit)
                pub:
                    04:46:3a:c6:93:42:91:0a:0e:55:88:fc:6f:f5:6b:
                    b6:3e:62:ec:ce:cb:14:8f:7d:4e:b0:3e:e5:52:60:
                    14:15:76:7d:16:a5:c6:63:f7:93:e4:91:23:26:0b:
                    82:97:a7:cd:7e:7c:fc:7b:31:6b:39:d9:8e:90:d2:
                    93:77:73:8e:82
                ASN1 OID: prime256v1
                NIST CURVE: P-256
        X509v3 extensions:
            X509v3 Basic Constraints: critical
                CA:FALSE
            X509v3 Key Usage: critical
                Digital Signature
            X509v3 Subject Key Identifier: 
                88:DD:E7:B3:00:38:29:32:CF:F7:34:C0:46:24:81:0F:44:16:8A:6F
            X509v3 Authority Key Identifier: 
                keyid:63:54:0E:47:F6:4B:1C:38:D1:38:84:A4:62:D1:6C:19:5D:8F:FB:3C

    Signature Algorithm: ecdsa-with-SHA256
         30:44:02:20:01:27:a2:7b:4b:44:61:0e:e2:fc:dc:4d:2b:78:
         85:56:36:60:bc:0f:76:f1:72:19:ed:6a:08:df:b2:b3:c1:cd:
         02:20:6b:59:e0:af:45:f3:eb:2a:85:b9:19:d3:57:31:52:8c:
         60:28:c4:15:23:95:45:e1:08:e4:e5:4e:70:97:13:53
-----BEGIN CERTIFICATE-----
MIIB5zCCAY6gAwIBAgIIac3xDenlTtEwCgYIKoZIzj0EAwIwPTElMCMGA1UEAwwc
TWF0dGVyIERldiBQQUkgMHhGRkYxIG5vIFBJRDEUMBIGCisGAQQBgqJ8AgEMBEZG
RjEwIBcNMjIwMjA1MDAwMDAwWhgPOTk5OTEyMzEyMzU5NTlaMFMxJTAjBgNVBAMM
HE1hdHRlciBEZXYgREFDIDB4RkZGMS8weDgwMDExFDASBgorBgEEAYKifAIBDARG
RkYxMRQwEgYKKwYBBAGConwCAgwEODAwMTBZMBMGByqGSM49AgEGCCqGSM49AwEH
A0IABEY6xpNCkQoOVYj8b/Vrtj5i7M7LFI99TrA+5VJgFBV2fRalxmP3k+SRIyYL
gpenzX58/HsxaznZjpDSk3dzjoKjYDBeMAwGA1UdEwEB/wQCMAAwDgYDVR0PAQH/
BAQDAgeAMB0GA1UdDgQWBBSI3eezADgpMs/3NMBGJIEPRBaKbzAfBgNVHSMEGDAW
gBRjVA5H9kscONE4hKRi0WwZXY/7PDAKBggqhkjOPQQDAgNHADBEAiABJ6J7S0Rh
DuL83E0reIVWNmC8D3bxchntagjfsrPBzQIga1ngr0Xz6yqFuRnTVzFSjGAoxBUj
lUXhCOTlTnCXE1M=
-----END CERTIFICATE-----

Can you tell me a bit more about the controller system? Is it using the DefaultDeviceAttestationVerifier? If so, does it have a current time set? The check for DAC expiry appears in the DefaultDeviceAttetationVerifier as

#if !defined(CURRENT_TIME_NOT_IMPLEMENTED)
    VerifyOrExit(IsCertificateValidAtCurrentTime(info.dacDerBuffer) == CHIP_NO_ERROR,
                 attestationError = AttestationVerificationResult::kDacExpired);
#endif

so if you don't have a way to get time, it is guarded by that setting.

TE-N-ElvenWang commented 2 years ago

@cecille Very appreciate for your help on this issue.

Now I figure the root cause is that the date is not set correctly by NTP and it is set date to "2021-March". So the kDacExpired will be triggered.

The binary based on TE8/RC3 and commit 1434c5194ac87e2ef30824461238136a9f2af42b are validated if set date to "2022-03-15". I'm not sure whether @MoeweX are in same situation, but I my issue is fixed.

Thank you very much for your support!

stale[bot] commented 1 year ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs.

stale[bot] commented 1 year ago

This stale issue has been automatically closed. Thank you for your contributions.