Leshan does not decode SenML-CBOR/JSON data value (vd/8) correctly #984

jacintobarbeira · 2021-03-19T15:15:05Z

Hi Leshan Team

I'm trying out the AVSystem's Coiote LwM2M stack (both bootstrap and device management) using Leshan client demo.
When I connect the client to the bootstrap server, I get this error when the server sends back the device manager info to connect to:

2021-03-19 14:26:48,006 ERROR LwM2mCoapResource - Exception while handling request [CON-PUT    MID= 7581, Token=3EA719C0258E200B, OptionSet={"Uri-Path":"0", "Content-Format":"application/senml+cbor"},
8d a3 21 63 2f 30 2f 00 63 31 2f 30 03 78 23 63 6f 61 70 73 3a 2f 2f 6c 77 6d 32 6d 2d 74 65 73
74 2e 61 76 73 79 73 74 65 6d 2e 69 6f 3a 35 36 39 34 a2 00 63 31 2f 32 02 00 a2 00 63 31 2f 33
08 47 74 65 73 74 2d 6a 62 a2 00 63 31 2f 35 08 58 18 58 59 37 6d 73 43 46 4f 30 47 61 67 64 34
46 77 6b 56 36 6f 36 6a 6b 33 a2 00 63 31 2f 34 08 40 a2 00 63 31 2f 31 04 f5 a2 00 63 32 2f 30
03 78 23 63 6f 61 70 73 3a 2f 2f 6c 77 6d 32 6d 2d 74 65 73 74 2e 61 76 73 79 73 74 65 6d 2e 69
6f 3a 35 36 38 34 a2 00 63 32 2f 32 02 00 a2 00 63 32 2f 33 08 47 74 65 73 74 2d 6a 62 a2 00 63
32 2f 35 08 58 18 6b 72 56 63 43 62 6e 55 61 42 56 72 53 35 48 59 32 52 42 51 4e 72 52 76 a2 00
63 32 2f 34 08 40 a2 00 63 32 2f 31 04 f4 a2 00 64 32 2f 31 30 02 01 ] on the resource /0 from Identity lwm2m-test.avsystem.io/35.241.179.127:5694[psk=test-jb]
org.eclipse.leshan.core.util.json.JsonException: Invalid SenML record : record must have a value (v,vb,vlo,vd,vs) : {0: "1/3", 8: h'746573742D6A62'}
	at org.eclipse.leshan.senml.cbor.upokecenter.SenMLCborPackSerDes.deserializeFromCbor(SenMLCborPackSerDes.java:117)
	at org.eclipse.leshan.senml.cbor.upokecenter.SenMLCborUpokecenterEncoderDecoder.fromSenML(SenMLCborUpokecenterEncoderDecoder.java:72)
	at org.eclipse.leshan.core.node.codec.senml.LwM2mNodeSenMLDecoder.decode(LwM2mNodeSenMLDecoder.java:68)
	at org.eclipse.leshan.core.node.codec.DefaultLwM2mNodeDecoder.decode(DefaultLwM2mNodeDecoder.java:127)
	at org.eclipse.leshan.core.node.codec.DefaultLwM2mNodeDecoder.decode(DefaultLwM2mNodeDecoder.java:109)
	at org.eclipse.leshan.client.californium.object.ObjectResource.handlePUT(ObjectResource.java:228)
	at org.eclipse.californium.core.CoapResource.handleRequest(CoapResource.java:228)
	at org.eclipse.leshan.core.californium.LwM2mCoapResource.handleRequest(LwM2mCoapResource.java:51)
	at org.eclipse.californium.core.server.ServerMessageDeliverer.deliverRequest(ServerMessageDeliverer.java:106)
	at org.eclipse.californium.core.network.stack.BaseCoapStack$StackTopAdapter.receiveRequest(BaseCoapStack.java:204)
	at org.eclipse.californium.core.network.stack.AbstractLayer.receiveRequest(AbstractLayer.java:84)
	at org.eclipse.californium.core.network.stack.AbstractLayer.receiveRequest(AbstractLayer.java:84)
	at org.eclipse.californium.core.network.stack.BlockwiseLayer.receiveRequest(BlockwiseLayer.java:413)
	at org.eclipse.californium.core.network.stack.ReliabilityLayer.receiveRequest(ReliabilityLayer.java:275)
	at org.eclipse.californium.core.network.stack.AbstractLayer.receiveRequest(AbstractLayer.java:84)
	at org.eclipse.californium.core.network.stack.BaseCoapStack.receiveRequest(BaseCoapStack.java:137)
	at org.eclipse.californium.core.network.CoapEndpoint$1.receiveRequest(CoapEndpoint.java:309)
	at org.eclipse.californium.core.network.UdpMatcher$2.run(UdpMatcher.java:270)
	at org.eclipse.californium.elements.util.SerialExecutor$1.run(SerialExecutor.java:289)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:836)
