Skip to main content

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index] [List Home]
Re: [leshan-dev] CoAP Reset Message on Observation Notification

Hello Klaus,

thanks for your advice. 
Activating californium core log got at least a hint was is going on here:

10:30:20.098 [CoapServer#1] DEBUG c.n.server.log.CoapMessageTracer - [CoAP] send CoAP request to the addr: /89.204.137.15
10:30:20.099 [CoapServer#1] DEBUG c.n.server.service.EventController - node: NODE-02 CoAP: {"timestamp":1534321820099,"incoming":false,"type":"CON","code":"GET","mId":53017,"token":"[a72bc945ce55a737]","options":"Uri-Path: \"3322\", \"0\", \"5700\" - Observe: 0","payload":null}
10:30:20.480 [CoapServer#1] DEBUG c.n.server.log.CoapMessageTracer - [CoAP] receive CoAP response from the addr: /89.204.137.15
10:30:20.481 [CoapServer#1] DEBUG c.n.server.service.EventController - node: NODE-02 CoAP: {"timestamp":1534321820480,"incoming":true,"type":"ACK","code":"2.05","mId":53017,"token":"[a72bc945ce55a737]","options":"Content-Format: \"application/vnd.oma.lwm2m+tlv\" - Observe: 0","payload":"Hex:e4164446754acd"}
10:30:20.493 [Thread-6] DEBUG c.n.server.service.EventController - received new observation: node: NODE-02 resource: /3322/0/5700


11:12:43.195 [CoapServer#1] DEBUG c.n.server.log.CoapMessageTracer - [CoAP] receive CoAP response from the addr: /89.204.137.15
11:12:43.195 [CoapServer#1] DEBUG c.n.server.service.EventController - node: NODE-02 CoAP: {"timestamp":1534324363195,"incoming":true,"type":"NON","code":"2.05","mId":53018,"token":"[a72bc945ce55a737]","options":"Content-Format: \"application/vnd.oma.lwm2m+tlv\" - Observe: 1","payload":"Hex:e41644467558cd"}
11:12:43.196 [CoapServer#1] INFO  o.e.c.core.network.UdpMatcher - ignoring potentially forged response for token Token=[a72bc945ce55a737] with non-matching endpoint context
11:12:43.196 [CoapServer#1] DEBUG c.n.server.log.CoapMessageTracer - [CoAP] send CoAP empty message to the addr: /89.204.137.15
11:12:43.196 [CoapServer#1] DEBUG c.n.server.service.EventController - node: NODE-02 CoAP: {"timestamp":1534324363196,"incoming":false,"type":"RST","code":null,"mId":53018,"token":"[]","options":null,"payload":null}

Btw, the server uses latest leshan 1.0.0-M8 with cf 2.0.0-M11.

BR's
  -wumpel

> On 15 August 2018 at 09:37 "Kraus Achim (INST/ECS4)" <Achim.Kraus@xxxxxxxxxxxx> wrote:
> 
> 
> Hi Wumpel,
> 
> I would prefer, if you create an issue for that, it's easier to follow up longer discussions :-).
> I'm not sure, if leshan's californium layer sends such RST at all. Maybe Simone knows that.
> If leshan doesn't send RST, then it may be better to open an issue in at the californium project.
> 
> https://github.com/eclipse/californium
> 
> Please provide the version information for californium (it's in leshan pom).
> And, if possible, please enable the logging in for californium (I would start with INFO for org.eclipse.californium.core).
> Also please ensure, that no confidential information is provided in your logs :-). 
> 
> Mit freundlichen Grüßen / Best regards
> 
>  Achim Kraus
> 
> (INST/ECS4) 
> Bosch Software Innovations GmbH | Stuttgarter Straße 130 | 71332 Waiblingen | GERMANY | www.bosch-si.com
> 
> Sitz: Berlin, Registergericht: Amtsgericht Charlottenburg; HRB 148411 B 
> Aufsichtsratsvorsitzender: Dr.-Ing. Thorsten Lücke; Geschäftsführung: Dr. Stefan Ferber, Michael Hahn 
> 
> 
> 
> -----Original Message-----
> From: leshan-dev-bounces@xxxxxxxxxxx <leshan-dev-bounces@xxxxxxxxxxx> On Behalf Of wumpel@xxxxxxxxxxxxxxx
> Sent: Dienstag, 14. August 2018 18:06
> To: leshan developer discussions <leshan-dev@xxxxxxxxxxx>; Simon Bernard <contact@xxxxxxxxxxxxxxx>
> Subject: Re: [leshan-dev] CoAP Reset Message on Observation Notification
> 
> Hello Simon,
> 
> this is the server side log, plain CoAP, no DTLS, device is connected through the mobile network connection.
> Would it be helpful to activate (if possible) californium logs? Do you know by chance, how to do it?
> 
> BR's
> -wumpel
> 
> > On 14 August 2018 at 14:23 Simon Bernard <contact@xxxxxxxxxxxxxxx mailto:contact@xxxxxxxxxxxxxxx > wrote:
> > 
> > 
> >     Hi,
> >       Reading the logs, I can not explain this behavior :/ ...
> > 
> >       The logs is at server side right ? are you using DTLS or just plain
> >     CoAP ? is your device behind  a NAT (or something like this) ?
> > 
> >     Simon
> > 
> >     Le 14/08/2018 à 13:27, wumpel@xxxxxxxxxxxxxxx mailto:wumpel@xxxxxxxxxxxxxxx a écrit :
> > 
> >         > > Hello,
> > > 
> > >         I'm facing an unexpected (at least to me) behavior while sending observation response from the device to the server. The devices LWM2M client life-time is set to 10mins, the server requests observation on a sensor resource, which is sent by the device periodically every hour. The observation request was acknowledge by the device and the current sensor value was sent. The client also performs every 10 minutes registration update, but the sensor value notification after one hour was rejected with RST message. (The same happens with all sensor value notification messages coming later). Please see the detailed log below. Worth to mention is, if the life-time is set let say to 2 minutes, the sensor value notification works as expected (accepted). Do I miss something in this use case?
> > > 
> > >         Thanks in Advance!
> > > 
> > >         BR’s,
> > >         -wumpel
> > > 
> > > 
> > > 
> > >         => registration
> > > 
> > >         02:39:18.312 [CoapServer#1] DEBUG c.n.server.log.CoapMessageTracer - [CoAP] receive CoAP request from the addr: /89.204.138.47
> > >         02:39:18.312 [CoapServer#1] DEBUG c.n.server.service.EventController - node: NODE-02 CoAP: {"timestamp":1534207158312,"incoming":true,"type":"CON","code":"POST","mId":35,"token":"[51a9e16e16332300]","options":"Uri-Path: \"rd\" - Content-Format: \"application/link-format\" - Uri-Query: \"ep=NODE-02\", \"lt=600\", \"sms=null\", \"lwm2m=1.0\", \"b=U\"","payload":"</>;rt=oma.lwm2m, </3322/0>, </7/0>, </6/0>, </5/0>, </4/0>, </3/0>, </2/7>, </2/6>, </2/5>, </2/4>, </2/3>, </2/2>, </2/1>, </2/0>, </1/0>"}
> > >         02:39:18.319 [CoapServer#1] DEBUG c.n.server.log.CoapMessageTracer - [CoAP] send CoAP response to the addr: /89.204.138.47
> > >         02:39:18.319 [CoapServer#1] DEBUG 
> > > c.n.server.service.EventController - node: NODE-02 CoAP: 
> > > {"timestamp":1534207158319,"incoming":false,"type":"ACK","code":"2.0
> > > 1","mId":35,"token":"[51a9e16e16332300]","options":"Location-Path: 
> > > \"rd\", \"EnHXqYVZIe\"","payload":null}
> > > 
> > > 
> > >         => start observation
> > > 
> > >         02:39:18.353 [CoapServer#1] DEBUG c.n.server.log.CoapMessageTracer - [CoAP] send CoAP request to the addr: /89.204.138.47
> > >         02:39:18.353 [CoapServer#1] DEBUG c.n.server.service.EventController - node: NODE-02 CoAP: {"timestamp":1534207158353,"incoming":false,"type":"CON","code":"GET","mId":20191,"token":"[834b299f1ea3ace6]","options":"Uri-Path: \"3322\", \"0\", \"5700\" - Observe: 0","payload":null}
> > >         02:39:18.799 [CoapServer#1] DEBUG c.n.server.log.CoapMessageTracer - [CoAP] receive CoAP response from the addr: /89.204.138.47
> > >         02:39:18.799 [CoapServer#1] DEBUG 
> > > c.n.server.service.EventController - node: NODE-02 CoAP: 
> > > {"timestamp":1534207158799,"incoming":true,"type":"ACK","code":"2.05
> > > ","mId":20191,"token":"[834b299f1ea3ace6]","options":"Content-Format
> > > : \"application/vnd.oma.lwm2m+tlv\" - Observe: 
> > > 0","payload":"Hex:e4164445cb0d9a"}
> > > 
> > >         => reg update
> > > 
> > >         02:49:09.290 [CoapServer#1] DEBUG c.n.server.log.CoapMessageTracer - [CoAP] receive CoAP request from the addr: /89.204.138.47
> > >         02:49:09.290 [CoapServer#1] DEBUG c.n.server.service.EventController - node: NODE-02 CoAP: {"timestamp":1534207749290,"incoming":true,"type":"CON","code":"POST","mId":36,"token":"[51a9e16e16332400]","options":"Uri-Path: \"rd\", \"EnHXqYVZIe\" - Uri-Query: \"ep=NODE-02\"","payload":null}
> > >         02:49:09.292 [CoapServer#1] DEBUG c.n.server.log.CoapMessageTracer - [CoAP] send CoAP response to the addr: /89.204.138.47
> > >         02:49:09.292 [CoapServer#1] DEBUG 
> > > c.n.server.service.EventController - node: NODE-02 CoAP: 
> > > {"timestamp":1534207749292,"incoming":false,"type":"ACK","code":"2.0
> > > 4","mId":36,"token":"[51a9e16e16332400]","options":null,"payload":nu
> > > ll}
> > > 
> > >         02:59:00.241 [CoapServer#1] DEBUG c.n.server.log.CoapMessageTracer - [CoAP] receive CoAP request from the addr: /89.204.138.47
> > >         02:59:00.245 [CoapServer#1] DEBUG c.n.server.service.EventController - node: NODE-02 CoAP: {"timestamp":1534208340245,"incoming":true,"type":"CON","code":"POST","mId":37,"token":"[51a9e16e16332500]","options":"Uri-Path: \"rd\", \"EnHXqYVZIe\" - Uri-Query: \"ep=NODE-02\"","payload":null}
> > >         02:59:00.247 [CoapServer#1] DEBUG c.n.server.log.CoapMessageTracer - [CoAP] send CoAP response to the addr: /89.204.138.47
> > >         02:59:00.247 [CoapServer#1] DEBUG 
> > > c.n.server.service.EventController - node: NODE-02 CoAP: 
> > > {"timestamp":1534208340247,"incoming":false,"type":"ACK","code":"2.0
> > > 4","mId":37,"token":"[51a9e16e16332500]","options":null,"payload":nu
> > > ll}
> > > 
> > >         03:08:51.217 [CoapServer#1] DEBUG c.n.server.log.CoapMessageTracer - [CoAP] receive CoAP request from the addr: /89.204.138.47
> > >         03:08:51.218 [CoapServer#1] DEBUG c.n.server.service.EventController - node: NODE-02 CoAP: {"timestamp":1534208931218,"incoming":true,"type":"CON","code":"POST","mId":38,"token":"[51a9e16e16332600]","options":"Uri-Path: \"rd\", \"EnHXqYVZIe\" - Uri-Query: \"ep=NODE-02\"","payload":null}
> > >         03:08:51.219 [CoapServer#1] DEBUG c.n.server.log.CoapMessageTracer - [CoAP] send CoAP response to the addr: /89.204.138.47
> > >         03:08:51.219 [CoapServer#1] DEBUG 
> > > c.n.server.service.EventController - node: NODE-02 CoAP: 
> > > {"timestamp":1534208931219,"incoming":false,"type":"ACK","code":"2.0
> > > 4","mId":38,"token":"[51a9e16e16332600]","options":null,"payload":nu
> > > ll}
> > > 
> > > 
> > >         => client notifies observer resource
> > > 
> > >         03:13:17.380 [CoapServer#1] DEBUG c.n.server.log.CoapMessageTracer - [CoAP] receive CoAP response from the addr: /89.204.138.47
> > >         03:13:17.380 [CoapServer#1] DEBUG c.n.server.service.EventController - node: NODE-02 CoAP: {"timestamp":1534209197380,"incoming":true,"type":"NON","code":"2.05","mId":20192,"token":"[834b299f1ea3ace6]","options":"Content-Format: \"application/vnd.oma.lwm2m+tlv\" - Observe: 1","payload":"Hex:e4164445cb519a"}
> > >         03:13:17.380 [CoapServer#1] DEBUG c.n.server.log.CoapMessageTracer - [CoAP] send CoAP empty message to the addr: /89.204.138.47
> > >         03:13:17.380 [CoapServer#1] DEBUG 
> > > c.n.server.service.EventController - node: NODE-02 CoAP: 
> > > {"timestamp":1534209197380,"incoming":false,"type":"RST","code":null
> > > ,"mId":20192,"token":"[]","options":null,"payload":null}
> > > 
> > >         => reg update
> > > 
> > >         03:18:42.180 [CoapServer#1] DEBUG c.n.server.log.CoapMessageTracer - [CoAP] receive CoAP request from the addr: /89.204.138.47
> > >         03:18:42.180 [CoapServer#1] DEBUG c.n.server.service.EventController - node: NODE-02 CoAP: {"timestamp":1534209522180,"incoming":true,"type":"CON","code":"POST","mId":39,"token":"[51a9e16e16332700]","options":"Uri-Path: \"rd\", \"EnHXqYVZIe\" - Uri-Query: \"ep=NODE-02\"","payload":null}
> > >         03:18:42.182 [CoapServer#1] DEBUG c.n.server.log.CoapMessageTracer - [CoAP] send CoAP response to the addr: /89.204.138.47
> > >         03:18:42.182 [CoapServer#1] DEBUG c.n.server.service.EventController - node: NODE-02 CoAP: {"timestamp":1534209522182,"incoming":false,"type":"ACK","code":"2.04","mId":39,"token":"[51a9e16e16332700]","options":null,"payload":null}
> > >         _______________________________________________
> > >         leshan-dev mailing list
> > >         leshan-dev@xxxxxxxxxxx mailto:leshan-dev@xxxxxxxxxxx
> > >         To change your delivery options, retrieve your password, or unsubscribe from this list, visit
> > >         https://dev.eclipse.org/mailman/listinfo/leshan-dev
> > > 
> > >     >     _______________________________________________
> >     leshan-dev mailing list
> >     leshan-dev@xxxxxxxxxxx mailto:leshan-dev@xxxxxxxxxxx
> >     To change your delivery options, retrieve your password, or unsubscribe from this list, visit
> >     https://dev.eclipse.org/mailman/listinfo/leshan-dev
> > 
> _______________________________________________
> leshan-dev mailing list
> leshan-dev@xxxxxxxxxxx
> To change your delivery options, retrieve your password, or unsubscribe from this list, visit https://dev.eclipse.org/mailman/listinfo/leshan-dev
> _______________________________________________
> leshan-dev mailing list
> leshan-dev@xxxxxxxxxxx
> To change your delivery options, retrieve your password, or unsubscribe from this list, visit
> https://dev.eclipse.org/mailman/listinfo/leshan-dev


Back to the top