search

Azure / iot-identity-service

Source of the Azure IoT Identity Service and related services.
MIT License
37 stars 46 forks source link

[Azure IoT Identity service (aziotctl)]: Device certificate request CSR is not being validated when using EST-Server (libest) #483

Open MZDN opened 1 year ago

MZDN commented 1 year ago

I already added a comment about this issue at https://github.com/Azure/iotedge/issues/6579#issuecomment-1295277467. I was asked to open an issue. I think it fits more here on this project.

Infrastructure:

Configurations:

Issue: when aziotctl requests device certificate by sending CSR, remote est-server (libest) is not validating that request OSSL error: 139832112584448:error:14094412:SSL routines:ssl3_read_bytes:sslv3 alert bad certificate:../ssl/record/rec_layer_s3.c:1543:SSL alert number 42

Additional note: Please note that aziotctl and est-server (libest) work fine when both were running on the same vm. Est-server is also working fine when I am interfacing with est-server (remote) with the example written by Kevin Saye in his blog: https://kevinsaye.wordpress.com/2021/08/09/interfacing-with-est-enrollment-over-secure-transport-with-c/

jlian commented 1 year ago

est server (libest) installed and well running on azure vm (remotely). Steps followed are in https://learn.microsoft.com/en-us/azure/iot-edge/tutorial-configure-est-server

Did you modify the dockerfile with the correct hostname for the VM? 

## If you want to host your EST server in the cloud (for example, an Azure Container Instance),
## change myestserver.westus.azurecontainer.io to the fully qualified DNS name of your EST server 
## and uncomment the next line.
# RUN sed -i "s|ip6-localhost|myestserver.westus.azurecontainer.io |g" ./ext.cnf

Please note that aziotctl and est-server (libest) work fine, when both were running on same vm.

Are you saying that with the same libest container, it works when it's on the same VM as IoT Edge, but gives error when it's remote?

Issue: when aziotctl requests device certificate by sending CSR, remote est-server (libest) is not validating that request OSSL error: 139832112584448:error:14094412:SSL routines:ssl3_read_bytes:sslv3 alert bad certificate:../ssl/record/rec_layer_s3.c:1543:SSL alert number 42

This line is from identity service?

MZDN commented 1 year ago

Thanks @jlian for the quick reply!

Did you modify the dockerfile with the correct hostname for the VM?

Yes, I have done that.

For other questions, let me explained what I have tried so far.I have tried following cases:

case 1: I installed and configured EST-Server(libest without docker) and aziotctl directly (without dockerizing anything) on the target device (linux machine). So the device I have run only libest and azure iot idententity service. Everything works as expected, I mean provisioning using x509 and DPS works.

case 2: I installed and configured aziotctl on the target device (linux) and libest as docker container running on another machine in the same network as the target device. I am able to connect and interact with the est-server, But the provisioning using x509 and DPS is not working. It seems that azure iot identity service is not able to get a valid certificate from libest.

case 3: I installed and configured aziotctl on the target device (directly without docker) and libest directly on an azure vm (without dockerizing it). I am able to connect and interact with the est-server, BUT provisioning using x509 and DPS is not working. It seems that azure iot identity service is not able to get a valid certificate from libest.

For case 2 and 3, I investigated more. I could observe on the log console of est-server that each time aziotctl is requesting with csr at est-server, the est-server is logging following:

OSSL error: 139832112584448:error:14094412:SSL routines:ssl3_read_bytes:sslv3 alert bad certificate:../ssl/record/rec_layer_s3.c:1543:SSL alert number 42

That means that est-server is not validating the certificate request coming from azure iot identity service.

I hope I could answer all your questions. Thanks in advance!

jlian commented 1 year ago

Our tutorial was adapted from Kevin's blog https://kevinsaye.wordpress.com/2021/05/19/enabling-enrollment-over-secure-transport-est-for-azure-iot-edge-1-2/

