TLS error in v2.3.3

[FlorentP42]

Describe the bug
This library is currently being used as part of the following repositories :

• https://github.com/fledge-power/fledge-north-iec104
• https://github.com/fledge-power/fledge-south-iec104

When attempting to upgrade the library version used from v2.3.2 to v2.3.3 (with unchanged mbedtls v2.28.9) we noticed several unit test of those fledge libraries started to fail.

We are currently trying to assess if those failure are due to a wrong usage of the lib60870 library in those plugins, or if some regression was introduced in v2.3.3.

So far we found no documentation indicating that any interface change was required when upgrading from v2.3.2 to v2.3.3.

To Reproduce
Steps to reproduce the behavior:

1. Use the scripts from the CI of this branch of fledge-north-iec104 to run the unit tests locally.
2. Notice the following unit tests fails :

#25 274.3 [----------] Global test environment tear-down
#25 274.3 [==========] 94 tests from 9 test suites ran. (89905 ms total)
#25 274.3 [  PASSED  ] 91 tests.
#25 274.3 [  FAILED  ] 3 tests, listed below:
#25 274.3 [  FAILED  ] ConnectionHandlerTest.TLSConnection
#25 274.3 [  FAILED  ] ConnectionHandlerTest.TLSConnectionStackRedundancyGroupsNotArray
#25 274.3 [  FAILED  ] ConnectionHandlerTest.TLSConnectionExchangeDataWrongDatapoints

3. Update the CI file to use lib60870 v2.3.2 and run the CI again.
4. Notice all tests are passed.

Expected behavior
All unit tests that passed in v2.3.2 still pass in v2.3.3.

Additional context
When activating debug logs in the CI :

cmake -DBUILD_TESTS=NO -DBUILD_EXAMPLES=NO -DCMAKE_C_FLAGS="-DCONFIG_DEBUG_TLS=1 -DCONFIG_DEBUG_OUTPUT=1" ..

Here is a comparison of the logs obtained for one of the failing unit tests :

v2.3.3

