8000 Leshan server demo throws null-pointer exception · Issue #1580 · eclipse-leshan/leshan · GitHub
[go: up one dir, main page]
More Web Proxy on the site http://driver.im/
Skip to content

Leshan server demo throws null-pointer exception #1580

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom
Closed
leandrolanzieri opened this issue Feb 2, 2024 · 14 comments · Fixed by #1581
Closed

Leshan server demo throws null-pointer exception #1580

leandrolanzieri opened this issue Feb 2, 2024 · 14 comments · Fixed by #1581
Labels
bug Dysfunctionnal behavior

Comments

@leandrolanzieri
Copy link

Version(s)

leshan-server-demo v2.0.0-SNAPSHOT Commit ID : f23254c Build Date: Wed Jan 31 18:03:33 CET 2024 (1706720613007) JVM: 11.0.21 (Oracle Corporation OpenJDK 64-Bit Server VM 11.0.21+9) OS: Linux 5.10.206-1-MANJARO amd64 Code Source: https://github.com/eclipse/leshan/tree/f23254c85928bf0eba54c10b515b36ef050a6959

Which components

leshan server demo

Tested With

wakaama-based RIOT implementation

What happened

After a successful client registration, attempts to read any resource from the client throw a NullPointerException. No packet is sent to the client.

How to reproduce

Configure and build the lwm2m example using this RIOT PR: RIOT-OS/RIOT#16233

Configure the right credentials on the Leshan server and trigger a registration. Upon successful registration, try to read any resource on the device.

Relevant Output

2024-02-02 14:34:46,768 EventServlet         [DEBUG] Dispatching REGISTRATION event from endpoint testRIOTDevice  
2024-02-02 14:34:47,045 SweepDeduplicator    [TRACE] Start Mark-And-Sweep with 0 entries  
2024-02-02 14:34:47,054 SweepDeduplicator    [TRACE] Start Mark-And-Sweep with 1 entries  
2024-02-02 14:34:47,054 SweepDeduplicator    [DEBUG] Sweep run took 0ms  
2024-02-02 14:34:47,059 DTLSConnector        [TRACE] 1 recent handshakes, cleaning up 0 - CID=30F0540BCC44  
2024-02-02 14:34:47,059 DTLSConnector        [DEBUG] 1 left recent handshakes, 0 removed in 0ms!  
2024-02-02 14:34:52,059 DTLSConnector        [TRACE] 1 recent handshakes, cleaning up 0 - CID=30F0540BCC44  
2024-02-02 14:34:52,060 DTLSConnector        [DEBUG] 1 left recent handshakes, 0 removed in 0ms!  
2024-02-02 14:34:54,884 ClientServlet        [WARN] Unexpected exception  
java.lang.NullPointerException: null
	at org.eclipse.leshan.server.request.DefaultDownlinkRequestSender.send(DefaultDownlinkRequestSender.java:93)
	at org.eclipse.leshan.server.queue.QueueModeLwM2mRequestSender.send(QueueModeLwM2mRequestSender.java:60)
	at org.eclipse.leshan.server.LeshanServer.send(LeshanServer.java:477)
	at org.eclipse.leshan.server.LeshanServer.send(LeshanServer.java:450)
	at org.eclipse.leshan.server.demo.servlet.ClientServlet.doGet(ClientServlet.java:252)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:687)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799)
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:554)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1440)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:505)
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1355)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
	at org.eclipse.jetty.server.Server.handle(Server.java:516)
	at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:487)
	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:732)
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:479)
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277)
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
	at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131)
	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:409)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034)
	at java.base/java.lang.Thread.run(Thread.java:829)
2024-02-02 14:34:57,045 SweepDeduplicator    [TRACE] Start Mark-And-Sweep with 0 entries  
2024-02-02 14:34:57,054 SweepDeduplicator    [TRACE] Start Mark-And-Sweep with 1 entries  
2024-02-02 14:34:57,054 SweepDeduplicator    [DEBUG] Sweep run took 0ms  
2024-02-02 14:34:57,060 DTLSConnector        [TRACE] 1 recent handshakes, cleaning up 0 - CID=30F0540BCC44  
2024-02-02 14:34:57,061 DTLSConnector        [DEBUG] 1 left recent handshakes, 0 removed in 0ms!  
2024-02-02 14:35:02,061 DTLSConnector        [TRACE] 1 recent handshakes, cleaning up 0 - CID=30F0540BCC44  
2024-02-02 14:35:02,062 DTLSConnector        [DEBUG] 1 left recent handshakes, 0 removed in 0ms!
@leandrolanzieri leandrolanzieri added the bug Dysfunctionnal behavior label Feb 2, 2024
@sbernard31
Copy link
Contributor

Hi, Thx for reporting this. 🙏

My guess is there is something which doesn't match about the endpoint URI.
But as I will not be able to reproduce it, so I will try to add some logs so we will maybe see clearer.