2021-03-19 14:28:19,770 INFO DefaultRegistrationEngine - Bootstrap sequence aborted: Timeout.

I asked about it and the guys at AV Systems say that it's probably a bug on Leshan's side as it is expecting text labels instead of numeric ones.
I've had the same result with master and demo_v2 branches and leshan-2.0.0-M2 tag

BR

Jacinto

The text was updated successfully, but these errors were encountered:

sbernard31 · 2021-03-19T15:58:35Z

Thx a lot to reporting this 🙏

I will investigate this. For now it seems that we expect base64 string for SenML Data Value (vd in json and 8in cbor). This is maybe a bug I need to read SenML and LWM2M specification again.

sbernard31 · 2021-03-19T16:31:20Z

I confirm this is a bug in Leshan.

LWM2M spec says :

OPAQUE for SenML-CBOR : Represented as a byte string, as defined in Section 2 of [RFC7049]

SenML RFC says :

Octets in the Data Value are encoded using a byte string with a definite length (major type 2).

sbernard31 · 2021-03-19T16:33:03Z

#985 should fix the issue.
Could you confirm it works for you ? 🙏

jacintobarbeira · 2021-03-19T16:59:13Z

what branch is it on?

jacintobarbeira · 2021-03-19T16:59:52Z

nevermind
just saw it

sbernard31 · 2021-03-19T17:00:21Z

you can see it in the PR below the title :

sbernard31 wants to merge 1 commit into master from fix_senml_cbor

jacintobarbeira · 2021-03-19T17:06:39Z

different error this time

2021-03-19 17:05:26,497 DEBUG LwM2mCoapResource - Invalid request [CON-PUT    MID=17397, Token=9532FADA258E200B, OptionSet={"Uri-Path":"0", "Content-Format":"application/senml+cbor"},
8d a3 21 63 2f 30 2f 00 63 31 2f 30 03 78 23 63 6f 61 70 73 3a 2f 2f 6c 77 6d 32 6d 2d 74 65 73
74 2e 61 76 73 79 73 74 65 6d 2e 69 6f 3a 35 36 39 34 a2 00 63 31 2f 32 02 00 a2 00 63 31 2f 33
08 47 74 65 73 74 2d 6a 62 a2 00 63 31 2f 35 08 58 18 51 64 63 4b 37 74 49 4f 4e 4e 78 4a 32 79
55 54 68 30 53 45 76 52 58 4a a2 00 63 31 2f 34 08 40 a2 00 63 31 2f 31 04 f5 a2 00 63 32 2f 30
03 78 23 63 6f 61 70 73 3a 2f 2f 6c 77 6d 32 6d 2d 74 65 73 74 2e 61 76 73 79 73 74 65 6d 2e 69
6f 3a 35 36 38 34 a2 00 63 32 2f 32 02 00 a2 00 63 32 2f 33 08 47 74 65 73 74 2d 6a 62 a2 00 63
32 2f 35 08 58 18 37 47 4c 4f 73 4e 4f 62 74 51 48 63 59 56 4b 46 69 51 52 65 57 34 51 31 a2 00
63 32 2f 34 08 40 a2 00 63 32 2f 31 04 f4 a2 00 64 32 2f 31 30 02 01 ] received on the resource /0 from Identity lwm2m-test.avsystem.io/35.241.179.127:5694[psk=test-jb]
org.eclipse.leshan.core.node.codec.CodecException: Invalid content [[B@dc67221f] for type OPAQUE for path /0/1/3
	at org.eclipse.leshan.core.node.codec.senml.LwM2mNodeSenMLDecoder.parseResourceValue(LwM2mNodeSenMLDecoder.java:496)
	at org.eclipse.leshan.core.node.codec.senml.LwM2mNodeSenMLDecoder.extractLwM2mResources(LwM2mNodeSenMLDecoder.java:416)
	at org.eclipse.leshan.core.node.codec.senml.LwM2mNodeSenMLDecoder.parseRecords(LwM2mNodeSenMLDecoder.java:195)
	at org.eclipse.leshan.core.node.codec.senml.LwM2mNodeSenMLDecoder.decode(LwM2mNodeSenMLDecoder.java:97)
	at org.eclipse.leshan.core.node.codec.DefaultLwM2mNodeDecoder.decode(DefaultLwM2mNodeDecoder.java:155)
	at org.eclipse.leshan.core.node.codec.DefaultLwM2mNodeDecoder.decode(DefaultLwM2mNodeDecoder.java:137)
	at org.eclipse.leshan.client.californium.object.ObjectResource.handlePUT(ObjectResource.java:228)
	at org.eclipse.californium.core.CoapResource.handleRequest(CoapResource.java:228)
	at org.eclipse.leshan.core.californium.LwM2mCoapResource.handleRequest(LwM2mCoapResource.java:51)
	at org.eclipse.californium.core.server.ServerMessageDeliverer.deliverRequest(ServerMessageDeliverer.java:106)
	at org.eclipse.californium.core.network.stack.BaseCoapStack$StackTopAdapter.receiveRequest(BaseCoapStack.java:204)
	at org.eclipse.californium.core.network.stack.AbstractLayer.receiveRequest(AbstractLayer.java:84)
	at org.eclipse.californium.core.network.stack.AbstractLayer.receiveRequest(AbstractLayer.java:84)
	at org.eclipse.californium.core.network.stack.BlockwiseLayer.receiveRequest(BlockwiseLayer.java:413)
	at org.eclipse.californium.core.network.stack.ReliabilityLayer.receiveRequest(ReliabilityLayer.java:275)
	at org.eclipse.californium.core.network.stack.AbstractLayer.receiveRequest(AbstractLayer.java:84)
	at org.eclipse.californium.core.network.stack.BaseCoapStack.receiveRequest(BaseCoapStack.java:137)
	at org.eclipse.californium.core.network.CoapEndpoint$1.receiveRequest(CoapEndpoint.java:309)
	at org.eclipse.californium.core.network.UdpMatcher$2.run(UdpMatcher.java:270)
	at org.eclipse.californium.elements.util.SerialExecutor$1.run(SerialExecutor.java:289)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:836)