Did you say when you followed @ksaye blog, it works? With the libest container in ACI?

ksaye commented 1 year ago

@MZDN I am a little confused also.

MZDN commented 1 year ago

Hi all, I have updated my comment https://github.com/Azure/iot-identity-service/issues/483#issuecomment-1312470553 I am not using iot edge runtime at all. I used only azure iot identity service and est-server (libest) to get device cert and provision them against dps. So, I cannot say that I followed the tutorial from @ksaye's blog 1to1, but it helped getting inspired a lot. Thanks @ksaye !

@ksaye Issue that azure iot identity service is not getting device certificates from est-server (libest) when this server is called from remotely. I have tried with Azure iot identity service azioctl 1.4.0 and 1.4.1.

I have written above in my 1st comment that est-server (libest) is returning correctly the device certificates that the dps needs, when I tried the code you have published in https://kevinsaye.wordpress.com/2021/08/09/interfacing-with-est-enrollment-over-secure-transport-with-c/ ,
where const string ESTHostname = "MY_REMOTE_LIBEST_EST_SERVER";

ksaye commented 1 year ago

@MZDN I have never used the Identity Service and EST without IoT Edge. I am not sure what portions of the DPS + x509 come from the Identity Service and what comes from Edge, nor what the product group has tested.

jlian commented 1 year ago

@MZDN without IoT Edge things might be a bit different, have you tried https://azure.github.io/iot-identity-service/using-est-with-certd.html

MZDN commented 1 year ago

Thanks for your reply @jlian! Yes, I have tried that. Here is my aziotctl config to contact est server

#Location: /etc/aziot/config.toml
[provisioning]
source = "dps"
global_endpoint = "https://global.azure-devices-provisioning.net"
id_scope = "DPS_ID_SCOPE"

[provisioning.attestation]
method = "x509"
registration_id = "device-demo4"

identity_cert = {method = "est"} 

[cert_issuance.est]
 trusted_certs = [
     "file:///var/secrets/est-server-vm-cacert.crt.pem",
 ]

[cert_issuance.est.auth]
username = "estuser"
password = "estpwd"

[cert_issuance.est.urls]
# est-server-ip: EST_SERVER_IP
default = "https://EST_SERVER_IP:443/.well-known/est"

I applied the config above with following command: sudo aziotctl config apply

I checked logs:

Est-server log side: Everytime when aziotctl requests est-sever, I can see the following on the console:

/home/azureuser/libest/src/est/.libs/libest-3.2.0p.so(+0xc010) [0x7f40a2f2a010]
/home/azureuser/libest/src/est/.libs/libest-3.2.0p.so(est_server_handle_request+0x2ad) [0x7f40a2f3c86d]
/home/azureuser/libest/example/server/.libs/estserver(+0x10441) [0x564b42044441]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x8609) [0x7f40a2b93609]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x43) [0x7f40a2ab8133]

***EST [ERROR][est_server_handle_request:1754]--> OpenSSL system call error

/home/azureuser/libest/src/est/.libs/libest-3.2.0p.so(+0xc010) [0x7f40a2f2a010]
/home/azureuser/libest/src/est/.libs/libest-3.2.0p.so(est_server_handle_request+0x483) [0x7f40a2f3ca43]
/home/azureuser/libest/example/server/.libs/estserver(+0x10441) [0x564b42044441]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x8609) [0x7f40a2b93609]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x43) [0x7f40a2ab8133]

***EST [WARNING][est_server_handle_request:1792]--> SSL_shutdown failed

/home/azureuser/libest/src/est/.libs/libest-3.2.0p.so(+0xc010) [0x7f40a2f2a010]
/home/azureuser/libest/src/est/.libs/libest-3.2.0p.so(est_server_handle_request+0x2ad) [0x7f40a2f3c86d]
/home/azureuser/libest/example/server/.libs/estserver(+0x10441) [0x564b42044441]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x8609) [0x7f40a2b93609]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x43) [0x7f40a2ab8133]

