Closed miraenator closed 7 years ago
kevinherron
commented
7 years ago I don't think there's any harm in increasing test timeouts so it builds more reliably on the RPi.
That said, it's pretty uncommon to run the build on the RPi itself and there's no real reason to do so, so I'm not sure the effort of putting together a dedicated guide is worth it.
kevinherron
commented
7 years ago Okay, seeing which timeout you're actually talking about now, it's a little more work than I thought. The hardcoded 5-second timeout waiting for an Acknowledge to the initial Hello should be configurable and then the tests should just configure a higher value.
kevinherron
commented
7 years ago If you can, try building the ack-timeout branch https://github.com/eclipse/milo/tree/ack-timeout on your RPi and see if the tests still timeout.
miraenator
commented
7 years ago It blocks (freezes) again (tried 2x). According to the load of the system, it stays low (1.8 max). When compared to the main branch (where the load peaked to 12), it seems that the tests fail in an early phase.
Output of: mvn clean compile package -Dorg.slf4j.simpleLogger.defaultLogLevel=debug
...
-------------------------------------------------------
T E S T S
-------------------------------------------------------
Running TestSuite
[main] INFO org.eclipse.milo.opcua.stack.core.Stack - Successfully removed cryptography restrictions.
[main] DEBUG io.netty.util.internal.logging.InternalLoggerFactory - Using SLF4J as the default logging framework
[main] DEBUG io.netty.util.internal.PlatformDependent0 - java.nio.Buffer.address: available
[main] DEBUG io.netty.util.internal.PlatformDependent0 - sun.misc.Unsafe.theUnsafe: available
[main] DEBUG io.netty.util.internal.PlatformDependent0 - sun.misc.Unsafe.copyMemory: available
[main] DEBUG io.netty.util.internal.PlatformDependent0 - java.nio.Bits.unaligned: false
[main] DEBUG io.netty.util.internal.PlatformDependent - Java version: 8
[main] DEBUG io.netty.util.internal.PlatformDependent - -Dio.netty.noUnsafe: false
[main] DEBUG io.netty.util.internal.PlatformDependent - sun.misc.Unsafe: available
[main] DEBUG io.netty.util.internal.PlatformDependent - -Dio.netty.noJavassist: false
[main] DEBUG io.netty.util.internal.PlatformDependent - Javassist: unavailable
[main] DEBUG io.netty.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.
[main] DEBUG io.netty.util.internal.PlatformDependent - -Dio.netty.tmpdir: /tmp (java.io.tmpdir)
[main] DEBUG io.netty.util.internal.PlatformDependent - -Dio.netty.bitMode: 32 (sun.arch.data.model)
[main] DEBUG io.netty.util.internal.PlatformDependent - -Dio.netty.noPreferDirect: false
[main] DEBUG io.netty.util.ResourceLeakDetector - -Dio.netty.leakDetection.level: simple
[main] DEBUG io.netty.util.ResourceLeakDetector - -Dio.netty.leakDetection.maxRecords: 4
[main] DEBUG io.netty.channel.MultithreadEventLoopGroup - -Dio.netty.eventLoopThreads: 2
[main] DEBUG io.netty.channel.nio.NioEventLoop - -Dio.netty.noKeySetOptimization: false
[main] DEBUG io.netty.channel.nio.NioEventLoop - -Dio.netty.selectorAutoRebuildThreshold: 512
[main] DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.numHeapArenas: 1
[main] DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.numDirectArenas: 1
[main] DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.pageSize: 8192
[main] DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.maxOrder: 11
[main] DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.chunkSize: 16777216
[main] DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.tinyCacheSize: 512
[main] DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.smallCacheSize: 256
[main] DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.normalCacheSize: 64
[main] DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.maxCachedBufferCapacity: 32768
[main] DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.cacheTrimInterval: 8192
[main] DEBUG io.netty.util.internal.ThreadLocalRandom - -Dio.netty.initialSeedUniquifier: 0x80ceba3873d0dbba (took 14 ms)
[main] DEBUG io.netty.buffer.ByteBufUtil - -Dio.netty.allocator.type: unpooled
[main] DEBUG io.netty.buffer.ByteBufUtil - -Dio.netty.threadLocalDirectBufferSize: 65536
[main] DEBUG io.netty.buffer.ByteBufUtil - -Dio.netty.maxThreadLocalCharBufferSize: 16384
[main] DEBUG io.netty.util.NetUtil - Loopback interface: lo (lo, 0:0:0:0:0:0:0:1%lo)
[main] DEBUG io.netty.util.NetUtil - /proc/sys/net/core/somaxconn: 128
[ua-netty-event-loop-0] DEBUG org.eclipse.milo.opcua.stack.server.tcp.SocketServers$SocketServer - [id: 0x4abadc56] REGISTERED
[ua-netty-event-loop-0] DEBUG org.eclipse.milo.opcua.stack.server.tcp.SocketServers$SocketServer - [id: 0x4abadc56] BIND(localhost/127.0.0.1:12685)
[main] INFO org.eclipse.milo.opcua.stack.server.tcp.UaTcpStackServer - opc.tcp://localhost:12685/test bound to localhost:12685 [None/None]
[ua-netty-event-loop-0] DEBUG org.eclipse.milo.opcua.stack.server.tcp.SocketServers$SocketServer - [id: 0x4abadc56, L:/127.0.0.1:12685] ACTIVE
[main] DEBUG org.eclipse.milo.opcua.stack.server.tcp.SocketServers$SocketServer - Added server at path: "/test"
[main] INFO org.eclipse.milo.opcua.stack.server.tcp.UaTcpStackServer - opc.tcp://localhost:12685/test bound to localhost:12685 [Basic128Rsa15/Sign]
[main] INFO org.eclipse.milo.opcua.stack.server.tcp.UaTcpStackServer - opc.tcp://localhost:12685/test bound to localhost:12685 [Basic256/Sign]
[main] INFO org.eclipse.milo.opcua.stack.server.tcp.UaTcpStackServer - opc.tcp://localhost:12685/test bound to localhost:12685 [Basic256Sha256/Sign]
[main] INFO org.eclipse.milo.opcua.stack.server.tcp.UaTcpStackServer - opc.tcp://localhost:12685/test bound to localhost:12685 [Basic128Rsa15/SignAndEncrypt]
[main] INFO org.eclipse.milo.opcua.stack.server.tcp.UaTcpStackServer - opc.tcp://localhost:12685/test bound to localhost:12685 [Basic256/SignAndEncrypt]
[main] INFO org.eclipse.milo.opcua.stack.server.tcp.UaTcpStackServer - opc.tcp://localhost:12685/test bound to localhost:12685 [Basic256Sha256/SignAndEncrypt]
[ua-netty-event-loop-0] DEBUG org.eclipse.milo.opcua.stack.server.tcp.SocketServers$SocketServer - [id: 0x4abadc56, L:/127.0.0.1:12685] RECEIVED: [id: 0x24d15e6a, L:/127.0.0.1:12685 - R:/127.0.0.1:47126]
[ua-netty-event-loop-1] DEBUG io.netty.buffer.AbstractByteBuf - -Dio.netty.buffer.bytebuf.checkAccessible: true
[Thread-0] DEBUG org.eclipse.milo.opcua.stack.client.ClientChannelManager - Channel bootstrap failed: timed out waiting for acknowledge
UaException: status=Bad_Timeout, message=timed out waiting for acknowledge
at org.eclipse.milo.opcua.stack.client.handlers.UaTcpClientAcknowledgeHandler.lambda$startHelloTimeout$4(UaTcpClientAcknowledgeHandler.java:158)
at io.netty.util.HashedWheelTimer$HashedWheelTimeout.expire(HashedWheelTimer.java:581)
at io.netty.util.HashedWheelTimer$HashedWheelBucket.expireTimeouts(HashedWheelTimer.java:655)
at io.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.java:367)
at java.lang.Thread.run(Thread.java:745)P.S.: ad 'not sure the effort of putting together a dedicated guide is worth it.': I did not mean a guide to compile the project, but to use it, such as: Easy OPC UA temperature server for RPi
kevinherron
commented
7 years ago I have a Pi here somewhere, I'll have to futz around this weekend to see just how slow some of the tests run and what the timeout needs to be.
I do keep a poorly updated UA server for RPi here: https://github.com/kevinherron/pi-server
Kind of a mess as it was mostly used for a demo, but it does know how to read from a GrovePi temperature and humidity sensor...
Hi,
I'm trying to compile Milo on Raspberry Pi (B+) with the command
mvn clean compile packageand the package phase freezes (infinitely) on the stack.server.tcpUaTcpStackServer test (see below, LISTING1).The problem is caused by short timeout = 5 seconds in the file
stack/client/handlers/UaTcpClientAcknowledgeHandler.java(line 162) where the RPi is not able to fulfill the test in time. Therefore, I tried to increase the timeout to 10 secs first (LISTING 3) and the test results (errors) revealed elapsed times about 30-50 secs. After increasing the timeout to 120 secs (LISTING 2) all tests passed.I've monitored the 1/5/15-minute load and during the compile phase, the load was about 1.5, however, in the test/package phase it peaked to the values of 12 (5min. avg to 8). This clearly shows, that the processor (1core) is overloaded by the tests.
I've made more tests and the timeout of 12 seconds is the cutting time (3 times OK, 2 times did not package). Therefore, minimum of 15 secs should be used.
The question is whether is it ok to:
Failing test can diverge many people, interested in the Milo project, to concurrent projects. Therefore I think, this should be fixed (or, at least for RPI/arm explicitly mentioned, i.e.: tutorial on how to compile for RPi).
IMHO, also a tutorial how to create a simple server on RPi and client on desktop (i.e. for home temperature(s) monitoring would be helpful). According to my experience, people (incl. me) are not sure where to start with OPC UA. And, provided that many RPi users are students/beginners, they would find it difficult to learn by (uncommented) examples and unit-tests.
Thanks for fixing,
m.
=== LISTING 2: DIFF, 120 secs ===
=== LISTING 3: Timeout: 10 sec ===
Output of
mvn -e -X package -Dorg.slf4j.simpleLogger.defaultLogLevel=debugOutput for timeout of 10 sec:=== LISTING 1 === Original sources: ends with errorr (original timeout of 5 sec).
=== System Info ==== System info:
=== Note (amd64) === On amd64 architecture (Debian Jessie), everything passes (even with increased timeout).