aws / aws-iot-device-sdk-embedded-C

SDK for connecting to AWS IoT from a device using embedded C.
MIT License
978 stars 625 forks source link

problems with setting up mbdetls as transport layer #1811

Closed ClaudioBaldo closed 2 years ago

ClaudioBaldo commented 2 years ago

We have tried to port the demo application but the connection is nor working and we get an error for invalid handler due to invalid certificates: mqttClientAws.c connectToServerWithBackoffRetries() 640 | rootCA /AmazonRootCA1.pem mqttClientAws.c connectToServerWithBackoffRetries() 641 | clientCRT /xxxxxxx-certificate.pem.crt mqttClientAws.c connectToServerWithBackoffRetries() 642 | clientKey /xxxxxxx-private.pem.crt mqttClientAws.c connectToServerWithBackoffRetries() 654 | ===SUCCESSFULLY INITIALIZED PKCS #11.=== mqttClientAws[5879] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:483] Successfully found object class attribute.^M mqttClientAws[5879] | [INFO] [PKCS11] [core_pkcs11_mbedtls.c:2823] Creating a 0x3 type object.^M mqttClientAws[5879] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:2057] Successfully found the key type in the template.^M mqttClientAws[5879] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:2086] Successfully found the label in the template.^M mqttClientAws[5879] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1259] Key was private type.^M mqttClientAws[5879] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1268] Received RSA key type.^M mqttClientAws[5879] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1288] Allocating a 1200 bytes sized buffer to write the key to.^M mqttClientAws[5879] | [DEBUG] [PKCS11] [core_pkcs11_pal_utils.c:123] Converted Device Priv TLS Key to corePKCS11_Key.dat^M mqttClientAws[5879] | Successfully wrote 1192 to corePKCS11_Key.dat[DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:3352] Search parameters other than label are ignored.^M mqttClientAws[5879] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:3446] Could not find the object handle in the list. Trying to search PKCS #11 PAL for object.^M mqttClientAws[5879] | [DEBUG] [PKCS11] [core_pkcs11_pal_utils.c:123] Converted Device Cert to corePKCS11_Certificate.dat^M mqttClientAws[5879] | [INFO] [PKCS11] [core_pkcs11_pal.c:63] Could not open corePKCS11_Certificate.dat for reading.^M mqttClientAws[5879] | [ERROR] [PKCS11] [core_pkcs11.c:370] xFindObjectWithLabelAndClass ERROR CK_INVALID_HANDLE^M mqttClientAws[5879] | [INFO] [FLEET_PROVISIONING_DEMO] [pkcs11_operations.c:770] Writing certificate into label "Device Cert".^M mqttClientAws[5879] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:483] Successfully found object class attribute.^M mqttClientAws[5879] | [INFO] [PKCS11] [core_pkcs11_mbedtls.c:2823] Creating a 0x1 type object.^M mqttClientAws[5879] | [DEBUG] [PKCS11] [core_pkcs11_pal_utils.c:123] Converted Device Cert to corePKCS11_Certificate.dat^M mqttClientAws[5879]/mqttClientAwsComponent T=main | mqttClientAws.c connectToServerWithBackoffRetries() 668 | ===SUCCESSFULLY PROVISIONED PKCS #11.=== mqttClientAws.c connectToServerWithBackoffRetries() 686 | Establishing a TLS session to axxxxxx-ats.iot.ap-southeast-2.amazonaws.com:443. mqttClientAws[5879] | Successfully wrote 861 to corePKCS11_Certificate.dat[DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:3352] Search parameters other than label are ignored.^M mqttClientAws[5879] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:3352] Search parameters other than label are ignored.^M mqttClientAws[5879] | [ERROR] [PKCS11] [core_pkcs11.c:370] xFindObjectWithLabelAndClass ERROR CK_INVALID_HANDLE^M mqttClientAws[5879] | [ERROR] [Transport_MbedTLS_PKCS11] [mbedtls_pkcs11_posix.c:625] Function returned ERROR.^M mqttClientAws[5879] | [ERROR] [Transport_MbedTLS_PKCS11] [mbedtls_pkcs11_posix.c:400] Failed to setup key handling by PKCS #11.^M mqttClientAws[5879] | [WARN] [DEMO] [mqttClientAws.c:724] Connection to the broker failed. Retrying connection after 270 ms backoff.^M

This is the code we are using, which we got partly from the mqtt_operation.c in the repository: BackoffAlgorithmStatus_t backoffAlgStatus = BackoffAlgorithmSuccess; MbedtlsPkcs11Status_t tlsStatus = MBEDTLS_PKCS11_SUCCESS; BackoffAlgorithmContext_t reconnectParams; MbedtlsPkcs11Credentials_t tlsCredentials = { 0 }; const char * alpn[] = { ALPN_PROTOCOL_NAME, NULL };

/ Set the pParams member of the network context with desired transport. / pNetworkContext->pParams = &tlsContext;

/ Initialize credentials for establishing TLS session. / tlsCredentials.pRootCaPath = rootCA; tlsCredentials.pClientCertLabel = clientCRT; tlsCredentials.pPrivateKeyLabel = clientKey; pkcs11ret = xInitializePkcs11Session( &tlsCredentials.p11Session ); if( pkcs11ret != CKR_OK ) { LogError( ( "Failed to initialize PKCS #11." ) ); }