On the device side: when I am logging with sudo aziotctl system logs -- -f, I could see following:

Nov 21 12:24:29 myiotedgedevice02 aziot-certd[15881]: 2022-11-21T11:24:29Z [INFO] - <-- POST /certificates?api-version=2020-09-01 {"content-type": "application/json", "host": "certd.sock", "content-length": "955"}
Nov 21 12:24:29 myiotedgedevice02 aziot-certd[15881]: 2022-11-21T11:24:29Z [ERR!] - !!! internal error
Nov 21 12:24:29 myiotedgedevice02 aziot-certd[15881]: 2022-11-21T11:24:29Z [ERR!] - !!! caused by: could not create cert
Nov 21 12:24:29 myiotedgedevice02 aziot-certd[15881]: 2022-11-21T11:24:29Z [ERR!] - !!! caused by: error trying to connect: error:1416F086:SSL routines:tls_process_server_certificate:certificate verify failed:../ssl/statem/statem_clnt.c:1924:: Hostname mismatch
Nov 21 12:24:29 myiotedgedevice02 aziot-certd[15881]: 2022-11-21T11:24:29Z [ERR!] - !!! caused by: error:1416F086:SSL routines:tls_process_server_certificate:certificate verify failed:../ssl/statem/statem_clnt.c:1924:: Hostname mismatch
Nov 21 12:24:29 myiotedgedevice02 aziot-certd[15881]: 2022-11-21T11:24:29Z [ERR!] - !!! caused by: error:1416F086:SSL routines:tls_process_server_certificate:certificate verify failed:../ssl/statem/statem_clnt.c:1924:
Nov 21 12:24:29 myiotedgedevice02 aziot-certd[15881]: 2022-11-21T11:24:29Z [ERR!] - !!! caused by: error:1416F086:SSL routines:tls_process_server_certificate:certificate verify failed:../ssl/statem/statem_clnt.c:1924:
Nov 21 12:24:29 myiotedgedevice02 aziot-certd[15881]: 2022-11-21T11:24:29Z [INFO] - --> 500 {"content-type": "application/json"}
Nov 21 12:24:29 myiotedgedevice02 aziot-identityd[17343]: 2022-11-21T11:24:29Z [ERR!] - Failed to provision with IoT Hub, and no valid device backup was found: internal error
Nov 21 12:24:29 myiotedgedevice02 aziot-identityd[17343]: 2022-11-21T11:24:29Z [ERR!] - service encountered an error
Nov 21 12:24:29 myiotedgedevice02 aziot-identityd[17343]: 2022-11-21T11:24:29Z [ERR!] - caused by: internal error
Nov 21 12:24:29 myiotedgedevice02 aziot-identityd[17343]: 2022-11-21T11:24:29Z [ERR!] - caused by: could not create certificate
Nov 21 12:24:29 myiotedgedevice02 aziot-identityd[17343]: 2022-11-21T11:24:29Z [ERR!] - caused by: internal error
Nov 21 12:24:29 myiotedgedevice02 aziot-identityd[17343]: 2022-11-21T11:24:29Z [ERR!] -    0: <unknown>
Nov 21 12:24:29 myiotedgedevice02 aziot-identityd[17343]:    1: <unknown>
jlian commented 1 year ago

Might have to dial in @arsing to take a look

MZDN commented 1 year ago

Hi @jlian, any update on this ?

onalante-msft commented 1 year ago

This seems like a certificate configuration issue rather than something wrong with IIS; the hostname verification should pass. You can inspect the resolved certificate with openssl s_client -showcerts -connect EST_SERVER_IP:443. ~I do not remember the correct incantation of flags and certificate options to get s_client to do the same verification as openssl::ssl::SslConnector. I need to search through my notes and OpenSSL's code to find this, so it may be a moment before I have a concrete debugging command for you.~ s_client does not seem to support hostname verification in the same manner openssl::ssl::SslConnector does (see below). curl --cacert "${PATH_TO_EST_SERVER_CA}" "https://${EST_SERVER_IP}" is a close analogue.

