1 INFO NodeMain [main]: NodeMain.main(): portalHost = null 1379 INFO NodeManager [main]: Starting NodeManager at 02/21/2016 15:54:08 GMT (1456070048725), version: $Name: $ 1381 INFO NodeManager [main]: Node IP: node2/134.89.36.2 2043 INFO NodeManager [main]: Node ID has been set to 1598 3223 INFO PortManager [main]: Found 14 configured ports in properties file 3248 INFO MOOSPortManager [main]: Found DPA at slot: 0 5139 INFO MOOSPortManager [main]: Found DPA at slot: 1 6749 INFO MOOSPortManager [main]: Found DPA at slot: 2 8339 INFO MOOSPortManager [main]: Found DPA at slot: 3 9927 INFO MOOSPortManager [main]: No DPA found at slot: 4 9931 INFO MOOSPortManager [main]: No DPA found at slot: 5 9966 INFO WDTManager [main]: WDTManager constructor 9967 INFO MOOSWDTManager [main]: MOOSWDTManager constructor 10031 INFO SleepManager [main]: SleepManager constructor 10034 INFO MOOSSleepManager [main]: MOOSSleepManager constructor 11735 INFO CommsLeaseListener [main]: CommsLeaseListener() complete 11801 INFO CpuLeaseSleepRollcallListener [main]: CpuLeaseSleepRollcallListener() constructor 11816 INFO CpuLease [main]: CpuLease() constructor 11818 INFO CpuLease [Thread-5]: CpuLease started 13796 ERROR NodeService [main]: Turbinator constructor failed: com.rbnb.sapi.SAPIException: Nesting java.net.ConnectException 13895 INFO MOOSNodeService [main]: Last MMC reset code: 6 14125 INFO NodeManager [main]: Starting registry... 14166 INFO NodeManager [main]: registry started. 14167 INFO NodeManager [main]: binding NodeService to rmi://localhost/node 14725 INFO NodeManager [main]: NodeService is bound to rmi://localhost/node 14750 INFO MOOSWDTManager [Thread-2]: WDTManager initializing watchdog timer 14896 ERROR MOOSWDTManager [Thread-2]: !!! Reboot due to watchdog reset !!! 15082 INFO PortManager [main]: Service jar not specified for port /dev/ttySX0 16003 INFO PortManager [main]: Starting service... 16335 INFO MOOSWDTManager [Thread-2]: WDTManager watchdog initialization successful 31804 INFO BaseInstrumentService [main]: initializeInstrument() for 33379 WARN StreamingSBE19 [main]: Did not receive expected confirmation prompt from command: MP 38414 INFO StreamingSBE19 [main]: Event detection disabled by attribute 38486 INFO BaseInstrumentService [main]: done with initializeInstrument() for 46882 INFO PortManager [main]: service started 47439 INFO NodeManager [Thread-1]: serviceInstalled(): invoke remote callbacks 48120 INFO PortManager [main]: Starting service... 68435 INFO BaseInstrumentService [main]: initializeInstrument() for 68436 INFO WetLabsECO [main]: Initializing... 83828 INFO WetLabsECO [main]: Initializing completed 83829 INFO BaseInstrumentService [main]: done with initializeInstrument() for 92851 INFO PolledInstrumentService [main]: prepareToRun(): sampleMasterId = 1827 92853 INFO PolledInstrumentService [main]: id 1535 slaved to 1827 92873 INFO PortManager [main]: service started 92874 INFO NodeManager [Thread-1]: serviceInstalled(): invoke remote callbacks 92897 INFO WetLabsECO [Thread-25]: TEST: ID=1535, trigger sample at 1456070140250 94988 INFO PortManager [main]: Starting service... 95272 INFO WetLabsECO [Thread-25]: TEST: ID=1535, got complete sample at + 1456070142626 155802 INFO BaseInstrumentService [main]: initializeInstrument() for 157868 INFO Aquadopp [main]: sendSoftBreak(): instrument in mode 2 164046 INFO BaseInstrumentService [main]: done with initializeInstrument() for 164153 INFO Aquadopp [main]: Retrieving Aquadopp state Metadata... 166177 INFO Aquadopp [main]: sendSoftBreak(): instrument in mode 2 173952 INFO PortManager [main]: service started 173955 INFO NodeManager [Thread-1]: serviceInstalled(): invoke remote callbacks 174371 INFO PortManager [main]: Starting service... 176067 INFO Aquadopp [Thread-34]: sendSoftBreak(): instrument in mode 2 185535 INFO BaseInstrumentService [main]: initializeInstrument() for 187454 ERROR StreamingInstrumentService [Thread-34]: acquireFromStream(), tried startStreaming(): Instrument didn't acknowledge SR command 190457 INFO BaseInstrumentService [main]: done with initializeInstrument() for 192379 INFO PolledInstrumentService [main]: prepareToRun(): sampleMasterId = 1535 192380 INFO PolledInstrumentService [main]: id 1524 slaved to 1535 192387 INFO PortManager [main]: service started 192395 INFO NodeManager [Thread-1]: serviceInstalled(): invoke remote callbacks 192407 INFO AanderaaO2 [Thread-38]: TT: ID=1524, trigger sample at 1456070239761 193471 INFO PortManager [main]: Starting service... 227893 INFO StreamingWorkhorseADCP-0 [main]: getSerialParameters(): baud=9600 233525 INFO BaseInstrumentService [main]: initializeInstrument() for 233527 INFO StreamingWorkhorseADCP-1825 [main]: Initializing Workhorse 1825 233537 INFO StreamingWorkhorseADCP-1825 [main]: Instrument has been pre-configured; ignore configuration attributes 236485 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request TE? 236524 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 236567 INFO StreamingWorkhorseADCP-1825 [main]: TE response: TE 00:00:10.00 --------- Time per Ensemble (hrs:min:sec.sec/100) > 236569 INFO StreamingWorkhorseADCP-1825 [main]: getProperty(): response=TE 00:00:10.00 --------- Time per Ensemble (hrs:min:sec.sec/100) > 236854 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request CF? 236893 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 236938 INFO StreamingWorkhorseADCP-1825 [main]: initializeInstrument(): response = CF = 11111 --------------- Flow Ctrl (EnsCyc;PngCyc;Binry;Ser;Rec) > 236939 INFO StreamingWorkhorseADCP-1825 [main]: getProperty(): response=CF = 11111 --------------- Flow Ctrl (EnsCyc;PngCyc;Binry;Ser;Rec) > 236941 INFO StreamingWorkhorseADCP-1825 [main]: initializeInstrument(): property=11111 --------------- Flow Ctrl (EnsCyc;PngCyc;Binry;Ser;Rec) >, char 3=1 236943 INFO StreamingWorkhorseADCP-1825 [main]: initializeInstrument(): property char 3=1 236944 INFO StreamingWorkhorseADCP-1825 [main]: Start pinging 237132 INFO BaseInstrumentService [main]: done with initializeInstrument() for 240184 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request WD? 240223 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 240764 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request WF? 240803 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 241334 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request WN? 241411 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 242001 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request WP? 242049 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 242574 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request WS? 242613 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 243164 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request WV? 243203 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 243735 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request TE? 243773 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 244345 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request TP? 244383 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 244915 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request TS? 244954 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 245494 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request EA? 245533 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 246064 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request EB? 246103 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 246634 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request ED? 246712 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 247263 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request ES? 247306 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 247834 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request EX? 247873 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 248425 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request EZ? 248463 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 248994 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request CF? 249034 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 249604 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request RA? 249626 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 250412 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request RR? 250465 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: got echo response: 255974 ERROR StreamingWorkhorseADCP-1825 [main]: sendRequest caught Timeout Exception: org.mbari.siam.distributed.TimeoutException: readUntil() Timed out after 5502 ms outbuf.len=8192 avail: 10 read: 5396Request=RR? 257055 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request RR? 259295 ERROR StreamingWorkhorseADCP-1825 [main]: sendRequest caught Timeout Exception: org.mbari.siam.distributed.TimeoutException: SkipUntil() Timed outRequest=RR? 260364 INFO StreamingWorkhorseADCP-1825 [main]: sendRequest: wrote request RR? 262572 ERROR StreamingWorkhorseADCP-1825 [main]: sendRequest caught Timeout Exception: org.mbari.siam.distributed.TimeoutException: SkipUntil() Timed outRequest=RR? 263162 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 263394 INFO PortManager [main]: service started 263404 INFO NodeManager [Thread-1]: serviceInstalled(): invoke remote callbacks 265404 INFO PortManager [main]: Starting service... 336267 ERROR DeviceLog [main]: readLogData: data size mismatch 336268 ERROR DeviceLog [main]: bytes read from file: 1173 336269 ERROR DeviceLog [main]: dataSize in index entry: 1927 336377 INFO StreamingWorkhorseADCP-0 [main]: getSerialParameters(): baud=9600 347054 INFO BaseInstrumentService [main]: initializeInstrument() for 347056 INFO StreamingWorkhorseADCP-1828 [main]: Initializing Workhorse 1828 347066 INFO StreamingWorkhorseADCP-1828 [main]: Instrument has been pre-configured; ignore configuration attributes 349775 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request TE? 349815 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 349869 INFO StreamingWorkhorseADCP-1828 [main]: TE response: TE 00:00:10.00 --------- Time per Ensemble (hrs:min:sec.sec/100) > 349870 INFO StreamingWorkhorseADCP-1828 [main]: getProperty(): response=TE 00:00:10.00 --------- Time per Ensemble (hrs:min:sec.sec/100) > 350127 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request CF? 350176 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 350387 INFO StreamingWorkhorseADCP-1828 [main]: initializeInstrument(): response = CF = 11111 --------------- Flow Ctrl (EnsCyc;PngCyc;Binry;Ser;Rec) > 350389 INFO StreamingWorkhorseADCP-1828 [main]: getProperty(): response=CF = 11111 --------------- Flow Ctrl (EnsCyc;PngCyc;Binry;Ser;Rec) > 350391 INFO StreamingWorkhorseADCP-1828 [main]: initializeInstrument(): property=11111 --------------- Flow Ctrl (EnsCyc;PngCyc;Binry;Ser;Rec) >, char 3=1 350392 INFO StreamingWorkhorseADCP-1828 [main]: initializeInstrument(): property char 3=1 350393 INFO StreamingWorkhorseADCP-1828 [main]: Start pinging 350692 INFO BaseInstrumentService [main]: done with initializeInstrument() for 353664 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request WD? 353705 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 354245 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request WF? 354284 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 354835 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request WN? 354873 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 355415 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request WP? 355454 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 355986 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request WS? 356034 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 356615 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request WV? 356653 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 357234 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request TE? 357274 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 357845 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request TP? 357884 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 358445 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request TS? 358484 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 359035 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request EA? 359073 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 359624 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request EB? 359663 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 360234 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request ED? 360273 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 360845 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request ES? 360884 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 361464 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request EX? 361504 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 362054 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request EZ? 362094 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 362664 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request CF? 362704 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 363264 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request RA? 363286 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 363864 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request RR? 363904 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: got echo response: 369419 ERROR StreamingWorkhorseADCP-1828 [main]: sendRequest caught Timeout Exception: org.mbari.siam.distributed.TimeoutException: readUntil() Timed out after 5511 ms outbuf.len=8192 avail: 2026 read: 3346Request=RR? 372114 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request RR? 374317 ERROR StreamingWorkhorseADCP-1828 [main]: sendRequest caught Timeout Exception: org.mbari.siam.distributed.TimeoutException: SkipUntil() Timed outRequest=RR? 377695 INFO StreamingWorkhorseADCP-1828 [main]: sendRequest: wrote request RR? 380065 ERROR StreamingWorkhorseADCP-1828 [main]: sendRequest caught Timeout Exception: org.mbari.siam.distributed.TimeoutException: SkipUntil() Timed outRequest=RR? 380635 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