/* AWS IoT requires devices to send the Server Name Indication (SNI)

do { /* Establish a TLS session with the MQTT broker. This example connects

Which we don`t understand why, same certificates we are using with the older SDK for embedded C from aws. Any help will be very much appreciated!!!

ClaudioBaldo commented 2 years ago

The problem seems to be with reading the client certificate which seem I can provision all right (it will return true) but then it will fail when we try to connect to the backend when mbetls tries to load it for establishing the connection. I have added a couple of lines to the logs for debugging and I am not sure why this is happening.

mqttClientAws.c connectToServerWithBackoffRetries() 654 | ===SUCCESSFULLY INITIALIZED PKCS #11.=== mqttClientAws[7891] | [DEBUG] [FLEET_PROVISIONING_DEMO] [pkcs11_operations.c:808] loadClaimCredentials readFile claimCert, 1^M mqttClientAws[7891] | [DEBUG] [FLEET_PROVISIONING_DEMO] [pkcs11_operations.c:814] loadClaimCredentials readFile claimPrivateKey, 1^M mqttClientAws[7891] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:483] Successfully found object class attribute.^M mqttClientAws[7891] | [INFO] [PKCS11] [core_pkcs11_mbedtls.c:2823] Creating a 0x3 type object.^M mqttClientAws[7891] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:2057] Successfully found the key type in the template.^M mqttClientAws[7891] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:2086] Successfully found the label in the template.^M mqttClientAws[7891] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1259] Key was private type.^M mqttClientAws[7891] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1268] Received RSA key type.^M mqttClientAws[7891] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1288] Allocating a 1200 bytes sized buffer to write the key to.^M mqttClientAws[7891] | [DEBUG] [PKCS11] [core_pkcs11_pal_utils.c:123] Converted Device Priv TLS Key to corePKCS11_Key.dat^M mqttClientAws[7891] | Successfully wrote 1192 to corePKCS11_Key.dat[DEBUG] [FLEET_PROVISIONING_DEMO] [pkcs11_operations.c:823] loadClaimCredentials provisionPrivateKey, 1^M mqttClientAws[7891] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:3352] Search parameters other than label are ignored.^M

mqttClientAws[7891] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:3446] Could not find the object handle in the list. Trying to search PKCS #11 PAL for object.^M mqttClientAws[7891] | [DEBUG] [PKCS11] [core_pkcs11_pal_utils.c:123] Converted Device Cert to corePKCS11_Certificate.dat^M mqttClientAws[7891] | [INFO] [PKCS11] [core_pkcs11_pal.c:63] Could not open corePKCS11_Certificate.dat for reading.^M mqttClientAws[7891] | [ERROR] [PKCS11] [core_pkcs11.c:370] xFindObjectWithLabelAndClass ERROR CK_INVALID_HANDLE^M

mqttClientAws[7891] | [INFO] [FLEET_PROVISIONING_DEMO] [pkcs11_operations.c:770] Writing certificate into label "Device Cert".^M mqttClientAws[7891] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:483] Successfully found object class attribute.^M mqttClientAws[7891] | [INFO] [PKCS11] [core_pkcs11_mbedtls.c:2823] Creating a 0x1 type object.^M mqttClientAws[7891] | [DEBUG] [PKCS11] [core_pkcs11_pal_utils.c:123] Converted Device Cert to corePKCS11_Certificate.dat^M mqttClientAws[7891] | Successfully wrote 861 to corePKCS11_Certificate.dat[DEBUG] [FLEET_PROVISIONING_DEMO] [pkcs11_operations.c:832] loadClaimCredentials provisionCertificate, 1^M mqttClientAws[7891]/mqttClientAwsComponent T=main | mqttClientAws.c connectToServerWithBackoffRetries() 669 | ===SUCCESSFULLY PROVISIONED PKCS #11.===

mqttClientAws.c connectToServerWithBackoffRetries() 688 | Establishing a TLS session to a1ui4kt3m4uic8-ats.iot.ap-southeast-2.amazonaws.com:8883. mqttClientAws[7891] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:3352] Search parameters other than label are ignored.^M mqttClientAws[7891] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:3352] Search parameters other than label are ignored.^M mqttClientAws[7891] | [ERROR] [PKCS11] [core_pkcs11.c:370] xFindObjectWithLabelAndClass ERROR CK_INVALID_HANDLE^M mqttClientAws[7891] | [ERROR] [Transport_MbedTLS_PKCS11] [mbedtls_pkcs11_posix.c:622] Function returned ERROR.^M mqttClientAws[7891] | [ERROR] [Transport_MbedTLS_PKCS11] [mbedtls_pkcs11_posix.c:397] Failed to setup key handling by PKCS #11.^M mqttClientAws[7891] | [ERROR] [Transport_MbedTLS_PKCS11] [mbedtls_pkcs11_posix.c:308] error at configureMbedtlsCertificates. 3, invalid credentials: 3 ^M mqttClientAws[7891] | [ERROR] [Transport_MbedTLS_PKCS11] [mbedtls_pkcs11_posix.c:814] error return from configureMbedtls function. 3, invalid credentials: 3 ^M mqttClientAws[7891] | [WARN] [DEMO] [mqttClientAws.c:726] Connection to the broker failed. Retrying connection after 432 ms backoff.^M mqttClientAws[7891]/mqttClientAwsComponent T=main | mqttClientAws.c connectToServerWithBackoffRetries() 688 | Establishing a TLS session to a1ui4kt3m4uic8-ats.iot.ap-southeast-2.amazonaws.com:8883. mqttClientAws[7891] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:3352] Search parameters other than label are ignored.^M Jul 15 07:00:49 fx30 user.info Legato: INFO | mqttClientAws[7891] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:3352] Search parameters other than label are ignored.^M mqttClientAws[7891] | [ERROR] [PKCS11] [core_pkcs11.c:370] xFindObjectWithLabelAndClass ERROR CK_INVALID_HANDLE^M mqttClientAws[7891] | [ERROR] [Transport_MbedTLS_PKCS11] [mbedtls_pkcs11_posix.c:622] Function returned ERROR.^M mqttClientAws[7891] | [ERROR] [Transport_MbedTLS_PKCS11] [mbedtls_pkcs11_posix.c:397] Failed to setup key handling by PKCS #11.^M mqttClientAws[7891] | [ERROR] [Transport_MbedTLS_PKCS11] [mbedtls_pkcs11_posix.c:308] error at configureMbedtlsCertificates. 3, invalid credentials: 3 ^M mqttClientAws[7891] | [ERROR] [Transport_MbedTLS_PKCS11] [mbedtls_pkcs11_posix.c:814] error return from configureMbedtls function. 3, invalid credentials: 3 ^

ClaudioBaldo commented 2 years ago

we have solved the problem with initialising the the mbedtls with using a different template based on mbedtls, so we have less things to port. It seem that we can connect to the backend with the Mqtt_init function but when we try with the Mqtt_Connect this will fail after the timeout period with "MQTTNoDataAvailable".

rootCA /home/root//home/root/AmazonRootCA1.pem clientCRT /home/root/certificate.pem.crt clientKey /home/root/private.pem.key mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:461] PKCS #11 module was successfully initialized.^M mqttClientAws[2427] | [INFO] [PKCS11] [core_pkcs11_mbedtls.c:1403] PKCS #11 successfully initialized.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1617] Successfully Returned a PKCS #11 slot with ID 1 with a count of 1.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1852] Assigned a 0x2 Type Session.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1863] Assigned Mechanisms to no operation in progress.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1879] Current session count at 0^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1965] C_Login is not implemented.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [pkcs11_operations.c:808] loadClaimCredentials readFile claimCert, 1^M mqttClientAws[2427] | [DEBUG] [PKCS11] [pkcs11_operations.c:814] loadClaimCredentials readFile claimPrivateKey, 1^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:483] Successfully found object class attribute.^M mqttClientAws[2427] | [INFO] [PKCS11] [core_pkcs11_mbedtls.c:2823] Creating a 0x3 type object.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:2057] Successfully found the key type in the template.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:2086] Successfully found the label in the template.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1259] Key was private type.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1268] Received RSA key type.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1288] Allocating a 1200 bytes sized buffer to write the key to.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_pal_utils.c:123] Converted Device Priv TLS Key to corePKCS11_Key.dat^M mqttClientAws[2427] | Successfully wrote 1192 to corePKCS11_Key.dat[DEBUG] [PKCS11] [pkcs11_operations.c:823] loadClaimCredentials provisionPrivateKey, 1^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:3352] Search parameters other than label are ignored.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:3446] Could not find the object handle in the list. Trying to search PKCS #11 PAL for object.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_pal_utils.c:123] Converted Device Cert to corePKCS11_Certificate.dat^M mqttClientAws[2427] | [INFO] [PKCS11] [core_pkcs11_pal.c:63] Could not open corePKCS11_Certificate.dat for reading.^M mqttClientAws[2427] | [INFO] [PKCS11] [pkcs11_operations.c:770] Writing certificate into label "Device Cert".^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:483] Successfully found object class attribute.^M mqttClientAws[2427] | [INFO] [PKCS11] [core_pkcs11_mbedtls.c:2823] Creating a 0x1 type object.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_pal_utils.c:123] Converted Device Cert to corePKCS11_Certificate.dat^M mqttClientAws[2427] | Successfully wrote 861 to corePKCS11_Certificate.dat[DEBUG] [PKCS11] [pkcs11_operations.c:832] loadClaimCredentials provisionCertificate, 1^M mqttClientAws[2427] | [INFO] [DEMO] [mqttClientAws.c:1217] Establishing MQTT session with claim certificate...^M mqttClientAws[2427] | [DEBUG] [MQTT] [mqtt_operations.c:376] Establishing a TLS session to a1ui4kt3m4uic8-ats.iot.ap-southeast-2.amazonaws.com:443.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:3352] Search parameters other than label are ignored.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1053] Found object in object list matching label.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:3452] Found object in PAL. Adding object handle to list.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1085] Found object in list by handle.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:3018] Object was a private key.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:3352] Search parameters other than label are ignored.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1053] Found object in object list matching label.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:3452] Found object in PAL. Adding object handle to list.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1085] Found object in list by handle.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:3034] Object was a certificate.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1085] Found object in list by handle.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:3034] Object was a certificate.^M mqttClientAws[2427] | [DEBUG] [Transport_MbedTLS_PKCS11] [mbedtls_pkcs11_posix.c:355] Configured MbedTLS context.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:5622] Successfully generated 28 random bytes.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:5622] Successfully generated 32 random bytes.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:5622] Successfully generated 32 random bytes.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:5622] Successfully generated 32 random bytes.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:5622] Successfully generated 32 random bytes.^M mqttClientAws[2427] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:5622] Successfully generated 32 random bytes.^M mqttClientAws[2427] | [INFO] [Transport_MbedTLS_PKCS11] [mbedtls_pkcs11_posix.c:857] TLS Connection to axxxxxxxx-ats.iot.ap-southeast-2.amazonaws.com established.^M mqttClientAws[1332] | [DEBUG] [MQTT] [mqtt_operations.c:651] Connected to MQTT broker a1ui4kt3m4uic8-ats.iot.ap-southeast-2.amazonaws.com.^M mqttClientAws[1332] | [DEBUG] [MQTT] [mqtt_operations.c:682] MQTT init status success!!^M mqttClientAws[1332] | [DEBUG] [MQTT] [core_mqtt_serializer.c:459] Encoded size for length 33 is 1 bytes.^M mqttClientAws[1332] | [DEBUG] [MQTT] [core_mqtt_serializer.c:1600] CONNECT packet remaining length=33 and packet size=35.^M mqttClientAws[1332] | [DEBUG] [MQTT] [core_mqtt.c:1784] CONNECT packet size is 35 and remaining length is 33.^M mqttClientAws[1332] | [DEBUG] [MQTT] [core_mqtt_serializer.c:459] Encoded size for length 33 is 1 bytes.^M mqttClientAws[1332] | [DEBUG] [MQTT] [core_mqtt_serializer.c:1499] Length of serialized CONNECT packet is 35.^M mqttClientAws[1332] | [DEBUG] [MQTT] [core_mqtt.c:645] BytesSent=35, BytesRemaining=0^M mqttClientAws[1332] | [DEBUG] [MQTT] [core_mqtt.c:666] Successfully sent packet at time 95250.^M mqttClientAws[1332] | [DEBUG] [MQTT] [core_mqtt.c:1809] Sent 35 bytes of CONNECT packet.^M mqttClientAws[1332] | [DEBUG] [Transport_MbedTLS_PKCS11] [mbedtls_pkcs11_posix.c:924] Failed to read data. However, a read can be retried on this error. mbedTLSError= SSL - The operation timed out : . mqttClientAws[1332] | [ERROR] [MQTT] [core_mqtt.c:1570] CONNACK recv failed with status = MQTTNoDataAvailable.^M mqttClientAws[1332] | [ERROR] [MQTT] [core_mqtt.c:1841] MQTT connection failed with status = MQTTNoDataAvailable.^M mqttClientAws[1332] | [ERROR] [MQTT] [mqtt_operations.c:732] Connection with MQTT broker failed with status MQTTNoDataAvailable.^M mqttClientAws[1332] | [ERROR] [DEMO] [mqttClientAws.c:1225] Failed to establish MQTT session.^M

So is not entirely clear this is due to an incorrect setup or the backend is not answering to the CONNECT packet? The firewall on the device is fully opened (for this testing), so this is not related to the unit dropping traffic coming back from backend: Chain INPUT (policy ACCEPT) target prot opt source destination
ACCEPT all -- anywhere anywhere
ACCEPT udp -- anywhere anywhere udp spt:ntp ctstate ESTABLISHED ACCEPT udp -- anywhere anywhere udp spt:443 state ESTABLISHED ACCEPT tcp -- anywhere anywhere tcp spt:https state ESTABLISHED ACCEPT udp -- anywhere anywhere udp spt:5686 state ESTABLISHED ACCEPT udp -- anywhere anywhere udp spt:5684 state ESTABLISHED ACCEPT icmp -- anywhere anywhere icmp echo-reply state ESTABLISHED ACCEPT tcp -- anywhere anywhere tcp spt:domain state ESTABLISHED ACCEPT udp -- anywhere anywhere udp spt:domain state ESTABLISHED DROP all -- anywhere anywhere
ACCEPT icmp -- anywhere anywhere
ACCEPT tcp -- anywhere anywhere tcp spt:domain state ESTABLISHED ACCEPT udp -- anywhere anywhere udp spt:domain state ESTABLISHED DROP all -- anywhere anywhere
ACCEPT tcp -- anywhere anywhere tcp dpt:ssh ACCEPT icmp -- anywhere anywhere icmp echo-request ACCEPT udp -- anywhere anywhere udp spts:bootps:bootpc dpts:bootps:bootpc

Chain FORWARD (policy ACCEPT) target prot opt source destination

Chain OUTPUT (policy ACCEPT) target prot opt source destination

alfred2g commented 2 years ago

Hello, We are taking a look at the issue, will get back to you shortly

alfred2g commented 2 years ago

Hello, I heard from some team members who faced the same issue (or almost) that there is a bug with corePKCS11 that required rebooting/re-initializing after importing a key

ClaudioBaldo commented 2 years ago

what exactly should we reboot? If we reboot the device the application will start loading the certificates once again:

    do
        {
            /* Initialize the buffer lengths to their max lengths. */

    /* Initialize the PKCS #11 module */
    pkcs11ret = xInitializePkcs11Session( &p11Session );

    if( pkcs11ret != CKR_OK )
    {
        LogError( ( "Failed to initialize PKCS #11." ) );
        status = false;
    }
    else
    {
        /* Insert the claim credentials into the PKCS #11 module */
        status = loadClaimCredentials( p11Session,
                                       clientCRT,
                                       pkcs11configLABEL_DEVICE_CERTIFICATE_FOR_TLS,
                                       clientKey,
                                       pkcs11configLABEL_DEVICE_PRIVATE_KEY_FOR_TLS );

        if( status == false )
        {
            LogError( ( "Failed to provision PKCS #11 with claim credentials." ) );
        }
    }

    /**** Connect to AWS IoT Core with provisioning claim credentials *****/

    /* We first use the claim credentials to connect to the broker. These
     * credentials should allow use of the RegisterThing API and one of the
     * CreateCertificatefromCsr or CreateKeysAndCertificate.
     * In this demo we use CreateCertificatefromCsr. */

    if( status == true )
    {
        /* Attempts to connect to the AWS IoT MQTT broker. If the
         * connection fails, retries after a timeout. Timeout value will
         * exponentially increase until maximum attempts are reached. */
        LogInfo( ( "Establishing MQTT session with claim certificate..." ) );
        status = EstablishMqttSession( provisioningPublishCallback,
                                       p11Session,
                                       pkcs11configLABEL_DEVICE_CERTIFICATE_FOR_TLS,
                                       pkcs11configLABEL_DEVICE_PRIVATE_KEY_FOR_TLS );

        if( status == false )
        {
            LogError( ( "Failed to establish MQTT session." ) );
        }
        else
        {
            LogInfo( ( "Established connection with claim credentials." ) );
            connectionEstablished = true;
        }
    }