openssl::ssl::SslConnector:

  1. https://github.com/sfackler/rust-openssl/blob/openssl-v0.10.45/openssl/src/ssl/connector.rs#L99
  2. https://github.com/sfackler/rust-openssl/blob/openssl-v0.10.45/openssl/src/ssl/connector.rs#L187
  3. https://github.com/sfackler/rust-openssl/blob/openssl-v0.10.45/openssl/src/ssl/connector.rs#L409
  4. https://github.com/sfackler/rust-openssl/blob/openssl-v0.10.45/openssl/src/ssl/connector.rs#L449
  5. https://github.com/sfackler/rust-openssl/blob/openssl-v0.10.45/openssl/src/ssl/connector.rs#L460-L512
MZDN commented 1 year ago

This seems like a certificate configuration issue rather than something wrong with IIS; the hostname verification should pass. You can inspect the resolved certificate with openssl s_client -showcerts -connect EST_SERVER_IP:443. ~I do not remember the correct incantation of flags and certificate options to get s_client to do the same verification as openssl::ssl::SslConnector. I need to search through my notes and OpenSSL's code to find this, so it may be a moment before I have a concrete debugging command for you.~ s_client does not seem to support hostname verification in the same manner openssl::ssl::SslConnector does (see below). curl --cacert "${PATH_TO_EST_SERVER_CA}" "https://${EST_SERVER_IP}" is a close analogue.

openssl::ssl::SslConnector:

  1. https://github.com/sfackler/rust-openssl/blob/openssl-v0.10.45/openssl/src/ssl/connector.rs#L99
  2. https://github.com/sfackler/rust-openssl/blob/openssl-v0.10.45/openssl/src/ssl/connector.rs#L187
  3. https://github.com/sfackler/rust-openssl/blob/openssl-v0.10.45/openssl/src/ssl/connector.rs#L409
  4. https://github.com/sfackler/rust-openssl/blob/openssl-v0.10.45/openssl/src/ssl/connector.rs#L449
  5. https://github.com/sfackler/rust-openssl/blob/openssl-v0.10.45/openssl/src/ssl/connector.rs#L460-L512

Hi all,

following have been tried:

  1. Certificate inspection: openssl s_client -showcerts -connect EST_SERVER_IP:443 I am able to inspect the est-server certificate from the edge-device machine.

    1. Verify cacert I called following from edge-device where it has the EST_SERVER_CA stored: curl --cacert "${PATH_TO_EST_SERVER_CA}" "https://${EST_SERVER_IP}" curl: (51) SSL: no alternative certificate subject name matches target host name EST_SERVER_IP

I am seeing the following log at the EST-SERVER:

***EST [INFO][est_server_handle_request:1719]--> Peer IP address: IP_ADDRESS
***EST [INFO][est_server_handle_request:1720]--> Peer port      : 61218
***EST [INFO][ossl_verify_cb:162]--> enter function: ok=1 cert_error=0
***EST [INFO][ossl_verify_cb:162]--> enter function: ok=1 cert_error=0
***EST [ERROR][pull:597]--> SSL_read error, code: 6

/home/azureuser/libest/src/est/.libs/libest-3.2.0p.so(+0xc010) [0x7f51116ad010]
/home/azureuser/libest/src/est/.libs/libest-3.2.0p.so(+0x1cc0e) [0x7f51116bdc0e]
/home/azureuser/libest/src/est/.libs/libest-3.2.0p.so(+0x1d897) [0x7f51116be897]
/home/azureuser/libest/src/est/.libs/libest-3.2.0p.so(est_server_handle_request+0x26c) [0x7f51116bf82c]
/home/azureuser/libest/example/server/.libs/estserver(+0x10441) [0x563155a4e441]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x8609) [0x7f5111316609]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x43) [0x7f511123b133]

