NCS Joiner fails

[Mary]

NCS version 1.9.1

nRF52840 DK

I have two projects based on the coap server and coap client examples.  I have made the server a commissioner, and call otCommissioerJoinerStart() when button 4 is pressed (instead of activating provisioning).  

I want the client to autostart openthread and join the network.  It does not succeed.

Server prj.conf

CONFIG_GPIO=y

CONFIG_SPI=y

#CONFIG_MINIMAL_LIBC=y
CONFIG_MINIMAL_LIBC_MALLOC=y
CONFIG_MINIMAL_LIBC_MALLOC_ARENA_SIZE=4096

# Debugging
CONFIG_ASSERT=y
CONFIG_STACK_SENTINEL=y
CONFIG_DEBUG_OPTIMIZATIONS=y
CONFIG_LOG=y
#CONFIG_LOG_PRINTK=y
CONFIG_MBEDTLS_DEBUG_C=y
CONFIG_MBEDTLS_SSL_DEBUG_ALL=y

# CRYPTO
#CONFIG_NORDIC_SECURITY_BACKEND=y
CONFIG_ENTROPY_GENERATOR=y
#CONFIG_ENTROPY_DEVICE_RANDOM_GENERATOR=y
#CONFIG_HARDWARE_DEVICE_CS_GENERATOR=y
##CONFIG_CTR_DRBG_CSPRNG_GENERATOR=y

#CONFIG_MBEDTLS=y
#CONFIG_MBEDTLS_BUILTIN=y
##CONFIG_APP_LINK_WITH_MBEDTLS=y
##CONFIG_MBEDTLS_LIBRARY=y
#CONFIG_PSA_CRYPTO_DRIVER_BUILTIN=y
#CONFIG_PSA_CRYPTO_DRIVER_OBERON=y
CONFIG_MBEDTLS_ENABLE_HEAP=y
# SSL inbuf/outbuf are 16K each
#CONFIG_MBEDTLS_HEAP_SIZE=40000
CONFIG_MBEDTLS_HEAP_SIZE=86016
#CONFIG_MBEDTLS_DEBUG_C=y

# Crypto
CONFIG_NORDIC_SECURITY_BACKEND=y
#CONFIG_CC3XX_BACKEND=n
#CONFIG_OBERON_BACKEND=y
#CONFIG_MBEDTLS_VANILLA_BACKEND=n

# build\modules\nrfxlib\nrf_security\include
CONFIG_MBEDTLS_PK_C=y
CONFIG_MBEDTLS_PK_WRITE_C=y
#CONFIG_MBEDTLS_CFG_FILE="../../../../mbedtls_config.h"
#CONFIG_MBEDTLS_PEM_CERTIFICATE_FORMAT=y

CONFIG_NRF_SECURITY=y
CONFIG_NRF_SECURITY_ADVANCED=y
CONFIG_MBEDTLS_TLS_LIBRARY=y

CONFIG_MBEDTLS_X509_LIBRARY=y

# JSON
#CONFIG_NEWLIB_LIBC=y
#CONFIG_CJSON_LIB=y

CONFIG_BASE64=y

# Heap and stacks
CONFIG_HEAP_MEM_POOL_SIZE=4096
#CONFIG_MAIN_STACK_SIZE=2048
CONFIG_MAIN_STACK_SIZE=8192
CONFIG_SYSTEM_WORKQUEUE_STACK_SIZE=2048
CONFIG_LOG_PROCESS_THREAD_STACK_SIZE=2048
CONFIG_ISR_STACK_SIZE=4096

###########################
#   COAP Server
###########################

# nRF board library
CONFIG_DK_LIBRARY=y

# Enable OpenThread CoAP support API
CONFIG_OPENTHREAD_COAP=y
#CONFIG_OPENTHREAD_COAP_OBSERVE=y

# Configure sample logging setting
#CONFIG_LOG=y
##CONFIG_COAP_SERVER_LOG_LEVEL_DBG=y
##CONFIG_OT_COAP_UTILS_LOG_LEVEL_DBG=y
#CONFIG_OPENTHREAD_LOG_LEVEL_NOTE=y
#CONFIG_OPENTHREAD_DEBUG=y

# Adjust log strdup settings
#CONFIG_LOG_STRDUP_MAX_STRING=128