ClaudioBaldo commented 2 years ago

we can`t re-initialize the handler or it will fail saying this was already initialized, if you could clarify what needs to be re-initialized and at what point in the code, thanks.

alfred2g commented 2 years ago

We will try to reproduce your use case with our fleet provisioning demo today, and we will post an update thanks!

alfred2g commented 2 years ago

Hello sorry for the delay, which demo setup were you following ?

We tried this one: https://aws.github.io/aws-iot-device-sdk-embedded-C/202108.00/docs/doxygen/output/html/fleet_provisioning_demo.html

and we had a different error

"[ERROR] [Transport_MbedTLS_PKCS11] [mbedtls_pkcs11_posix.c:915] Failed to read data: mbedTLSError= SSL - The peer notified us that the connection is going to be closed : <No-Low-Level-Code>."

We will try with a different setup and update the case.

paulbartell commented 2 years ago

@ClaudioBaldo : I was able to successfully run the demo by using the script in this repository to setup the cloud side of things: https://github.com/FreeRTOS/FreeRTOS/tree/main/FreeRTOS-Plus/Demo/AWS/Fleet_Provisioning_Windows_Simulator/Fleet_Provisioning_With_CSR_Demo/DemoSetup . After updating democonfig.h with the relevant items, the fleet_provisioning_with_csr_demo completed successfully.

When mbedtls returns an error like this: "The peer notified us that the connection is going to be closed", that usually indicates that the service has rejected the connection attempt. You can enable more detailed mbedtls logging by increasing MBEDTLS_DEBUG_LOG_LEVEL in mbedtls_pkcs11_posix.h.l

Could you give that script a try or take another look at your cloud-side setup and make sure the policies match what you expect?

ClaudioBaldo commented 2 years ago

@paulbartell @alfred2g we are just trying to connect to the backend via mbedtls, not looking at implementing the fleet monitoring demo in full (at this stage). The only reason why we are using this demo is because is the only one which provide a sample of how to establish a connection through mbedtls. The other example called "simple_tls" still uses openssl as transport layer for the connection. Many embedded devices will just not have support for the openssl library you are using and possibly implement an older version, we did raise this concern in an old issue but it looks like didn`t really got listened to. And the urgency of solving this problem probably didn't make it to your end, we have engaged with our aws account manager and tech support as we need to solve this problem urgently...

