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