I let you know when I have something you can use to reproduce.

@sbernard31
Copy link
Contributor

I created a new branch unknown_endpoint about that.
(code is in commit 3388cf8)

Is it easy for you to test just like this ? (I mean do you already build Leshan?)

@leandrolanzieri
Copy link
Author
leandrolanzieri commented Feb 2, 2024 •
edited
Loading

Thanks. Here are the new logs. I think there may be something wrong when defining the interface of the endpoint at which the node registered itself, because then it can't be match to the actual ones.

024-02-02 18:37:00,164 ClientServlet        [WARN] Unexpected exception  
java.lang.IllegalStateException: Client testRIOTDevice register itself to coaps://[fe80:0:0:0:6098:a7ff:fed9:3cea%2533]:5684 endpoint, but it seems there is no available endpoints identified byt this URI.
Available endpoints are : 
coap://[fe80:0:0:0:6098:a7ff:fed9:3cea%33]:5683
coaps://[fe80:0:0:0:6098:a7ff:fed9:3cea%33]:5684
coap://[0:0:0:0:0:0:0:0]:5685
	at org.eclipse.leshan.server.request.DefaultDownlinkRequestSender.getEndpoint(DefaultDownlinkRequestSender.java:165)
	at org.eclipse.leshan.server.request.DefaultDownlinkRequestSender.send(DefaultDownlinkRequestSender.java:89)
	at org.eclipse.leshan.server.queue.QueueModeLwM2mRequestSender.send(QueueModeLwM2mRequestSender.java:60)
	at org.eclipse.leshan.server.LeshanServer.send(LeshanServer.java:477)
	at org.eclipse.leshan.server.LeshanServer.send(LeshanServer.java:450)
	at org.eclipse.leshan.server.demo.servlet.ClientServlet.doGet(ClientServlet.java:252)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:687)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799)
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:554)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1440)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:505)
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1355)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
	at org.eclipse.jetty.server.Server.handle(Server.java:516)
	at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:487)
	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:732)
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:479)
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277)
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
	at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131)
	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:409)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034)
	at java.base/java.lang.Thread.run(Thread.java:1583)
2024-02-02 18:37:01,529 DTLSConnector        [TRACE] 1 recent handshakes, cleaning up 0 - CID=D83431010328  
2024-02-02 18:37:01,530 DTLSConnector        [DEBUG] 1 left recent handshakes, 0 removed in 0ms!  
2024-02-02 18:37:06,511 SweepDeduplicator    [TRACE] Start Mark-And-Sweep with 0 entries  
2024-02-02 18:37:06,521 SweepDeduplicator    [TRACE] Start Mark-And-Sweep with 1 entries  
2024-02-02 18:37:06,521 SweepDeduplicator    [DEBUG] Sweep run took 0ms  
2024-02-02 18:37:06,530 DTLSConnector        [TRACE] 1 recent handshakes, cleaning up 0 - CID=D83431010328  
2024-02-02 18:37:06,530 DTLSConnector        [DEBUG] 1 left recent handshakes, 0 removed in 0ms!  
2024-02-02 18:37:11,531 DTLSConnector        [TRACE] 1 recent handshakes, cleaning up 0 - CID=D83431010328  
2024-02-02 18:37:11,531 DTLSConnector        [DEBUG] 1 left recent handshakes, 0 removed in 0ms (full)!  
2024-02-02 18:37:16,511 SweepDeduplicator    [TRACE] Start Mark-And-Sweep with 0 entries  
2024-02-02 18:37:16,521 SweepDeduplicator    [TRACE] Start Mark-And-Sweep with 1 entries  
2024-02-02 18:37:16,521 SweepDeduplicator    [DEBUG] Sweep run took 0ms  
2024-02-02 18:37:16,531 DTLSConnector        [TRACE] 1 recent handshakes, cleaning up 0 - CID=D83431010328  
2024-02-02 18:37:16,532 DTLSConnector        [DEBUG] 1 left recent handshakes, 0 removed in 0ms!

@sbernard31
Copy link
Contributor
sbernard31 commented Feb 5, 2024 •
edited
Loading

Yep it seems there is something unexpected with :

coaps://[fe80:0:0:0:6098:a7ff:fed9:3cea%2533]:5684 
VS
coaps://[fe80:0:0:0:6098:a7ff:fed9:3cea%33]:5684

I will try to investigate a bit more.

Perhaps, a workaround for you would be to use IPv4 ?

@leandrolanzieri
Copy link
Author

Thanks. Unfortunately, IPv4 is currently not an option for me, as most of the networking infrastructure in RIOT is IPv6.

@sbernard31
Copy link
Contributor