Anyhow, yet with the set to MBEDTLS_DEBUG_LOG_LEVEL 1 (default is 0), we still have the same problem that the device doesn`t get anything back from the backend when it sends the CONNECT packet: Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:461] PKCS #11 module was successfully initialized.^M Jul 21 06:25:48 | mqttClientAws[3416] | [INFO] [PKCS11] [core_pkcs11_mbedtls.c:1403] PKCS #11 successfully initialized.^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1617] Successfully Returned a PKCS #11 slot with ID 1 with a count of 1.^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1852] Assigned a 0x2 Type Session.^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1863] Assigned Mechanisms to no operation in progress.^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1879] Current session count at 0^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1965] C_Login is not implemented.^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [pkcs11_operations.c:808] loadClaimCredentials readFile claimCert, 1^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [pkcs11_operations.c:814] loadClaimCredentials readFile claimPrivateKey, 1^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:483] Successfully found object class attribute.^M Jul 21 06:25:48 | mqttClientAws[3416] | [INFO] [PKCS11] [core_pkcs11_mbedtls.c:2823] Creating a 0x3 type object.^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:2057] Successfully found the key type in the template.^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:2086] Successfully found the label in the template.^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1259] Key was private type.^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1268] Received RSA key type.^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1288] Allocating a 1200 bytes sized buffer to write the key to.^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_pal_utils.c:123] Converted Claim Key to corePKCS11_Claim_Key.dat^M Jul 21 06:25:48 | mqttClientAws[3416] | Successfully wrote 1192 to corePKCS11_Claim_Key.dat[DEBUG] [PKCS11] [pkcs11_operations.c:823] loadClaimCredentials provisionPrivateKey, 1^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:3352] Search parameters other than label are ignored.^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:3446] Could not find the object handle in the list. Trying to search PKCS #11 PAL for object.^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_pal_utils.c:123] Converted Claim Cert to corePKCS11_Claim_Certificate.dat^M Jul 21 06:25:48 | mqttClientAws[3416] | [INFO] [PKCS11] [core_pkcs11_pal.c:63] Could not open corePKCS11_Claim_Certificate.dat for reading.^M Jul 21 06:25:48 | mqttClientAws[3416] | [INFO] [PKCS11] [pkcs11_operations.c:770] Writing certificate into label "Claim Cert".^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:483] Successfully found object class attribute.^M Jul 21 06:25:48 | mqttClientAws[3416] | [INFO] [PKCS11] [core_pkcs11_mbedtls.c:2823] Creating a 0x1 type object.^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_pal_utils.c:123] Converted Claim Cert to corePKCS11_Claim_Certificate.dat^M Jul 21 06:25:48 | mqttClientAws[3416] | Successfully wrote 861 to corePKCS11_Claim_Certificate.dat[DEBUG] [PKCS11] [pkcs11_operations.c:832] loadClaimCredentials provisionCertificate, 1^M Jul 21 06:25:48 | mqttClientAws[3416] | [INFO] [DEMO] [mqttClientAws.c:1229] Establishing MQTT session with claim certificate...^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [MQTT] [mqtt_operations.c:376] Establishing a TLS session to a1ui4kt3m4uic8-ats.iot.ap-southeast-2.amazonaws.com:443.^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:3352] Search parameters other than label are ignored.^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1053] Found object in object list matching label.^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:3452] Found object in PAL. Adding object handle to list.^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1085] Found object in list by handle.^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:3018] Object was a private key.^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:3352] Search parameters other than label are ignored.^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1053] Found object in object list matching label.^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:3452] Found object in PAL. Adding object handle to list.^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1085] Found object in list by handle.^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:3034] Object was a certificate.^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:1085] Found object in list by handle.^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:3034] Object was a certificate.^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [Transport_MbedTLS_PKCS11] [mbedtls_pkcs11_posix.c:355] Configured MbedTLS context.^M Jul 21 06:25:48 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:5622] Successfully generated 28 random bytes.^M Jul 21 06:25:49 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:5622] Successfully generated 32 random bytes.^M Jul 21 06:25:49 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:5622] Successfully generated 32 random bytes.^M Jul 21 06:25:49 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:5622] Successfully generated 32 random bytes.^M Jul 21 06:25:49 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:5622] Successfully generated 32 random bytes.^M Jul 21 06:25:49 | mqttClientAws[3416] | [DEBUG] [PKCS11] [core_pkcs11_mbedtls.c:5622] Successfully generated 32 random bytes.^M Jul 21 06:25:50 | mqttClientAws[3416] | [INFO] [Transport_MbedTLS_PKCS11] [mbedtls_pkcs11_posix.c:857] TLS Connection to a1ui4kt3m4uic8-ats.iot.ap-southeast-2.amazonaws.com established.^M Jul 21 06:25:50 | mqttClientAws[3416] | [DEBUG] [MQTT] [mqtt_operations.c:651] Connected to MQTT broker a1ui4kt3m4uic8-ats.iot.ap-southeast-2.amazonaws.com.^M Jul 21 06:25:50 | mqttClientAws[3416] | [DEBUG] [MQTT] [mqtt_operations.c:665] current time is :634022^M Jul 21 06:25:50 | mqttClientAws[3416] | [DEBUG] [MQTT] [mqtt_operations.c:682] MQTT init status success!!^M Jul 21 06:25:50 fx30 user.info Legato: INFO | mqttClientAws[3416] | [DEBUG] [MQTT] [core_mqtt_serializer.c:459] Encoded size for length 17 is 1 bytes.^M Jul 21 06:25:50 | mqttClientAws[3416] | [DEBUG] [MQTT] [core_mqtt_serializer.c:1600] CONNECT packet remaining length=17 and packet size=19.^M Jul 21 06:25:50 | mqttClientAws[3416] | [DEBUG] [MQTT] [core_mqtt.c:1784] CONNECT packet size is 19 and remaining length is 17.^M Jul 21 06:25:50 | mqttClientAws[3416] | [DEBUG] [MQTT] [core_mqtt_serializer.c:459] Encoded size for length 17 is 1 bytes.^M Jul 21 06:25:50 | mqttClientAws[3416] | [DEBUG] [MQTT] [core_mqtt_serializer.c:1499] Length of serialized CONNECT packet is 19.^M Jul 21 06:25:50 | mqttClientAws[3416] | [DEBUG] [MQTT] [core_mqtt.c:645] BytesSent=19, BytesRemaining=0^M Jul 21 06:25:50 | mqttClientAws[3416] | [DEBUG] [MQTT] [core_mqtt.c:666] Successfully sent packet at time 634024.^M Jul 21 06:25:50 | mqttClientAws[3416] | [DEBUG] [MQTT] [core_mqtt.c:1809] Sent 19 bytes of CONNECT packet.^M

ClaudioBaldo commented 2 years ago

we have increased the log value for the logging of mbetls, this is what we see: Jul 21 07:03:39 | mqttClientAws[7705] | [INFO] [Transport_MbedTLS_PKCS11] [mbedtls_pkcs11_posix.c:857] TLS Connection to axxxxxxx-ats.iot.ap-southeast-2.amazonaws.com established.^M Jul 21 07:03:39 | mqttClientAws[7705] | [DEBUG] [MQTT] [mqtt_operations.c:651] Connected to MQTT broker axxxxxxx-ats.iot.ap-southeast-2.amazonaws.com.^M Jul 21 07:03:39 | mqttClientAws[7705] | [DEBUG] [MQTT] [mqtt_operations.c:665] current time is :2903390^M Jul 21 07:03:39 | mqttClientAws[7705] | [DEBUG] [MQTT] [mqtt_operations.c:682] MQTT init status success!!^M Jul 21 07:03:39 | mqttClientAws[7705] | [DEBUG] [MQTT] [core_mqtt_serializer.c:459] Encoded size for length 17 is 1 bytes.^M Jul 21 07:03:39 | mqttClientAws[7705] | [DEBUG] [MQTT] [core_mqtt_serializer.c:1600] CONNECT packet remaining length=17 and packet size=19.^M Jul 21 07:03:39 | mqttClientAws[7705] | [DEBUG] [MQTT] [core_mqtt.c:1784] CONNECT packet size is 19 and remaining length is 17.^M Jul 21 07:03:39 | mqttClientAws[7705] | [DEBUG] [MQTT] [core_mqtt_serializer.c:459] Encoded size for length 17 is 1 bytes.^M Jul 21 07:03:39 | mqttClientAws[7705] | [DEBUG] [MQTT] [core_mqtt_serializer.c:1499] Length of serialized CONNECT packet is 19.^M Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |2| => write Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |2| => write record Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |2| => encrypt buf Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |4| dumping 'before encrypt: output payload' (19 bytes) Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |4| 0000: 10 11 00 04 4d 51 54 54 04 00 00 3c 00 05 46 58 ....MQTT...<..FX Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |4| 0010: 33 30 53 30S Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |4| dumping 'IV used (internal)' (12 bytes) Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |4| 0000: a0 38 f6 92 00 00 00 00 00 00 00 01 .8.......... Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |4| dumping 'IV used (transmitted)' (8 bytes) Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |4| 0000: 00 00 00 00 00 00 00 01 ........ Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |4| dumping 'additional data used for AEAD' (13 bytes) Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |4| 0000: 00 00 00 00 00 00 00 01 17 03 03 00 13 ............. Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |3| before encrypt: msglen = 19, including 0 bytes of padding Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |4| dumping 'after encrypt: tag' (16 bytes) Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |4| 0000: e7 f9 a2 79 3d 42 00 0f 58 c1 7c cd 91 ed c2 60 ...y=B..X.|.... Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |2| <= encrypt buf Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |3| output record: msgtype = 23, version = [3:3], msglen = 43 Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |4| dumping 'output record sent to network' (48 bytes) Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |4| 0000: 17 03 03 00 2b 00 00 00 00 00 00 00 01 7d 68 9a ....+........}h. Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |4| 0010: 9f cb 38 89 7c af fb 22 20 97 aa 24 fb 36 16 22 ..8.|.." ..$.6." Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |4| 0020: e7 f9 a2 79 3d 42 00 0f 58 c1 7c cd 91 ed c2 60 ...y=B..X.|.... Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |2| => flush output Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |2| message length: 48, out_left: 48 Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |2| ssl->f_send() returned 48 (-0xffffffd0) Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |2| <= flush output Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |2| <= write record Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |2| <= write Jul 21 07:03:39 | mqttClientAws[7705] | [DEBUG] [MQTT] [core_mqtt.c:645] BytesSent=19, BytesRemaining=0^M Jul 21 07:03:39 | mqttClientAws[7705] | [DEBUG] [MQTT] [core_mqtt.c:666] Successfully sent packet at time 2903398.^M Jul 21 07:03:39 | mqttClientAws[7705] | [DEBUG] [MQTT] [core_mqtt.c:1809] Sent 19 bytes of CONNECT packet.^M Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |2| => read Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |2| => read record Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |2| => fetch input Jul 21 07:03:39 | mqttClientAws[7705] | mbedTLS: |2| in_left: 0, nb_want: 5 Jul 21 07:03:49 | mqttClientAws[7705] | mbedTLS: |2| in_left: 0, nb_want: 5 Jul 21 07:03:49 | mqttClientAws[7705] | mbedTLS: |2| ssl->f_recv(_timeout)() returned -26624 (-0x6800) Jul 21 07:03:49 | mqttClientAws[7705] | mbedTLS: |1| mbedtls_ssl_fetch_input() returned -26624 (-0x6800) Jul 21 07:03:49 | mqttClientAws[7705] | mbedTLS: |1| ssl_get_next_record() returned -26624 (-0x6800) Jul 21 07:03:49 | mqttClientAws[7705] | mbedTLS: |1| mbedtls_ssl_read_record() returned -26624 (-0x6800) Jul 21 07:03:49 | mqttClientAws[7705] | [DEBUG] [Transport_MbedTLS_PKCS11] [mbedtls_pkcs11_posix.c:924] Failed to read data. However, a read can be retried on this error. mbedTLSError= SSL - The operation timed out : . Jul 21 07:03:49 | mqttClientAws[7705] | [ERROR] [MQTT] [core_mqtt.c:1570] CONNACK recv failed with status = MQTTNoDataAvailable.^M Jul 21 07:03:49 | mqttClientAws[7705] | [ERROR] [MQTT] [core_mqtt.c:1841] MQTT connection failed with status = MQTTNoDataAvailable.^M Jul 21 07:03:49 | mqttClientAws[7705] | [ERROR] [MQTT] [mqtt_operations.c:732] Connection with MQTT broker failed with status MQTTNoDataAvailable.^M Jul 21 07:03:49 | mqttClientAws[7705] | [ERROR] [DEMO] [mqttClientAws.c:1237] Failed to establish MQTT session.^M

ClaudioBaldo commented 2 years ago

on this target we don`t have FreeRTOS but we have implemented all the mbedtls libraries from the repository and the code execute properly. Just to add it to the comments.

