ARMmbed / mbed-os-example-tls

mbed TLS Sample application
Apache License 2.0
30 stars 53 forks source link

Run-time failure on K66F "ECDSA-x25519 : Public function returned -0x4F80" #297

Closed Patater closed 3 years ago

Patater commented 3 years ago

Description of defect

[1623110205.06][GLRM][INF] remote resources flashing with 'mbed-os-example-tls/benchmark/BUILD/K66F/GCC_ARM/benchmark.bin'...
[1623110205.06][urllib3.connectionpool]Starting new HTTP connection (1): 10.6.54.131:8000
[1623110205.17][urllib3.connectionpool]http://10.6.54.131:8000 "POST /file HTTP/1.1" 200 245
[1623110224.21][GLRM][INF] opening connection to platform at baudrate='9600'
[1623110224.39][GLRM][INF] remote resources reset...
[1623110226.63][GLRM][INF] waiting 1.00 sec after reset
[1623110227.70][GLRM][TXD] mbedmbedmbedmbedmbedmbedmbedmbedmbedmbed
[1623110227.70][CONN][WRN] skipping __sync packet (specified with --sync=0)
[1623110227.73][CONN][RXD]   MD4 :       7541 KB/s
[1623110228.73][CONN][RXD]   MD5 :       5349 KB/s
[1623110229.74][CONN][RXD]   RIPEMD160 :       2368 KB/s
[1623110230.84][CONN][RXD]   SHA-1 :       3088 KB/s
[1623110231.85][CONN][RXD]   SHA-256 :       1503 KB/s
[1623110232.86][CONN][RXD]   SHA-512 :        741 KB/s
[1623110233.85][CONN][RXD]   ARC4 :       4251 KB/s
[1623110234.96][CONN][RXD]   3DES :        138 KB/s
[1623110235.97][CONN][RXD]   DES :        400 KB/s
[1623110236.96][CONN][RXD]   3DES-CMAC :        130 KB/s
[1623110238.07][CONN][RXD]   AES-CBC-128 :        631 KB/s
[1623110239.07][CONN][RXD]   AES-CBC-192 :        540 KB/s
[1623110240.07][CONN][RXD]   AES-CBC-256 :        472 KB/s
[1623110241.07][CONN][RXD]   AES-CTR-128 :        619 KB/s
[1623110242.18][CONN][RXD]   AES-CTR-192 :        531 KB/s
[1623110243.18][CONN][RXD]   AES-CTR-256 :        465 KB/s
[1623110244.18][CONN][RXD]   AES-GCM-128 :        401 KB/s
[1623110245.30][CONN][RXD]   AES-GCM-192 :        362 KB/s
[1623110246.29][CONN][RXD]   AES-GCM-256 :        330 KB/s
[1623110247.29][CONN][RXD]   AES-CCM-128 :        286 KB/s
[1623110248.41][CONN][RXD]   AES-CCM-192 :        248 KB/s
[1623110249.40][CONN][RXD]   AES-CCM-256 :        218 KB/s
[1623110250.40][CONN][RXD]   AES-CMAC-128 :        562 KB/s
[1623110251.51][CONN][RXD]   AES-CMAC-192 :        488 KB/s
[1623110252.51][CONN][RXD]   AES-CMAC-256 :        430 KB/s
[1623110253.51][CONN][RXD]   AES-CMAC-PRF-128 :        562 KB/s
[1623110254.63][CONN][RXD]   CAMELLIA-CBC-128 :        588 KB/s
[1623110255.62][CONN][RXD]   CAMELLIA-CBC-192 :        452 KB/s
[1623110256.63][CONN][RXD]   CAMELLIA-CBC-256 :        452 KB/s
[1623110257.73][CONN][RXD]   BLOWFISH-CBC-128 :       1403 KB/s
[1623110258.73][CONN][RXD]   BLOWFISH-CBC-192 :       1403 KB/s
[1623110259.74][CONN][RXD]   BLOWFISH-CBC-256 :       1403 KB/s
[1623110260.84][CONN][RXD]   CTR_DRBG (NOPR) :        456 KB/s
[1623110261.85][CONN][RXD]   CTR_DRBG (PR) :        340 KB/s
[1623110262.85][CONN][RXD]   HMAC_DRBG SHA-1 (NOPR) :        206 KB/s
[1623110263.95][CONN][RXD]   HMAC_DRBG SHA-1 (PR) :        191 KB/s
[1623110264.96][CONN][RXD]   HMAC_DRBG SHA-256 (NOPR) :        153 KB/s
[1623110266.06][CONN][RXD]   HMAC_DRBG SHA-256 (PR) :        153 KB/s
[1623110266.06][CONN][RXD]   RSA-2048 :      31 ms/ public
[1623110267.27][CONN][RXD]   RSA-2048 :    1118 ms/private
[1623110268.37][CONN][RXD]   ECDSA-secp384r1 :     567 ms/sign
[1623110269.17][CONN][RXD]   ECDSA-secp256r1 :     386 ms/sign
[1623110269.47][CONN][RXD]   ECDSA-x25519 :  Public function returned -0x4F80
[1623110269.57][CONN][RXD]   !  ECP - Bad input parameters to function
[1623110271.18][CONN][RXD]   ECDHE-secp384r1 :    1052 ms/handshake
[1623110272.38][CONN][RXD]   ECDHE-secp256r1 :     746 ms/handshake
[1623110273.29][CONN][RXD]   ECDHE-x25519 :     609 ms/handshake
[1623110274.99][CONN][RXD]   ECDHE-x448 :    1107 ms/handshake
[1623110276.30][CONN][RXD]   ECDH-secp384r1 :     517 ms/handshake
[1623110277.21][CONN][RXD]   ECDH-secp256r1 :     372 ms/handshake
[1623110278.10][CONN][RXD]   ECDH-x25519 :     306 ms/handshake
[1623110279.81][CONN][RXD]   ECDH-x448 :     567 ms/handshake
[1623110280.81][CONN][RXD]   ECDHE-Curve25519 :     603 ms/handshake
[1623110281.72][CONN][RXD]   ECDH-Curve25519 :     310 ms/handshake
[1623110281.72][CONN][RXD] DONE
[1623110790.28][HTST][INF] test suite run finished after 600.88 sec...
[1623110790.28][HTST][ERR] Expected output [\s+ECDSA-secp384r1\s*:\s*(\d+ ms/verify|Feature unsupported)] not received in log.
[1623110790.28][CONN][INF] received special event '__host_test_finished' value='True', finishing
[1623110790.28][urllib3.connectionpool]Starting new HTTP connection (1): 10.6.54.131:8000
[1623110790.40][urllib3.connectionpool]http://10.6.54.131:8000 "PUT /resource/0311000048824e450009700add8900188761000097969900/disconnect HTTP/1.1" 200 88
[1623110793.67][HTST][INF] CONN exited with code: 0
[1623110793.67][HTST][INF] No events in queue
[1623110793.67][HTST][INF] stopped consuming events
[1623110793.67][HTST][INF] host test result(): None
[1623110793.67][HTST][WRN] missing __exit event from DUT
[1623110793.67][HTST][WRN] missing __exit_event_queue event from host test
[1623110793.67][HTST][ERR] missing __exit_event_queue event from host test and no result from host test, timeout...
[1623110793.67][HTST][INF] calling blocking teardown()
[1623110793.67][HTST][INF] teardown() finished
[1623110793.67][HTST][INF] {{result;timeout}}
mbedgt: retry mbedhtrun 2/5
[1623110793.87][HTST][INF] host test executor ver. 1.8.4
[1623110793.87][HTST][INF] copy image onto target... SKIPPED!
[1623110793.87][HTST][INF] starting host test process...
[1623110793.87][CONN][INF] starting connection process...
[1623110793.87][CONN][INF] notify event queue about extra 600 sec timeout for serial port pooling
[1623110793.87][CONN][INF] initializing global resource mgr listener...
[1623110793.87][HTST][INF] setting timeout to: 600 sec
[1623110793.91][GLRM][INF] remote resources initialization: remote(host=http://10.6.54.131, port=8000)
[1623110793.92][urllib3.connectionpool]Starting new HTTP connection (1): 10.6.54.131:8000
[1623110793.96][urllib3.connectionpool]http://10.6.54.131:8000 "POST /login HTTP/1.1" 200 273
[1623110793.97][urllib3.connectionpool]Starting new HTTP connection (1): 10.6.54.131:8000
[1623110794.02][urllib3.connectionpool]http://10.6.54.131:8000 "GET /socket.io/?token=eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJ1c2VybmFtZSI6InVzZXIiLCJncm91cCI6InVzZXIiLCJpYXQiOjE2MjMxMTA3OTMsImV4cCI6MTYyMzcxNTU5MywianRpIjoiNjI4ZDBlMDAtYzdlZC0xMWViLThjNDYtM2Y3MjllOWY2MDYxIn0.mBB28JGCYDiAcw5yULQP5WX0YN6bkcpNeQuVnYkT3Xw&EIO=3&transport=polling&t=1623110793965-0 HTTP/1.1" 200 101
[1623110794.08][urllib3.connectionpool]Starting new HTTP connection (1): 10.6.54.131:8000
[1623110794.10][dummy]socketio unknown event received: info
[1623110794.12][urllib3.connectionpool]http://10.6.54.131:8000 "GET /this/resource HTTP/1.1" 200 2749
[1623110794.12][urllib3.connectionpool]Starting new HTTP connection (1): 10.6.54.131:8000
[1623110794.19][urllib3.connectionpool]http://10.6.54.131:8000 "GET /resource HTTP/1.1" 200 134545
[1623110794.27][GLRM][INF] remote resources count: 88
[1623110805.48][urllib3.connectionpool]Starting new HTTP connection (1): 10.6.54.131:8000
[1623110805.52][urllib3.connectionpool]http://10.6.54.131:8000 "GET /resource/0311000048824e4500117009dd89002a8761000097969900 HTTP/1.1" 200 2097
[1623110805.53][GLRM][INF] remote resources flashing with 'mbed-os-example-tls/benchmark/BUILD/K66F/GCC_ARM/benchmark.bin'...
[1623110805.53][urllib3.connectionpool]Starting new HTTP connection (1): 10.6.54.131:8000
[1623110805.64][urllib3.connectionpool]http://10.6.54.131:8000 "POST /file HTTP/1.1" 200 245
[1623110823.86][GLRM][INF] opening connection to platform at baudrate='9600'
[1623110824.06][GLRM][INF] remote resources reset...
[1623110826.30][GLRM][INF] waiting 1.00 sec after reset
[1623110827.36][GLRM][TXD] mbedmbedmbedmbedmbedmbedmbedmbedmbedmbed
[1623110827.36][CONN][WRN] skipping __sync packet (specified with --sync=0)
[1623110827.40][CONN][RXD]   MD4 :       7541 KB/s
[1623110828.41][CONN][RXD]   MD5 :       5349 KB/s
[1623110829.41][CONN][RXD]   RIPEMD160 :       2368 KB/s
[1623110830.51][CONN][RXD]   SHA-1 :       3088 KB/s
[1623110831.51][CONN][RXD]   SHA-256 :       1503 KB/s
[1623110832.51][CONN][RXD]   SHA-512 :        741 KB/s
[1623110833.52][CONN][RXD]   ARC4 :       4251 KB/s
[1623110834.62][CONN][RXD]   3DES :        138 KB/s
[1623110835.63][CONN][RXD]   DES :        400 KB/s
[1623110836.63][CONN][RXD]   3DES-CMAC :        130 KB/s
[1623110837.73][CONN][RXD]   AES-CBC-128 :        631 KB/s
[1623110838.73][CONN][RXD]   AES-CBC-192 :        540 KB/s
[1623110839.74][CONN][RXD]   AES-CBC-256 :        472 KB/s
[1623110840.74][CONN][RXD]   AES-CTR-128 :        619 KB/s
[1623110841.84][CONN][RXD]   AES-CTR-192 :        531 KB/s
[1623110842.85][CONN][RXD]   AES-CTR-256 :        465 KB/s
[1623110843.85][CONN][RXD]   AES-GCM-128 :        401 KB/s
[1623110844.95][CONN][RXD]   AES-GCM-192 :        362 KB/s
[1623110845.96][CONN][RXD]   AES-GCM-256 :        330 KB/s
[1623110846.96][CONN][RXD]   AES-CCM-128 :        286 KB/s
[1623110848.06][CONN][RXD]   AES-CCM-192 :        248 KB/s
[1623110849.06][CONN][RXD]   AES-CCM-256 :        218 KB/s
[1623110850.06][CONN][RXD]   AES-CMAC-128 :        562 KB/s
[1623110851.17][CONN][RXD]   AES-CMAC-192 :        488 KB/s
[1623110852.17][CONN][RXD]   AES-CMAC-256 :        430 KB/s
[1623110853.18][CONN][RXD]   AES-CMAC-PRF-128 :        562 KB/s
[1623110854.28][CONN][RXD]   CAMELLIA-CBC-128 :        588 KB/s
[1623110855.28][CONN][RXD]   CAMELLIA-CBC-192 :        452 KB/s
[1623110856.29][CONN][RXD]   CAMELLIA-CBC-256 :        452 KB/s
[1623110857.39][CONN][RXD]   BLOWFISH-CBC-128 :       1403 KB/s
[1623110858.40][CONN][RXD]   BLOWFISH-CBC-192 :       1403 KB/s
[1623110859.39][CONN][RXD]   BLOWFISH-CBC-256 :       1403 KB/s
[1623110860.50][CONN][RXD]   CTR_DRBG (NOPR) :        456 KB/s
[1623110861.51][CONN][RXD]   CTR_DRBG (PR) :        340 KB/s
[1623110862.50][CONN][RXD]   HMAC_DRBG SHA-1 (NOPR) :        206 KB/s
[1623110863.61][CONN][RXD]   HMAC_DRBG SHA-1 (PR) :        191 KB/s
[1623110864.61][CONN][RXD]   HMAC_DRBG SHA-256 (NOPR) :        153 KB/s
[1623110865.71][CONN][RXD]   HMAC_DRBG SHA-256 (PR) :        153 KB/s
[1623110865.71][CONN][RXD]   RSA-2048 :      31 ms/ public
[1623110866.92][CONN][RXD]   RSA-2048 :    1118 ms/private
[1623110868.02][CONN][RXD]   ECDSA-secp384r1 :     567 ms/sign
[1623110868.82][CONN][RXD]   ECDSA-secp256r1 :     386 ms/sign
[1623110869.23][CONN][RXD]   ECDSA-x25519 :  Public function returned -0x4F80
[1623110869.23][CONN][RXD]   !  ECP - Bad input parameters to function
[1623110870.83][CONN][RXD]   ECDHE-secp384r1 :    1052 ms/handshake
[1623110872.03][CONN][RXD]   ECDHE-secp256r1 :     746 ms/handshake
[1623110872.94][CONN][RXD]   ECDHE-x25519 :     609 ms/handshake
[1623110874.64][CONN][RXD]   ECDHE-x448 :    1107 ms/handshake
[1623110875.94][CONN][RXD]   ECDH-secp384r1 :     517 ms/handshake
[1623110876.85][CONN][RXD]   ECDH-secp256r1 :     372 ms/handshake
[1623110877.75][CONN][RXD]   ECDH-x25519 :     306 ms/handshake
[1623110879.46][CONN][RXD]   ECDH-x448 :     567 ms/handshake
[1623110880.46][CONN][RXD]   ECDHE-Curve25519 :     603 ms/handshake
[1623110881.36][CONN][RXD]   ECDH-Curve25519 :     310 ms/handshake
[1623110881.36][CONN][RXD] DONE
[1623111393.93][HTST][INF] test suite run finished after 600.05 sec...
[1623111393.93][HTST][ERR] Expected output [\s+ECDSA-secp384r1\s*:\s*(\d+ ms/verify|Feature unsupported)] not received in log.
[1623111393.93][CONN][INF] received special event '__host_test_finished' value='True', finishing
[1623111393.93][urllib3.connectionpool]Starting new HTTP connection (1): 10.6.54.131:8000
[1623111394.04][urllib3.connectionpool]http://10.6.54.131:8000 "PUT /resource/0311000048824e4500117009dd89002a8761000097969900/disconnect HTTP/1.1" 200 88
[1623111397.27][HTST][INF] CONN exited with code: 0
[1623111397.27][HTST][INF] No events in queue
[1623111397.27][HTST][INF] stopped consuming events
[1623111397.27][HTST][INF] host test result(): None
[1623111397.27][HTST][WRN] missing __exit event from DUT
[1623111397.27][HTST][WRN] missing __exit_event_queue event from host test
[1623111397.27][HTST][ERR] missing __exit_event_queue event from host test and no result from host test, timeout...
[1623111397.27][HTST][INF] calling blocking teardown()
[1623111397.27][HTST][INF] teardown() finished
[1623111397.27][HTST][INF] {{result;timeout}}
mbedgt: retry mbedhtrun 3/5
[1623111397.47][HTST][INF] host test executor ver. 1.8.4
[1623111397.47][HTST][INF] copy image onto target... SKIPPED!
[1623111397.47][HTST][INF] starting host test process...
[1623111397.47][CONN][INF] starting connection process...
[1623111397.47][CONN][INF] notify event queue about extra 600 sec timeout for serial port pooling
[1623111397.47][CONN][INF] initializing global resource mgr listener...
[1623111397.47][HTST][INF] setting timeout to: 600 sec
[1623111397.52][GLRM][INF] remote resources initialization: remote(host=http://10.6.54.131, port=8000)
[1623111397.52][urllib3.connectionpool]Starting new HTTP connection (1): 10.6.54.131:8000
[1623111397.57][urllib3.connectionpool]http://10.6.54.131:8000 "POST /login HTTP/1.1" 200 273
[1623111397.57][urllib3.connectionpool]Starting new HTTP connection (1): 10.6.54.131:8000
[1623111397.62][urllib3.connectionpool]http://10.6.54.131:8000 "GET /socket.io/?token=eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJ1c2VybmFtZSI6InVzZXIiLCJncm91cCI6InVzZXIiLCJpYXQiOjE2MjMxMTEzOTcsImV4cCI6MTYyMzcxNjE5NywianRpIjoiY2E1MmYzZjAtYzdlZS0xMWViLThjNDYtM2Y3MjllOWY2MDYxIn0.pAoTOJKqx_hhxyWzVcyzy6GKWOvpm1Mzhc0xFGkAec4&EIO=3&transport=polling&t=1623111397567-0 HTTP/1.1" 200 101
[1623111397.67][urllib3.connectionpool]Starting new HTTP connection (1): 10.6.54.131:8000
[1623111397.69][dummy]socketio unknown event received: info
[1623111397.73][urllib3.connectionpool]http://10.6.54.131:8000 "GET /this/resource HTTP/1.1" 200 2749
[1623111397.73][urllib3.connectionpool]Starting new HTTP connection (1): 10.6.54.131:8000
[1623111397.80][urllib3.connectionpool]http://10.6.54.131:8000 "GET /resource HTTP/1.1" 200 131652
[1623111397.87][GLRM][INF] remote resources count: 88
[1623111408.40][urllib3.connectionpool]Starting new HTTP connection (1): 10.6.54.131:8000
[1623111408.48][urllib3.connectionpool]http://10.6.54.131:8000 "GET /resource/0311000048824e4500267008dd8900508761000097969900 HTTP/1.1" 200 2110
[1623111408.48][GLRM][INF] remote resources flashing with 'mbed-os-example-tls/benchmark/BUILD/K66F/GCC_ARM/benchmark.bin'...
[1623111408.48][urllib3.connectionpool]Starting new HTTP connection (1): 10.6.54.131:8000
[1623111408.62][urllib3.connectionpool]http://10.6.54.131:8000 "POST /file HTTP/1.1" 200 245
[1623111427.98][GLRM][INF] opening connection to platform at baudrate='9600'
[1623111428.15][GLRM][INF] remote resources reset...
[1623111430.37][GLRM][INF] waiting 1.00 sec after reset
[1623111431.43][GLRM][TXD] mbedmbedmbedmbedmbedmbedmbedmbedmbedmbed
[1623111431.43][CONN][WRN] skipping __sync packet (specified with --sync=0)
[1623111431.48][CONN][RXD]   MD4 :       7541 KB/s
[1623111432.48][CONN][RXD]   MD5 :       5349 KB/s
[1623111433.48][CONN][RXD]   RIPEMD160 :       2368 KB/s
[1623111434.59][CONN][RXD]   SHA-1 :       3087 KB/s
[1623111435.59][CONN][RXD]   SHA-256 :       1503 KB/s
[1623111436.60][CONN][RXD]   SHA-512 :        741 KB/s
[1623111437.60][CONN][RXD]   ARC4 :       4251 KB/s
[1623111438.70][CONN][RXD]   3DES :        138 KB/s
[1623111439.70][CONN][RXD]   DES :        400 KB/s
[1623111440.71][CONN][RXD]   3DES-CMAC :        130 KB/s
[1623111441.71][CONN][RXD]   AES-CBC-128 :        631 KB/s
[1623111442.81][CONN][RXD]   AES-CBC-192 :        540 KB/s
[1623111443.82][CONN][RXD]   AES-CBC-256 :        472 KB/s
[1623111444.82][CONN][RXD]   AES-CTR-128 :        619 KB/s
[1623111445.92][CONN][RXD]   AES-CTR-192 :        531 KB/s
[1623111446.93][CONN][RXD]   AES-CTR-256 :        465 KB/s
[1623111447.93][CONN][RXD]   AES-GCM-128 :        401 KB/s
[1623111449.04][CONN][RXD]   AES-GCM-192 :        362 KB/s
[1623111450.04][CONN][RXD]   AES-GCM-256 :        330 KB/s
[1623111451.04][CONN][RXD]   AES-CCM-128 :        286 KB/s
[1623111452.05][CONN][RXD]   AES-CCM-192 :        248 KB/s
[1623111453.16][CONN][RXD]   AES-CCM-256 :        218 KB/s
[1623111454.16][CONN][RXD]   AES-CMAC-128 :        562 KB/s
[1623111455.16][CONN][RXD]   AES-CMAC-192 :        488 KB/s
[1623111456.27][CONN][RXD]   AES-CMAC-256 :        430 KB/s
[1623111457.28][CONN][RXD]   AES-CMAC-PRF-128 :        562 KB/s
[1623111458.27][CONN][RXD]   CAMELLIA-CBC-128 :        588 KB/s
[1623111459.37][CONN][RXD]   CAMELLIA-CBC-192 :        452 KB/s
[1623111460.38][CONN][RXD]   CAMELLIA-CBC-256 :        452 KB/s
[1623111461.38][CONN][RXD]   BLOWFISH-CBC-128 :       1403 KB/s
[1623111462.48][CONN][RXD]   BLOWFISH-CBC-192 :       1403 KB/s
[1623111463.48][CONN][RXD]   BLOWFISH-CBC-256 :       1403 KB/s
[1623111464.49][CONN][RXD]   CTR_DRBG (NOPR) :        456 KB/s
[1623111465.60][CONN][RXD]   CTR_DRBG (PR) :        340 KB/s
[1623111466.60][CONN][RXD]   HMAC_DRBG SHA-1 (NOPR) :        206 KB/s
[1623111467.70][CONN][RXD]   HMAC_DRBG SHA-1 (PR) :        191 KB/s
[1623111468.72][CONN][RXD]   HMAC_DRBG SHA-256 (NOPR) :        153 KB/s
[1623111469.81][CONN][RXD]   HMAC_DRBG SHA-256 (PR) :        153 KB/s
[1623111469.81][CONN][RXD]   RSA-2048 :      31 ms/ public
[1623111471.01][CONN][RXD]   RSA-2048 :    1118 ms/private
[1623111472.11][CONN][RXD]   ECDSA-secp384r1 :     567 ms/sign
[1623111472.92][CONN][RXD]   ECDSA-secp256r1 :     386 ms/sign
[1623111473.22][CONN][RXD]   ECDSA-x25519 :  Public function returned -0x4F80
[1623111473.32][CONN][RXD]   !  ECP - Bad input parameters to function
[1623111474.92][CONN][RXD]   ECDHE-secp384r1 :    1052 ms/handshake
[1623111476.13][CONN][RXD]   ECDHE-secp256r1 :     746 ms/handshake
[1623111477.03][CONN][RXD]   ECDHE-x25519 :     609 ms/handshake
[1623111478.73][CONN][RXD]   ECDHE-x448 :    1107 ms/handshake
[1623111480.04][CONN][RXD]   ECDH-secp384r1 :     517 ms/handshake
[1623111480.95][CONN][RXD]   ECDH-secp256r1 :     372 ms/handshake
[1623111481.85][CONN][RXD]   ECDH-x25519 :     306 ms/handshake
[1623111483.56][CONN][RXD]   ECDH-x448 :     567 ms/handshake
[1623111484.46][CONN][RXD]   ECDHE-Curve25519 :     603 ms/handshake
[1623111485.46][CONN][RXD]   ECDH-Curve25519 :     310 ms/handshake
[1623111485.46][CONN][RXD] DONE
[1623111998.02][HTST][INF] test suite run finished after 600.55 sec...
[1623111998.02][HTST][ERR] Expected output [\s+ECDSA-secp384r1\s*:\s*(\d+ ms/verify|Feature unsupported)] not received in log.
[1623111998.02][CONN][INF] received special event '__host_test_finished' value='True', finishing
[1623111998.02][urllib3.connectionpool]Starting new HTTP connection (1): 10.6.54.131:8000
[1623111998.12][urllib3.connectionpool]http://10.6.54.131:8000 "PUT /resource/0311000048824e4500267008dd8900508761000097969900/disconnect HTTP/1.1" 200 88
[1623112001.39][HTST][INF] CONN exited with code: 0
[1623112001.39][HTST][INF] No events in queue
[1623112001.39][HTST][INF] stopped consuming events
[1623112001.39][HTST][INF] host test result(): None
[1623112001.39][HTST][WRN] missing __exit event from DUT
[1623112001.39][HTST][WRN] missing __exit_event_queue event from host test
[1623112001.39][HTST][ERR] missing __exit_event_queue event from host test and no result from host test, timeout...
[1623112001.39][HTST][INF] calling blocking teardown()
[1623112001.39][HTST][INF] teardown() finished
[1623112001.39][HTST][INF] {{result;timeout}}
mbedgt: retry mbedhtrun 4/5
[1623112001.59][HTST][INF] host test executor ver. 1.8.4
[1623112001.59][HTST][INF] copy image onto target... SKIPPED!
[1623112001.59][HTST][INF] starting host test process...
[1623112001.59][CONN][INF] starting connection process...
[1623112001.59][CONN][INF] notify event queue about extra 600 sec timeout for serial port pooling
[1623112001.59][CONN][INF] initializing global resource mgr listener...
[1623112001.59][HTST][INF] setting timeout to: 600 sec
[1623112001.64][GLRM][INF] remote resources initialization: remote(host=http://10.6.54.131, port=8000)
[1623112001.64][urllib3.connectionpool]Starting new HTTP connection (1): 10.6.54.131:8000
[1623112001.69][urllib3.connectionpool]http://10.6.54.131:8000 "POST /login HTTP/1.1" 200 273
[1623112001.69][urllib3.connectionpool]Starting new HTTP connection (1): 10.6.54.131:8000
[1623112001.73][urllib3.connectionpool]http://10.6.54.131:8000 "GET /socket.io/?token=eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJ1c2VybmFtZSI6InVzZXIiLCJncm91cCI6InVzZXIiLCJpYXQiOjE2MjMxMTIwMDEsImV4cCI6MTYyMzcxNjgwMSwianRpIjoiMzI2ODMyNjAtYzdmMC0xMWViLThjNDYtM2Y3MjllOWY2MDYxIn0.ezS_ZmMRbbNnFNV3YNdbp8HeDOqsdpUYyeTzozhEits&EIO=3&transport=polling&t=1623112001685-0 HTTP/1.1" 200 101
[1623112001.79][urllib3.connectionpool]Starting new HTTP connection (1): 10.6.54.131:8000
[1623112001.81][dummy]socketio unknown event received: info
[1623112001.83][urllib3.connectionpool]http://10.6.54.131:8000 "GET /this/resource HTTP/1.1" 200 2749
[1623112001.83][urllib3.connectionpool]Starting new HTTP connection (1): 10.6.54.131:8000
[1623112001.89][urllib3.connectionpool]http://10.6.54.131:8000 "GET /resource HTTP/1.1" 200 128578
[1623112001.95][GLRM][INF] remote resources count: 88
[1623112006.86][urllib3.connectionpool]Starting new HTTP connection (1): 10.6.54.131:8000
[1623112006.91][urllib3.connectionpool]http://10.6.54.131:8000 "GET /resource/0311000048824e450009700add8900188761000097969900 HTTP/1.1" 200 2098
[1623112006.91][GLRM][INF] remote resources flashing with 'mbed-os-example-tls/benchmark/BUILD/K66F/GCC_ARM/benchmark.bin'...
[1623112006.91][urllib3.connectionpool]Starting new HTTP connection (1): 10.6.54.131:8000
[1623112007.03][urllib3.connectionpool]http://10.6.54.131:8000 "POST /file HTTP/1.1" 200 245
[1623112026.04][GLRM][INF] opening connection to platform at baudrate='9600'
[1623112026.22][GLRM][INF] remote resources reset...
[1623112028.48][GLRM][INF] waiting 1.00 sec after reset
[1623112029.55][GLRM][TXD] mbedmbedmbedmbedmbedmbedmbedmbedmbedmbed
[1623112029.55][CONN][WRN] skipping __sync packet (specified with --sync=0)
[1623112029.58][CONN][RXD]   MD4 :       7541 KB/s
[1623112030.59][CONN][RXD]   MD5 :       5349 KB/s
[1623112031.59][CONN][RXD]   RIPEMD160 :       2368 KB/s
[1623112032.69][CONN][RXD]   SHA-1 :       3088 KB/s
[1623112033.69][CONN][RXD]   SHA-256 :       1503 KB/s
[1623112034.70][CONN][RXD]   SHA-512 :        741 KB/s
[1623112035.70][CONN][RXD]   ARC4 :       4251 KB/s
[1623112036.80][CONN][RXD]   3DES :        138 KB/s
[1623112037.81][CONN][RXD]   DES :        400 KB/s
[1623112038.81][CONN][RXD]   3DES-CMAC :        130 KB/s
[1623112039.81][CONN][RXD]   AES-CBC-128 :        631 KB/s
[1623112040.92][CONN][RXD]   AES-CBC-192 :        540 KB/s
[1623112041.92][CONN][RXD]   AES-CBC-256 :        472 KB/s
[1623112042.92][CONN][RXD]   AES-CTR-128 :        619 KB/s
[1623112044.03][CONN][RXD]   AES-CTR-192 :        531 KB/s
[1623112045.03][CONN][RXD]   AES-CTR-256 :        465 KB/s
[1623112046.04][CONN][RXD]   AES-GCM-128 :        401 KB/s
[1623112047.13][CONN][RXD]   AES-GCM-192 :        362 KB/s
[1623112048.14][CONN][RXD]   AES-GCM-256 :        330 KB/s
[1623112049.14][CONN][RXD]   AES-CCM-128 :        286 KB/s
[1623112050.24][CONN][RXD]   AES-CCM-192 :        248 KB/s
[1623112051.25][CONN][RXD]   AES-CCM-256 :        218 KB/s
[1623112052.25][CONN][RXD]   AES-CMAC-128 :        562 KB/s
[1623112053.36][CONN][RXD]   AES-CMAC-192 :        488 KB/s
[1623112054.36][CONN][RXD]   AES-CMAC-256 :        430 KB/s
[1623112055.36][CONN][RXD]   AES-CMAC-PRF-128 :        562 KB/s
[1623112056.46][CONN][RXD]   CAMELLIA-CBC-128 :        588 KB/s
[1623112057.47][CONN][RXD]   CAMELLIA-CBC-192 :        452 KB/s
[1623112058.47][CONN][RXD]   CAMELLIA-CBC-256 :        452 KB/s
[1623112059.57][CONN][RXD]   BLOWFISH-CBC-128 :       1403 KB/s
[1623112060.58][CONN][RXD]   BLOWFISH-CBC-192 :       1403 KB/s
[1623112061.58][CONN][RXD]   BLOWFISH-CBC-256 :       1403 KB/s
[1623112062.68][CONN][RXD]   CTR_DRBG (NOPR) :        456 KB/s
[1623112063.69][CONN][RXD]   CTR_DRBG (PR) :        340 KB/s
[1623112064.69][CONN][RXD]   HMAC_DRBG SHA-1 (NOPR) :        206 KB/s
[1623112065.80][CONN][RXD]   HMAC_DRBG SHA-1 (PR) :        191 KB/s
[1623112066.79][CONN][RXD]   HMAC_DRBG SHA-256 (NOPR) :        153 KB/s
[1623112067.90][CONN][RXD]   HMAC_DRBG SHA-256 (PR) :        153 KB/s
[1623112067.90][CONN][RXD]   RSA-2048 :      31 ms/ public
[1623112069.10][CONN][RXD]   RSA-2048 :    1118 ms/private
[1623112070.20][CONN][RXD]   ECDSA-secp384r1 :     567 ms/sign
[1623112071.01][CONN][RXD]   ECDSA-secp256r1 :     386 ms/sign
[1623112071.41][CONN][RXD]   ECDSA-x25519 :  Public function returned -0x4F80
[1623112071.41][CONN][RXD]   !  ECP - Bad input parameters to function
[1623112073.02][CONN][RXD]   ECDHE-secp384r1 :    1052 ms/handshake
[1623112074.21][CONN][RXD]   ECDHE-secp256r1 :     746 ms/handshake
[1623112075.12][CONN][RXD]   ECDHE-x25519 :     609 ms/handshake
[1623112076.82][CONN][RXD]   ECDHE-x448 :    1107 ms/handshake
[1623112078.13][CONN][RXD]   ECDH-secp384r1 :     517 ms/handshake
[1623112079.03][CONN][RXD]   ECDH-secp256r1 :     372 ms/handshake
[1623112079.93][CONN][RXD]   ECDH-x25519 :     306 ms/handshake
[1623112081.64][CONN][RXD]   ECDH-x448 :     567 ms/handshake
[1623112082.64][CONN][RXD]   ECDHE-Curve25519 :     603 ms/handshake
[1623112083.55][CONN][RXD]   ECDH-Curve25519 :     310 ms/handshake
[1623112083.55][CONN][RXD] DONE
[1623112602.12][HTST][INF] test suite run finished after 600.52 sec...
[1623112602.12][HTST][ERR] Expected output [\s+ECDSA-secp384r1\s*:\s*(\d+ ms/verify|Feature unsupported)] not received in log.
[1623112602.12][CONN][INF] received special event '__host_test_finished' value='True', finishing
[1623112602.12][urllib3.connectionpool]Starting new HTTP connection (1): 10.6.54.131:8000
[1623112602.24][urllib3.connectionpool]http://10.6.54.131:8000 "PUT /resource/0311000048824e450009700add8900188761000097969900/disconnect HTTP/1.1" 200 88
[1623112605.50][HTST][INF] CONN exited with code: 0
[1623112605.50][HTST][INF] No events in queue
[1623112605.50][HTST][INF] stopped consuming events
[1623112605.50][HTST][INF] host test result(): None
[1623112605.50][HTST][WRN] missing __exit event from DUT
[1623112605.50][HTST][WRN] missing __exit_event_queue event from host test
[1623112605.50][HTST][ERR] missing __exit_event_queue event from host test and no result from host test, timeout...
[1623112605.50][HTST][INF] calling blocking teardown()
[1623112605.50][HTST][INF] teardown() finished
[1623112605.50][HTST][INF] {{result;timeout}}
mbedgt: retry mbedhtrun 5/5
mbedgt: ['mbedhtrun', '-m', 'K66F', '-p', 'DUMMY:9600', '-f', '"mbed-os-example-tls/benchmark/BUILD/K66F/GCC_ARM/benchmark.bin"', '-e', '"mbed-os-example-tls/benchmark"', '--grm', 'raas_client:http://10.6.54.131:8000', '--compare-log', 'mbed-os-example-tls/tests/benchmark.log', '-C', '4', '--sync', '0', '-P', '600'] failed after 5 count
mbedgt: checking for GCOV data...
mbedgt: mbed-host-test-runner: stopped and returned 'TIMEOUT'
mbedgt: test case summary event not found
    no test case report present, assuming test suite to be a single test case!
    test suite: mbed-os-example-tls/benchmark
    test case: mbed-os-example-tls/benchmark
mbedgt: test on hardware with target id: DUMMY
mbedgt: test suite 'mbed-os-example-tls/benchmark' ................................................... TIMEOUT in 604.11 sec
    test case: 'mbed-os-example-tls/benchmark' ................................................... ERROR in 604.11 sec
mbedgt: test case summary: 0 passes, 1 failure

Target(s) affected by this defect ?

Toolchain(s) (name and version) displaying this defect ?

What version of Mbed-os are you using (tag or sha) ?

e377383f6ddbf01bb8e842a32fb1a250c0598520

What version(s) of tools are you using. List all that apply (E.g. mbed-cli)

How is this defect reproduced ?

Run the benchmark example.

ciarmcom commented 3 years ago

Thank you for raising this detailed GitHub issue. I am now notifying our internal issue triagers. Internal Jira reference: https://jira.arm.com/browse/IOTOSM-4056

LDong-Arm commented 3 years ago

The fix #298 has been merged