0 Replies Latest reply on Mar 23, 2016 1:21 PM by trauhut RSS
    trauhut Explorer

    Problem connecting Java Edge SDK to Server using osgi felix framework and websockets

    Hello Community,

     

    I got a device with osgi felix framework (if i got it right) and try to get connection to our could.

     

    After a while i fixed connection with a java (jar) program running on it using http.

    Right now i am trying to get my websocket connection working, but i have some issues getting connection.

    Before i put it on my device i tested my program with eclipse and everything works fine.

     

    I got this ERROR / DEBUG:

     

     

    23:47:34.456 [Timer-0] INFO  c.t.c.c.p.ClientMessageProcessor - Created new ClientMessageProcessor [minPoolSize: 4, maxPoolSize: 10, maxThreadLife: 10000, maxQueueSize: 1000]

    23:47:34.994 [Timer-0] DEBUG i.n.u.i.l.InternalLoggerFactory - Using SLF4J as the default logging framework

    23:47:35.030 [Timer-0] DEBUG i.n.c.MultithreadEventLoopGroup - -Dio.netty.eventLoopThreads: 2

    23:47:35.114 [Timer-0] DEBUG i.n.util.internal.PlatformDependent0 - sun.nio.ch.DirectBuffer.cleaner(): available

    23:47:35.122 [Timer-0] DEBUG i.n.util.internal.PlatformDependent0 - java.nio.Buffer.address: available

    23:47:35.124 [Timer-0] DEBUG i.n.util.internal.PlatformDependent0 - sun.misc.Unsafe.theUnsafe: available

    23:47:35.126 [Timer-0] DEBUG i.n.util.internal.PlatformDependent0 - sun.misc.Unsafe.copyMemory: available

    23:47:35.129 [Timer-0] DEBUG i.n.util.internal.PlatformDependent0 - java.nio.Bits.unaligned: true

    23:47:35.164 [Timer-0] DEBUG i.n.util.internal.PlatformDependent - Could not determine the current UID using /usr/bin/id; attempting to bind at privileged ports.

    23:47:35.167 [Timer-0] DEBUG i.n.util.internal.PlatformDependent - UID: 0 (succeded to bind at port 1023)

    23:47:35.174 [Timer-0] DEBUG i.n.util.internal.PlatformDependent - Java version: 7

    23:47:35.176 [Timer-0] DEBUG i.n.util.internal.PlatformDependent - -Dio.netty.noUnsafe: false

    23:47:35.176 [Timer-0] DEBUG i.n.util.internal.PlatformDependent - sun.misc.Unsafe: available

    23:47:35.181 [Timer-0] DEBUG i.n.util.internal.PlatformDependent - -Dio.netty.noJavassist: false

    23:47:35.188 [Timer-0] DEBUG i.n.util.internal.PlatformDependent - Javassist: unavailable

    23:47:35.189 [Timer-0] DEBUG i.n.util.internal.PlatformDependent - You don't have Javassist in your class path or you don't have enough permission to load dynamically generated classes.  Please check the configuration for better performance.

    23:47:35.194 [Timer-0] WARN  i.n.util.internal.PlatformDependent - Failed to get the temporary directory; falling back to: /tmp

    23:47:35.196 [Timer-0] DEBUG i.n.util.internal.PlatformDependent - -Dio.netty.bitMode: 32 (sun.arch.data.model)

    23:47:35.196 [Timer-0] DEBUG i.n.util.internal.PlatformDependent - -Dio.netty.noPreferDirect: false

    23:47:35.490 [Timer-0] DEBUG io.netty.channel.nio.NioEventLoop - -Dio.netty.noKeySetOptimization: false

    23:47:35.492 [Timer-0] DEBUG io.netty.channel.nio.NioEventLoop - -Dio.netty.selectorAutoRebuildThreshold: 512

    23:47:35.693 [Timer-0] DEBUG i.n.buffer.PooledByteBufAllocator - -Dio.netty.allocator.numHeapArenas: 0

    23:47:35.694 [Timer-0] DEBUG i.n.buffer.PooledByteBufAllocator - -Dio.netty.allocator.numDirectArenas: 0

    23:47:35.696 [Timer-0] DEBUG i.n.buffer.PooledByteBufAllocator - -Dio.netty.allocator.pageSize: 8192

    23:47:35.696 [Timer-0] DEBUG i.n.buffer.PooledByteBufAllocator - -Dio.netty.allocator.maxOrder: 11

    23:47:35.696 [Timer-0] DEBUG i.n.buffer.PooledByteBufAllocator - -Dio.netty.allocator.chunkSize: 16777216

    23:47:35.697 [Timer-0] DEBUG i.n.buffer.PooledByteBufAllocator - -Dio.netty.allocator.tinyCacheSize: 512

    23:47:35.697 [Timer-0] DEBUG i.n.buffer.PooledByteBufAllocator - -Dio.netty.allocator.smallCacheSize: 256

    23:47:35.697 [Timer-0] DEBUG i.n.buffer.PooledByteBufAllocator - -Dio.netty.allocator.normalCacheSize: 64

    23:47:35.698 [Timer-0] DEBUG i.n.buffer.PooledByteBufAllocator - -Dio.netty.allocator.maxCachedBufferCapacity: 32768

    23:47:35.700 [Timer-0] DEBUG i.n.buffer.PooledByteBufAllocator - -Dio.netty.allocator.cacheTrimInterval: 8192

    23:47:35.700 [Timer-0] DEBUG i.n.buffer.PooledByteBufAllocator - -Dio.netty.allocator.cacheCleanupInterval: 5000 ms

    23:47:35.732 [Timer-0] DEBUG c.t.c.c.e.m.CommunicationEndpointMonitorTask - Initializing CommunicationEndpoint Connection Monitor...

    23:47:35.744 [Client-EndpointMonitor-1] DEBUG c.t.c.c.e.m.CommunicationEndpointMonitorTask - CommunicationEndpoint Monitor - checking for disconnected endpoints

    23:47:35.747 [Client-EndpointMonitor-1] INFO  c.t.c.c.e.m.CommunicationEndpointMonitorTask - Endpoint not connected [name: EP_0, id: 0]. Attempting [re]connect...

    23:47:35.749 [Client-EndpointMonitor-1] DEBUG c.t.c.c.e.ClientCommunicationEndpoint - Clearing endpoint authentication data [id: 0]

    23:47:35.749 [Client-EndpointMonitor-1] INFO  c.t.c.c.e.ClientCommunicationEndpoint - Needed to refill connections on client endpoint [id: 0] : [active: 0, max: 1]

    ...

    23:47:40.025 [Client-EndpointMonitor-1] DEBUG i.n.util.internal.ThreadLocalRandom - -Dio.netty.initialSeedUniquifier: 0xf24f7ba025faae8c

    23:47:40.084 [Client-EndpointMonitor-1] DEBUG i.n.channel.ChannelOutboundBuffer - -Dio.netty.threadLocalDirectBufferSize: 65536

    23:47:40.089 [Client-EndpointMonitor-1] DEBUG io.netty.util.Recycler - -Dio.netty.recycler.maxCapacity.default: 262144

    23:47:40.204 [Client-EndpointMonitor-1] DEBUG io.netty.buffer.ByteBufUtil - -Dio.netty.allocator.type: unpooled

    23:47:40.574 [NettyClient-NIO-1] DEBUG io.netty.util.ResourceLeakDetector - -Dio.netty.leakDetectionLevel: simple

    ...

    23:47:50.273 [Client-EndpointMonitor-1] INFO  c.t.c.c.c.n.NettyClientConnectionFactory - forcing underlying tcp channel closed [is open: false, is active: false]

    23:47:50.277 [Client-EndpointMonitor-1] ERROR c.t.c.c.e.ClientCommunicationEndpoint - Refilling connections on [endpoint 0, uri: ws://*.*.*.*:80/Thingworx/WS] failed : timeout waiting for websocket handshake to complete

    23:47:50.279 [Client-EndpointMonitor-1] INFO  c.t.c.c.e.m.CommunicationEndpointMonitorTask - Endpoint reconnection was unsuccessful [name: EP_0, id: 0]

     

     

    I Thing especially the last 3 lines are important...

    My device is in the same network as my pc. Right now for debugging reasons its directly connected to my pc by LAN cable and so connected to the internet.

    I also took a look at my network traffic and followed it using wireshark.

     

    No Time Source Dstination Protocol Length Info

    107 27.141011 device -> cloud TCP 62 64692 → 80 [SYN] Seq=0 Win=60000 Len=0 MSS=1416 WS=1

    108 27.242567 cloud -> device TCP 62 80 → 64692 [SYN, ACK] Seq=0 Ack=1 Win=26883 Len=0 MSS=8961 WS=128

    109 27.242951 device -> cloud TCP 60 64692 → 80 [ACK] Seq=1 Ack=1 Win=60000 Len=0

    110 27.243904 device -> cloud TCP 60 64692 → 80 [FIN, ACK] Seq=1 Ack=1 Win=60000 Len=0

    111 27.344677 cloud -> device TCP 54 80 → 64692 [FIN, ACK] Seq=1 Ack=2 Win=27008 Len=0

    112 27.344951 device -> cloud TCP 60 64692 → 80 [ACK] Seq=2 Ack=2 Win=60000 Len=0

     

    Noramlly after the third action my device should use a http request to ask the server (cloud) for a websocket conenction...

     

    Could anyone explain my problem?

    What does this ERROR mean.

    Why is my device not able to start a websocket connection?

     

    Maybe you also have got some idea to fix this issue.

     

    Thanks

    Timo