paulbartell commented 2 years ago

@ClaudioBaldo : Are you using a high latency connection ( LTE Cat NB1 perhaps? ).

If you adjust TRANSPORT_SEND_RECV_TIMEOUT_MS value to be 2-3 x the ping time to your aws iot endpoint, that should allow enough time to receive a response from the server.

Moving forward, consider setting the socket to non-blocking mode with mbedtls_net_set_nonblock() and use the mbedtls_net_poll() function to determine if any data is available within your desired timeout. This will required modifying mbedtls_pkcs11_posix.c accordingly.

Please note that currently there is a limitation in the coreMQTT library where the library expects to always receive a full mqtt message at a time. This is not always the case for low latency or low-MSS (maximum segment size) connections.

ClaudioBaldo commented 2 years ago

@paulbartell I don`t think that is the problem, we can increase the value to 60s and still the socket will timeout, see the timestamp at the beginning of the line:

Jul 22 06:13:26 | mqttClientAws[2480] | [INFO] [Transport_MbedTLS_PKCS11] [mbedtls_pkcs11_posix.c:857] TLS Connection to a1ui4kt3m4uic8-ats.iot.ap-southeast-2.amazonaws.com established.^M Jul 22 06:13:26 | mqttClientAws[2480] | [DEBUG] [MQTT] [mqtt_operations.c:651] Connected to MQTT broker a1ui4kt3m4uic8-ats.iot.ap-southeast-2.amazonaws.com.^M Jul 22 06:13:26 | mqttClientAws[2480] | [DEBUG] [MQTT] [mqtt_operations.c:665] current time is :105012^M Jul 22 06:13:26 | mqttClientAws[2480] | [DEBUG] [MQTT] [mqtt_operations.c:682] MQTT init status success!!^M Jul 22 06:13:26 | mqttClientAws[2480] | [DEBUG] [MQTT] [core_mqtt_serializer.c:459] Encoded size for length 17 is 1 bytes.^M Jul 22 06:13:26 | mqttClientAws[2480] | [DEBUG] [MQTT] [core_mqtt_serializer.c:1600] CONNECT packet remaining length=17 and packet size=19.^M Jul 22 06:13:26 | mqttClientAws[2480] | [DEBUG] [MQTT] [core_mqtt.c:1784] CONNECT packet size is 19 and remaining length is 17.^M Jul 22 06:13:26 | mqttClientAws[2480] | [DEBUG] [MQTT] [core_mqtt_serializer.c:459] Encoded size for length 17 is 1 bytes.^M Jul 22 06:13:26 | mqttClientAws[2480] | [DEBUG] [MQTT] [core_mqtt_serializer.c:1499] Length of serialized CONNECT packet is 19.^M Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |2| => write Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |2| => write record Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |2| => encrypt buf Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |4| dumping 'before encrypt: output payload' (19 bytes) Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |4| 0000: 10 11 00 04 4d 51 54 54 04 00 00 3c 00 05 46 58 ....MQTT...<..FX Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |4| 0010: 33 30 53 30S Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |4| dumping 'IV used (internal)' (12 bytes) Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |4| 0000: 03 0a 22 29 00 00 00 00 00 00 00 01 ..")........ Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |4| dumping 'IV used (transmitted)' (8 bytes) Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |4| 0000: 00 00 00 00 00 00 00 01 ........ Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |4| dumping 'additional data used for AEAD' (13 bytes) Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |4| 0000: 00 00 00 00 00 00 00 01 17 03 03 00 13 ............. Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |3| before encrypt: msglen = 19, including 0 bytes of padding Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |4| dumping 'after encrypt: tag' (16 bytes) Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |4| 0000: e7 9f 4f 6c ea 00 76 51 3f 2a d0 76 57 7a 0c 6d ..Ol..vQ?.vWz.m Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |2| <= encrypt buf Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |3| output record: msgtype = 23, version = [3:3], msglen = 43 Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |4| dumping 'output record sent to network' (48 bytes) Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |4| 0000: 17 03 03 00 2b 00 00 00 00 00 00 00 01 2c ed 49 ....+........,.I Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |4| 0010: 34 a2 bc 08 5a e1 9f 7e dc f1 a9 da 3e 55 bc de 4...Z..~....>U.. Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |4| 0020: e7 9f 4f 6c ea 00 76 51 3f 2a d0 76 57 7a 0c 6d ..Ol..vQ?.vWz.m Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |2| => flush output Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |2| message length: 48, out_left: 48 Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |2| ssl->f_send() returned 48 (-0xffffffd0) Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |2| <= flush output Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |2| <= write record Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |2| <= write Jul 22 06:13:26 | mqttClientAws[2480] | [DEBUG] [MQTT] [core_mqtt.c:645] BytesSent=19, BytesRemaining=0^M Jul 22 06:13:26 | mqttClientAws[2480] | [DEBUG] [MQTT] [core_mqtt.c:666] Successfully sent packet at time 105028.^M Jul 22 06:13:26 | mqttClientAws[2480] | [DEBUG] [MQTT] [core_mqtt.c:1809] Sent 19 bytes of CONNECT packet.^M Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |2| => read Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |2| => read record Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |2| => fetch input Jul 22 06:13:26 | mqttClientAws[2480] | mbedTLS: |2| in_left: 0, nb_want: 5 <----- Waiting for the answer to CONNECT packet -----> Jul 22 06:14:26 | mqttClientAws[2480] | mbedTLS: |2| in_left: 0, nb_want: 5 Jul 22 06:14:26 | mqttClientAws[2480] | mbedTLS: |2| ssl->f_recv(_timeout)() returned -26624 (-0x6800) Jul 22 06:14:26 | mqttClientAws[2480] | mbedTLS: |1| mbedtls_ssl_fetch_input() returned -26624 (-0x6800) Jul 22 06:14:26 | mqttClientAws[2480] | mbedTLS: |1| ssl_get_next_record() returned -26624 (-0x6800) Jul 22 06:14:26 | mqttClientAws[2480] | mbedTLS: |1| mbedtls_ssl_read_record() returned -26624 (-0x6800) Jul 22 06:14:26 | mqttClientAws[2480] | [DEBUG] [Transport_MbedTLS_PKCS11] [mbedtls_pkcs11_posix.c:924] Failed to read data. However, a read can be retried on this error. mbedTLSError= SSL - The operation timed out : .

And this is the ping time to the backend: ping xxxxxxxxxxxxx-ats.iot.ap-southeast-2.amazonaws.com PING xxxxxxxxxxxxx-ats.iot.ap-southeast-2.amazonaws.com (52.63.245.21): 56 data bytes 64 bytes from 52.63.245.21: seq=0 ttl=233 time=122.114 ms 64 bytes from 52.63.245.21: seq=1 ttl=233 time=127.664 ms 64 bytes from 52.63.245.21: seq=2 ttl=233 time=234.024 ms 64 bytes from 52.63.245.21: seq=3 ttl=233 time=475.246 ms 64 bytes from 52.63.245.21: seq=4 ttl=233 time=279.140 ms 64 bytes from 52.63.245.21: seq=5 ttl=233 time=273.854 ms 64 bytes from 52.63.245.21: seq=6 ttl=233 time=299.010 ms 64 bytes from 52.63.245.21: seq=7 ttl=233 time=204.316 ms 64 bytes from 52.63.245.21: seq=8 ttl=233 time=275.728 ms 64 bytes from 52.63.245.21: seq=9 ttl=233 time=167.760 ms 64 bytes from 52.63.245.21: seq=10 ttl=233 time=231.004 ms ^C --- xxxxxxxxxxxxx-ats.iot.ap-southeast-2.amazonaws.com ping statistics --- 12 packets transmitted, 11 packets received, 8% packet loss round-trip min/avg/max = 122.114/244.532/475.246 ms

ClaudioBaldo commented 2 years ago

@paulbartell @alfred2g any idea why this is happening????

paulbartell commented 2 years ago

@ClaudioBaldo : Can you run your program with strace so we can see what syscalls are being generated during the read operation?

A packet capture may also be helpful if it's possible to capture one.

You might also try connecting via port 443 instead of 8883 in case there is some firewall restriction on your network. Make sure that the "x-amzn-mqtt-ca" alpn is enabled when using port 443.

Are you able to reproduce the issue on a normal linux machine or just your embedded target?

ClaudioBaldo commented 2 years ago

yes, I do have the port opened on the firewall (443), see below, and I am using the 443 port with mqtt protocol: Chain INPUT (policy ACCEPT) target prot opt source destination ACCEPT udp -- anywhere anywhere udp spt:ntp ctstate ESTABLISHED ACCEPT udp -- anywhere anywhere udp spt:443 state ESTABLISHED ACCEPT tcp -- anywhere anywhere tcp spt:https state ESTABLISHED ACCEPT udp -- anywhere anywhere udp spt:5686 state ESTABLISHED ACCEPT udp -- anywhere anywhere udp spt:5684 state ESTABLISHED ACCEPT icmp -- anywhere anywhere icmp echo-reply state ESTABLISHED ACCEPT tcp -- anywhere anywhere tcp spt:domain state ESTABLISHED ACCEPT udp -- anywhere anywhere udp spt:domain state ESTABLISHED DROP all -- anywhere anywhere ACCEPT icmp -- anywhere anywhere ACCEPT tcp -- anywhere anywhere tcp spt:domain state ESTABLISHED ACCEPT udp -- anywhere anywhere udp spt:domain state ESTABLISHED DROP all -- anywhere anywhere ACCEPT tcp -- anywhere anywhere tcp dpt:ssh ACCEPT icmp -- anywhere anywhere icmp echo-request ACCEPT udp -- anywhere anywhere udp spts:bootps:bootpc dpts:bootps:bootpc

Chain FORWARD (policy ACCEPT) target prot opt source destination

Chain OUTPUT (policy ACCEPT) target prot opt source destination

I can`t run with strace as there is not support of that on the image....

