search

eclipse-leshan / leshan

Java Library for LWM2M
https://www.eclipse.org/leshan/
BSD 3-Clause "New" or "Revised" License
652 stars 407 forks source link

Problem of sending msg to client on Linux Platform #550

Closed djydzgk closed 6 years ago

djydzgk commented 6 years ago

i'm using the client and server demo (). in the server demo,i add this to get some info from client (https://github.com/eclipse/leshan/wiki/Getting-Started-:-Server).

public void registered(Registration registration, Registration previousReg,
            Collection<Observation> previousObsersations) {
    System.out.println("new device: " + registration.getEndpoint());
    try {
        **ReadResponse response = server.send(registration, new ReadRequest(3,0,13));**
        if (response.isSuccess()) {
            System.out.println("Device time:" + ((LwM2mResource)response.getContent()).getValue());
        }else {
            System.out.println("Failed to read:" + response.getCode() + " " + response.getErrorMessage());
        }
    } catch (InterruptedException e) {
        e.printStackTrace();
    }
}

this works fine on windows,but failed on linux(centos /ubuntu)... : (

sbernard31 commented 6 years ago

What does it mean "failed on linux(centos /ubuntu)" ?

Any logs, captures or more precise description of what happened ?

Which version of leshan are you using ?

djydzgk commented 6 years ago

I am writing a simple lwm2m server according to this page（version 1.0.0-M8）： https://github.com/eclipse/leshan/wiki/Getting-Started-:-Server

the server send some request to the device as the device registered ReadResponse response = server.send(registration, new ReadRequest(3,0,15));

using the leshan-client-demo.jar as a client，my server works ok on my windows.

But when I deploy the my jar to centos， the "response" is always null. I have capture packages in wireshark，it seems that my client did not receive any request from server.

The code is:


public class App
{
    static LeshanServerBuilder builder = new LeshanServerBuilder();
    static LeshanServer server = builder.build();

    public static void main(String[] args)
    {
        System.out.println("start server in m8");
        server.start();

        server.getRegistrationService().addListener(new RegistrationListener()
        {
            public void registered(Registration registration, Registration previousReg,
                    Collection<Observation> previousObsersations)
            {
                System.out.println(">> registered") ;
                getDeviceInfo(registration, previousReg, previousObsersations);
            }

            public void updated(RegistrationUpdate update, Registration updatedReg, Registration previousReg)
            {
                System.out.println(">> updated");
                System.out.println("device is still here: " + updatedReg.getEndpoint());
            }

            public void unregistered(Registration registration, Collection<Observation> observations, boolean expired,
                    Registration newReg)
            {
                System.out.println(">>unregistered");
                System.out.println("device left: " + registration.getEndpoint());
            }
        });

    }

    public static void getDeviceInfo(Registration registration, Registration previousReg,
            Collection<Observation> previousObsersations)
    {
        System.out.println("new device: " + registration.getEndpoint());
        try
        {
            ReadResponse response = server.send(registration, new ReadRequest(3, 0, 15));
            if (response == null)
            {
                System.out.println("!!!!!response is null!!!!");
                return;
            }

            if (response.isSuccess())
            {
                System.out.println("Device time:" + ((LwM2mResource) response.getContent()).getValue());
            }
            else
            {
                System.out.println("Failed to read:" + response.getCode() + " " + response.getErrorMessage());
            }
        }
        catch (InterruptedException e)
        {
            e.printStackTrace();
        }
        catch (Exception e)
        {
            e.printStackTrace();
        }
    }

}
djydzgk commented 6 years ago

I add the code from https://github.com/eclipse/leshan/wiki/Getting-Started-:-Server to leshan-server-demo.jar, can not get response using leshan-client-demo.jar as a client on WINDOWS.

ReadResponse response = server.send(registration, new ReadRequest(3,0,15)); response is null

Did i ignore some IMPORTANT steps？

Thanks a lot！

sbernard31 commented 6 years ago

I use leshan only on linux and the sandbox https://leshan.eclipse.org/#/clients is on linux too. I don't think the issue is relative to linux...

Could you share your logs ?

You can activate more logs.

  1. for Leshan Server Demo, add a logback-config.xml file in your working directory

    <?xml version="1.0" encoding="UTF-8"?>
<configuration>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
        <pattern>%d %p %C{0} - %m%n</pattern>
    </encoder>
</appender>

<root level="WARN">
    <appender-ref ref="STDOUT" />
</root>

<logger name="org.eclipse.leshan" level="DEBUG"/><!-- default value is INFO -->
<logger name="org.eclipse.leshan.server.security.SecurityCheck" level="DEBUG"/>
<logger name="org.eclipse.leshan.core.model.LwM2mModel" level="TRACE"/>

    <!-- All above is the default config, the line below is to search something in DTLS stack -->
    <logger name="org.eclipse.californium" level="DEBUG"/>
</configuration>
  2. for leshan-client-demo, add this jvm params to your command line : -Dorg.slf4j.simpleLogger.defaultLogLevel=debug
djydzgk commented 6 years ago

2018-08-02 21:47:12,186 DEBUG EventServlet - Dispatching REGISTRATION event from endpoint wujiabin new device: wujiabin ____1111111111111111111111 /10.12.12.64:64202 send......11111 request 2018-08-02 21:47:16,299 DEBUG SweepDeduplicator$SweepAlgorithm - Sweep run took 1ms 2018-08-02 21:47:26,300 DEBUG SweepDeduplicator$SweepAlgorithm - Sweep run took 0ms 2018-08-02 21:47:36,301 DEBUG SweepDeduplicator$SweepAlgorithm - Sweep run took 0ms 2018-08-02 21:47:39,231 DEBUG UDPConnector$Receiver - UDPConnector (0.0.0.0/0.0.0.0:5683) received 26 bytes from /10.12.12.64:64202 2018-08-02 21:47:41,271 DEBUG UDPConnector$Receiver - UDPConnector (0.0.0.0/0.0.0.0:5683) received 26 bytes from /10.12.12.64:64202 2018-08-02 21:47:42,298 DEBUG CoapSyncRequestObserver - Synchronous request cancelled CON-GET MID= -1, Token=null, OptionSet={"Uri-Path":["3","0","14"]}, no payload 2018-08-02 21:47:42,302 DEBUG EventServlet - Dispatching DEREGISTRATION event from endpoint wujiabin ____33333333333333333333333333 device left: wujiabin !!!!!response is null!!!! 2018-08-02 21:47:42,306 DEBUG ReliabilityLayer - Exchange[L2] send request, failed transmissions: 0 2018-08-02 21:47:42,307 DEBUG ReliabilityLayer - Exchange[L2] prepare retransmission for CON-GET MID= -1, Token=null, OptionSet={"Uri-Path":["3","0","14"]}, no payload 2018-08-02 21:47:42,313 DEBUG InMemoryMessageExchangeStore - Exchange[L2] added with generated mid KeyMID[20926, [0a0c0c40]:64202], CON-GET MID=20926, Token=null, OptionSet={"Uri-Path":["3","0","14"]}, no payload 2018-08-02 21:47:42,336 DEBUG InMemoryMessageExchangeStore - Exchange[L2] added with generated token Token=[fe2df877866a3621], CON-GET MID=20926, Token=[fe2df877866a3621], OptionSet={"Uri-Path":["3","0","14"]}, no payload 2018-08-02 21:47:42,337 DEBUG UdpMatcher - tracking open request [MID: 20926, Token: Token=[fe2df877866a3621]] 2018-08-02 21:47:42,338 DEBUG Exchange - Exchange[L2, complete]! 2018-08-02 21:47:42,338 DEBUG InMemoryMessageExchangeStore - removing Exchange[L2, complete] for token Token=[fe2df877866a3621] 2018-08-02 21:47:42,338 DEBUG InMemoryMessageExchangeStore - removing Exchange[L2, complete] for MID KeyMID[20926, [0a0c0c40]:64202] 2018-08-02 21:47:42,339 DEBUG Exchange - local Exchange[L2, complete] completed CON-GET MID=20926, Token=[fe2df877866a3621], OptionSet={"Uri-Path":["3","0","14"]}, no payload! 2018-08-02 21:47:42,340 DEBUG UdpMatcher - duplicate request: CON-POST MID=49395, Token=[32571c52274c848d], OptionSet={"Uri-Path":["rd","pa6lW8HYu1"]}, no payload 2018-08-02 21:47:42,340 DEBUG RegisterResource - POST received : CON-POST MID=49395, Token=[32571c52274c848d], OptionSet={"Uri-Path":["rd","pa6lW8HYu1"]}, no payload 2018-08-02 21:47:42,342 DEBUG ReliabilityLayer - Exchange[R3] send response null-4.04 MID= -1, Token=null, OptionSet={"Content-Format":"text/plain"}, no payload, failed transmissions: 0 2018-08-02 21:47:42,343 DEBUG Exchange - Exchange[R3, complete]! 2018-08-02 21:47:42,343 DEBUG Exchange - Remote Exchange[R3, complete] completed ACK-4.04 MID=49395, Token=[32571c52274c848d], OptionSet={"Content-Format":"text/plain"}, no payload! 2018-08-02 21:47:42,344 DEBUG ReliabilityLayer - Exchange[R3] respond with the current response to the duplicate request 2018-08-02 21:47:42,344 DEBUG Exchange - Exchange[R3, complete]! 2018-08-02 21:47:42,344 DEBUG Exchange - Remote Exchange[R3, complete] completed ACK-4.04 MID=49395, Token=[32571c52274c848d], OptionSet={"Content-Format":"text/plain"}, no payload! 2018-08-02 21:47:42,347 DEBUG UDPConnector$Sender - UDPConnector (Thread[UDP-Sender-0.0.0.0/0.0.0.0:5683[0],5,Californium/Elements]) sent 13 bytes to /10.12.12.64:64202 2018-08-02 21:47:42,348 DEBUG UDPConnector$Sender - UDPConnector (Thread[UDP-Sender-0.0.0.0/0.0.0.0:5683[0],5,Californium/Elements]) sent 13 bytes to /10.12.12.64:64202 2018-08-02 21:47:42,393 DEBUG UDPConnector$Receiver - UDPConnector (0.0.0.0/0.0.0.0:5683) received 103 bytes from /10.12.12.64:64202 2018-08-02 21:47:42,394 DEBUG RegisterResource - POST received : CON-POST MID=49396, Token=[60c0abc323f1f86f], OptionSet={"Uri-Path":"rd", "Content-Format":"application/link-format", "Uri-Query":["b=U","lwm2m=1.0","lt=30","ep=wujiabin"]}, "</>;rt="oma.lwm2m", </1/".. 53 bytes 2018-08-02 21:47:42,397 DEBUG RegistrationHandler - New registration: Registration [registrationDate=Thu Aug 02 21:47:42 EDT 2018, identity=Identity /10.12.12.64:64202[unsecure], registrationEndpoint=0.0.0.0/0.0.0.0:5683, lifeTimeInSec=30, smsNumber=null, lwM2mVersion=1.0, bindingMode=U, endpoint=wujiabin, registrationId=IykZXJA6Lz, objectLinks=[</>;rt="oma.lwm2m", </1/0>, </3/0>, </6/0>, </3303/0>], lastUpdate=Thu Aug 02 21:47:42 EDT 2018] 2018-08-02 21:47:42,399 DEBUG ReliabilityLayer - Exchange[R5] send response null-2.01 MID= -1, Token=null, OptionSet={"Location-Path":["rd","IykZXJA6Lz"]}, no payload, failed transmissions: 0 2018-08-02 21:47:42,400 DEBUG Exchange - Exchange[R5, complete]! 2018-08-02 21:47:42,401 DEBUG Exchange - Remote Exchange[R5, complete] completed ACK-2.01 MID=49396, Token=[60c0abc323f1f86f], OptionSet={"Location-Path":["rd","IykZXJA6Lz"]}, no payload! 2018-08-02 21:47:42,412 DEBUG UDPConnector$Sender - UDPConnector (Thread[UDP-Sender-0.0.0.0/0.0.0.0:5683[0],5,Californium/Elements]) sent 26 bytes to /10.12.12.64:64202 2018-08-02 21:47:42,415 DEBUG EventServlet - Dispatching REGISTRATION event from endpoint wujiabin new device: wujiabin ____1111111111111111111111 /10.12.12.64:64202 send......11111 request 2018-08-02 21:47:46,302 DEBUG SweepDeduplicator$SweepAlgorithm - Sweep run took 0ms 2018-08-02 21:47:56,303 DEBUG SweepDeduplicator$SweepAlgorithm - Sweep run took 0ms 2018-08-02 21:48:06,305 DEBUG SweepDeduplicator$SweepAlgorithm - Sweep run took 0ms 2018-08-02 21:48:09,452 DEBUG UDPConnector$Receiver - UDPConnector (0.0.0.0/0.0.0.0:5683) received 26 bytes from /10.12.12.64:64202 2018-08-02 21:48:11,515 DEBUG UDPConnector$Receiver - UDPConnector (0.0.0.0/0.0.0.0:5683) received 26 bytes from /10.12.12.64:64202 2018-08-02 21:48:14,294 DEBUG CoapSyncRequestObserver - Synchronous request cancelled CON-GET MID= -1, Token=null, OptionSet={"Uri-Path":["3","0","14"]}, no payload 2018-08-02 21:48:14,297 DEBUG EventServlet - Dispatching DEREGISTRATION event from endpoint wujiabin ____33333333333333333333333333 device left: wujiabin !!!!!response is null!!!!

hi,this is my server's log. i see that my device register,but
" Synchronous request cancelled CON-GET MID= -1, Token=null, OptionSet={"Uri-Path":["3","0","14"]}, no payload" the request is cancelled and then "my device left" then i print the log "!!!!!response is null!!!!"

this is the code: ReadResponse response = server.send(registration, new ReadRequest(3, 0, 14));

this is the windows's log, request is sent correctly

new device: wujiabin ____1111111111111111111111 /127.0.0.1:52164 ___send......11111 request 2018-08-03 10:21:28,461 DEBUG ReliabilityLayer - Exchange[L2] send request, failed transmissions: 0 2018-08-03 10:21:28,462 DEBUG ReliabilityLayer - Exchange[L2] prepare retransmission for CON-GET MID= -1, Token=null, OptionSet={"Uri-Path":["3","0","14"]}, no payload 2018-08-03 10:21:28,465 DEBUG InMemoryMessageExchangeStore - Exchange[L2] added with generated mid KeyMID[39864, [7f000001]:52164], CON-GET MID=39864, Token=null, OptionSet={"Uri-Path":["3","0","14 "]}, no payload 2018-08-03 10:21:28,467 DEBUG InMemoryMessageExchangeStore - Exchange[L2] added with generated token Token=[68f2ee540f8e1141], CON-GET MID=39864, Token=[68f2ee540f8e1141], OptionSet={"Uri-Path":["3 ","0","14"]}, no payload 2018-08-03 10:21:28,470 DEBUG UdpMatcher - tracking open request [MID: 39864, Token: Token=[68f2ee540f8e1141]] 2018-08-03 10:21:28,471 DEBUG UDPConnector$Sender - UDPConnector (Thread[UDP-Sender-0.0.0.0/0.0.0.0:5683[1],5,Californium/Elements]) sent 19 bytes to /127.0.0.1:52164 2018-08-03 10:21:28,488 DEBUG UDPConnector$Receiver - UDPConnector (0.0.0.0/0.0.0.0:5683) received 21 bytes from /127.0.0.1:52164 2018-08-03 10:21:28,490 DEBUG InMemoryMessageExchangeStore - removing Exchange[L2] for MID KeyMID[39864, [7f000001]:52164] 2018-08-03 10:21:28,492 DEBUG UdpMatcher - closed open request [KeyMID[39864, [7f000001]:52164]] 2018-08-03 10:21:28,494 DEBUG Exchange - Exchange[L2, complete]!

thanks for your patience：）

djydzgk commented 6 years ago

1. When I run leshan-server-demo.jar on Linux, the UDP port 5683 is not even opened, only TCP port 5683 is opened.

[root@localhost my]# netstat -ano|grep 5683 udp6 0 0 :::5683 ::: off (0.00/0/0) [root@localhost my]# netstat -ano|grep 5684 udp6 0 0 :::5684 ::: off (0.00/0/0

How can I open the UDP 5683? Or why it not opened?

2. When on windows , UPD 5683 is opened E:\lwm2m>netstat -ano|findstr 5683 UDP 0.0.0.0:5683 : 138560 UDP [::]:5683 : 138560

3. when i run an app (using org.eclipse.californium.core.CoapServer as coap server) on the same Linux, UPD 5683 is opened and all functions are ok. [root@localhost my]# netstat -ano|grep 5683 tcp6 0 0 :::5683 ::: LISTEN off (0.00/0/0) udp6 0 0 :::5683 ::: off (0.00/0/0)

Thanks a lot!

sbernard31 commented 6 years ago

About the logs: Your devices seems to be deregistered and so this cancel the ongoing requests linked to the current registration. So, cancellation seems "normal". The question is "Why you device deregister itself ?" or "Why the server deregister this devices ?" ... :thinking:

About udp port Did you try to deactivate your firewall ? By the way I can see any differences between your coapserver result and leshan result, except for tcp port but leshan does not use coap over tcp.

What make you think that your udp port is not opened the result of your netstat command is : udp6 0 0 :::5683 :::* off (0.00/0/0) Which I understand as it is opened.

djydzgk commented 6 years ago

thanks!

  1. I just use the leshan-server-demo.jar and leshan-client-demo.jar for test on windows and linux, but the two platforms give different result.
  2. I do deactivate my firewall, and I've try this on both Centos7 and Ubuntu, it does not work well on Ubuntu either. Are there some special rules to follow when deploying on Linux?
sbernard31 commented 6 years ago

I did nothing special on the debian we are using for our sandbox : https://leshan.eclipse.org.

djydzgk commented 6 years ago

Maybe something else of my server is not ok, thanks a lot : )

sbernard31 commented 6 years ago

Hey, Did you succeed to make it works with linux ?

djydzgk commented 6 years ago

No, It still does not work with linux.

sbernard31 commented 6 years ago

Should we close this issue ? or do you have any other inputs which could help to find the issue ?

djydzgk commented 6 years ago

No,I have no other inputs. I am not working onthis problem now, thanks!

sbernard31 commented 6 years ago

OK So I close this feel free to reopen it or open a new issue if needed.

If you finally succeed, pls let us know using this issue. Thx.