1 INFO NodeMain [main]: NodeMain.main(): portalHost = null 1396 INFO NodeManager [main]: Starting NodeManager at 02/20/2016 12:33:09 GMT (1455971589702), version: $Name: $ 1398 INFO NodeManager [main]: Node IP: node2/134.89.36.2 2070 INFO NodeManager [main]: Node ID has been set to 1598 3285 INFO PortManager [main]: Found 14 configured ports in properties file 3348 INFO MOOSPortManager [main]: Found DPA at slot: 0 5229 INFO MOOSPortManager [main]: Found DPA at slot: 1 6839 INFO MOOSPortManager [main]: Found DPA at slot: 2 8429 INFO MOOSPortManager [main]: Found DPA at slot: 3 10017 INFO MOOSPortManager [main]: No DPA found at slot: 4 10021 INFO MOOSPortManager [main]: No DPA found at slot: 5 10056 INFO WDTManager [main]: WDTManager constructor 10057 INFO MOOSWDTManager [main]: MOOSWDTManager constructor 10121 INFO SleepManager [main]: SleepManager constructor 10124 INFO MOOSSleepManager [main]: MOOSSleepManager constructor 11805 INFO CommsLeaseListener [main]: CommsLeaseListener() complete 11871 INFO CpuLeaseSleepRollcallListener [main]: CpuLeaseSleepRollcallListener() constructor 11886 INFO CpuLease [main]: CpuLease() constructor 11908 INFO CpuLease [Thread-5]: CpuLease started 13916 ERROR NodeService [main]: Turbinator constructor failed: com.rbnb.sapi.SAPIException: Nesting java.net.ConnectException 14055 INFO MOOSNodeService [main]: Last MMC reset code: 6 14255 INFO NodeManager [main]: Starting registry... 14293 INFO NodeManager [main]: registry started. 14294 INFO NodeManager [main]: binding NodeService to rmi://localhost/node 14884 INFO NodeManager [main]: NodeService is bound to rmi://localhost/node 15025 INFO MOOSWDTManager [Thread-2]: WDTManager initializing watchdog timer 15033 ERROR MOOSWDTManager [Thread-2]: !!! Reboot due to watchdog reset !!! 15207 INFO PortManager [main]: Service jar not specified for port /dev/ttySX0 15872 INFO MOOSWDTManager [Thread-2]: WDTManager watchdog initialization successful 16170 INFO PortManager [main]: Starting service... 32365 INFO BaseInstrumentService [main]: initializeInstrument() for 33939 WARN StreamingSBE19 [main]: Did not receive expected confirmation prompt from command: MP 38964 INFO StreamingSBE19 [main]: Event detection disabled by attribute 39073 INFO BaseInstrumentService [main]: done with initializeInstrument() for 47163 INFO PortManager [main]: service started 47649 INFO NodeManager [Thread-1]: serviceInstalled(): invoke remote callbacks 48366 INFO PortManager [main]: Starting service... 68855 INFO BaseInstrumentService [main]: initializeInstrument() for 68857 INFO WetLabsECO [main]: Initializing... 84298 INFO WetLabsECO [main]: Initializing completed 84299 INFO BaseInstrumentService [main]: done with initializeInstrument() for 93341 INFO PolledInstrumentService [main]: prepareToRun(): sampleMasterId = 1827 93343 INFO PolledInstrumentService [main]: id 1535 slaved to 1827 93362 INFO PortManager [main]: service started 93365 INFO NodeManager [Thread-1]: serviceInstalled(): invoke remote callbacks 93447 INFO WetLabsECO [Thread-25]: TEST: ID=1535, trigger sample at 1455971681761 95477 INFO PortManager [main]: Starting service... 95824 INFO WetLabsECO [Thread-25]: TEST: ID=1535, got complete sample at + 1455971684137 157712 INFO BaseInstrumentService [main]: initializeInstrument() for 159728 INFO Aquadopp [main]: sendSoftBreak(): instrument in mode 2 165896 INFO BaseInstrumentService [main]: done with initializeInstrument() for 166013 INFO Aquadopp [main]: Retrieving Aquadopp state Metadata... 167997 INFO Aquadopp [main]: sendSoftBreak(): instrument in mode 2 175818 INFO PortManager [main]: service started 175825 INFO NodeManager [Thread-1]: serviceInstalled(): invoke remote callbacks 176264 INFO PortManager [main]: Starting service... 177957 INFO Aquadopp [Thread-34]: sendSoftBreak(): instrument in mode 2 187504 INFO BaseInstrumentService [main]: initializeInstrument() for 189308 ERROR StreamingInstrumentService [Thread-34]: acquireFromStream(), tried startStreaming(): Instrument didn't acknowledge SR command 192407 INFO BaseInstrumentService [main]: done with initializeInstrument() for 194299 INFO PolledInstrumentService [main]: prepareToRun(): sampleMasterId = 1535 194300 INFO PolledInstrumentService [main]: id 1524 slaved to 1535 194306 INFO PortManager [main]: service started 194315 INFO NodeManager [Thread-1]: serviceInstalled(): invoke remote callbacks 194327 INFO AanderaaO2 [Thread-38]: TT: ID=1524, trigger sample at 1455971782641 195390 INFO PortManager [main]: Starting service... 231261 INFO StreamingWorkhorseADCP-0 [main]: getSerialParameters(): baud=9600 236884 INFO BaseInstrumentService [main]: initializeInstrument() for 236886 INFO StreamingWorkhorseADCP-1825 [main]: Initializing Workhorse 1825 236896 INFO StreamingWorkhorseADCP-1825 [main]: Instrument has been pre-configured; ignore configuration attributes 239785 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request TE? 239823 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 239867 INFO StreamingWorkhorseADCP-1825 [main]: TE response: TE 00:00:10.00 --------- Time per Ensemble (hrs:min:sec.sec/100) > 239868 INFO StreamingWorkhorseADCP-1825 [main]: getProperty(): response=TE 00:00:10.00 --------- Time per Ensemble (hrs:min:sec.sec/100) > 240144 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request CF? 240191 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 240249 INFO StreamingWorkhorseADCP-1825 [main]: initializeInstrument(): response = CF = 11111 --------------- Flow Ctrl (EnsCyc;PngCyc;Binry;Ser;Rec) > 240250 INFO StreamingWorkhorseADCP-1825 [main]: getProperty(): response=CF = 11111 --------------- Flow Ctrl (EnsCyc;PngCyc;Binry;Ser;Rec) > 240252 INFO StreamingWorkhorseADCP-1825 [main]: initializeInstrument(): property=11111 --------------- Flow Ctrl (EnsCyc;PngCyc;Binry;Ser;Rec) >, char 3=1 240253 INFO StreamingWorkhorseADCP-1825 [main]: initializeInstrument(): property char 3=1 240255 INFO StreamingWorkhorseADCP-1825 [main]: Start pinging 240442 INFO BaseInstrumentService [main]: done with initializeInstrument() for 243434 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request WD? 243473 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 244014 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request WF? 244053 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 244585 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request WN? 244668 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 245195 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request WP? 245233 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 245764 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request WS? 245803 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 246334 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request WV? 246421 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 246955 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request TE? 247030 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 247574 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request TP? 247613 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 248144 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request TS? 248188 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 248734 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request EA? 248773 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 249305 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request EB? 249343 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 249875 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request ED? 249913 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 250455 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request ES? 250493 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 251024 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request EX? 251063 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 251604 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request EZ? 251691 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 252226 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request CF? 252267 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 252825 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request RA? 252845 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 253484 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request RR? 253523 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 259031 ERROR StreamingWorkhorseADCP-1825 [main]: sendRequest caught Timeout Exception: org.mbari.siam.distributed.TimeoutException: readUntil() Timed out after 5502 ms outbuf.len=8192 avail: 109 read: 5257Request=RR? 260115 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request RR? 262385 ERROR StreamingWorkhorseADCP-1825 [main]: sendRequest caught Timeout Exception: org.mbari.siam.distributed.TimeoutException: SkipUntil() Timed outRequest=RR? 263475 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request RR? 265715 ERROR StreamingWorkhorseADCP-1825 [main]: sendRequest caught Timeout Exception: org.mbari.siam.distributed.TimeoutException: SkipUntil() Timed outRequest=RR? 266302 ERROR StreamingWorkhorseADCP-1825 [main]: getInstrumentMetadata: Exception - java.lang.Exception: sendRequest(RR?) - Maximum retries attempted java.lang.Exception: sendRequest(RR?) - Maximum retries attempted Stack trace: java/lang/Throwable.()V java/lang/Throwable.(Ljava/lang/String;)V org/mbari/siam/devices/workhorse/StreamingWorkhorseADCP.sendRequest(Ljava/lang/String;)Ljava/lang/String; org/mbari/siam/devices/workhorse/StreamingWorkhorseADCP.getInstrumentStateMetadata()[B org/mbari/siam/core/BaseInstrumentService.getMetadataPayload(I[Ljava/lang/String;)[B org/mbari/siam/core/BaseInstrumentService.getMetadata([BI[Ljava/lang/String;Z)Lorg/mbari/siam/distributed/MetadataPacket; org/mbari/siam/core/BaseInstrumentService.getMetadata([BIZ)Lorg/mbari/siam/distributed/MetadataPacket; org/mbari/siam/core/BaseInstrumentService.prepareToRun()V org/mbari/siam/core/PortManager.scanPort(Lorg/mbari/siam/core/DevicePort;Ljava/lang/String;)V org/mbari/siam/core/PortManager.scanPorts()V org/mbari/siam/core/NodeManager.start(Ljava/lang/String;Ljava/lang/String;)V org/mbari/siam/core/NodeMain.main([Ljava/lang/String;)V 266581 INFO PortManager [main]: service started 266585 INFO NodeManager [Thread-1]: serviceInstalled(): invoke remote callbacks 268431 INFO PortManager [main]: Starting service... 340407 ERROR DeviceLog [main]: readLogData: data size mismatch 340409 ERROR DeviceLog [main]: bytes read from file: 1173 340410 ERROR DeviceLog [main]: dataSize in index entry: 1927 340486 INFO StreamingWorkhorseADCP-0 [main]: getSerialParameters(): baud=9600 351155 INFO BaseInstrumentService [main]: initializeInstrument() for 351157 INFO StreamingWorkhorseADCP-1828 [main]: Initializing Workhorse 1828 351167 INFO StreamingWorkhorseADCP-1828 [main]: Instrument has been pre-configured; ignore configuration attributes 353865 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request TE? 353904 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 354002 INFO StreamingWorkhorseADCP-1828 [main]: TE response: TE 00:00:10.00 --------- Time per Ensemble (hrs:min:sec.sec/100) > 354004 INFO StreamingWorkhorseADCP-1828 [main]: getProperty(): response=TE 00:00:10.00 --------- Time per Ensemble (hrs:min:sec.sec/100) > 354264 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request CF? 354303 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 354369 INFO StreamingWorkhorseADCP-1828 [main]: initializeInstrument(): response = CF = 11111 --------------- Flow Ctrl (EnsCyc;PngCyc;Binry;Ser;Rec) > 354370 INFO StreamingWorkhorseADCP-1828 [main]: getProperty(): response=CF = 11111 --------------- Flow Ctrl (EnsCyc;PngCyc;Binry;Ser;Rec) > 354372 INFO StreamingWorkhorseADCP-1828 [main]: initializeInstrument(): property=11111 --------------- Flow Ctrl (EnsCyc;PngCyc;Binry;Ser;Rec) >, char 3=1 354384 INFO StreamingWorkhorseADCP-1828 [main]: initializeInstrument(): property char 3=1 354385 INFO StreamingWorkhorseADCP-1828 [main]: Start pinging 354572 INFO BaseInstrumentService [main]: done with initializeInstrument() for 357415 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request WD? 357458 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 358035 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request WF? 358073 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 358635 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request WN? 358673 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 359244 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request WP? 359283 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 359835 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request WS? 359873 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 360404 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request WV? 360444 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 360984 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request TE? 361023 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 361564 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request TP? 361603 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 362134 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request TS? 362173 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 362715 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request EA? 362753 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 363284 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request EB? 363323 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 363855 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request ED? 363893 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 364424 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request ES? 364463 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 364995 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request EX? 365035 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 365574 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request EZ? 365614 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 366216 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request CF? 366421 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 366957 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request RA? 366981 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 367546 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request RR? 367593 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 373168 ERROR StreamingWorkhorseADCP-1828 [main]: sendRequest caught Timeout Exception: org.mbari.siam.distributed.TimeoutException: readUntil() Timed out after 5528 ms outbuf.len=8192 avail: 56 read: 5344Request=RR? 374275 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request RR? 376493 ERROR StreamingWorkhorseADCP-1828 [main]: sendRequest caught Timeout Exception: org.mbari.siam.distributed.TimeoutException: SkipUntil() Timed outRequest=RR? 377586 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request RR? 379805 ERROR StreamingWorkhorseADCP-1828 [main]: sendRequest caught Timeout Exception: org.mbari.siam.distributed.TimeoutException: SkipUntil() Timed outRequest=RR? 380375 ERROR StreamingWorkhorseADCP-1828 [main]: getInstrumentMetadata: Exception - java.lang.Exception: sendRequest(RR?) - Maximum retries attempted java.lang.Exception: sendRequest(RR?) - Maximum retries attempted Stack trace: java/lang/Throwable.()V java/lang/Throwable.(Ljava/lang/String;)V org/mbari/siam/devices/workhorse/StreamingWorkhorseADCP.sendRequest(Ljava/lang/String;)Ljava/lang/String; org/mbari/siam/devices/workhorse/StreamingWorkhorseADCP.getInstrumentStateMetadata()[B org/mbari/siam/core/BaseInstrumentService.getMetadataPayload(I[Ljava/lang/String;)[B org/mbari/siam/core/BaseInstrumentService.getMetadata([BI[Ljava/lang/String;Z)Lorg/mbari/siam/distributed/MetadataPacket; org/mbari/siam/core/BaseInstrumentService.getMetadata([BIZ)Lorg/mbari/siam/distributed/MetadataPacket; org/mbari/siam/core/BaseInstrumentService.prepareToRun()V org/mbari/siam/core/PortManager.scanPort(Lorg/mbari/siam/core/DevicePort;Ljava/lang/String;)V org/mbari/siam/core/PortManager.scanPorts()V org/mbari/siam/core/NodeManager.start(Ljava/lang/String;Ljava/lang/String;)V org/mbari/siam/core/NodeMain.main([Ljava/lang/String;)V