#25 196.5 [ RUN      ] ConnectionHandlerTest.TLSConnection
#25 196.5 iec104 - IEC104Config::importExchangeConfig - GI GROUPS = 1
#25 196.5 iec104 - IEC104Config::importExchangeConfig -  address: 45-672 type: M_SP_NA_1
#25 196.5 iec104 - IEC104Config::importExchangeConfig -  CA: 45 IOA: 672
#25 196.5 iec104 - IEC104Config::importExchangeConfig - GI GROUPS = 1
#25 196.5 iec104 - IEC104Config::importExchangeConfig -  address: 45-984 type: M_ME_NA_1
#25 196.5 iec104 - IEC104Config::importExchangeConfig -  CA: 45 IOA: 984
#25 196.5 iec104 - IEC104Config::importExchangeConfig - GI GROUPS = 1
#25 196.5 iec104 - IEC104Config::importExchangeConfig -  address: 45-10005 type: C_SC_NA_1
#25 196.5 iec104 - IEC104Config::importExchangeConfig -  CA: 45 IOA: 10005
#25 196.5 iec104 - IEC104Config::importProtocolConfig - south_monitoring is missing "asset" element
#25 196.5 iec104 - IEC104Config::importProtocolConfig - south_monitoring is missing "asset" element
#25 196.5 iec104 - IEC104Config::importProtocolConfig - Adding red group with name: red-group-1
#25 196.5 iec104 - IEC104Config::importProtocolConfig -  add to group: 192.168.2.244
#25 196.5 iec104 - IEC104Config::importProtocolConfig -  add to group: 192.168.0.11
#25 196.5 iec104 - IEC104Config::importProtocolConfig - Adding red group with name: red-group-2
#25 196.5 iec104 - IEC104Config::importProtocolConfig -  add to group: 192.168.2.224
#25 196.5 iec104 - IEC104Config::importProtocolConfig -  add to group: 192.168.0.11
#25 196.5 iec104 - IEC104Config::importProtocolConfig -  add to group: 192.168.0.12
#25 196.5 iec104 - IEC104Config::importProtocolConfig - Adding red group with name: catch-all
#25 196.5 iec104 - IEC104Config::importProtocolConfig -  connections does not exist or is not an array -> adding fallback group
#25 196.5 iec104 - IEC104Config::importProtocolConfig - Using local IP address: 0.0.0.0
#25 196.5 iec104 - IEC104Server::createTLSConfiguration - Loaded own certificate file: ./tests/data/etc/certs/iec104_server.cer
#25 196.5 iec104 - IEC104Server::createTLSConfiguration - Loaded private key file: ./tests/data/etc/certs/iec104_server.key
#25 196.5 iec104 - IEC104Server::createTLSConfiguration - Allowed remote certificate file: ./tests/data/etc/certs/iec104_client.cer
#25 196.5 iec104 - IEC104Server::createTLSConfiguration - Allowed CA certificate file: ./tests/data/etc/certs/iec104_ca.cer
#25 196.5 iec104 - IEC104Server::createTLSConfiguration - Failed to access CA certificate file: ./tests/data/etc/certs/iec104_ca2.cer -> ignore certificate
#25 196.5 iec104 - IEC104Server::createTLSConfiguration - TLS configuration complete
#25 196.5 iec104 - IEC104Server::setJsonConfig - TCP/IP parameters:
#25 196.5 iec104 - IEC104Server::setJsonConfig -  TCP port: 19998
#25 196.5 iec104 - IEC104Server::setJsonConfig -  IP address: 0.0.0.0
#25 196.5 iec104 - IEC104Server::setJsonConfig - APCI parameters:
#25 196.5 iec104 - IEC104Server::setJsonConfig -  t0: 10
#25 196.5 iec104 - IEC104Server::setJsonConfig -  t1: 15
#25 196.5 iec104 - IEC104Server::setJsonConfig -  t2: 10
#25 196.5 iec104 - IEC104Server::setJsonConfig -  t3: 20
#25 196.5 iec104 - IEC104Server::setJsonConfig -  k: 12
#25 196.5 iec104 - IEC104Server::setJsonConfig -  w: 8
#25 196.5 iec104 - IEC104Server::setJsonConfig - Activating multiple redundancy groups mode (3 groups configured)
#25 196.5 iec104 - IEC104Server::setJsonConfig - CS104 server initialized
#25 196.5 iec104 - IEC104Server::_monitoringThread - Monitoring thread called
#25 196.5 iec104 - IEC104Server::requestSouthConnectionStatus - Send request_connection_status operation
#25 196.5 iec104 - IEC104Server::operation - Sending operation: {type: "request_connection_status", nbParams=1, names=["desc"], parameters=["request connection status"], cmdDest=""}
#25 196.5 iec104 - IEC104Server::operation - No operation callback available -> abort (registerControl must be called first)
#25 196.5 iec104 - IEC104Server::_monitoringThread - Server started - mode: CONNECT_ALWAYS
#25 196.6 iec104 - IEC104Server::requestSouthConnectionStatus - Send request_connection_status operation
#25 196.6 iec104 - IEC104Server::operation - Sending operation: {type: "request_connection_status", nbParams=1, names=["desc"], parameters=["request connection status"], cmdDest=""}
#25 196.6 iec104 - IEC104Server::operation - No operation callback available -> abort (registerControl must be called first)
#25 196.7 iec104 - IEC104Server::requestSouthConnectionStatus - Send request_connection_status operation
#25 196.7 iec104 - IEC104Server::operation - Sending operation: {type: "request_connection_status", nbParams=1, names=["desc"], parameters=["request connection status"], cmdDest=""}
#25 196.7 iec104 - IEC104Server::operation - No operation callback available -> abort (registerControl must be called first)
#25 196.8 iec104 - IEC104Server::requestSouthConnectionStatus - Send request_connection_status operation
#25 196.8 iec104 - IEC104Server::operation - Sending operation: {type: "request_connection_status", nbParams=1, names=["desc"], parameters=["request connection status"], cmdDest=""}
#25 196.8 iec104 - IEC104Server::operation - No operation callback available -> abort (registerControl must be called first)
#25 196.9 iec104 - IEC104Server::requestSouthConnectionStatus - Send request_connection_status operation
#25 196.9 iec104 - IEC104Server::operation - Sending operation: {type: "request_connection_status", nbParams=1, names=["desc"], parameters=["request connection status"], cmdDest=""}
#25 196.9 iec104 - IEC104Server::operation - No operation callback available -> abort (registerControl must be called first)
#25 197.0 iec104 - IEC104Server::requestSouthConnectionStatus - Send request_connection_status operation
#25 197.0 iec104 - IEC104Server::operation - Sending operation: {type: "request_connection_status", nbParams=1, names=["desc"], parameters=["request connection status"], cmdDest=""}
#25 197.0 iec104 - IEC104Server::operation - No operation callback available -> abort (registerControl must be called first)
#25 197.0 iec104 - IEC104Server::connectionRequestHandler - New connection request from 127.0.0.1
#25 197.0 TLS: Verify cert: depth 1
#25 197.0 TLS:    flags: 00000000
#25 197.0 TLS:   cert. version     : 3
#25 197.0   serial number     : 79:D0:F3:59:E4:37:B5:87:41:5F:F1:82:BD:E9:6C:C2
#25 197.0   issuer name       : CN=test root ca
#25 197.0   subject name      : CN=test root ca
#25 197.0   issued  on        : 2017-09-10 05:58:21
#25 197.0   expires on        : 2039-12-31 23:59:59
#25 197.0   signed using      : RSA with SHA1
#25 197.0   RSA key size      : 2048 bits
#25 197.0   basic constraints : CA=true
#25 197.0
#25 197.0 TLS: Verify cert: depth 0
#25 197.0 TLS:    flags: 00004000
#25 197.0 TLS:   cert. version     : 3
#25 197.0   serial number     : B1:A4:0A:AB:51:19:C5:82:43:6A:05:72:7B:9E:85:A6
#25 197.0   issuer name       : CN=test root ca
#25 197.0   subject name      : CN=test-server
#25 197.0   issued  on        : 2017-09-10 06:03:27
#25 197.0   expires on        : 2039-12-31 23:59:59
#25 197.0   signed using      : RSA with SHA1
#25 197.0   RSA key size      : 2048 bits
#25 197.0
#25 197.0 TLS: Check against list of allowed certs
#25 197.0 TLS: Compare With:
#25 197.0 TLS:      cert. version     : 3
#25 197.0      serial number     : B1:A4:0A:AB:51:19:C5:82:43:6A:05:72:7B:9E:85:A6
#25 197.0      issuer name       : CN=test root ca
#25 197.0      subject name      : CN=test-server
#25 197.0      issued  on        : 2017-09-10 06:03:27
#25 197.0      expires on        : 2039-12-31 23:59:59
#25 197.0      signed using      : RSA with SHA1
#25 197.0      RSA key size      : 2048 bits
#25 197.0
#25 197.0 TLS: handshake failed - mbedtls_ssl_handshake returned -0x2700
#25 197.0 TLS: handshake failed - mbedtls_ssl_handshake returned -0x7780
#25 197.0 /tmp/fledge-north-iec104/tests/test_connectionHandler.cpp:1837: Failure
#25 197.0 Value of: result
#25 197.0   Actual: false
#25 197.0 Expected: true
#25 197.0 iec104 - IEC104Server::stop - IEC104 server stopping...
#25 197.0 iec104 - IEC104Server::stop - Waiting for monitoring thread to join
#25 197.1 iec104 - IEC104Server::stop - Stopping CS104 slave
#25 197.1 iec104 - IEC104Server::stop - Deleting TLS configuration
#25 197.1 iec104 - IEC104Server::stop - IEC104 server stopped!
#25 197.1 iec104 - IEC104Server::stop - IEC104 server stopping...
#25 197.1 iec104 - IEC104Server::stop - IEC104 server stopped!
#25 197.1 [  FAILED  ] ConnectionHandlerTest.TLSConnection (624 ms)

