2016/12/03 05:55:00 - currents1665 3.13.0-24-generic #47-Ubuntu SMP Fri May 2 23:30:00 UTC 2014 x86_64 2016/12/03 05:55:01 - /dev/ttyUSB4 2016/12/03 05:55:01 - /dev/ttyUSB5 2016/12/03 05:55:01 - In CruiseSetup.init 2016/12/03 05:55:01 - About to run mainloop 2016/12/03 09:55:35 - adcptree.py /home/data/EX1608_Testing/proc/wh300 -d uhdas --configpath /home/data/EX1608_Testing/raw/config --cruisename EX1608_Testing 2016/12/03 09:55:35 - found adcp templates at /usr/local/lib/python2.7/dist-packages/pycurrents/adcp/templates otherdemo is /usr/local/lib/python2.7/dist-packages/pycurrents/adcp/templates/uhdas_template ** data type is uhdas making directory /home/data/EX1608_Testing/proc/wh300/adcpdb making directory /home/data/EX1608_Testing/proc/wh300/cal making directory /home/data/EX1608_Testing/proc/wh300/cal/watertrk making directory /home/data/EX1608_Testing/proc/wh300/cal/botmtrk making directory /home/data/EX1608_Testing/proc/wh300/cal/heading making directory /home/data/EX1608_Testing/proc/wh300/cal/rotate making directory /home/data/EX1608_Testing/proc/wh300/contour making directory /home/data/EX1608_Testing/proc/wh300/edit making directory /home/data/EX1608_Testing/proc/wh300/grid making directory /home/data/EX1608_Testing/proc/wh300/load making directory /home/data/EX1608_Testing/proc/wh300/nav making directory /home/data/EX1608_Testing/proc/wh300/quality making directory /home/data/EX1608_Testing/proc/wh300/ping making directory /home/data/EX1608_Testing/proc/wh300/scan making directory /home/data/EX1608_Testing/proc/wh300/stick making directory /home/data/EX1608_Testing/proc/wh300/vector - copying additional files for data type uhdas - config files for raw processing are in /home/data/EX1608_Testing/proc/wh300/config copying config files using this wildcard expansion: /home/data/EX1608_Testing/raw/config/EX1608_Testing* 2016/12/03 09:55:35 - adcptree.py /home/data/EX1608_Testing/proc/os38bb -d uhdas --configpath /home/data/EX1608_Testing/raw/config --cruisename EX1608_Testing 2016/12/03 09:55:35 - found adcp templates at /usr/local/lib/python2.7/dist-packages/pycurrents/adcp/templates otherdemo is /usr/local/lib/python2.7/dist-packages/pycurrents/adcp/templates/uhdas_template ** data type is uhdas making directory /home/data/EX1608_Testing/proc/os38bb/adcpdb making directory /home/data/EX1608_Testing/proc/os38bb/cal making directory /home/data/EX1608_Testing/proc/os38bb/cal/watertrk making directory /home/data/EX1608_Testing/proc/os38bb/cal/botmtrk making directory /home/data/EX1608_Testing/proc/os38bb/cal/heading making directory /home/data/EX1608_Testing/proc/os38bb/cal/rotate making directory /home/data/EX1608_Testing/proc/os38bb/contour making directory /home/data/EX1608_Testing/proc/os38bb/edit making directory /home/data/EX1608_Testing/proc/os38bb/grid making directory /home/data/EX1608_Testing/proc/os38bb/load making directory /home/data/EX1608_Testing/proc/os38bb/nav making directory /home/data/EX1608_Testing/proc/os38bb/quality making directory /home/data/EX1608_Testing/proc/os38bb/ping making directory /home/data/EX1608_Testing/proc/os38bb/scan making directory /home/data/EX1608_Testing/proc/os38bb/stick making directory /home/data/EX1608_Testing/proc/os38bb/vector - copying additional files for data type uhdas - config files for raw processing are in /home/data/EX1608_Testing/proc/os38bb/config copying config files using this wildcard expansion: /home/data/EX1608_Testing/raw/config/EX1608_Testing* 2016/12/03 09:55:35 - adcptree.py /home/data/EX1608_Testing/proc/os38nb -d uhdas --configpath /home/data/EX1608_Testing/raw/config --cruisename EX1608_Testing 2016/12/03 09:55:35 - found adcp templates at /usr/local/lib/python2.7/dist-packages/pycurrents/adcp/templates otherdemo is /usr/local/lib/python2.7/dist-packages/pycurrents/adcp/templates/uhdas_template ** data type is uhdas making directory /home/data/EX1608_Testing/proc/os38nb/adcpdb making directory /home/data/EX1608_Testing/proc/os38nb/cal making directory /home/data/EX1608_Testing/proc/os38nb/cal/watertrk making directory /home/data/EX1608_Testing/proc/os38nb/cal/botmtrk making directory /home/data/EX1608_Testing/proc/os38nb/cal/heading making directory /home/data/EX1608_Testing/proc/os38nb/cal/rotate making directory /home/data/EX1608_Testing/proc/os38nb/contour making directory /home/data/EX1608_Testing/proc/os38nb/edit making directory /home/data/EX1608_Testing/proc/os38nb/grid making directory /home/data/EX1608_Testing/proc/os38nb/load making directory /home/data/EX1608_Testing/proc/os38nb/nav making directory /home/data/EX1608_Testing/proc/os38nb/quality making directory /home/data/EX1608_Testing/proc/os38nb/ping making directory /home/data/EX1608_Testing/proc/os38nb/scan making directory /home/data/EX1608_Testing/proc/os38nb/stick making directory /home/data/EX1608_Testing/proc/os38nb/vector - copying additional files for data type uhdas - config files for raw processing are in /home/data/EX1608_Testing/proc/os38nb/config copying config files using this wildcard expansion: /home/data/EX1608_Testing/raw/config/EX1608_Testing* 2016/12/03 09:55:37 - Entering buildLoggers 2016/12/03 09:55:37 - Created output directory with mode 775 2016/12/03 09:55:37 - Created output directory with mode 775 2016/12/03 09:55:37 - Created output directory with mode 775 2016/12/03 09:55:37 - Created output directory with mode 775 2016/12/03 09:55:37 - Created output directory with mode 775 2016/12/03 09:55:37 - >>>> C_ss enabled <<<<< 2016/12/03 09:55:37 - Leaving buildLoggers 2016/12/03 09:55:37 - Start Cruise 2016/12/03 10:24:51 - enter StartLogging, resume = 2016/12/03 10:24:51 - 0 2016/12/03 10:24:54 - TS? 2016/12/03 10:24:54 - TS16/12/03, 10:24:54 2016/12/03 10:24:54 - CR1 2016/12/03 10:24:54 - CL0 2016/12/03 10:24:54 - WD 111 000 000 2016/12/03 10:24:54 - TE00:00:00.00 2016/12/03 10:24:54 - CF11110 2016/12/03 10:24:54 - EX00000 2016/12/03 10:24:54 - EZ1011101 2016/12/03 10:24:54 - CL0 2016/12/03 10:24:54 - WP1 2016/12/03 10:24:54 - WN70 2016/12/03 10:24:54 - WS200 2016/12/03 10:24:54 - WF1000 2016/12/03 10:24:55 - BP0 2016/12/03 10:24:55 - BX2000 2016/12/03 10:24:55 - WB0 2016/12/03 10:24:55 - WV550 2016/12/03 10:24:55 - TP00:00.80 2016/12/03 10:24:55 - B? 2016/12/03 10:24:55 - W? 2016/12/03 10:24:56 - E? 2016/12/03 10:24:57 - C? 2016/12/03 10:24:58 - T? 2016/12/03 10:24:59 - PS0 2016/12/03 10:25:01 - In whbb_check_D_params 2016/12/03 10:25:01 - CF11110 2016/12/03 10:25:13 - term 1 ADCP os38 startup failure 2016/12/03 10:25:13 - Traceback (most recent call last): 2016/12/03 10:25:13 - File "/usr/local/lib/python2.7/dist-packages/uhdas/uhdas/DAS.py", line 356, in StartLogging 2016/12/03 10:25:13 - term.start_binary(cmdlist) 2016/12/03 10:25:13 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/oswh_term.py", line 234, in start_binary 2016/12/03 10:25:13 - self.wakeup() 2016/12/03 10:25:13 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/oswh_term.py", line 155, in wakeup 2016/12/03 10:25:13 - self.slow_wakeup() 2016/12/03 10:25:13 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/oswh_term.py", line 126, in slow_wakeup 2016/12/03 10:25:13 - self.waitfor(b'>', timeout=3, quiet=0.5) 2016/12/03 10:25:13 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/tk_terminal.py", line 286, in waitfor 2016/12/03 10:25:13 - raise Timeout 2016/12/03 10:25:13 - Timeout 2016/12/03 10:25:27 - TS? 2016/12/03 10:25:44 - enter StartLogging, resume = 2016/12/03 10:25:44 - 0 2016/12/03 10:25:47 - TS? 2016/12/03 10:25:47 - TS16/12/03, 10:25:47 2016/12/03 10:25:47 - CR1 2016/12/03 10:25:47 - CL0 2016/12/03 10:25:47 - WD 111 000 000 2016/12/03 10:25:47 - TE00:00:00.00 2016/12/03 10:25:47 - CF11110 2016/12/03 10:25:47 - EX00000 2016/12/03 10:25:48 - EZ1011101 2016/12/03 10:25:48 - CL0 2016/12/03 10:25:48 - WP1 2016/12/03 10:25:48 - WN70 2016/12/03 10:25:48 - WS200 2016/12/03 10:25:48 - WF1000 2016/12/03 10:25:48 - BP0 2016/12/03 10:25:48 - BX2000 2016/12/03 10:25:48 - WB0 2016/12/03 10:25:48 - WV550 2016/12/03 10:25:48 - TP00:00.80 2016/12/03 10:25:48 - B? 2016/12/03 10:25:48 - W? 2016/12/03 10:25:49 - E? 2016/12/03 10:25:50 - C? 2016/12/03 10:25:51 - T? 2016/12/03 10:25:52 - PS0 2016/12/03 10:25:54 - In whbb_check_D_params 2016/12/03 10:25:54 - CF11110 2016/12/03 10:26:07 - term 1 ADCP os38 startup failure 2016/12/03 10:26:07 - Traceback (most recent call last): 2016/12/03 10:26:07 - File "/usr/local/lib/python2.7/dist-packages/uhdas/uhdas/DAS.py", line 356, in StartLogging 2016/12/03 10:26:07 - term.start_binary(cmdlist) 2016/12/03 10:26:07 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/oswh_term.py", line 234, in start_binary 2016/12/03 10:26:07 - self.wakeup() 2016/12/03 10:26:07 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/oswh_term.py", line 155, in wakeup 2016/12/03 10:26:07 - self.slow_wakeup() 2016/12/03 10:26:07 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/oswh_term.py", line 126, in slow_wakeup 2016/12/03 10:26:07 - self.waitfor(b'>', timeout=3, quiet=0.5) 2016/12/03 10:26:07 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/tk_terminal.py", line 286, in waitfor 2016/12/03 10:26:07 - raise Timeout 2016/12/03 10:26:07 - Timeout 2016/12/03 10:26:17 - Entering Loggers.start_logging 2016/12/03 10:26:17 - /usr/local/bin/ser_bin -y 2016 -P ttyUSB4 -b 38400 -d /home/data/EX1608_Testing/raw/wh300 -i /tmp/SerialLogger/inpipe.ttyUSB4 -o /tmp/SerialLogger/outpipe.ttyUSB4 -T 1480760777 -f ex -F -m 1 -H 2 -e raw -rlE -c -O -I -Z tcp://127.0.0.1:38010 2> /tmp/stderr.ttyUSB4 & 2016/12/03 10:26:17 - /usr/local/bin/ser_bin -y 2016 -P ttyUSB5 -b 38400 -d /home/data/EX1608_Testing/raw/os38 -i /tmp/SerialLogger/inpipe.ttyUSB5 -o /tmp/SerialLogger/outpipe.ttyUSB5 -T 1480760777 -f ex -F -m 1 -H 2 -e raw -rlE -c -O -I 2> /tmp/stderr.ttyUSB5 & 2016/12/03 10:26:18 - /usr/local/bin/ser_asc -y 2016 -P ttyUSB3 -b 9600 -d /home/data/EX1608_Testing/raw/cnav -i /tmp/SerialLogger/inpipe.ttyUSB3 -o /tmp/SerialLogger/outpipe.ttyUSB3 -T 1480760777 -f ex -F -m 1 -H 2 -e gps -tc '' 2> /tmp/stderr.ttyUSB3 & 2016/12/03 10:26:18 - /usr/local/bin/zmq_asc -y 2016 -Z tcp://127.0.0.1:38000 -d /home/data/EX1608_Testing/raw/posmv -i /tmp/SerialLogger/inpipe.tcp:--127.0.0.1:38000 -o /tmp/SerialLogger/outpipe.tcp:--127.0.0.1:38000 -T 1480760777 -f ex -F -m 1 -H 2 -e pmv '$GPGGA' '$PASHR' 2> /tmp/stderr.tcp:--127.0.0.1:38000 & 2016/12/03 10:26:18 - /usr/local/bin/ser_asc -y 2016 -P ttyUSB0 -b 4800 -d /home/data/EX1608_Testing/raw/gyro -i /tmp/SerialLogger/inpipe.ttyUSB0 -o /tmp/SerialLogger/outpipe.ttyUSB0 -T 1480760777 -f ex -F -m 1 -H 2 -e hdg -tc -s5 '$HEHDT' 2> /tmp/stderr.ttyUSB0 & 2016/12/03 10:26:18 - Leaving Loggers.start_logging 2016/12/03 10:26:18 - Updated SVs_present from SVs and wrote cmds 2016/12/03 10:26:18 - 0 2016/12/03 10:26:18 - Updated SVs_present from SVs and wrote cmds 2016/12/03 10:26:18 - 1 2016/12/03 10:26:18 - Running /usr/local/currents/bin/DAS_while_logging.py 2016/12/03 10:26:18 - Exiting StartLogging 2016/12/03 10:27:09 - Entering StopLogging 2016/12/03 10:27:16 - Loggers.check_stop_logging: all log processes ended 2016/12/03 10:27:19 - TS? 2016/12/03 10:27:31 - Wakeup of os38 timed out. 2016/12/03 10:27:31 - Removed /home/adcp/flags/DAS.logging 2016/12/03 10:27:31 - Exiting StopLogging 2016/12/03 10:27:37 - enter StartLogging, resume = 2016/12/03 10:27:37 - 0 2016/12/03 10:27:40 - TS? 2016/12/03 10:27:40 - TS16/12/03, 10:27:40 2016/12/03 10:27:40 - CR1 2016/12/03 10:27:40 - CL0 2016/12/03 10:27:40 - WD 111 000 000 2016/12/03 10:27:40 - TE00:00:00.00 2016/12/03 10:27:40 - CF11110 2016/12/03 10:27:40 - EX00000 2016/12/03 10:27:40 - EZ1011101 2016/12/03 10:27:40 - CL0 2016/12/03 10:27:40 - WP1 2016/12/03 10:27:40 - WN70 2016/12/03 10:27:41 - WS200 2016/12/03 10:27:41 - WF1000 2016/12/03 10:27:41 - BP0 2016/12/03 10:27:41 - BX2000 2016/12/03 10:27:41 - WB0 2016/12/03 10:27:41 - WV550 2016/12/03 10:27:41 - TP00:00.80 2016/12/03 10:27:41 - B? 2016/12/03 10:27:41 - W? 2016/12/03 10:27:42 - E? 2016/12/03 10:27:43 - C? 2016/12/03 10:27:44 - T? 2016/12/03 10:27:45 - PS0 2016/12/03 10:27:47 - In whbb_check_D_params 2016/12/03 10:27:47 - CF11110 2016/12/03 10:27:59 - term 1 ADCP os38 startup failure 2016/12/03 10:27:59 - Traceback (most recent call last): 2016/12/03 10:27:59 - File "/usr/local/lib/python2.7/dist-packages/uhdas/uhdas/DAS.py", line 356, in StartLogging 2016/12/03 10:27:59 - term.start_binary(cmdlist) 2016/12/03 10:27:59 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/oswh_term.py", line 234, in start_binary 2016/12/03 10:27:59 - self.wakeup() 2016/12/03 10:27:59 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/oswh_term.py", line 155, in wakeup 2016/12/03 10:27:59 - self.slow_wakeup() 2016/12/03 10:27:59 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/oswh_term.py", line 126, in slow_wakeup 2016/12/03 10:27:59 - self.waitfor(b'>', timeout=3, quiet=0.5) 2016/12/03 10:27:59 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/tk_terminal.py", line 286, in waitfor 2016/12/03 10:27:59 - raise Timeout 2016/12/03 10:27:59 - Timeout 2016/12/03 10:28:09 - TS? 2016/12/03 10:28:43 - enter StartLogging, resume = 2016/12/03 10:28:43 - 0 2016/12/03 10:28:46 - TS? 2016/12/03 10:28:46 - TS16/12/03, 10:28:46 2016/12/03 10:28:46 - CR1 2016/12/03 10:28:46 - CL0 2016/12/03 10:28:46 - WD 111 000 000 2016/12/03 10:28:46 - TE00:00:00.00 2016/12/03 10:28:46 - CF11110 2016/12/03 10:28:46 - EX00000 2016/12/03 10:28:46 - EZ1011101 2016/12/03 10:28:47 - CL0 2016/12/03 10:28:47 - WP1 2016/12/03 10:28:47 - WN70 2016/12/03 10:28:47 - WS200 2016/12/03 10:28:47 - WF1000 2016/12/03 10:28:47 - BP0 2016/12/03 10:28:47 - BX2000 2016/12/03 10:28:47 - WB0 2016/12/03 10:28:47 - WV550 2016/12/03 10:28:47 - TP00:00.80 2016/12/03 10:28:47 - B? 2016/12/03 10:28:47 - W? 2016/12/03 10:28:48 - E? 2016/12/03 10:28:49 - C? 2016/12/03 10:28:50 - T? 2016/12/03 10:28:51 - PS0 2016/12/03 10:28:53 - In whbb_check_D_params 2016/12/03 10:28:53 - CF11110 2016/12/03 10:28:54 - Entering Loggers.start_logging 2016/12/03 10:28:54 - /usr/local/bin/ser_bin -y 2016 -P ttyUSB4 -b 38400 -d /home/data/EX1608_Testing/raw/wh300 -i /tmp/SerialLogger/inpipe.ttyUSB4 -o /tmp/SerialLogger/outpipe.ttyUSB4 -T 1480760934 -f ex -F -m 1 -H 2 -e raw -rlE -c -O -I -Z tcp://127.0.0.1:38010 2> /tmp/stderr.ttyUSB4 & 2016/12/03 10:28:54 - /usr/local/bin/ser_asc -y 2016 -P ttyUSB3 -b 9600 -d /home/data/EX1608_Testing/raw/cnav -i /tmp/SerialLogger/inpipe.ttyUSB3 -o /tmp/SerialLogger/outpipe.ttyUSB3 -T 1480760934 -f ex -F -m 1 -H 2 -e gps -tc '' 2> /tmp/stderr.ttyUSB3 & 2016/12/03 10:28:55 - /usr/local/bin/zmq_asc -y 2016 -Z tcp://127.0.0.1:38000 -d /home/data/EX1608_Testing/raw/posmv -i /tmp/SerialLogger/inpipe.tcp:--127.0.0.1:38000 -o /tmp/SerialLogger/outpipe.tcp:--127.0.0.1:38000 -T 1480760934 -f ex -F -m 1 -H 2 -e pmv '$GPGGA' '$PASHR' 2> /tmp/stderr.tcp:--127.0.0.1:38000 & 2016/12/03 10:28:55 - /usr/local/bin/ser_asc -y 2016 -P ttyUSB0 -b 4800 -d /home/data/EX1608_Testing/raw/gyro -i /tmp/SerialLogger/inpipe.ttyUSB0 -o /tmp/SerialLogger/outpipe.ttyUSB0 -T 1480760934 -f ex -F -m 1 -H 2 -e hdg -tc -s5 '$HEHDT' 2> /tmp/stderr.ttyUSB0 & 2016/12/03 10:28:55 - Leaving Loggers.start_logging 2016/12/03 10:28:55 - Updated SVs_present from SVs and wrote cmds 2016/12/03 10:28:55 - 0 2016/12/03 10:28:55 - Updated SVs_present from SVs and wrote cmds 2016/12/03 10:28:55 - 1 2016/12/03 10:28:55 - Running /usr/local/currents/bin/DAS_while_logging.py 2016/12/03 10:28:55 - Exiting StartLogging 2016/12/03 10:30:13 - Entering StopLogging 2016/12/03 10:30:15 - Loggers.check_stop_logging: all log processes ended 2016/12/03 10:30:19 - TS? 2016/12/03 10:30:19 - Removed /home/adcp/flags/DAS.logging 2016/12/03 10:30:19 - Exiting StopLogging 2016/12/03 10:30:29 - enter StartLogging, resume = 2016/12/03 10:30:29 - 0 2016/12/03 10:30:32 - TS? 2016/12/03 10:30:32 - TS16/12/03, 10:30:32 2016/12/03 10:30:32 - CR1 2016/12/03 10:30:32 - CL0 2016/12/03 10:30:32 - WD 111 000 000 2016/12/03 10:30:32 - TE00:00:00.00 2016/12/03 10:30:32 - CF11110 2016/12/03 10:30:32 - EX00000 2016/12/03 10:30:32 - EZ1011101 2016/12/03 10:30:33 - CL0 2016/12/03 10:30:33 - WP1 2016/12/03 10:30:33 - WN70 2016/12/03 10:30:33 - WS200 2016/12/03 10:30:33 - WF1000 2016/12/03 10:30:33 - BP0 2016/12/03 10:30:33 - BX2000 2016/12/03 10:30:33 - WB0 2016/12/03 10:30:33 - WV550 2016/12/03 10:30:33 - TP00:00.80 2016/12/03 10:30:33 - B? 2016/12/03 10:30:33 - W? 2016/12/03 10:30:34 - E? 2016/12/03 10:30:35 - C? 2016/12/03 10:30:36 - T? 2016/12/03 10:30:37 - PS0 2016/12/03 10:30:39 - In whbb_check_D_params 2016/12/03 10:30:39 - CF11110 2016/12/03 10:30:52 - term 1 ADCP os38 startup failure 2016/12/03 10:30:52 - Traceback (most recent call last): 2016/12/03 10:30:52 - File "/usr/local/lib/python2.7/dist-packages/uhdas/uhdas/DAS.py", line 356, in StartLogging 2016/12/03 10:30:52 - term.start_binary(cmdlist) 2016/12/03 10:30:52 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/oswh_term.py", line 234, in start_binary 2016/12/03 10:30:52 - self.wakeup() 2016/12/03 10:30:52 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/oswh_term.py", line 155, in wakeup 2016/12/03 10:30:52 - self.slow_wakeup() 2016/12/03 10:30:52 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/oswh_term.py", line 126, in slow_wakeup 2016/12/03 10:30:52 - self.waitfor(b'>', timeout=3, quiet=0.5) 2016/12/03 10:30:52 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/tk_terminal.py", line 286, in waitfor 2016/12/03 10:30:52 - raise Timeout 2016/12/03 10:30:52 - Timeout 2016/12/03 10:31:00 - TS? 2016/12/03 10:35:22 - enter StartLogging, resume = 2016/12/03 10:35:22 - 0 2016/12/03 10:35:25 - TS? 2016/12/03 10:35:25 - TS16/12/03, 10:35:25 2016/12/03 10:35:25 - CR1 2016/12/03 10:35:25 - CL0 2016/12/03 10:35:25 - WD 111 000 000 2016/12/03 10:35:26 - TE00:00:00.00 2016/12/03 10:35:26 - CF11110 2016/12/03 10:35:26 - EX00000 2016/12/03 10:35:26 - EZ1011101 2016/12/03 10:35:26 - CL0 2016/12/03 10:35:26 - WP1 2016/12/03 10:35:26 - WN70 2016/12/03 10:35:26 - WS200 2016/12/03 10:35:26 - WF1000 2016/12/03 10:35:26 - BP0 2016/12/03 10:35:26 - BX2000 2016/12/03 10:35:26 - WB0 2016/12/03 10:35:26 - WV550 2016/12/03 10:35:26 - TP00:00.80 2016/12/03 10:35:26 - B? 2016/12/03 10:35:26 - W? 2016/12/03 10:35:28 - E? 2016/12/03 10:35:28 - C? 2016/12/03 10:35:29 - T? 2016/12/03 10:35:31 - PS0 2016/12/03 10:35:32 - In whbb_check_D_params 2016/12/03 10:35:32 - CF11110 2016/12/03 10:35:33 - Entering Loggers.start_logging 2016/12/03 10:35:33 - /usr/local/bin/ser_bin -y 2016 -P ttyUSB4 -b 38400 -d /home/data/EX1608_Testing/raw/wh300 -i /tmp/SerialLogger/inpipe.ttyUSB4 -o /tmp/SerialLogger/outpipe.ttyUSB4 -T 1480761333 -f ex -F -m 1 -H 2 -e raw -rlE -c -O -I -Z tcp://127.0.0.1:38010 2> /tmp/stderr.ttyUSB4 & 2016/12/03 10:35:34 - /usr/local/bin/ser_asc -y 2016 -P ttyUSB3 -b 9600 -d /home/data/EX1608_Testing/raw/cnav -i /tmp/SerialLogger/inpipe.ttyUSB3 -o /tmp/SerialLogger/outpipe.ttyUSB3 -T 1480761333 -f ex -F -m 1 -H 2 -e gps -tc '' 2> /tmp/stderr.ttyUSB3 & 2016/12/03 10:35:34 - /usr/local/bin/zmq_asc -y 2016 -Z tcp://127.0.0.1:38000 -d /home/data/EX1608_Testing/raw/posmv -i /tmp/SerialLogger/inpipe.tcp:--127.0.0.1:38000 -o /tmp/SerialLogger/outpipe.tcp:--127.0.0.1:38000 -T 1480761333 -f ex -F -m 1 -H 2 -e pmv '$GPGGA' '$PASHR' 2> /tmp/stderr.tcp:--127.0.0.1:38000 & 2016/12/03 10:35:34 - /usr/local/bin/ser_asc -y 2016 -P ttyUSB0 -b 4800 -d /home/data/EX1608_Testing/raw/gyro -i /tmp/SerialLogger/inpipe.ttyUSB0 -o /tmp/SerialLogger/outpipe.ttyUSB0 -T 1480761333 -f ex -F -m 1 -H 2 -e hdg -tc -s5 '$HEHDT' 2> /tmp/stderr.ttyUSB0 & 2016/12/03 10:35:34 - Leaving Loggers.start_logging 2016/12/03 10:35:34 - Updated SVs_present from SVs and wrote cmds 2016/12/03 10:35:34 - 0 2016/12/03 10:35:34 - Updated SVs_present from SVs and wrote cmds 2016/12/03 10:35:34 - 1 2016/12/03 10:35:34 - Running /usr/local/currents/bin/DAS_while_logging.py 2016/12/03 10:35:34 - Exiting StartLogging 2016/12/03 23:26:18 - Entering StopLogging 2016/12/03 23:26:24 - Loggers.check_stop_logging: all log processes ended 2016/12/03 23:26:27 - TS? 2016/12/03 23:26:27 - Removed /home/adcp/flags/DAS.logging 2016/12/03 23:26:27 - Exiting StopLogging 2016/12/04 02:29:42 - Ready to destroy_loggers. 2016/12/04 02:29:42 - After destroy_loggers. 2016/12/04 02:29:42 - cp -au /home/adcp/log/* /home/data/EX1608_Testing/raw/log/ 2016/12/04 02:29:42 - End Cruise 2016/12/04 02:30:09 - adcptree.py /home/data/EX1608_01/proc/wh300 -d uhdas --configpath /home/data/EX1608_01/raw/config --cruisename EX1608_01 2016/12/04 02:30:09 - found adcp templates at /usr/local/lib/python2.7/dist-packages/pycurrents/adcp/templates otherdemo is /usr/local/lib/python2.7/dist-packages/pycurrents/adcp/templates/uhdas_template ** data type is uhdas making directory /home/data/EX1608_01/proc/wh300/adcpdb making directory /home/data/EX1608_01/proc/wh300/cal making directory /home/data/EX1608_01/proc/wh300/cal/watertrk making directory /home/data/EX1608_01/proc/wh300/cal/botmtrk making directory /home/data/EX1608_01/proc/wh300/cal/heading making directory /home/data/EX1608_01/proc/wh300/cal/rotate making directory /home/data/EX1608_01/proc/wh300/contour making directory /home/data/EX1608_01/proc/wh300/edit making directory /home/data/EX1608_01/proc/wh300/grid making directory /home/data/EX1608_01/proc/wh300/load making directory /home/data/EX1608_01/proc/wh300/nav making directory /home/data/EX1608_01/proc/wh300/quality making directory /home/data/EX1608_01/proc/wh300/ping making directory /home/data/EX1608_01/proc/wh300/scan making directory /home/data/EX1608_01/proc/wh300/stick making directory /home/data/EX1608_01/proc/wh300/vector - copying additional files for data type uhdas - config files for raw processing are in /home/data/EX1608_01/proc/wh300/config copying config files using this wildcard expansion: /home/data/EX1608_01/raw/config/EX1608_01* 2016/12/04 02:30:09 - adcptree.py /home/data/EX1608_01/proc/os38bb -d uhdas --configpath /home/data/EX1608_01/raw/config --cruisename EX1608_01 2016/12/04 02:30:09 - found adcp templates at /usr/local/lib/python2.7/dist-packages/pycurrents/adcp/templates otherdemo is /usr/local/lib/python2.7/dist-packages/pycurrents/adcp/templates/uhdas_template ** data type is uhdas making directory /home/data/EX1608_01/proc/os38bb/adcpdb making directory /home/data/EX1608_01/proc/os38bb/cal making directory /home/data/EX1608_01/proc/os38bb/cal/watertrk making directory /home/data/EX1608_01/proc/os38bb/cal/botmtrk making directory /home/data/EX1608_01/proc/os38bb/cal/heading making directory /home/data/EX1608_01/proc/os38bb/cal/rotate making directory /home/data/EX1608_01/proc/os38bb/contour making directory /home/data/EX1608_01/proc/os38bb/edit making directory /home/data/EX1608_01/proc/os38bb/grid making directory /home/data/EX1608_01/proc/os38bb/load making directory /home/data/EX1608_01/proc/os38bb/nav making directory /home/data/EX1608_01/proc/os38bb/quality making directory /home/data/EX1608_01/proc/os38bb/ping making directory /home/data/EX1608_01/proc/os38bb/scan making directory /home/data/EX1608_01/proc/os38bb/stick making directory /home/data/EX1608_01/proc/os38bb/vector - copying additional files for data type uhdas - config files for raw processing are in /home/data/EX1608_01/proc/os38bb/config copying config files using this wildcard expansion: /home/data/EX1608_01/raw/config/EX1608_01* 2016/12/04 02:30:09 - adcptree.py /home/data/EX1608_01/proc/os38nb -d uhdas --configpath /home/data/EX1608_01/raw/config --cruisename EX1608_01 2016/12/04 02:30:09 - found adcp templates at /usr/local/lib/python2.7/dist-packages/pycurrents/adcp/templates otherdemo is /usr/local/lib/python2.7/dist-packages/pycurrents/adcp/templates/uhdas_template ** data type is uhdas making directory /home/data/EX1608_01/proc/os38nb/adcpdb making directory /home/data/EX1608_01/proc/os38nb/cal making directory /home/data/EX1608_01/proc/os38nb/cal/watertrk making directory /home/data/EX1608_01/proc/os38nb/cal/botmtrk making directory /home/data/EX1608_01/proc/os38nb/cal/heading making directory /home/data/EX1608_01/proc/os38nb/cal/rotate making directory /home/data/EX1608_01/proc/os38nb/contour making directory /home/data/EX1608_01/proc/os38nb/edit making directory /home/data/EX1608_01/proc/os38nb/grid making directory /home/data/EX1608_01/proc/os38nb/load making directory /home/data/EX1608_01/proc/os38nb/nav making directory /home/data/EX1608_01/proc/os38nb/quality making directory /home/data/EX1608_01/proc/os38nb/ping making directory /home/data/EX1608_01/proc/os38nb/scan making directory /home/data/EX1608_01/proc/os38nb/stick making directory /home/data/EX1608_01/proc/os38nb/vector - copying additional files for data type uhdas - config files for raw processing are in /home/data/EX1608_01/proc/os38nb/config copying config files using this wildcard expansion: /home/data/EX1608_01/raw/config/EX1608_01* 2016/12/04 02:30:10 - Entering buildLoggers 2016/12/04 02:30:10 - Created output directory with mode 775 2016/12/04 02:30:10 - Created output directory with mode 775 2016/12/04 02:30:10 - Created output directory with mode 775 2016/12/04 02:30:10 - Created output directory with mode 775 2016/12/04 02:30:10 - Created output directory with mode 775 2016/12/04 02:30:10 - >>>> C_ss enabled <<<<< 2016/12/04 02:30:10 - Leaving buildLoggers 2016/12/04 02:30:10 - Start Cruise 2016/12/04 02:31:44 - enter StartLogging, resume = 2016/12/04 02:31:44 - 0 2016/12/04 02:31:47 - TS? 2016/12/04 02:31:47 - TS16/12/04, 02:31:47 2016/12/04 02:31:47 - CR1 2016/12/04 02:31:47 - CL0 2016/12/04 02:31:47 - WD 111 000 000 2016/12/04 02:31:47 - TE00:00:00.00 2016/12/04 02:31:47 - CF11110 2016/12/04 02:31:47 - EX00000 2016/12/04 02:31:47 - EZ1011101 2016/12/04 02:31:47 - CL0 2016/12/04 02:31:47 - WP1 2016/12/04 02:31:47 - WN70 2016/12/04 02:31:48 - WS200 2016/12/04 02:31:48 - WF1000 2016/12/04 02:31:48 - BP0 2016/12/04 02:31:48 - BX2000 2016/12/04 02:31:48 - WB0 2016/12/04 02:31:48 - WV550 2016/12/04 02:31:48 - TP00:00.80 2016/12/04 02:31:48 - B? 2016/12/04 02:31:48 - W? 2016/12/04 02:31:49 - E? 2016/12/04 02:31:50 - C? 2016/12/04 02:31:51 - T? 2016/12/04 02:31:52 - PS0 2016/12/04 02:31:54 - In whbb_check_D_params 2016/12/04 02:31:54 - CF11110 2016/12/04 02:31:57 - TS? 2016/12/04 02:31:58 - TS161204023158 2016/12/04 02:31:58 - CR1 2016/12/04 02:31:58 - WD 111 00 0000 2016/12/04 02:31:58 - ND 111 00 0000 2016/12/04 02:31:58 - EA04500 2016/12/04 02:31:58 - NP1 2016/12/04 02:31:58 - NN60 2016/12/04 02:31:58 - NS2400 2016/12/04 02:31:58 - NF1600 2016/12/04 02:31:58 - WP1 2016/12/04 02:31:58 - WN80 2016/12/04 02:31:58 - WS1200 2016/12/04 02:31:58 - WF1600 2016/12/04 02:31:58 - BP0 2016/12/04 02:31:58 - BX10000 2016/12/04 02:31:59 - TP00:03.00 2016/12/04 02:31:59 - CX0,0 2016/12/04 02:31:59 - B? 2016/12/04 02:31:59 - N? 2016/12/04 02:32:01 - W? 2016/12/04 02:32:02 - E? 2016/12/04 02:32:04 - C? 2016/12/04 02:32:06 - T? 2016/12/04 02:32:06 - PS0 2016/12/04 02:32:07 - In os_check_D_params 2016/12/04 02:32:07 - in os_check_D_params: 111000000 2016/12/04 02:32:07 - in os_check_D_params: 111000000 2016/12/04 02:32:07 - CF11110 2016/12/04 02:32:08 - Entering Loggers.start_logging 2016/12/04 02:32:08 - /usr/local/bin/ser_bin -y 2016 -P ttyUSB4 -b 38400 -d /home/data/EX1608_01/raw/wh300 -i /tmp/SerialLogger/inpipe.ttyUSB4 -o /tmp/SerialLogger/outpipe.ttyUSB4 -T 1480818728 -f ex -F -m 1 -H 2 -e raw -rlE -c -O -I -Z tcp://127.0.0.1:38010 2> /tmp/stderr.ttyUSB4 & 2016/12/04 02:32:09 - /usr/local/bin/ser_bin -y 2016 -P ttyUSB5 -b 38400 -d /home/data/EX1608_01/raw/os38 -i /tmp/SerialLogger/inpipe.ttyUSB5 -o /tmp/SerialLogger/outpipe.ttyUSB5 -T 1480818728 -f ex -F -m 1 -H 2 -e raw -rlE -c -O -I 2> /tmp/stderr.ttyUSB5 & 2016/12/04 02:32:09 - /usr/local/bin/ser_asc -y 2016 -P ttyUSB3 -b 9600 -d /home/data/EX1608_01/raw/cnav -i /tmp/SerialLogger/inpipe.ttyUSB3 -o /tmp/SerialLogger/outpipe.ttyUSB3 -T 1480818728 -f ex -F -m 1 -H 2 -e gps -tc '' 2> /tmp/stderr.ttyUSB3 & 2016/12/04 02:32:09 - /usr/local/bin/zmq_asc -y 2016 -Z tcp://127.0.0.1:38000 -d /home/data/EX1608_01/raw/posmv -i /tmp/SerialLogger/inpipe.tcp:--127.0.0.1:38000 -o /tmp/SerialLogger/outpipe.tcp:--127.0.0.1:38000 -T 1480818728 -f ex -F -m 1 -H 2 -e pmv '$GPGGA' '$PASHR' 2> /tmp/stderr.tcp:--127.0.0.1:38000 & 2016/12/04 02:32:09 - /usr/local/bin/ser_asc -y 2016 -P ttyUSB0 -b 4800 -d /home/data/EX1608_01/raw/gyro -i /tmp/SerialLogger/inpipe.ttyUSB0 -o /tmp/SerialLogger/outpipe.ttyUSB0 -T 1480818728 -f ex -F -m 1 -H 2 -e hdg -tc -s5 '$HEHDT' 2> /tmp/stderr.ttyUSB0 & 2016/12/04 02:32:09 - Leaving Loggers.start_logging 2016/12/04 02:32:09 - Updated SVs_present from SVs and wrote cmds 2016/12/04 02:32:09 - 0 2016/12/04 02:32:09 - Updated SVs_present from SVs and wrote cmds 2016/12/04 02:32:09 - 1 2016/12/04 02:32:09 - Running /usr/local/currents/bin/DAS_while_logging.py 2016/12/04 02:32:09 - Exiting StartLogging 2016/12/04 03:01:45 - Entering StopLogging 2016/12/04 03:01:55 - Changed Mind 2016/12/04 03:02:30 - Entering StopLogging 2016/12/04 03:02:33 - Loggers.check_stop_logging: all log processes ended 2016/12/04 03:02:33 - Wakeup of wh300 timed out. 2016/12/04 03:02:37 - Wakeup of os38 timed out. 2016/12/04 03:02:37 - Removed /home/adcp/flags/DAS.logging 2016/12/04 03:02:37 - Exiting StopLogging 2016/12/04 03:02:41 - enter StartLogging, resume = 2016/12/04 03:02:41 - 0 2016/12/04 03:02:41 - An unexpected active lock file was found. 2016/12/04 03:02:41 - The lock file is /var/lock/LCK..ttyUSB4. 2016/12/04 03:02:41 - Lock is owned by this process, with pid = 7736. 2016/12/04 03:02:41 - term 0 ADCP wh300 startup failure 2016/12/04 03:02:41 - Traceback (most recent call last): 2016/12/04 03:02:41 - File "/usr/local/lib/python2.7/dist-packages/uhdas/uhdas/DAS.py", line 356, in StartLogging 2016/12/04 03:02:41 - term.start_binary(cmdlist) 2016/12/04 03:02:41 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/oswh_term.py", line 234, in start_binary 2016/12/04 03:02:41 - self.wakeup() 2016/12/04 03:02:41 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/oswh_term.py", line 155, in wakeup 2016/12/04 03:02:41 - self.slow_wakeup() 2016/12/04 03:02:41 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/oswh_term.py", line 111, in slow_wakeup 2016/12/04 03:02:41 - self.change_baud(self.default_baud) 2016/12/04 03:02:41 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/tk_terminal.py", line 527, in change_baud 2016/12/04 03:02:41 - self.open_port(save=False) 2016/12/04 03:02:41 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/serialport.py", line 72, in open_port 2016/12/04 03:02:41 - sp_lock.lock_port(self.__device) # Raises exception if locked. 2016/12/04 03:02:41 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/sp_lock.py", line 74, in lock_port 2016/12/04 03:02:41 - check_lock(device) 2016/12/04 03:02:41 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/sp_lock.py", line 71, in check_lock 2016/12/04 03:02:41 - raise LockedError(status, device) 2016/12/04 03:02:41 - LockedError: (1, '/dev/ttyUSB4') 2016/12/04 03:02:56 - enter StartLogging, resume = 2016/12/04 03:02:56 - 0 2016/12/04 03:02:56 - An unexpected active lock file was found. 2016/12/04 03:02:56 - The lock file is /var/lock/LCK..ttyUSB4. 2016/12/04 03:02:56 - Lock is owned by this process, with pid = 7736. 2016/12/04 03:02:56 - term 0 ADCP wh300 startup failure 2016/12/04 03:02:56 - Traceback (most recent call last): 2016/12/04 03:02:56 - File "/usr/local/lib/python2.7/dist-packages/uhdas/uhdas/DAS.py", line 356, in StartLogging 2016/12/04 03:02:56 - term.start_binary(cmdlist) 2016/12/04 03:02:56 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/oswh_term.py", line 234, in start_binary 2016/12/04 03:02:56 - self.wakeup() 2016/12/04 03:02:56 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/oswh_term.py", line 155, in wakeup 2016/12/04 03:02:56 - self.slow_wakeup() 2016/12/04 03:02:56 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/oswh_term.py", line 111, in slow_wakeup 2016/12/04 03:02:56 - self.change_baud(self.default_baud) 2016/12/04 03:02:56 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/tk_terminal.py", line 527, in change_baud 2016/12/04 03:02:56 - self.open_port(save=False) 2016/12/04 03:02:56 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/serialport.py", line 72, in open_port 2016/12/04 03:02:56 - sp_lock.lock_port(self.__device) # Raises exception if locked. 2016/12/04 03:02:56 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/sp_lock.py", line 74, in lock_port 2016/12/04 03:02:56 - check_lock(device) 2016/12/04 03:02:56 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/sp_lock.py", line 71, in check_lock 2016/12/04 03:02:56 - raise LockedError(status, device) 2016/12/04 03:02:56 - LockedError: (1, '/dev/ttyUSB4') 2016/12/04 03:02:59 - Exception in thread Thread-20: Traceback (most recent call last): File "/usr/lib/python2.7/threading.py", line 810, in __bootstrap_inner self.run() File "/usr/lib/python2.7/threading.py", line 763, in run self.__target(*self.__args, **self.__kwargs) File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/tk_terminal.py", line 415, in listen self.outfile.write(cc) ValueError: I/O operation on closed file 2016/12/04 03:03:02 - term 1 ADCP os38 startup failure 2016/12/04 03:03:02 - Traceback (most recent call last): 2016/12/04 03:03:02 - File "/usr/local/lib/python2.7/dist-packages/uhdas/uhdas/DAS.py", line 356, in StartLogging 2016/12/04 03:03:02 - term.start_binary(cmdlist) 2016/12/04 03:03:02 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/oswh_term.py", line 234, in start_binary 2016/12/04 03:03:02 - self.wakeup() 2016/12/04 03:03:02 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/oswh_term.py", line 155, in wakeup 2016/12/04 03:03:02 - self.slow_wakeup() 2016/12/04 03:03:02 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/oswh_term.py", line 117, in slow_wakeup 2016/12/04 03:03:02 - self.waitfor(timeout=2.5, quiet=0.5) 2016/12/04 03:03:02 - File "/usr/local/lib/python2.7/dist-packages/uhdas/serial/tk_terminal.py", line 286, in waitfor 2016/12/04 03:03:02 - raise Timeout 2016/12/04 03:03:02 - Timeout 2016/12/04 03:03:13 - Entering Loggers.start_logging 2016/12/04 03:03:13 - /usr/local/bin/ser_bin -y 2016 -P ttyUSB4 -b 38400 -d /home/data/EX1608_01/raw/wh300 -i /tmp/SerialLogger/inpipe.ttyUSB4 -o /tmp/SerialLogger/outpipe.ttyUSB4 -T 1480820593 -f ex -F -m 1 -H 2 -e raw -rlE -c -O -I -Z tcp://127.0.0.1:38010 2> /tmp/stderr.ttyUSB4 &