Caused by: java.lang.ClassCastException: [B incompatible with java.lang.String
	at org.eclipse.leshan.core.node.codec.senml.LwM2mNodeSenMLDecoder.parseResourceValue(LwM2mNodeSenMLDecoder.java:487)

sbernard31 · 2021-03-19T17:13:52Z

Thx again I will look at this on Monday hoping I will be able to provide a fix quickly.

jacintobarbeira · 2021-03-19T17:15:57Z

thks. have a nice weekend :)

sbernard31 · 2021-03-19T17:21:15Z

I pushed a quick commit on fix_senml_cbor just in case. (not tested at all)

sbernard31 · 2021-03-19T17:22:02Z

Have a nice weekend too and thx again to report this kind of bug.
This helps a lot 🙏

jacintobarbeira · 2021-03-22T10:41:47Z

failing compilation on integration tests

[ERROR] Failures: 
[ERROR]   QueueModeTest.sleeping_if_timeout:161 expected null, but was:<ReadResponse [code=NOT_FOUND, errormessage=]>
[ERROR]   WriteOpaqueValueTest.write_opaque_resource:92 expected:<CHANGED> but was:<INTERNAL_SERVER_ERROR>
[ERROR]   WriteOpaqueValueTest.write_opaque_resource:92 expected:<CHANGED> but was:<INTERNAL_SERVER_ERROR>
[ERROR] Errors: 
[ERROR]   BootstrapTest.bootstrap_senmlcbor_only:129 » Runtime java.util.concurrent.Time...
[ERROR]   ReadOpaqueValueTest.can_read_empty_opaque_resource:81 » LwM2mNode Value does n...
[ERROR]   ReadOpaqueValueTest.can_read_empty_opaque_resource:81 » LwM2mNode Value does n...
[INFO] 
[ERROR] Tests run: 317, Failures: 3, Errors: 3, Skipped: 0

sbernard31 · 2021-03-22T15:15:44Z

Ok I finally take time to look at this deeper.

This was not 1 bug but a nest !

I hope this time it's OK.

jacintobarbeira · 2021-03-22T16:14:47Z

ok, we progressed. The bootstrap task on the server side completes without error, but afterwards the client then throws this:

2021-03-22 16:10:01,098 INFO LeshanClientDemo - Commands available :

  - create <objectId> : to enable a new object.
  - delete <objectId> : to disable a new object.
  - update : to trigger a registration update.
  - w : to move to North.
  - a : to move to East.
  - s : to move to South.
  - d : to move to West.

2021-03-22 16:10:01,098 INFO LeshanClient - Starting Leshan client ...
2021-03-22 16:10:01,103 INFO LeshanClient - Leshan client[endpoint:test-jb] started.
2021-03-22 16:10:01,103 INFO DefaultRegistrationEngine - Trying to start bootstrap session to coaps://lwm2m-test.avsystem.io:5694 ...
2021-03-22 16:10:01,812 INFO CaliforniumEndpointsManager - New endpoint created for server coaps://lwm2m-test.avsystem.io:5694 at coaps://0.0.0.0:64504
2021-03-22 16:10:01,835 INFO LeshanClientDemo - DTLS Full Handshake initiated by client : STARTED ...
2021-03-22 16:10:01,977 INFO LeshanClientDemo - DTLS Full Handshake initiated by client : SUCCEED
2021-03-22 16:10:02,220 INFO DefaultRegistrationEngine - Bootstrap started
2021-03-22 16:10:02,496 DEBUG Security - Write on Security resource /0/1/0
2021-03-22 16:10:02,497 DEBUG Security - Write on Security resource /0/1/1
2021-03-22 16:10:02,497 DEBUG Security - Write on Security resource /0/1/2
2021-03-22 16:10:02,497 DEBUG Security - Write on Security resource /0/1/3
2021-03-22 16:10:02,497 DEBUG Security - Write on Security resource /0/1/4
2021-03-22 16:10:02,497 DEBUG Security - Write on Security resource /0/1/5
2021-03-22 16:10:02,498 DEBUG Security - Write on Security resource /0/2/0
2021-03-22 16:10:02,498 DEBUG Security - Write on Security resource /0/2/1
2021-03-22 16:10:02,498 DEBUG Security - Write on Security resource /0/2/2
2021-03-22 16:10:02,498 DEBUG Security - Write on Security resource /0/2/3
2021-03-22 16:10:02,498 DEBUG Security - Write on Security resource /0/2/4
2021-03-22 16:10:02,498 DEBUG Security - Write on Security resource /0/2/5
2021-03-22 16:10:02,498 DEBUG Security - Write on Security resource /0/2/10
2021-03-22 16:10:02,537 DEBUG Server - Write on Server resource /1/2/0
2021-03-22 16:10:02,537 DEBUG Server - Write on Server resource /1/2/1
2021-03-22 16:10:02,537 DEBUG Server - Write on Server resource /1/2/6
2021-03-22 16:10:02,537 DEBUG Server - Write on Server resource /1/2/7
2021-03-22 16:10:02,612 INFO DefaultRegistrationEngine - Bootstrap finished coaps://lwm2m-test.avsystem.io:5694.
2021-03-22 16:10:02,612 INFO DefaultRegistrationEngine - Unable to send Bootstrap request : null
2021-03-22 16:10:02,613 ERROR DefaultRegistrationEngine - Unexpected exception during bootstrap task
java.lang.NullPointerException
	at org.eclipse.leshan.client.object.Security.read(Security.java:244)
	at org.eclipse.leshan.client.resource.BaseInstanceEnabler.read(BaseInstanceEnabler.java:118)
	at org.eclipse.leshan.client.resource.ObjectEnabler.doRead(ObjectEnabler.java:201)
	at org.eclipse.leshan.client.resource.BaseObjectEnabler.read(BaseObjectEnabler.java:173)
	at org.eclipse.leshan.client.servers.ServersInfoExtractor.getInfo(ServersInfoExtractor.java:69)
	at org.eclipse.leshan.client.servers.ServersInfoExtractor.getBootstrapServerInfo(ServersInfoExtractor.java:150)
	at org.eclipse.leshan.client.engine.DefaultRegistrationEngine.scheduleClientInitiatedBootstrap(DefaultRegistrationEngine.java:493)
	at org.eclipse.leshan.client.engine.DefaultRegistrationEngine.access$500(DefaultRegistrationEngine.java:74)
	at org.eclipse.leshan.client.engine.DefaultRegistrationEngine$ClientInitiatedBootstrapTask.run(DefaultRegistrationEngine.java:524)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:836)
2021-03-22 16:10:02,614 INFO LeshanClient - Destroying Leshan client ...
2021-03-22 16:10:02,616 INFO LeshanClient - Leshan client destroyed.

