Failing Client Authentication with .Net application

Tip / Sign in to post questions, reply, level up, and achieve exciting badges. Know more

cross mob
lock attach
Attachments are accessible only for community members.
LeWi_2227251
Level 3
Level 3
First like received Welcome!

I reviewed the network packet captures more closely and the difference I see between the network packet captures of the failing .Net  and working SSL is .Net does not add the TLS Record Header (Type/Version/Size) to every message (which is not required).

.Net concatenates several messages under one TLS Record Header as show below.

Failing .Net Client response after Server Hello Done:  Certifcate, Client Key Exchange, Certificate Verify, Change Cipher Spec, Encrypted Handshake Message

IP 10.57.10.145.4585 > 10.57.30.133.26: . 179:1497(1318)

0x0000:  4500 054e 38c2 4000 8006 7f60 0a39 0a91

0x0010:  0a39 1e85 11e9 001a 02ee 77fc 27b8 982c

0x0020:  5010 0101 e2b3 0000 1603 0306 ae0b 0004       Handshake TLS1.2 size=0x06ae certificate=0x0b size=0x0496

0x0030:  9c00 0499 0004 9630 8204 9230 8203 7aa0

                                  .

                                  .

                                  .

0x04c0:  9350 7474 859a fbce 2919 e123 4f10 0001         Client Key Exchange=0x10 size=0x0102

0x04d0:  0201 0048 7881 5f19 9669 c93b 0fc3 e62f

0x04e0:  4a78 e0b8 82a7 04c8 342d a812 2434 2518

Working SSL Client response after Server Hello Done:  Certificate, Client Key Exchange

IP 10.57.10.145.4850 > 10.57.30.133.26: . 518:1836(1318)

0x0000:  4500 054e 4d6c 4000 8006 6ab6 0a39 0a91

0x0010:  0a39 1e85 12f2 001a 7380 4bd7 48b6 faef

0x0020:  5010 ffff c888 0000 1603 0304 a00b 0004      Handshake TLS1.2 size=0x04a0 certificate=0x0b size=0x0496

0x0030:  9c00 0499 0004 9630 8204 9230 8203 7aa0

0x0040:  0302 0102 0201 0530 0d06 092a 8648 86f7

                                 .

                                  .

                                  .

0x04c0:  9350 7474 859a fbce 2919 e123 4f16 0303           Handshake TLS1.2 size=0x0106 Client Key Exchange=0x10 size=0x0102

0x04d0:  0106 1000 0102 0100 9467 13b9 863d d746

0x04e0:  4ade 4123 884a 636a 9664 3d2a f221 14c4

Does this SDK handle several messages concatenated in a single Record Layer message?

Using an ISM43362 development board running a TCP server socket secured with TLS1.2 and mutual authentication.  I can connect an openSSL client and also another ISM43362 acting as a client with no issues.

Trying to connect to our .NET application function:  wiced_tcp_accept() --> wiced_tcp_start_tls() -->  wiced_generic_start_tls_with_ciphers() --> ssl_handshake_server_async( &tls_context->context ) fails, returning error = 64416.

Connects fine if I disable client authentication.

Could you tell me what the error code 64416 from ssl_handshake_server_async() is for?

SDK version: WICED-Studio-4.1.1.8-IDE