This is the setup of port and alp:

define ALPN_PROTOCOL_NAME "\x0ex-amzn-mqtt-ca"

define AWS_IOT_MQTT_PORT 443 ///< default port for MQTT/S

static bool connectToBrokerWithBackoffRetries( NetworkContext_t pNetworkContext, CK_SESSION_HANDLE p11Session, char pClientCertLabel, char pPrivateKeyLabel ) { bool returnStatus = false; BackoffAlgorithmStatus_t backoffAlgStatus = BackoffAlgorithmSuccess; MbedtlsPkcs11Status_t tlsStatus = MBEDTLS_PKCS11_SUCCESS; BackoffAlgorithmContext_t reconnectParams; MbedtlsPkcs11Credentials_t tlsCredentials = { 0 }; uint16_t nextRetryBackOff = 0U; const char alpn[] = { ALPN_PROTOCOL_NAME, NULL };

      /* Set the pParams member of the network context with desired transport. */
      pNetworkContext->pParams = &tlsContext;

      /* Initialize credentials for establishing TLS session. */
      tlsCredentials.pRootCaPath = AWS_IOT_ROOT_CA_FILENAME;
      tlsCredentials.pClientCertLabel = pClientCertLabel;
      tlsCredentials.pPrivateKeyLabel = pPrivateKeyLabel;
      tlsCredentials.p11Session = p11Session;

      /* AWS IoT requires devices to send the Server Name Indication (SNI)
       * extension to the Transport Layer Security (TLS) protocol and provide
       * the complete endpoint address in the host_name field. Details about
       * SNI for AWS IoT can be found in the link below.
       * https://docs.aws.amazon.com/iot/latest/developerguide/transport-security.html
       */
      tlsCredentials.disableSni = false;

      if( AWS_IOT_MQTT_PORT == 443 )
      {
          /* Pass the ALPN protocol name depending on the port being used.
           * Please see more details about the ALPN protocol for AWS IoT MQTT endpoint
           * in the link below.
           * https://aws.amazon.com/blogs/iot/mqtt-with-tls-client-authentication-on-port-443-why-it-is-useful-and-how-it-works/
           */
          tlsCredentials.pAlpnProtos = alpn;
      }

      /* Initialize reconnect attempts and interval */
      BackoffAlgorithm_InitializeParams( &reconnectParams,
                                         CONNECTION_RETRY_BACKOFF_BASE_MS,
                                         CONNECTION_RETRY_MAX_BACKOFF_DELAY_MS,
                                         CONNECTION_RETRY_MAX_ATTEMPTS );

      do
      {
          /* Establish a TLS session with the MQTT broker. This example connects
           * to the MQTT broker as specified in AWS_IOT_ENDPOINT and AWS_MQTT_PORT
           * at the demo config header. */
          LogDebug( ( "Establishing a TLS session to %.*s:%d.",
                      AWS_IOT_ENDPOINT_LENGTH,
                      BROKER_ENDPOINT,
                      AWS_IOT_MQTT_PORT ) );

          tlsStatus = Mbedtls_Pkcs11_Connect( pNetworkContext,
                                              BROKER_ENDPOINT,
                                              AWS_IOT_MQTT_PORT,
                                              &tlsCredentials,
                                              TRANSPORT_SEND_RECV_TIMEOUT_MS );

          if( tlsStatus == MBEDTLS_PKCS11_SUCCESS )
          {
              /* Connection successful. */
              returnStatus = true;
          }
          else
          {
              /* Generate a random number and get back-off value (in milliseconds) for the next connection retry. */
              backoffAlgStatus = BackoffAlgorithm_GetNextBackoff( &reconnectParams, generateRandomNumber(), &nextRetryBackOff );

              if( backoffAlgStatus == BackoffAlgorithmRetriesExhausted )
              {
                  LogError( ( "Connection to the broker failed, all attempts exhausted." ) );
              }
              else if( backoffAlgStatus == BackoffAlgorithmSuccess )
              {
                  LogWarn( ( "Connection to the broker failed. Retrying connection "
                             "after %hu ms backoff.",
                             ( unsigned short ) nextRetryBackOff ) );
                  Clock_SleepMs( nextRetryBackOff );
              }
          }
      } while( ( tlsStatus != MBEDTLS_PKCS11_SUCCESS ) && ( backoffAlgStatus == BackoffAlgorithmSuccess ) );

      return returnStatus;
    }