sbernard31 · 2021-03-22T16:31:47Z

At first sight, I guess this is a another issue not related to CBOR
It seems that sever id (/0/?/10) is null after the bootstrap session and leshan client does not like this. I need to investigate more.

sbernard31 · 2021-03-22T17:23:29Z

I looked at this a little and I'm not sure to understand what happened :/
Could you create a new issue and provide a wireshark capture ?

sbernard31 · 2021-03-23T09:49:09Z

I created a dedicated issue : #986

jacintobarbeira · 2021-03-23T12:27:29Z

ok. I'll close this one

sbernard31 added the question Any question about leshan label Mar 19, 2021

sbernard31 added a commit that referenced this issue Mar 19, 2021

#984 fix issue about decoding data value (vd/8) with SenML_CBOR.

59fd168

sbernard31 mentioned this issue Mar 19, 2021

Fix issue about decoding data value (vd/8) with SenML_CBOR. #985

Merged

sbernard31 added bug Dysfunctionnal behavior and removed question Any question about leshan labels Mar 19, 2021

sbernard31 changed the title ~~Error using Leshan client demo with AV Systems Coiote bootstrap server~~ Leshan does not decode SenML-CBOR data value (vd/8) correctly Mar 19, 2021

sbernard31 added a commit that referenced this issue Mar 22, 2021

#984 fix issue about decoding data value (vd/8) with SenML_CBOR.

3c66a57

sbernard31 changed the title ~~Leshan does not decode SenML-CBOR data value (vd/8) correctly~~ Leshan does not decode SenML-CBOR/JSON data value (vd/8) correctly Mar 22, 2021

sbernard31 mentioned this issue Mar 23, 2021

Unable to bootstrap to AVSystem's Coiote LwM2M stack. #986

Closed

jacintobarbeira closed this as completed Mar 23, 2021

sbernard31 added a commit that referenced this issue Mar 23, 2021

#984 fix issue about decoding data value (vd/8) with SenML_CBOR.

d5607f0

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Leshan does not decode SenML-CBOR/JSON data value (vd/8) correctly #984

Leshan does not decode SenML-CBOR/JSON data value (vd/8) correctly #984

jacintobarbeira commented Mar 19, 2021

sbernard31 commented Mar 19, 2021

sbernard31 commented Mar 19, 2021

sbernard31 commented Mar 19, 2021

jacintobarbeira commented Mar 19, 2021

jacintobarbeira commented Mar 19, 2021

sbernard31 commented Mar 19, 2021 •

edited

Loading

jacintobarbeira commented Mar 19, 2021

sbernard31 commented Mar 19, 2021

jacintobarbeira commented Mar 19, 2021

sbernard31 commented Mar 19, 2021 •

edited

Loading

sbernard31 commented Mar 19, 2021

jacintobarbeira commented Mar 22, 2021

sbernard31 commented Mar 22, 2021

jacintobarbeira commented Mar 22, 2021

sbernard31 commented Mar 22, 2021

sbernard31 commented Mar 22, 2021

sbernard31 commented Mar 23, 2021

jacintobarbeira commented Mar 23, 2021

Leshan does not decode SenML-CBOR/JSON data value (vd/8) correctly #984

Leshan does not decode SenML-CBOR/JSON data value (vd/8) correctly #984

Comments

jacintobarbeira commented Mar 19, 2021

sbernard31 commented Mar 19, 2021

sbernard31 commented Mar 19, 2021

sbernard31 commented Mar 19, 2021

jacintobarbeira commented Mar 19, 2021

jacintobarbeira commented Mar 19, 2021

sbernard31 commented Mar 19, 2021 • edited Loading

jacintobarbeira commented Mar 19, 2021

sbernard31 commented Mar 19, 2021

jacintobarbeira commented Mar 19, 2021

sbernard31 commented Mar 19, 2021 • edited Loading

sbernard31 commented Mar 19, 2021

jacintobarbeira commented Mar 22, 2021

sbernard31 commented Mar 22, 2021

jacintobarbeira commented Mar 22, 2021

sbernard31 commented Mar 22, 2021

sbernard31 commented Mar 22, 2021

sbernard31 commented Mar 23, 2021

jacintobarbeira commented Mar 23, 2021

sbernard31 commented Mar 19, 2021 •

edited

Loading

sbernard31 commented Mar 19, 2021 •

edited

Loading