Coap client not triggering handler for observed resource

[Mary]

I am using:

NCS 3.0.1
nRF52840DK

My project is based on the coap_client sample, currently running on a nRF52840DK.  I have modified it to add the 'observe' option in the request to the server.  The response handler is invoked when the server responds to the original request.  However, the client returns a Reset message to later notifications from the server, and does not invoke the response handler.

I have implemented observer functionality on the client using NCS 2.4.1, and when I compile this project for NCS 2.4.1, the client sends an ACK to the server when it receives a notifications.

The server is implemented on a Raspberry Pi (with OTBR) using libcoap.

In prf.conf

# Enable OpenThread CoAP support API

CONFIG_OPENTHREAD_COAP=y

CONFIG_OPENTHREAD_COAP_OBSERVE=y

static void send_dustsensor_request(struct k_work *item)
{
	ARG_UNUSED(item);

	LOG_INF("Send 'dustsensor' GET request \r\n");

	if (g_server_addr.mFields.m8[0] == 0) {
 		LOG_WRN("Peer address not set. Can't send dustsensor get");
 		return;
 	}

	poll_period_response_set();
	
	ot_coap_send_request(OT_COAP_CODE_GET, &g_server_addr, dustsensor_option, 
		(uint8_t *)&g_eui64, sizeof(g_eui64), 
		on_dustsensor_reply, 1, 0);												// observe
}

otError ot_coap_send_request(enum otCoapCode code, otIp6Address *addr,const char *uri_path, 
			uint8_t *payload, uint16_t payload_size, 
			otCoapResponseHandler reply_cb, bool observe_option, uint32_t observe_flag)
{
	otError error = OT_ERROR_NO_BUFS;
	otMessage *request;
    otInstance *instance;
    otMessageInfo message_info;

    instance = openthread_get_default_instance();

	request = otCoapNewMessage(instance, NULL);
	if (request == NULL) {
		goto end;
	}

    memset(&message_info, 0, sizeof(otMessageInfo));
    memcpy(&(message_info.mPeerAddr), addr, sizeof(otIp6Address)); 
    message_info.mPeerPort = OT_DEFAULT_COAP_PORT;

	otCoapMessageInit(request, OT_COAP_TYPE_CONFIRMABLE, code);

    otCoapMessageGenerateToken(request, 8);

	// Options, must be in ascending order of option number
	if ((code == OT_COAP_CODE_GET) && observe_option)
	{
		//error = otCoapMessageAppendUintOption(request, OT_COAP_OPTION_OBSERVE, observe_flag);
		error = otCoapMessageAppendObserveOption(request, observe_flag);
		if (error != OT_ERROR_NONE)
			LOG_ERR("otCoapMessageAppendUintOption() returned %d", error);

	}

    error = otCoapMessageAppendUriPathOptions(request, uri_path);

 //   otCoapMessageAppendContentFormatOption(request, OT_COAP_OPTION_CONTENT_FORMAT_TEXT_PLAIN);

	// Payload
 	error = otCoapMessageSetPayloadMarker(request);
	if (error != OT_ERROR_NONE) {
		goto end;
	}

    if (payload != NULL)
    {
        error = otMessageAppend(request, payload, payload_size);
        if (error != OT_ERROR_NONE) {
            goto end;
        }
    }

	otCoapTxParameters txParms;
	txParms.mAckRandomFactorDenominator = 1.0;
	
 	error = otCoapSendRequest(instance, request, &message_info, reply_cb, NULL);
    LOG_INF("otCoapSendRequest() returned %d\r\n", error);

end:
	if (error != OT_ERROR_NONE && request != NULL) 
    {
		otMessageFree(request);
	}

	if (error == OT_ERROR_NO_BUFS)
		g_reboot = true;

	return error;

}

See attached Wireshark log.  

observed_resource_reset.pcapng
Frame 1458:  original request from client
Frame 1460: server response
Frame 1469: Server notification
Frame 1471:  RST from client

What's changed since 2.4.1?
How do I get debug log output from ot:coap?  I've included the 'debug' snippet, and the 'logging' snippet, but am not seeing an low level debug output.

Mary

[Achim Kraus]

wireshark 1458 is a NON request, but the snippet requests a OT_COAP_TYPE_CONFIRMABLE. Not sure, what goes wrong.

wireshark 1469 is a CON response (notify)

Let me recommend to capture also with NCS 2.4.1 and check, if the observe-request there uses CON or NON.

(Looking forward to the analysis/answer from Nordic.)

[Mary]

Here's a capture with NCS 2.4.1.

Frame 64:  Request from client (CON)
Frame 66:  Response from server (ACK)

Frame 73:  Notification from server (CON)
Frame 75:  ACK from client

The network key is the same.

Mary

observed_resource_ack_241.pcapng

[Achim Kraus]

Yes.

I guess that's two issues:

1. NCS 3.0.1 uses NON instead of CON. Maybe OT_COAP_TYPE_CONFIRMABLE is broken or requires some additional setup.

2. The coap-client rejects a CON notify response for a NON request. I would recommend Nordic to open an issue in Constrained Application Protocol (CoAP): Corrections and Clarifications to ensure, that this a compliant handling.

[Mary]

1. It's not broken.  I've been trying different things, and must have tried NON in the original request.  I just tried it again with CON, and got the same result.  ACK from the server for the original request, then RST from the client on subsequent notifications.  Sorry for the confusion.

I've tried both CON and NON on the server side for the notification.  With NON, it still sends a CON every 5th notification (as required by the spec).  The client responds to the CON with a RST, and never invokes the response handler in either case.

Frame 90: Request (CON)
Frame 92: ACK from server

Frame 97: Notification from server (CON)
Frame 99: RST from client

Mary

observed_resouce_CON_reset.pcapng

[Achim Kraus]

Mary said:

Sorry for the confusion.

Luckily Nordic has now this second capture with CON and the first issues (CON/NON) is already "solved" ;-).

Mary said:

With NON, it still sends a CON every 5th notification (as required by the spec).  The client responds to the CON with a RST, and never invokes the response handler in either case.

Just to be clear:

In this cases the received NON notifications are also not handled by the response handler? 

Let's see, what the analysis there shows.

[Mary]

Achim Kraus said:

In this cases the received NON notifications are also not handled by the response handler? 

You are correct.  The response handler is not called for either NON or CON notifications.  It's only called for the original request, after the ACK is received at the client.

Mary

[dejans]

Hi Mary,

For logging verbosity change, you could try to include CONFIG_OPENTHREAD_SOURCES=y

I will get back to you regarding reset problem.

Best regards,
Dejan

[Mary]

I added CONFIG_OPENTHREAD_SOURCES=y

Not only did I see the debug info.  It works now.  The client properly responds to notifications from the server.

From this ticket, 

One of my colleagues figured it out. By default NCS uses a pre-compiled OpenThread lib. One must set CONFIG_OPENTHREAD_SOURCES=y in order for any OpenThread KCONFIGS to take effect.

Mary