HW Platform:  ISM43362 (Inventek  43362-M3G development board

Log:

Starting WICED v4.1.1

Platform DPM3_ISM43362_M3G_L44 initialised

Started ThreadX v5.6

Initialising NetX_Duo v5.7_sp2

Creating Packet pools

WWD SDIO interface initialised

WLAN MAC Address : C4:7F:51:01:6A:E9

WLAN Firmware    : wl0: Oct  6 2016 01:32:44 version 5.90.230.15 FWID 01-2ef61140

application_start: Time: 6:20:30 3/23/17

Joining : mtcorp

Successfully joined : mtcorp

Obtaining IPv4 address via DHCP

DHCP CLIENT hostname WICED IP

IPv4 network ready IP: 10.57.30.133

Setting IPv6 link-local address

IPv6 network ready IP: FE80:0000:0000:0000:C67F:51FF:FE01:6AE9

Link is Up

application_start: Mutual Authentication:  Init Root CA: tls_DpgRootCA len=1480

application_start: Lock DCT, Read the certificate Key

application_start: Init TLS Server Identity

application_start: unLock DCT

application_start: Init TLS Server Context for peer DynaPED Server

application_start: Create Server Socket

application_start: Register Server callbacks

application_start: Enable Server TLS

application_start: Enable Server Listen

application_start: Get IPv4 address

application_start: DynaProGo Server at 10.57.30.133:26

client_connected_callback: Accept client connection

wiced_generic_start_tls_with_ciphers: Error[64416] with TLS server handshake

wiced_generic_start_tls_with_ciphers: ERROR [64416] Exit

wiced_tcp_start_tls: Error[64416]

client_connected_callback: ERROR [1]: wiced_tcp_accept

Source Code:

void application_start( void )

{

    wiced_result_t result;

    wiced_interface_t interface = WICED_STA_INTERFACE;

    wiced_network_config_t ip_config = WICED_USE_EXTERNAL_DHCP_SERVER;

    platform_dct_security_t* dct_security = NULL;

    platform_rtc_time_t time;

    wiced_ip_address_t address;

    uint32_t ipv4;

    /* Initialise the device and WICED framework */

    result = wiced_init();

    if (result != WICED_SUCCESS) {

    WPRINT_APP_INFO( ("%s: ERROR [%d]: Wiced Init\r\n",__FUNCTION__,result) );

        return;

    }

    result = platform_rtc_get_time( &time );

    WPRINT_APP_INFO( ("%s: Time: %u:%u:%u %u/%u/%u\r\n",__FUNCTION__,time.hr,time.min,time.sec,time.month,time.date,time.year) );

    /* Bring up the STA (client) interface */

    result = wiced_network_up( interface, ip_config, NULL );

    if (result != WICED_SUCCESS) {

    WPRINT_APP_INFO( ("%s: ERROR [%d]: No Connection to AP\r\n",__FUNCTION__,result) );

        return;

    }

    WPRINT_APP_INFO( ("Link is Up\r\n") );

#if (MUTUAL_AUTHENTICATE == 1)

    WPRINT_APP_INFO( ( "%s: Mutual Authentication:  Init Root CA: tls_DynaPEDRootCA len=%u\r\n",__FUNCTION__ ,strlen( tls_DynaPEDRootCA )) );

    /* Initialize the root CA certificate */

    result = wiced_tls_init_root_ca_certificates( tls_DynaPEDRootCA, strlen( tls_DynaPEDRootCA ) );

    if ( result != WICED_SUCCESS )

    {

        WPRINT_APP_INFO( ( "%s: ERROR [%d]: Root CA certificate failed to initialize\n",__FUNCTION__, result) );

        return;

    }

#endif

    /* Lock the DCT to allow us to access the certificate and key */

    WPRINT_APP_INFO(( "%s: Lock DCT, Read the certificate Key\r\n",__FUNCTION__ ));

    result = wiced_dct_read_lock( (void**) &dct_security, WICED_FALSE, DCT_SECURITY_SECTION, 0, sizeof( *dct_security ) );

    if ( result != WICED_SUCCESS )

    {

        WPRINT_APP_INFO(("%s: ERROR [%d]: Unable to lock DCT to read certificate\n",__FUNCTION__, result));

        return;

    }

    WPRINT_APP_INFO( ("%s: Init TLS Server Identity\r\n",__FUNCTION__) );

    /* Setup TLS Server identity */

    result = wiced_tls_init_identity( &tls_server_identity, dct_security->private_key, strlen( dct_security->private_key ), (uint8_t*) dct_security->certificate, strlen( dct_security->certificate ) );

    if ( result != WICED_SUCCESS )

    {

        WPRINT_APP_INFO(( "%s: ERROR [%d]: Unable to initialize TLS server identity\n",__FUNCTION__, result ));

        return;

    }

    WPRINT_APP_INFO( ("%s: unLock DCT\r\n",__FUNCTION__) );

    /* Finished accessing the certificates */

    result = wiced_dct_read_unlock( dct_security, WICED_FALSE );

    if ( result != WICED_SUCCESS )

    {

        WPRINT_APP_INFO(( "%s: ERROR [%d]: DCT Read Unlock\n",__FUNCTION__, result ));

        return;

    }

    WPRINT_APP_INFO( ("%s: Init TLS Server Context for peer %s\r\n",__FUNCTION__,HOST_CLIENT_CN) );

    /* Setup TLS Context */

    result = wiced_tls_init_context( &tls_server_context, &tls_server_identity, HOST_CLIENT_CN );

    if ( result != WICED_SUCCESS )

    {

        WPRINT_APP_INFO(( "%s: ERROR [%d]:  Unable to initialize TLS Server context %s\n",__FUNCTION__,result,HOST_CLIENT_CN ));

        return;

    }

    WPRINT_APP_INFO( ("%s: Create Server Socket\r\n",__FUNCTION__) );

    /* Create a TCP server socket */

    if ( wiced_tcp_create_socket( &tcp_server_socket, WICED_STA_INTERFACE ) != WICED_SUCCESS )

    {

        WPRINT_APP_INFO( ("%s: ERROR [%d]: TCP Server socket creation failed\r\n",__FUNCTION__, result) );

        return;

    }

    /* Register Server callbacks to handle various TCP events */

    WPRINT_APP_INFO( ("%s: Register Server callbacks\r\n",__FUNCTION__) );

    result = wiced_tcp_register_callbacks( &tcp_server_socket, client_connected_callback, received_data_from_client_callback, client_disconnected_callback, NULL );

    if ( result != WICED_SUCCESS )

    {

        WPRINT_APP_INFO( ("%s: ERROR [%d]: TCP server socket initialization\r\n",__FUNCTION__,result) );

        return;

    }

    /* Set Server socket as TLS */

    WPRINT_APP_INFO( ("%s: Enable Server TLS\r\n",__FUNCTION__) );

    result = wiced_tcp_enable_tls( &tcp_server_socket, &tls_server_context );

    if ( result != WICED_SUCCESS )

    {

        WPRINT_APP_INFO( ("%s: ERROR [%d]: TLS server enable\r\n",__FUNCTION__,result) );

        return;

    }

    /* Start TCP server to listen for connections */

    WPRINT_APP_INFO( ("%s: Enable Server Listen\r\n",__FUNCTION__) );

    if ( wiced_tcp_listen( &tcp_server_socket, TCP_SERVER_LISTEN_PORT ) != WICED_SUCCESS )

    {

        WPRINT_APP_INFO( ("%s: TCP server socket initialization failed\r\n",__FUNCTION__) );

        /* Clean up and halt */

    }

    while (1);

    return;

}

static wiced_result_t client_connected_callback( wiced_tcp_socket_t* socket, void* arg )

{

    wiced_result_t      result;

    wiced_ip_address_t  ipaddr;

    uint16_t            port;

    platform_rtc_time_t time;

    UNUSED_PARAMETER( arg );

    /* Accept connection request */

    WPRINT_APP_INFO(("%s: Accept client connection\r\n",__FUNCTION__));

    result = wiced_tcp_accept( socket );

    if ( result != WICED_SUCCESS )

    {

        WPRINT_APP_INFO( ("%s: ERROR [%d]: wiced_tcp_accept\r\n",__FUNCTION__,result) );

    }

    else

    {

        /* Extract IP address and the Port of the connected client */

        wiced_tcp_server_peer( socket, &ipaddr, &port );

        WPRINT_APP_INFO ( ("%s: Connected Client IP: %u.%u.%u.%u Port %d\r\n",__FUNCTION__,

                                             (unsigned char) ( ( GET_IPV4_ADDRESS(ipaddr) >> 24 ) & 0xff ),

                                                      (unsigned char) ( ( GET_IPV4_ADDRESS(ipaddr) >> 16 ) & 0xff ),

                                                      (unsigned char) ( ( GET_IPV4_ADDRESS(ipaddr) >>  8 ) & 0xff ),

                                                      (unsigned char) ( ( GET_IPV4_ADDRESS(ipaddr) >>  0 ) & 0xff ),

                                                      port ) );

        result = platform_rtc_get_time( &time );

        WPRINT_APP_INFO( ("%s: Time: %u:%u:%u %u/%u/%u\r\n",__FUNCTION__,time.hr,time.min,time.sec,time.month,time.date,time.year) );

        return WICED_SUCCESS;

    }

    return WICED_ERROR;

}

static wiced_result_t client_disconnected_callback( wiced_tcp_socket_t* socket, void* arg )

{

    UNUSED_PARAMETER( arg );

    WPRINT_APP_INFO(("%s: Client disconnected\r\n",__FUNCTION__));

    wiced_tcp_disconnect(socket);

    /* Start listening on the socket again */

    if ( wiced_tcp_listen( socket, TCP_SERVER_LISTEN_PORT ) != WICED_SUCCESS )

    {

        WPRINT_APP_INFO( ("%s: TCP server socket re-initialization failed\r\n",__FUNCTION__) );

        wiced_tcp_delete_socket( socket );

        return WICED_ERROR;

    }

    WPRINT_APP_INFO( ("%s: Enable Server Listen port %u\r\n",__FUNCTION__,TCP_SERVER_LISTEN_PORT) );

    return WICED_SUCCESS;

}

static wiced_result_t received_data_from_client_callback( wiced_tcp_socket_t* socket, void* arg )

{

    wiced_result_t      result;

    wiced_packet_t*     tx_packet;

    char*               tx_data;

    wiced_packet_t*     rx_packet = NULL;

    char*               request;

    uint16_t            request_length;

    uint16_t            available_data_length;

    result = wiced_tcp_receive( socket, &rx_packet, WICED_WAIT_FOREVER );

    if ( result != WICED_SUCCESS )

    {

        return result;

    }

    wiced_packet_get_data( rx_packet, 0, (uint8_t**) &request, &request_length, &available_data_length );

    /* Null terminate the received string */

    request[request_length] = '\x0';

    WPRINT_APP_INFO(("%s: Received data: size=%u \r\n",__FUNCTION__, request_length));

    /* Send echo back */

    if ( wiced_packet_create_tcp( socket, TCP_PACKET_MAX_DATA_LENGTH, &tx_packet, (uint8_t**)&tx_data, &available_data_length ) != WICED_SUCCESS )

    {

        WPRINT_APP_INFO(("%s: TCP packet creation failed\r\n",__FUNCTION__));

        return WICED_ERROR;

    }

    /* Write the message into tx_data"  */

    tx_data[request_length] = '\x0';

    memcpy( tx_data, request, request_length );

    /* Set the end of the data portion */

    wiced_packet_set_data_end( tx_packet, (uint8_t*)tx_data + request_length );

    /* Send the TCP packet */

    if ( wiced_tcp_send_packet( socket, tx_packet ) != WICED_SUCCESS )

    {

        WPRINT_APP_INFO( ("%s: TCP packet send failed\r\n",__FUNCTION__) );

        /* Delete packet, since the send failed */

        wiced_packet_delete( tx_packet );

    }

    WPRINT_APP_INFO(("%s: Echo data: \r\n",__FUNCTION__));

    /* Release a packet */

    wiced_packet_delete( rx_packet );

    return WICED_SUCCESS;

}

WireShark Traces:  filter with:  ip.addr == 10.57.30.133 and tcp

SSLClient (OK), PcNetClient_NoClientAuth (OK), PcNetClient_ClientAuth (Fails)

0 Likes
1 Solution

I tested the fix in the latest release of WICED 5.0 and it works correctly now. You can contact Inventek to obtain early access of the release.

View solution in original post

0 Likes
19 Replies
GauravS_31
Moderator
Moderator
Moderator
10 questions asked 250 solutions authored 250 sign-ins

Can you please share your complete project with .mk file? I tried running the source code but I was facing problems making it work. I want to reproduce the issue on our side.

0 Likes
lock attach
Attachments are accessible only for community members.

dynaProGo is the app project, contains a Readme to compile and run the WinSocket applications.

certificates replaces resources\certificates and contains certifcates/keys/CA am using.

PC_Applications contains client and server source code for the WinSocket applications.

WinSocket server and WICED device client works, WinSocket client and WICED device server is failing somewhere in the client certificate/key exchange/certificate Verify part of the TLS1.2 handshake.

0 Likes
lock attach
Attachments are accessible only for community members.

Forgot the WinSocket applications.

0 Likes

Here is the complete project if that helps

0 Likes

I tested the .NET client application with Microsoft Visual Studio and the WICED TCP server received "Error starting TLS connection". I observed that when I ran the .NET application in debug mode, an exception 'System.ArgumentOutOfRangeException' was thrown at return localCertificates[0] inside public static X509Certificate ValidateClientCertificate(). Additional information on the exception was: "Index was out of range. Must be non-negative and less than the size of the collection." However after I replaced return localCertificates[0]; with return remoteCertificate; the TCP server and .NET client worked correctly.

Thanks for looking into this, interesting that it is working for you?  Did you install DynaPED_Root_server.p12 in your Trusted Root?

How To Import a Trusted Root Certification Authority In Windows 7/Vista/XP?

I am not seeing the same results/error in return localCertificates[0].  If I modify to return remote Certificate the .NET client does not return a certificate. Using localCertificates[0] the function returns the certificate requested by WICED TCP in the certificate request. 

Using WireShark to capture the network traffic I see the certificate being returned by .NET client along with Client Key exchange, Certificate Verify, Change Cipher Spec, and Encrypted Handshake Message.  Function ssl_handshake_server_async() returns with an error 64416.

Would you have the definition for error code 64416?

Could you capture the network traffic with WireShark?  Need to Edit --> Preferences --> Protocols --> HTTP -> SSL/TLS ports to add 26, set Expression to filter with:   ip.addr == "IP of WICED TCP device" and tcp

ex. ip.addr == 10.57.10.100 and tcp

Thanks

0 Likes

The reason why it worked was because I disabled #define MUTUAL_AUTHENTICATE 1 in the TCP server project thereby disabling wiced_tls_init_root_ca_certificates( tls_DynaPEDRootCA, strlen( tls_DynaPEDRootCA ) ); I tested this project on platform BCM943438WCD1. After enabling it, I observed the error "client_connected_callback: ERROR [57825]: wiced_tcp_accept" which is different form the error code that you obtained. I will debug further to find out the issue. Both error codes are not defined in wiced_result_t and I will find out what they mean.

0 Likes

Any update on this issue?  We are getting close to submitting for certification which requires our WICED server to authenticate the client.

Thanks

0 Likes
lock attach
Attachments are accessible only for community members.

I am still working on this problem. The function wiced_tcp_start_tls() inside wiced_tcp_accept() returned the error code 5023 which means ERROR_BAD_HS_CERTIFICATE. I have attached the error logs ("NET TCP Client-WICED TCP Server.jpg") for your reference. Strangely I was getting errors when I tested the .NET TCP client application with .NET TCP server application as shown in the attachment "NET TCP server logs.txt".

Did you test the .NET client application on any other TCP server (other than WICED TCP server)?

I am not seeing any errors in .NET to .NET and do not get the error [5023] on the WICED device. 

I do get that error when the .NET application does not return a certificate for client authentication (when VS is not run in administrator mode)

My WICED device is giving error [64416].  Do you have the definition for this error code?

For .NET make sure you run Visual Studio in Administrator mode or will fail reading certificates from Trusted Root.

Make sure DynaPED_Root_server.p12 is installed in your Trusted Root:

www.sqlservermart.com/HowTo/Windows_Import_Certificate.aspx

Yes, I have tested .NET Client application using C++ s-channel, openssl and TI's CC3200 WiFi device which we were using prior to this device which worked.

Should first verify the .Net and WICED applications using openssl s_client and s_server which is installed in cygwin. 

To use OpenSSL, run from the command line in the following directory:

43xxx_Wi-Fi\resources\certificates\DynaProGo\SSLTest.txt

Change IP address to your device (WICED) or PC for .NET:

c:\cygwin\bin\openssl s_client -connect 10.57.30.143:26 -cert .\PKI_Magtek_DynaPED\certs\Root_CA_Signed\DynaPED_Root_server.pem -certform PEM  -key .\PKI_Magtek_DynaPED\certs\DynaPED_server.key -keyform PEM -CAfile .\PKI_Magtek_DynaPED\ca\DynaPED_root-ca.pem -tls1_2 -cipher AES256-SHA

openssl s_server

c:\cygwin\bin\openssl s_server -accept 26 -Verify 1 -cert .\PKI_Magtek_DynaPED\certs\Root_CA_Signed\DynaPED_Root_server.pem -certform PEM  -key .\PKI_Magtek_DynaPED\certs\DynaPED_server.key -keyform PEM -CAfile .\PKI_Magtek_DynaPED\ca\DynaPED_root-ca.pem -tls1_2 -cipher AES256-SHA

To verify your setup run openssl s_client to openssl s_server,

.NET client to openssl s_server,

openSSL client to .NET server.

I Can run openssl s_client to WICED dpm3_tcp_server with no errors.

WICED dpm3_tcp_client to WICED dpm3_tcp_server with no errors.

CC3200 client to WICED dpm3_tcp_server with no errors. 

Only have issues with .NET client to WICED dpm3_tcp_server

0 Likes

Thank you for the information. I could reproduce the issue with error code 64416 after running Visual Studio in Administrator mode. I also observed from Wireshark logs that the .Net application appends multiple TLS handshake protocols under 1 TLS record layer. But the Wiced application (TCP server or TCP client) always appended one handshake protocol under one TLS record layer. I have raised a ticket internally explaining this issue in detail along with the Wireshark logs. I have also enquired internally about the definition of error code 64416. I will update once I receive feedback internally.

Yes, that is correct. 

However if you run the .NET server application and the Wiced TCP client you will see that the .Net application appends multiple TLS handshake protocols under one TLS record (Server Hello/Certificate/Certificate Request/Hello Done) and the Wiced TCP client handles it just fine, no errors?

It would be helpful to find out what the definition of error code 64416, perhaps tell which handshake message is failing.  Certificate, Client Key Exchange, or Certificate Verify?

openssl client and Wiced TCP server also work but openssl sends the full TLS Record Header (Type/Version/Size) in the concatenated messages.

0 Likes
lock attach
Attachments are accessible only for community members.

Yes. I agree that the Wiced TCP Client and .NET TCP server do not show this problem so the cause of the problem still needs to be determined. I debugged further to find out where the issue is happening and what is the memory allocation before and after ssl_handshake_server_async(). I have attached the UART logs for your reference. I used the variable tls_context->context.state to determine the current state of SSL handshake. The current states are defined in the enum tls_states_t in tls_types.h. The state is incremented after every call to ssl_handshake_server_async(). When I tested the .NET Client and WICED Server, the ssl_handshake_server_async() was called multiple times and returned value was 0 until the 64416 error was seen. Looking at the Wireshark logs, the handshake protocols Certificate and Client Key Exchange were appended under the same TLS Record Layer but now it is clear (from the attached logs) that the WICED TCP Server could recognize them and process them successfully (result=0).

The error 64416 happened when the state value was 9 which corresponds to SSL_CERTIFICATE_VERIFY before calling ssl_handshake_server_async(). So it seems that the Certificate Verify message sent from the Client is failing. The arena block increased from 28732 to 32828 bytes after Client Key Exchange (8) before processing the next state SSL_CERTIFICATE_VERIFY (9).

I am still waiting for an internal response . I will let you know.

0 Likes

grsr

Has there been any progress?  We are very close to submission for certification and really need this issue resolved.

0 Likes

The issue has been fixed in the ticket and this will be available in Wiced 5.0.x. We will provide the fix internally to you.

0 Likes

Thanks, really appreciate all the help.  Please let me know when the fix is available and how to acquire it.

0 Likes

As mentioned is there a way to get this fix internally?  Need it as soon as possible.

0 Likes

I do not know through which channels you will receive the fix. I had already requested the Cypress engineer to provide a timeline for releasing the fix to Magtek. I will send him a reminder now.

0 Likes

I tested the fix in the latest release of WICED 5.0 and it works correctly now. You can contact Inventek to obtain early access of the release.

0 Likes