v2.3.2

#25 212.8 [ RUN      ] ConnectionHandlerTest.TLSConnection
#25 212.8 iec104 - IEC104Config::importExchangeConfig - GI GROUPS = 1
#25 212.8 iec104 - IEC104Config::importExchangeConfig -  address: 45-672 type: M_SP_NA_1
#25 212.8 iec104 - IEC104Config::importExchangeConfig -  CA: 45 IOA: 672
#25 212.8 iec104 - IEC104Config::importExchangeConfig - GI GROUPS = 1
#25 212.8 iec104 - IEC104Config::importExchangeConfig -  address: 45-984 type: M_ME_NA_1
#25 212.8 iec104 - IEC104Config::importExchangeConfig -  CA: 45 IOA: 984
#25 212.8 iec104 - IEC104Config::importExchangeConfig - GI GROUPS = 1
#25 212.8 iec104 - IEC104Config::importExchangeConfig -  address: 45-10005 type: C_SC_NA_1
#25 212.8 iec104 - IEC104Config::importExchangeConfig -  CA: 45 IOA: 10005
#25 212.8 iec104 - IEC104Config::importProtocolConfig - south_monitoring is missing "asset" element
#25 212.8 iec104 - IEC104Config::importProtocolConfig - south_monitoring is missing "asset" element
#25 212.8 iec104 - IEC104Config::importProtocolConfig - Adding red group with name: red-group-1
#25 212.8 iec104 - IEC104Config::importProtocolConfig -  add to group: 192.168.2.244
#25 212.8 iec104 - IEC104Config::importProtocolConfig -  add to group: 192.168.0.11
#25 212.8 iec104 - IEC104Config::importProtocolConfig - Adding red group with name: red-group-2
#25 212.8 iec104 - IEC104Config::importProtocolConfig -  add to group: 192.168.2.224
#25 212.8 iec104 - IEC104Config::importProtocolConfig -  add to group: 192.168.0.11
#25 212.8 iec104 - IEC104Config::importProtocolConfig -  add to group: 192.168.0.12
#25 212.8 iec104 - IEC104Config::importProtocolConfig - Adding red group with name: catch-all
#25 212.8 iec104 - IEC104Config::importProtocolConfig -  connections does not exist or is not an array -> adding fallback group
#25 212.8 iec104 - IEC104Config::importProtocolConfig - Using local IP address: 0.0.0.0
#25 212.8 iec104 - IEC104Server::createTLSConfiguration - Loaded own certificate file: ./tests/data/etc/certs/iec104_server.cer
#25 212.8 iec104 - IEC104Server::createTLSConfiguration - Loaded private key file: ./tests/data/etc/certs/iec104_server.key
#25 212.8 iec104 - IEC104Server::createTLSConfiguration - Allowed remote certificate file: ./tests/data/etc/certs/iec104_client.cer
#25 212.8 iec104 - IEC104Server::createTLSConfiguration - Allowed CA certificate file: ./tests/data/etc/certs/iec104_ca.cer
#25 212.8 iec104 - IEC104Server::createTLSConfiguration - Failed to access CA certificate file: ./tests/data/etc/certs/iec104_ca2.cer -> ignore certificate
#25 212.8 iec104 - IEC104Server::createTLSConfiguration - TLS configuration complete
#25 212.8 iec104 - IEC104Server::setJsonConfig - TCP/IP parameters:
#25 212.8 iec104 - IEC104Server::setJsonConfig -  TCP port: 19998
#25 212.8 iec104 - IEC104Server::setJsonConfig -  IP address: 0.0.0.0
#25 212.8 iec104 - IEC104Server::setJsonConfig - APCI parameters:
#25 212.8 iec104 - IEC104Server::setJsonConfig -  t0: 10
#25 212.8 iec104 - IEC104Server::setJsonConfig -  t1: 15
#25 212.8 iec104 - IEC104Server::setJsonConfig -  t2: 10
#25 212.8 iec104 - IEC104Server::setJsonConfig -  t3: 20
#25 212.8 iec104 - IEC104Server::setJsonConfig -  k: 12
#25 212.8 iec104 - IEC104Server::setJsonConfig -  w: 8
#25 212.8 iec104 - IEC104Server::setJsonConfig - Activating multiple redundancy groups mode (3 groups configured)
#25 212.8 iec104 - IEC104Server::setJsonConfig - CS104 server initialized
#25 212.8 iec104 - IEC104Server::_monitoringThread - Monitoring thread called
#25 212.8 iec104 - IEC104Server::requestSouthConnectionStatus - Send request_connection_status operation
#25 212.8 iec104 - IEC104Server::operation - Sending operation: {type: "request_connection_status", nbParams=1, names=["desc"], parameters=["request connection status"], cmdDest=""}
#25 212.8 iec104 - IEC104Server::operation - No operation callback available -> abort (registerControl must be called first)
#25 212.8 iec104 - IEC104Server::_monitoringThread - Server started - mode: CONNECT_ALWAYS
#25 212.9 iec104 - IEC104Server::requestSouthConnectionStatus - Send request_connection_status operation
#25 212.9 iec104 - IEC104Server::operation - Sending operation: {type: "request_connection_status", nbParams=1, names=["desc"], parameters=["request connection status"], cmdDest=""}
#25 212.9 iec104 - IEC104Server::operation - No operation callback available -> abort (registerControl must be called first)
#25 213.0 iec104 - IEC104Server::requestSouthConnectionStatus - Send request_connection_status operation
#25 213.0 iec104 - IEC104Server::operation - Sending operation: {type: "request_connection_status", nbParams=1, names=["desc"], parameters=["request connection status"], cmdDest=""}
#25 213.0 iec104 - IEC104Server::operation - No operation callback available -> abort (registerControl must be called first)
#25 213.1 iec104 - IEC104Server::requestSouthConnectionStatus - Send request_connection_status operation
#25 213.1 iec104 - IEC104Server::operation - Sending operation: {type: "request_connection_status", nbParams=1, names=["desc"], parameters=["request connection status"], cmdDest=""}
#25 213.1 iec104 - IEC104Server::operation - No operation callback available -> abort (registerControl must be called first)
#25 213.2 iec104 - IEC104Server::requestSouthConnectionStatus - Send request_connection_status operation
#25 213.2 iec104 - IEC104Server::operation - Sending operation: {type: "request_connection_status", nbParams=1, names=["desc"], parameters=["request connection status"], cmdDest=""}
#25 213.2 iec104 - IEC104Server::operation - No operation callback available -> abort (registerControl must be called first)
#25 213.3 iec104 - IEC104Server::requestSouthConnectionStatus - Send request_connection_status operation
#25 213.3 iec104 - IEC104Server::operation - Sending operation: {type: "request_connection_status", nbParams=1, names=["desc"], parameters=["request connection status"], cmdDest=""}
#25 213.3 iec104 - IEC104Server::operation - No operation callback available -> abort (registerControl must be called first)
#25 213.3 iec104 - IEC104Server::connectionRequestHandler - New connection request from 127.0.0.1
#25 213.3 TLS: Verify cert: depth 1
#25 213.3 TLS:    flags: 00000000
#25 213.3 TLS:   cert. version     : 3
#25 213.3   serial number     : 79:D0:F3:59:E4:37:B5:87:41:5F:F1:82:BD:E9:6C:C2
#25 213.3   issuer name       : CN=test root ca
#25 213.3   subject name      : CN=test root ca
#25 213.3   issued  on        : 2017-09-10 05:58:21
#25 213.3   expires on        : 2039-12-31 23:59:59
#25 213.3   signed using      : RSA with SHA1
#25 213.3   RSA key size      : 2048 bits
#25 213.3   basic constraints : CA=true
#25 213.3
#25 213.3 TLS: Verify cert: depth 0
#25 213.3 TLS:    flags: 00004000
#25 213.3 TLS:   cert. version     : 3
#25 213.3   serial number     : B1:A4:0A:AB:51:19:C5:82:43:6A:05:72:7B:9E:85:A6
#25 213.3   issuer name       : CN=test root ca
#25 213.3   subject name      : CN=test-server
#25 213.3   issued  on        : 2017-09-10 06:03:27
#25 213.3   expires on        : 2039-12-31 23:59:59
#25 213.3   signed using      : RSA with SHA1
#25 213.3   RSA key size      : 2048 bits
#25 213.3
#25 213.3 TLS: Check against list of allowed certs
#25 213.3 TLS: Compare With:
#25 213.3 TLS:      cert. version     : 3
#25 213.3      serial number     : B1:A4:0A:AB:51:19:C5:82:43:6A:05:72:7B:9E:85:A6
#25 213.3      issuer name       : CN=test root ca
#25 213.3      subject name      : CN=test-server
#25 213.3      issued  on        : 2017-09-10 06:03:27
#25 213.3      expires on        : 2039-12-31 23:59:59
#25 213.3      signed using      : RSA with SHA1
#25 213.3      RSA key size      : 2048 bits
#25 213.3
#25 213.3 TLS: Verify cert: depth 1
#25 213.3 TLS:    flags: 00000000
#25 213.3 TLS:   cert. version     : 3
#25 213.3   serial number     : 79:D0:F3:59:E4:37:B5:87:41:5F:F1:82:BD:E9:6C:C2
#25 213.3   issuer name       : CN=test root ca
#25 213.3   subject name      : CN=test root ca
#25 213.3   issued  on        : 2017-09-10 05:58:21
#25 213.3   expires on        : 2039-12-31 23:59:59
#25 213.3   signed using      : RSA with SHA1
#25 213.3   RSA key size      : 2048 bits
#25 213.3   basic constraints : CA=true
#25 213.3
#25 213.3 TLS: Verify cert: depth 0
#25 213.3 TLS:    flags: 00004000
#25 213.3 TLS:   cert. version     : 3
#25 213.3   serial number     : E3:A8:E9:D6:D8:78:34:A7:4C:1A:E9:7F:CF:74:16:0D
#25 213.3   issuer name       : CN=test root ca
#25 213.3   subject name      : CN=client1
#25 213.3   issued  on        : 2017-09-10 06:05:30
#25 213.3   expires on        : 2039-12-31 23:59:59
#25 213.3   signed using      : RSA with SHA1
#25 213.3   RSA key size      : 2048 bits
#25 213.3
#25 213.3 TLS: Check against list of allowed certs
#25 213.3 TLS: Compare With:
#25 213.3 TLS:      cert. version     : 3
#25 213.3      serial number     : E3:A8:E9:D6:D8:78:34:A7:4C:1A:E9:7F:CF:74:16:0D
#25 213.3      issuer name       : CN=test root ca
#25 213.3      subject name      : CN=client1
#25 213.3      issued  on        : 2017-09-10 06:05:30
#25 213.3      expires on        : 2039-12-31 23:59:59
#25 213.3      signed using      : RSA with SHA1
#25 213.3      RSA key size      : 2048 bits
#25 213.3
#25 213.3 iec104 - IEC104Server::connectionEventHandler - Connection opened (127.0.0.1:60772)
#25 213.4 iec104 - IEC104Server::requestSouthConnectionStatus - Send request_connection_status operation
#25 213.4 iec104 - IEC104Server::operation - Sending operation: {type: "request_connection_status", nbParams=1, names=["desc"], parameters=["request connection status"], cmdDest=""}
#25 213.4 iec104 - IEC104Server::operation - No operation callback available -> abort (registerControl must be called first)
#25 213.4 iec104 - IEC104Server::connectionEventHandler - Connection closed (127.0.0.1:60772)
#25 213.4 TLS:  connection was closed gracefully
#25 213.4 iec104 - IEC104Server::stop - IEC104 server stopping...
#25 213.4 iec104 - IEC104Server::stop - Waiting for monitoring thread to join
#25 213.5 iec104 - IEC104Server::stop - Stopping CS104 slave
#25 213.5 iec104 - IEC104Server::stop - Deleting TLS configuration
#25 213.5 iec104 - IEC104Server::stop - IEC104 server stopped!
#25 213.5 iec104 - IEC104Server::stop - IEC104 server stopping...
#25 213.5 iec104 - IEC104Server::stop - IEC104 server stopped!
#25 213.5 [       OK ] ConnectionHandlerTest.TLSConnection (722 ms)

EDIT: It seems the method used to activate debug logs at the time of those recordings did not work as intended, which was later fixed by #169. The following method should work pre-2.3.4 :

cd ..
sed -i 's/#define CONFIG_DEBUG_OUTPUT 0/#define CONFIG_DEBUG_OUTPUT 1/' config/lib60870_config.h
mkdir build
cd build
cmake -DBUILD_TESTS=NO -DBUILD_EXAMPLES=NO -DCMAKE_C_FLAGS="-DCONFIG_DEBUG_TLS=1" ..

EDIT2 : An additional test was made with lib60870 v2.3.3 + mbedtls v3.6.2 and led to the same results.

[FlorentP42]

Email answer on this topic from @mzillgith :

Hi Romain,

I think the problem are the certificates as they are signed with RSA/SHA-1. It seems that mbedtls doesn’t accept these certificates by default when TLS 1.2 is used.

We had this problem also with the library examples and updated them with newer test certificates that were signed with RSA/SHA-256.

We are currently in the process of converting our certificats to SHA-256 signatures, will close this if it was enough to fix the failing unit tests with the new lib60870 version.