***EST [INFO][est_server_handle_request:1788]--> SSL_shutdown succeeded

Any idea what could be the error on the 2nd one?

jlian commented 1 year ago

@arsing - this is an libest issue right? Any idea here?

@MZDN - when you used openssl showcerts, what did the Subject CN say?

arsing commented 1 year ago

Subject CN doesn't matter because CNs can't be IP addresses.

What is needed is a SAN IP entry for $EST_SERVER_IP, which I assume is not present. Post the full certificate to be sure, either the original PEM blob that openssl s_client showed, or run it through openssl x509 -noout -text.

MZDN commented 1 year ago

openssl s_client -showcerts -connect EST_SERVER_IP:443

CONNECTED(00000005)
depth=1 CN = estExampleCA
verify error:num=19:self signed certificate in certificate chain
---
Certificate chain
 0 s:CN = 127.0.0.1
   i:CN = estExampleCA
-----BEGIN CERTIFICATE-----
...
-----END CERTIFICATE-----
 1 s:CN = estExampleCA
   i:CN = estExampleCA
-----BEGIN CERTIFICATE-----
...
-----END CERTIFICATE-----
---
Server certificate
subject=CN = 127.0.0.1

issuer=CN = estExampleCA

---
No client certificate CA names sent
Client Certificate Types: RSA sign, DSA sign, ECDSA sign
Requested Signature Algorithms: ECDSA+SHA256:ECDSA+SHA384:ECDSA+SHA512:Ed25519:Ed448:RSA-PSS+SHA256:RSA-PSS+SHA384:RSA-PSS+SHA512:RSA-PSS+SHA256:RSA-PSS+SHA384:RSA-PSS+SHA512:RSA+SHA256:RSA+SHA384:RSA+SHA512:ECDSA+SHA224:RSA+SHA224:DSA+SHA224:DSA+SHA256:DSA+SHA384:DSA+SHA512
Shared Requested Signature Algorithms: ECDSA+SHA256:ECDSA+SHA384:ECDSA+SHA512:Ed25519:Ed448:RSA-PSS+SHA256:RSA-PSS+SHA384:RSA-PSS+SHA512:RSA-PSS+SHA256:RSA-PSS+SHA384:RSA-PSS+SHA512:RSA+SHA256:RSA+SHA384:RSA+SHA512:ECDSA+SHA224:RSA+SHA224:DSA+SHA224:DSA+SHA256:DSA+SHA384:DSA+SHA512
Peer signing digest: SHA256
Peer signature type: ECDSA
Server Temp Key: ECDH, P-256, 256 bits
---
SSL handshake has read 1164 bytes and written 483 bytes
Verification error: self signed certificate in certificate chain
---
New, TLSv1.2, Cipher is ECDHE-ECDSA-AES256-GCM-SHA384
Server public key is 256 bit
Secure Renegotiation IS supported
Compression: NONE
Expansion: NONE
No ALPN negotiated
SSL-Session:
    Protocol  : TLSv1.2
    Cipher    : ECDHE-ECDSA-AES256-GCM-SHA384
    Session-ID: ...
    Session-ID-ctx: 
    Master-Key: ...
    PSK identity: None
    PSK identity hint: None
    SRP username: None
    Start Time: 1678958923
    Timeout   : 7200 (sec)
    Verify return code: 19 (self signed certificate in certificate chain)
    Extended master secret: yes
---
^C
arsing commented 1 year ago 
0 s:CN = 127.0.0.1
  i:CN = estExampleCA
-----BEGIN CERTIFICATE-----
...
-----END CERTIFICATE-----
1 s:CN = estExampleCA
  i:CN = estExampleCA
-----BEGIN CERTIFICATE-----
...
-----END CERTIFICATE-----
---

You've cut out the PEM blob that I asked for.

jlian commented 1 year ago

@MZDN, this command from dockerfile in the tutorial:

RUN sed -i "s|ip6-localhost|myestserver.westus.azurecontainer.io |g" ./ext.cnf

Uses sed to "find and replace" the localhost Subject Alternative Name (SAN) DNS name with an example hostname in the ext.cnf

However, since you're using IP address you might want to actually open up the ext.cnf and modify it to make sure your VM's IP address is recorded as a IP SAN. Here's an example from libest

https://github.com/cisco/libest/blob/main/example/server/ext.cnf

Here, you'd replace IP.1 = 127.0.0.1 with the IP address of your VM

And I guess you can just do it in the dockerfile by changing the aforementioned line to:

RUN sed -i "s|127.0.0.1|<YOUR VM IP ADDRESS>|g" ./ext.cnf

@arsing keep me honest also

MZDN commented 1 year ago

openssl s_client -showcerts -connect

@arsing 

0 s:CN = 127.0.0.1
  i:CN = estExampleCA
-----BEGIN CERTIFICATE-----
...
-----END CERTIFICATE-----
1 s:CN = estExampleCA
  i:CN = estExampleCA
-----BEGIN CERTIFICATE-----
...
-----END CERTIFICATE-----
---

You've cut out the PEM blob that I asked for.

here it is: 

-----BEGIN CERTIFICATE-----
MIIBvjCCAWSgAwIBAgIBATAKBggqhkjOPQQDAjAXMRUwEwYDVQQDDAxlc3RFeGFt
cGxlQ0EwHhcNMjMwMzE3MTExMjM0WhcNMjMwNjE1MTExMjM0WjAUMRIwEAYDVQQD
DAkxMjcuMC4wLjEwWTATBgcqhkjOPQIBBggqhkjOPQMBBwNCAAQDivfu/CAACdLV
z0pRjMYfFEUuCwhTMv1HH6F7zVSqXgK+WKf9aCZA3rAdl9hNNK2mv3ELFXKtT+62
RNlhevNyo4GjMIGgMAkGA1UdEwQCMAAwCwYDVR0PBAQDAgXgMFkGA1UdEQRSMFCC
CWxvY2FsaG9zdIIrZXN0c2VydmVydGVzdC53ZXN0ZXVyb3BlLmNsb3VkYXBwLmF6
dXJlLmNvbYcEFOV4uocQAAAAAAAAAAAAAAAAAAAAATArBgNVHR8EJDAiMCCgHqAc
hhpodHRwOi8vZXhhbXBsZS5jb20vY3JsLnBlbTAKBggqhkjOPQQDAgNIADBFAiAB
smFLw3Sf1Zc7ij/FayFRKoCFB7CwGGQ/tm+ymvGSTQIhAIsCgrZYIItWwNLGUFw0
EtU8KtWZ/bjEGyGkmf8gcM1U
-----END CERTIFICATE-----
 1 s:CN = estExampleCA
   i:CN = estExampleCA
-----BEGIN CERTIFICATE-----
MIIBXjCCAQWgAwIBAgIUIa/kI/Tk+ZMoEyMcGlTXeFk6Hr4wCgYIKoZIzj0EAwIw
FzEVMBMGA1UEAwwMZXN0RXhhbXBsZUNBMB4XDTIzMDMxNzExMTIzNFoXDTQzMDMx
MjExMTIzNFowFzEVMBMGA1UEAwwMZXN0RXhhbXBsZUNBMFkwEwYHKoZIzj0CAQYI
KoZIzj0DAQcDQgAEKYwiqpHdYvJ2PlbrK9uBngh5Py+VObffqI6v6WD+F8PONgso
SpTWPMQJp8ZdjO+LBlCW+fhyTFu9rNMyHKUahaMvMC0wDAYDVR0TBAUwAwEB/zAd
BgNVHQ4EFgQUaxoehtr+xzriy4zwojB3inHmcq8wCgYIKoZIzj0EAwIDRwAwRAIg
HUpyi5yBBLNGgCHBo8VF85WpFiJGJBPWHYuTfnsz128CIDA/DBVH7ZJdJ/Iy7y3s
jJSgR7YN6P516Nyl90UmwMw9
-----END CERTIFICATE-----
MZDN commented 1 year ago