# Network shell
#CONFIG_SHELL=y
#CONFIG_OPENTHREAD_SHELL=y
#CONFIG_SHELL_ARGC_MAX=26
#CONFIG_SHELL_CMD_BUFF_SIZE=416

# Same network Master Key for client and server
CONFIG_OPENTHREAD_NETWORKKEY="00:11:22:33:44:55:66:77:88:99:aa:bb:cc:dd:ee:ff"
CONFIG_OPENTHREAD_COMMISSIONER=y
CONFIG_OPENTHREAD_FTD=y

# L2 OpenThread enabling
CONFIG_NET_L2_OPENTHREAD=y

# Generic networking options
CONFIG_NETWORKING=y

## (defined above)CONFIG_ASSERT=y
#CONFIG_ASSERT_NO_COND_INFO=y
#CONFIG_MBEDTLS_SHA1_C=n
#CONFIG_FPU=y

# Add in mbedtls elements disabled by openthread, but needed by certificates
CONFIG_MBEDTLS_CIPHER_MODE_CTR=y
CONFIG_MBEDTLS_CHACHA20_C=y
CONFIG_MBEDTLS_POLY1305_C=y
CONFIG_MBEDTLS_CHACHAPOLY_C=y
CONFIG_MBEDTLS_DHM_C=y
CONFIG_MBEDTLS_RSA_C=y
CONFIG_MBEDTLS_SHA512_C=y
CONFIG_MBEDTLS_GCM_C=y

CONFIG_MBEDTLS_KEY_EXCHANGE_PSK_ENABLED=y
CONFIG_MBEDTLS_KEY_EXCHANGE_DHE_PSK_ENABLED=y
CONFIG_MBEDTLS_KEY_EXCHANGE_ECDHE_PSK_ENABLED=y
CONFIG_MBEDTLS_KEY_EXCHANGE_RSA_PSK_ENABLED=y
CONFIG_MBEDTLS_KEY_EXCHANGE_RSA_ENABLED=y
CONFIG_MBEDTLS_KEY_EXCHANGE_DHE_RSA_ENABLED=y
CONFIG_MBEDTLS_KEY_EXCHANGE_ECDHE_RSA_ENABLED=y
CONFIG_MBEDTLS_KEY_EXCHANGE_ECDHE_ECDSA_ENABLED=y
CONFIG_MBEDTLS_KEY_EXCHANGE_ECDH_ECDSA_ENABLED=y
CONFIG_MBEDTLS_ECDSA_DETERMINISTIC=y
CONFIG_MBEDTLS_KEY_EXCHANGE_ECDH_RSA_ENABLED=y
CONFIG_MBEDTLS_KEY_EXCHANGE_ECJPAKE_ENABLED=y

CONFIG_MBEDTLS_CIPHER=y

CONFIG_MBEDTLS_SHA1_C=y

CONFIG_MBEDTLS_SSL_ALL_ALERT_MESSAGES=y
CONFIG_MBEDTLS_SSL_CONTEXT_SERIALIZATION=y
CONFIG_MBEDTLS_SSL_DEBUG_ALL=y
CONFIG_MBEDTLS_SSL_KEEP_PEER_CERTIFICATE=y

CONFIG_MBEDTLS_SSL_OUT_CONTENT_LEN=16380
CONFIG_MBEDTLS_SSL_IN_CONTENT_LEN=16380

#CONFIG_MBEDTLS_CIPHER_PADDING_PKCS7=y
#CONFIG_MBEDTLS_CIPHER_PADDING_ONE_AND_ZEROS=y
#CONFIG_MBEDTLS_CIPHER_PADDING_ZEROS_AND_LEN=y
#CONFIG_MBEDTLS_CIPHER_PADDING_ZEROS=y

#CONFIG_MBEDTLS_SHA224_C=y
#CONFIG_MBEDTLS_SHA384_C=y

client pjf.conf

#
# Copyright (c) 2020 Nordic Semiconductor
#
# SPDX-License-Identifier: LicenseRef-Nordic-5-Clause
#

# nRF board library
CONFIG_DK_LIBRARY=y

# Enable CoAP utils and CoAP protocol
CONFIG_COAP_UTILS=y