I try to understand the %xxxx part of the ipv6 address in your case. (First finding : https://superuser.com/questions/99746/why-is-there-a-percent-sign-in-the-ipv6-address)

It seems this is relative to local link address, so I guess you should not get same issue when testing with : https://leshan.eclipseprojects.io ? Or ?

@leandrolanzieri
Copy link
Author

It is indeed because I'm using link local addresses. It specifies the interface. I'm not able to test with leshan.eclipseprojects.io because I don't see an IPv6 for it. I can try later again by using global addresses, locally.

@sbernard31
Copy link
Contributor
sbernard31 commented Feb 5, 2024 •
edited
Loading

I'm not able to test with leshan.eclipseprojects.io because I don't see an IPv6 for it. I

I didn't test it recently but I remember that we add an ipv6 address to leshan sandbox : #1210

I just run nslookup and get :

$> nslookup leshan.eclipseprojects.io                                                                                                                                             

Server:		212.27.40.241
Address:	212.27.40.241#53

Non-authoritative answer:
Name:	leshan.eclipseprojects.io
Address: 23.97.187.154
Name:	leshan.eclipseprojects.io
Address: 2a01:111:f100:9001::1761:93fa

Tell what makes you think that ipv6 is not supported ? (maybe it doesn't really work ?)

It is indeed because I'm using link local addresses. It specifies the interface.

Yep I need to understand this better to know how Leshan should behave in this case 🤔

@leandrolanzieri
Copy link
Author

I just run nslookup and get :

Hmm interesting, dig shows only the IPv4 entry:

$ dig leshan.eclipseprojects.io

; <<>> DiG 9.18.21 <<>> leshan.eclipseprojects.io
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 29132
;; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags:; udp: 1232
; COOKIE: bd0b0a7151dc17120100000065c0a8b08967c90c3a868a9b (good)
;; QUESTION SECTION:
;leshan.eclipseprojects.io.	IN	A

;; ANSWER SECTION:
leshan.eclipseprojects.io. 85383 IN	A	23.97.187.154

;; Query time: 10 msec
;; SERVER: 131.169.40.200#53(131.169.40.200) (UDP)
;; WHEN: Mon Feb 05 10:21:52 CET 2024
;; MSG SIZE  rcvd: 98

I'll give it a try later

@sbernard31
Copy link
Contributor
sbernard31 commented Feb 5, 2024 •
edited
Loading

Ok It's still not crystal clear to me how Leshan should behave with zone id but I understand this should be more or less transparent.

The question remaining is why we get %2533 on one side and %33 on the other side... 🤔

In Leshan we have 2 ways to create the endpoint URI :

  • EndpointUriUtil.createUri which use InetSocketAddress.getHostString() which seems to NOT replace the % by %25
  • CoapEndpoint.getUri which use : ‎StringUtil::getUriHostname which replaces the % by %25

Looking at : https://www.rfc-editor.org/rfc/rfc6874#section-2, we can read :

In a URI, a literal IPv6 address is always embedded between "[" and
"]". This document specifies how a <zone_id> can be appended to the
address. According to URI syntax [RFC3986], "%" is always treated as
an escape character in a URI, so, according to the established URI
syntax [RFC3986] any occurrences of literal "%" symbols in a URI MUST
be percent-encoded and represented in the form "%25". Thus, the
scoped address fe80::a%en1 would appear in a URI as
http://[fe80::a%25en1].

and :

 IP-literal = "[" ( IPv6address / IPv6addrz / IPvFuture  ) "]"

 ZoneID = 1*( unreserved / pct-encoded )

IPv6addrz = IPv6address "%25" ZoneID

I understand the right way should be to use %25 in URI. 🤔
I will try to adapt the code.

sbernard31 added a commit that referenced this issue Feb 5, 2024
@sbernard31
GH-1580: ipv6 zone id in URI should be prefixed by %25.
c93f774
@sbernard31 sbernard31 mentioned this issue Feb 5, 2024
Merged
@sbernard31
Copy link
Contributor
sbernard31 commented Feb 5, 2024 •
edited
Loading

I created a PR to try to fix that : #1581.

Could you test it and tell me if it fix your issue. 🙏

@leandrolanzieri
Copy link
Author

Could you test it and tell me if it fix your issue. 🙏

it works!

@sbernard31
Copy link
Contributor

it works!

Great 🎉

Thx a lot for your help 🙏

I will integrate this soon in master, unless you want more time to play with it and maybe provide more feedback ?

@sbernard31 sbernard31 mentioned this issue Feb 5, 2024
Closed
8B32 @sbernard31
Copy link
Contributor

I gonna integrate #1581 in master. The fix should be available in next release 2.0.0-M15.

mgdlkundera pushed a commit to JaroslawLegierski/leshan that referenced this issue Apr 18, 2024
@sbernard31 @mgdlkundera
eclipse-leshanGH-1580: ipv6 zone id in URI should be prefixed by %25.
cb7e56f
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Dysfunctionnal behavior
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Ipv6 zone id in URI should be prefixed by %25 eclipse-leshan/leshan
2 participants
@sbernard31 @leandrolanzieri
0