@MZDN, this command from dockerfile in the tutorial:

RUN sed -i "s|ip6-localhost|myestserver.westus.azurecontainer.io |g" ./ext.cnf

Uses sed to "find and replace" the localhost Subject Alternative Name (SAN) DNS name with an example hostname in the ext.cnf

However, since you're using IP address you might want to actually open up the ext.cnf and modify it to make sure your VM's IP address is recorded as a IP SAN. Here's an example from libest

https://github.com/cisco/libest/blob/main/example/server/ext.cnf

Here, you'd replace IP.1 = 127.0.0.1 with the IP address of your VM

And I guess you can just do it in the dockerfile by changing the aforementioned line to:

RUN sed -i "s|127.0.0.1|<YOUR VM IP ADDRESS>|g" ./ext.cnf

@arsing keep me honest also

Thanks @jlian. I have configured as suggested, but still have the same issue.

arsing commented 1 year ago

Okay, running that through openssl x509 -noout -text says:

X509v3 Subject Alternative Name: 
    DNS:localhost, DNS:estservertest.westeurope.cloudapp.azure.com, IP Address:20.229.120.186, IP Address:0:0:0:0:0:0:0:1

Is 20.229.120.186 the EST_SERVER_IP you've been using?

MZDN commented 1 year ago

Okay, running that through openssl x509 -noout -text says:

X509v3 Subject Alternative Name: 
    DNS:localhost, DNS:estservertest.westeurope.cloudapp.azure.com, IP Address:20.229.120.186, IP Address:0:0:0:0:0:0:0:1

Is 20.229.120.186 the EST_SERVER_IP you've been using?

Yes!

arsing commented 1 year ago

Try using estservertest.westeurope.cloudapp.azure.com instead, just in case openssl is unhappy with connecting to an IP. And if that also fails, post both the client logs and the server logs as you did in https://github.com/Azure/iot-identity-service/issues/483#issuecomment-1321826454

MZDN commented 1 year ago

Try using estservertest.westeurope.cloudapp.azure.com instead, just in case openssl is unhappy with connecting to an IP. And if that also fails, post both the client logs and the server logs as you did in #483 (comment)

server side: no log, when aziotctl hits

root@est-server-vm:/home/azureuser/libest/example/server# ./runserver.sh
Using OpenSSL 1.1.1f  31 Mar 2020
***EST [INFO][est_log_version:231]--> libest 3.2.0p (API level 4)
***EST [INFO][est_log_version:235]--> Compiled against OpenSSL 1.1.1f  31 Mar 2020
***EST [INFO][est_log_version:236]--> Linking to OpenSSL 1.1.1f  31 Mar 2020
***EST [INFO][ossl_init_cert_store_from_raw:257]--> Cert being added to trust store: CN = estExampleCA
***EST [INFO][ossl_init_cert_store_from_raw:257]--> Cert being added to trust store: CN = estEXTERNALCA

Retry period being set to: 300

Disabling PoP check
Launching EST server...
***EST [INFO][set_ssl_option:1409]--> Using default ECDHE curve (prime256v1)
***EST [INFO][set_ssl_option:1459]--> TLS SRP not enabled

client side:

Mär 24 14:59:09 myiotedgedevice02 systemd[1]: Stopped Azure IoT Identity Service.
Mär 24 14:59:09 myiotedgedevice02 systemd[1]: Started Azure IoT Identity Service.
Mär 24 14:59:09 myiotedgedevice02 aziot-identityd[6102]: 2023-03-24T13:59:09Z [INFO] - Starting service...
Mär 24 14:59:09 myiotedgedevice02 aziot-identityd[6102]: 2023-03-24T13:59:09Z [INFO] - Version - 1.4.3
Mär 24 14:59:09 myiotedgedevice02 aziot-identityd[6102]: 2023-03-24T13:59:09Z [INFO] - Provisioning starting. Reason: Startup
Mär 24 14:59:09 myiotedgedevice02 aziot-keyd[3525]: 2023-03-24T13:59:09Z [INFO] - <-- GET /keypair/device-id?api-version=2021-05-01 {"host": "keyd.sock"}
Mär 24 14:59:09 myiotedgedevice02 aziot-keyd[3525]: 2023-03-24T13:59:09Z [ERR!] - invalid parameter "id": not found
Mär 24 14:59:09 myiotedgedevice02 aziot-keyd[3525]: 2023-03-24T13:59:09Z [INFO] - !!! a parameter has an invalid value
Mär 24 14:59:09 myiotedgedevice02 aziot-keyd[3525]: 2023-03-24T13:59:09Z [INFO] - --> 400 {"content-type": "application/json"}
Mär 24 14:59:09 myiotedgedevice02 aziot-certd[3545]: 2023-03-24T13:59:09Z [INFO] - <-- GET /certificates/device-id?api-version=2020-09-01 {"host": "certd.sock"}
Mär 24 14:59:09 myiotedgedevice02 aziot-certd[3545]: 2023-03-24T13:59:09Z [INFO] - !!! parameter "id" has an invalid value
Mär 24 14:59:09 myiotedgedevice02 aziot-certd[3545]: 2023-03-24T13:59:09Z [INFO] - !!! caused by: not found
Mär 24 14:59:09 myiotedgedevice02 aziot-certd[3545]: 2023-03-24T13:59:09Z [INFO] - --> 400 {"content-type": "application/json"}
Mär 24 14:59:09 myiotedgedevice02 aziot-identityd[6102]: 2023-03-24T13:59:09Z [ERR!] - Failed to provision with IoT Hub, and no valid device backup was found: internal error
Mär 24 14:59:09 myiotedgedevice02 aziot-identityd[6102]: 2023-03-24T13:59:09Z [ERR!] - service encountered an error
Mär 24 14:59:09 myiotedgedevice02 aziot-identityd[6102]: 2023-03-24T13:59:09Z [ERR!] - caused by: internal error
Mär 24 14:59:09 myiotedgedevice02 aziot-identityd[6102]: 2023-03-24T13:59:09Z [ERR!] - caused by: could not create certificate
Mär 24 14:59:09 myiotedgedevice02 aziot-identityd[6102]: 2023-03-24T13:59:09Z [ERR!] - caused by: identity cert does not exist; cannot create new cert as registration ID is unknown
Mär 24 14:59:09 myiotedgedevice02 aziot-identityd[6102]: 2023-03-24T13:59:09Z [ERR!] -    0: <unknown>
Mär 24 14:59:09 myiotedgedevice02 aziot-identityd[6102]:    1: <unknown>
Mär 24 14:59:09 myiotedgedevice02 systemd[1]: aziot-identityd.service: Main process exited, code=exited, status=1/FAILURE
Mär 24 14:59:09 myiotedgedevice02 systemd[1]: aziot-identityd.service: Failed with result 'exit-code'.
jlian commented 1 year ago

@arsing any ideas?

jlian commented 1 year ago

@MZDN what about curl --cacert "${PATH_TO_EST_SERVER_CA}" "https://${EST_SERVER_IP}" with estservertest.westeurope.cloudapp.azure.com instead? Does that work?

@arsing can you help here? Does the error identity cert does not exist; cannot create new cert as registration ID is unknown indicate maybe a misconfiguration? The error is different now compared to the beginning too

jlian commented 1 year ago

@MZDN and @arsing can you help take a look?

MZDN commented 1 year ago

Hello @jlian,

That request is hitting the endpoint.

In this issue, I have the feeling that the request that is constructed by aziotctl can't be validated at libest-server when aziotctl and libest-server are not the same network.