This function will actually execute successfully, only the Mqtt_connect will always failt with timeout doesn`t matter how high I set the timeout

paulbartell commented 2 years ago

@ClaudioBaldo:

ACCEPT udp -- anywhere anywhere udp spt:443 state ESTABLISHED

Would indicate that you're connected via a udp socket. Mqtt operates over TCP.

ClaudioBaldo commented 2 years ago

would it work differently for the older sdk? As the setup is the same,we haven`t modified the firewall.... We have also tried to keep the firewall wide opened just for testing and with no diffence.

Mqtt_Init() does return success. Mqtt_Connect() timeouts

Plus is the problem was the protocol, wouldn`t also the tls initial handshake fail?

ClaudioBaldo commented 2 years ago

also the following line should technically allow traffic for HTTPS over tcp which should be port 443

ACCEPT tcp -- anywhere anywhere tcp spt:https state ESTABLISHED

paulbartell commented 2 years ago

You're correct. This firewall rule is probably covering it.

ACCEPT tcp -- anywhere anywhere tcp spt:https state ESTABLISHED

is Server Name Indication enabled?

ClaudioBaldo commented 2 years ago

tlsCredentials.disableSni = false;

What we were wondering is the connectionInfo part and if this could cause the problem with the connection: /* If #createCleanSession is true, start with a clean session

/* The maximum time interval in seconds which is allowed to elapse

/ Username and password for authentication. Not used in this demo. / LogDebug ( ("pUserName: %s, lenght: %d", METRICS_STRING, METRICS_STRING_LENGTH) ); connectInfo.pUserName = NULL; connectInfo.userNameLength = 0U; connectInfo.pPassword = NULL; connectInfo.passwordLength = 0U;

paulbartell commented 2 years ago

How was your claim certificate and private key generated? Via an aws iot API call or some other method?

ClaudioBaldo commented 2 years ago

ok, so this solved the problem, I think the string was meant to be for openssl:

define ALPN_PROTOCOL_NAME "\x0ex-amzn-mqtt-ca"

changed to remove the \x0e and the connection works.

define ALPN_PROTOCOL_NAME "x-amzn-mqtt-ca"

Thank you for the help.

paulbartell commented 2 years ago

You're welcome. I will make sure to fix that definition in the rest of the locations it exists in.