# Configure sample logging setting
CONFIG_LOG=y
CONFIG_COAP_CLIENT_LOG_LEVEL_DBG=y
CONFIG_COAP_CLIENT_UTILS_LOG_LEVEL_DBG=y
CONFIG_COAP_UTILS_LOG_LEVEL_DBG=y
CONFIG_OPENTHREAD_LOG_LEVEL_NOTE=y
CONFIG_OPENTHREAD_DEBUG=y

# Adjust log strdup settings
CONFIG_LOG_STRDUP_MAX_STRING=128

# Generic networking options
CONFIG_NETWORKING=y

# L2 OpenThread enabling
CONFIG_NET_L2_OPENTHREAD=y

# Network shell
CONFIG_SHELL=y
CONFIG_OPENTHREAD_SHELL=y
CONFIG_SHELL_ARGC_MAX=26
CONFIG_SHELL_CMD_BUFF_SIZE=416

# Enable OpenThread features set
CONFIG_OPENTHREAD_NORDIC_LIBRARY_MASTER=y


# Network sockets
CONFIG_NET_SOCKETS=y
CONFIG_NET_SOCKETS_POSIX_NAMES=y
CONFIG_NET_SOCKETS_POLL_MAX=4

# Thread Joiner
CONFIG_OPENTHREAD_JOINER=y
CONFIG_OPENTHREAD_JOINER_AUTOSTART=y
CONFIG_OPENTHREAD_JOINER_PSKD="J01NUS"
CONFIG_OPENTHREAD_MANUAL_START=n

# Same network Master Key for client and server
#CONFIG_OPENTHREAD_NETWORKKEY="00:11:22:33:44:55:66:77:88:99:aa:bb:cc:dd:ee:ff"

CONFIG_ASSERT=y
CONFIG_ASSERT_NO_COND_INFO=y
CONFIG_MBEDTLS_SHA1_C=n
CONFIG_FPU=y

Server starts Commissioner joiner add when Button 4 is pressed by calling activate_provisioning().

static void commissioner_joiner_cb(otCommissionerJoinerEvent aEvent, const otJoinerInfo *aJoinerInfo, const otExtAddress *aJoinerId, void *aContext)
{
	switch(aEvent)
	{
   		case OT_COMMISSIONER_JOINER_START:
			printk("\r\nCommissioner joiner started.\r\n");
			break;
    	case OT_COMMISSIONER_JOINER_CONNECTED:
			printk("\r\nCommissioner joiner connected\r\n");
			break;
    	case OT_COMMISSIONER_JOINER_FINALIZE:
			printk("\r\nCommissioner joiner finalized\r\n");
			break;
    	case OT_COMMISSIONER_JOINER_END:
			printk("\r\nCommissioner joiner end\r\n");
			break;
    	case OT_COMMISSIONER_JOINER_REMOVED:
			printk("\r\nCommissioner joiner removed\r\n");
			break;
	}
}

#define JOINER_TIMEOUT	120
static char		pskd[] = "J01NUS";
static void activate_provisioning(struct k_work *item)
{
	ARG_UNUSED(item);

	//ot_coap_activate_provisioning();
	struct openthread_context *ot_context = openthread_get_default_context();
	otError err;

	otInstance *instance = ot_context->instance;

	// err = otCommissionerStart(instance, commissioner_state_cb, commissioner_joiner_cb, ot_context);
	// if (err != OT_ERROR_NONE)
	// 	printk("otCommissionerStart() failed [%d]\r\n", err);
	otCommissionerState state;
	if ((state = otCommissionerGetState(instance)) == OT_COMMISSIONER_STATE_ACTIVE)
	{
		err = otCommissionerAddJoiner(instance, NULL, pskd, JOINER_TIMEOUT); 
		if (err != OT_ERROR_NONE)
		{
			printk("\r\notCommissionerAddJoiner() failed [%d]\r\n", err);
		}
		else
		{
			k_timer_start(&led_timer, K_MSEC(100), K_MSEC(100));
			k_timer_start(&provisioning_timer, K_SECONDS(JOINER_TIMEOUT), K_NO_WAIT);

			printk("\r\nCommissioner joiner started for %d seconds...\r\n", JOINER_TIMEOUT);
		}
	}
	else
	{
		printk("\r\nCommissioner state = %d. Can't add joiner.", state);
	}
	//LOG_INF("Provisioning activated");
}

Console output from Server:

................
..................................
Commissioner joiner started for 120 seconds...
...............................................................
Commissioner joiner started.
........................................
Commissioner joiner started.
..................................................................
Commissioner joiner started.
...................................................................................
..........................................................................
Commissioner joiner started.
.................................................................
.....................................................................................................................................................
...........................
Commissioner joiner removed
.............................

Console output from client:

*** Booting Zephyr OS build v2.7.99-ncs1-1  ***
FloLogic CoAP-client POC version 0.2


[00:00:04.966,552] <inf> net_openthread: [NOTE]-MAC-----: Failed to send IPv6 UDP msg, len:56, chksum:62e1, to:None, sec:no, error:Abort, prio:net
[00:00:04.966,857] <inf> net_openthread: [NOTE]-MAC-----:     src:[fe80:0:0:0:888c:b654:d626:2eaf]:19788
[00:00:04.967,102] <inf> net_openthread: [NOTE]-MAC-----:     dst:[ff02:0:0:0:0:0:0:2]:19788
[00:00:09.423,675] <wrn> net_openthread: [WARN]-MLE-----: Failed to process UDP: InvalidState
[00:00:35.960,357] <wrn> net_openthread: [WARN]-MLE-----: Failed to process UDP: InvalidState
[00:01:17.562,255] <wrn> net_openthread: [WARN]-MLE-----: Failed to process UDP: InvalidState
[00:01:52.352,416] <wrn> net_openthread: [WARN]-MLE-----: Failed to process UDP: InvalidState
[00:02:15.436,553] <wrn> net_openthread: [WARN]-MLE-----: Failed to process UDP: InvalidState
[00:02:50.947,540] <wrn> net_openthread: [WARN]-MLE-----: Failed to process UDP: InvalidState
[00:03:11.212,310] <wrn> net_openthread: [WARN]-MLE-----: Failed to process UDP: InvalidState
uart:~$

I'm also attaching a Wireshark file. 

 Joiner_failed.pcapng

How do I fix this?

Also, can I call 

             openthread_set_state_changed_cb(on_thread_state_changed);

when openthread is autostarted?

Thanks,

Mary

[Edvin]

Hello Mary,

Also, can I call 

             openthread_set_state_changed_cb(on_thread_state_changed);

when openthread is autostarted?

This is a callback, so you can't call it to force it to change state, if that is what you are asking. 

I am a bit confused about the sniffer trace. Perhaps they are not decrypted correctly, but what devices (addresses) are your client and server? Do you see the UDP message in the sniffer trace? Does the client connect to the network? Where is the error message in the log printed?

BR,

Edvin

[Mary]

The function 'openthread_set_state_changed_cb()' is not a callback.  It sets a callback function to be called on a state change.  I want to know if a callback can be set after the openthread stack is already running.

I presume the source address for the "Client Hello" message is from the client.

I do not see the UDP message in the sniffer trace.

The client does not connect to the network.

The error log messages are printed to the console, which is shown in my original post.

My coap_client can join the network if I run the cli example instead of the coap_server, and enter these commands:

ot ifconfig up
ot thread start
ot commissioner start
ot commissioner joiner add * J01NUS 100

I've attached the Wireshark capture for this scenario.  Note the DTLS exchange (Server Hello, key exhange, etc), which is not present when running the coap_server.

I'm probably missing some key CONFIG_ parameter in prj.conf, but I don't know what.  I've compared the .config files for the clI and my coap_server and have added the ones listed below, but still cannot join.

CONFIG_SHELL=y

CONFIG_OPENTHREAD_SHELL=y

CONFIG_OPENTHREAD_NORDIC_LIBRARY_MASTER=y

#CONFIG_MBEDTLS_SHA1_C=y

CONFIG_MBEDTLS_SHA1_C=n

cli_commish_coap_client_joiner_ok.pcapng

Mary

[Susheel Nuguru]

Hi, Edvin has started his summer vacation, and we are lacking some mesh experts due to the holidays. We need to wait for a week until few experts come back. I will update this thread when I can ask someone regarding this. Thanks for your patience.

[Mary]

I got it to work.  The changes I made were:

Increase CONFIG_OPENTHREAD_RADIO_WORKQUEUE_STACK_SIZE (from 1024) to 2048
Increase CONFIG_OPENTHREAD_THREAD_STACK_SIZE (from 6240 ) to 8192

Increase MBEDTLS_HEAP_SIZE by 20K bytes

Mary