search

itm / testbed-runtime

WISEBED Wireless Sensor Network Testbed Infrastructure Software
https://github.com/itm/testbed-runtime/wiki
15 stars 11 forks source link

Exception when flashing nodes for the second time #196

Closed danbim closed 12 years ago

danbim commented 12 years ago

When flashing nodes the second time after IWSN restart the following error message is logged:

2012-07-18 14:28:19,029 | pool-36-thread-1               | WSNDeviceAppConnector          | WARN  | urn:wisebed:uzl1:0x2000 => flashProgram: Failed flashing node. Reason: de.uniluebeck.itm.wsn.drivers.core.exception.TimeoutException
2012-07-18 14:28:19,031 | :wisebed:uzl1:0x2001]-Driver 3 | ion$$EnhancerByGuice$$c4a1461d | ERROR | Exception during operation execution
de.uniluebeck.itm.wsn.drivers.core.exception.TimeoutException
    at de.uniluebeck.itm.wsn.drivers.core.AbstractConnection.waitDataAvailable(AbstractConnection.java:105)
    at de.uniluebeck.itm.wsn.drivers.jennic.JennicHelper.receiveBootloaderReply(JennicHelper.java:151)
    at de.uniluebeck.itm.wsn.drivers.jennic.JennicGetChipTypeOperation.callInternal(JennicGetChipTypeOperation.java:63)
    at de.uniluebeck.itm.wsn.drivers.core.serialport.SerialPortProgrammingModeInterceptor.invoke(SerialPortProgrammingModeInterceptor.java:39)
    at de.uniluebeck.itm.wsn.drivers.jennic.JennicGetChipTypeOperation.callInternal(JennicGetChipTypeOperation.java:21)
    at de.uniluebeck.itm.wsn.drivers.core.operation.TimeLimitedOperation$1.call(TimeLimitedOperation.java:115)
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
    at java.util.concurrent.FutureTask.run(FutureTask.java:138)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:662)
    at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:232)
    at java.util.concurrent.FutureTask.get(FutureTask.java:91)
    at com.google.common.util.concurrent.Uninterruptibles.getUninterruptibly(Uninterruptibles.java:164)
    at com.google.common.util.concurrent.SimpleTimeLimiter.callWithTimeout(SimpleTimeLimiter.java:136)
    at de.uniluebeck.itm.wsn.drivers.core.operation.TimeLimitedOperation.call(TimeLimitedOperation.java:112)
    at de.uniluebeck.itm.wsn.drivers.core.operation.TimeLimitedOperation.runSubOperation(TimeLimitedOperation.java:209)
    at de.uniluebeck.itm.wsn.drivers.jennic.JennicProgramOperation.callInternal(JennicProgramOperation.java:55)
    at de.uniluebeck.itm.wsn.drivers.jennic.JennicProgramOperation$$EnhancerByGuice$$7f608822.CGLIB$callInternal$0(<generated>)
    at de.uniluebeck.itm.wsn.drivers.jennic.JennicProgramOperation$$EnhancerByGuice$$7f608822$$FastClassByGuice$$ad62d2f.invoke(<generated>)
    at com.google.inject.internal.cglib.proxy.$MethodProxy.invokeSuper(MethodProxy.java:228)
    at com.google.inject.internal.InterceptorStackCallback$InterceptedMethodInvocation.proceed(InterceptorStackCallback.java:72)
    at de.uniluebeck.itm.wsn.drivers.core.serialport.SerialPortProgrammingModeInterceptor.invoke(SerialPortProgrammingModeInterceptor.java:49)
    at com.google.inject.internal.InterceptorStackCallback$InterceptedMethodInvocation.proceed(InterceptorStackCallback.java:72)
    at com.google.inject.internal.InterceptorStackCallback.intercept(InterceptorStackCallback.java:52)
    at de.uniluebeck.itm.wsn.drivers.jennic.JennicProgramOperation$$EnhancerByGuice$$7f608822.callInternal(<generated>)
    at de.uniluebeck.itm.wsn.drivers.jennic.JennicProgramOperation.callInternal(JennicProgramOperation.java:18)
    at de.uniluebeck.itm.wsn.drivers.core.operation.TimeLimitedOperation$1.call(TimeLimitedOperation.java:115)
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
    at java.util.concurrent.FutureTask.run(FutureTask.java:138)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:662)

This happens e.g., if I flash the node with the uart_test program of wiselib twice consecutively.

danbim commented 12 years ago

Searched long for this issue today but couldn't find the root cause yet. It seems that somehow the connection between the driver streams and the channel sink of Netty is broken so that no messages are being read from the streams. But this seems to be just an effect of the root cause. When trying to flash the "waiting for boot loader" process times out which indicates that some other Thread is reading from the device stream.

danbim commented 12 years ago

Base line: we should make a code review of the thread synchronization logic that works its magic between the application thread and rxtx threads.

Maybe even a rewrite using simple message queues inside the driver would do the job less error-prone.