2018-11-05T21:31:26.971Z,1541453486.971 [CommandLine](IMPORTANT): got command restart logs
2018-11-05T21:31:32.877Z,1541453492.877 [NAL9602](INFO): SBD MO Status=0, MOMSN=10466, MT Status=0, MTMSN=0
2018-11-05T21:31:32.877Z,1541453492.877 [NAL9602](INFO): No messages in MT queue
2018-11-05T21:31:48.879Z,1541453508.879 [NAL9602](INFO): GPS fix at 20181105T213122: (36.809635, -121.840479)
2018-11-05T21:31:48.941Z,1541453508.941 [Default:CheckIn:Read_GPS] Stopped
2018-11-05T21:31:48.941Z,1541453508.941 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-11-05T21:31:54.039Z,1541453514.039 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20181105T203532/Courier0025.lzma
2018-11-05T21:31:54.829Z,1541453514.829 [DataOverHttps](INFO): Moved sent file to Logs/20181105T203532/Courier0025.lzma.bak
2018-11-05T21:31:54.829Z,1541453514.829 [DataOverHttps](INFO): SBD MOMSN=8792534
2018-11-05T21:32:05.460Z,1541453525.460 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20181105T213126/Courier0000.lzma
2018-11-05T21:32:06.256Z,1541453526.256 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Courier0000.lzma.bak
2018-11-05T21:32:06.257Z,1541453526.257 [DataOverHttps](INFO): SBD MOMSN=8792536
2018-11-05T21:32:16.388Z,1541453536.388 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20181105T213126/Courier0003.lzma
2018-11-05T21:32:17.189Z,1541453537.189 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Courier0003.lzma.bak
2018-11-05T21:32:17.189Z,1541453537.189 [DataOverHttps](INFO): SBD MOMSN=8792540
2018-11-05T21:32:26.819Z,1541453546.819 [NAL9602](INFO): Powering down
2018-11-05T21:32:26.921Z,1541453546.921 [DataOverHttps](INFO): Sending 252 bytes from file Logs/20181105T203532/Express0026.lzma
2018-11-05T21:32:27.713Z,1541453547.713 [DataOverHttps](INFO): Moved sent file to Logs/20181105T203532/Express0026.lzma.bak
2018-11-05T21:32:27.713Z,1541453547.713 [DataOverHttps](INFO): SBD MOMSN=8792542
2018-11-05T21:32:37.895Z,1541453557.895 [DataOverHttps](INFO): Sending 267 bytes from file Logs/20181105T213126/Express0001.lzma
2018-11-05T21:32:38.681Z,1541453558.681 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Express0001.lzma.bak
2018-11-05T21:32:38.681Z,1541453558.681 [DataOverHttps](INFO): SBD MOMSN=8792547
2018-11-05T21:32:50.646Z,1541453570.646 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20181105T213126/Express0004.lzma
2018-11-05T21:32:51.437Z,1541453571.437 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Express0004.lzma.bak
2018-11-05T21:32:51.437Z,1541453571.437 [DataOverHttps](INFO): SBD MOMSN=8792550
2018-11-05T21:32:52.001Z,1541453572.001 [Default:CheckIn:Read_Iridium] Stopped
2018-11-05T21:32:52.001Z,1541453572.001 [Default:CheckIn:C.Wait] Running Loop=1
2018-11-05T21:32:52.001Z,1541453572.001 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-11-05T21:35:48.511Z,1541453748.511 [CBIT](INFO): Clearing failed state for component DropWeight
2018-11-05T21:35:48.511Z,1541453748.511 [DropWeight] No Fault, FailCount= 1
2018-11-05T21:37:52.692Z,1541453872.692 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-11-05T21:37:52.692Z,1541453872.692 [Default:CheckIn:C.Wait] Stopped
2018-11-05T21:37:52.692Z,1541453872.692 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-11-05T21:37:52.692Z,1541453872.692 [Default:CheckIn:D] Running Loop=1
2018-11-05T21:37:53.068Z,1541453873.068 [Default:CheckIn:D] Stopped
2018-11-05T21:37:53.068Z,1541453873.068 [Default:CheckIn:E] Running Loop=1
2018-11-05T21:37:53.483Z,1541453873.483 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 59.620532 min 
2018-11-05T21:37:53.484Z,1541453873.484 [Default:CheckIn:E] Stopped
2018-11-05T21:37:53.484Z,1541453873.484 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-11-05T21:37:53.484Z,1541453873.484 [Default:CheckIn] Stopped
2018-11-05T21:37:53.484Z,1541453873.484 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-11-05T21:37:53.484Z,1541453873.484 [Default:CheckIn](INFO): Running loop #9
2018-11-05T21:37:53.484Z,1541453873.484 [Default:CheckIn] Running Loop=9
2018-11-05T21:37:53.484Z,1541453873.484 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-11-05T21:37:53.484Z,1541453873.484 [Default:CheckIn:Read_GPS] Running Loop=1
2018-11-05T21:37:57.077Z,1541453877.077 [NAL9602](INFO): Powering up
2018-11-05T21:38:08.012Z,1541453888.012 [NAL9602](INFO): NAL9602 initialized
2018-11-05T21:38:23.621Z,1541453903.621 [NAL9602](INFO): SBD MO Status=0, MOMSN=10467, MT Status=0, MTMSN=0
2018-11-05T21:38:23.622Z,1541453903.622 [NAL9602](INFO): No messages in MT queue
2018-11-05T21:38:56.415Z,1541453936.415 [NAL9602](INFO): GPS fix at 20181105T213830: (36.804600, -121.798642)
2018-11-05T21:38:56.467Z,1541453936.467 [Default:CheckIn:Read_GPS] Stopped
2018-11-05T21:38:56.467Z,1541453936.467 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-11-05T21:39:23.608Z,1541453963.608 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-11-05T21:39:28.741Z,1541453968.741 [NAL9602](INFO): Powering down
2018-11-05T21:39:29.127Z,1541453969.127 [DataOverHttps](INFO): Sending 65 bytes from file Logs/20181105T213126/Courier0006.lzma
2018-11-05T21:39:29.925Z,1541453969.925 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Courier0006.lzma.bak
2018-11-05T21:39:29.925Z,1541453969.925 [DataOverHttps](INFO): SBD MOMSN=8792553
2018-11-05T21:39:42.679Z,1541453982.679 [DataOverHttps](INFO): Sending 167 bytes from file Logs/20181105T213126/Express0007.lzma
2018-11-05T21:39:43.480Z,1541453983.480 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Express0007.lzma.bak
2018-11-05T21:39:43.480Z,1541453983.480 [DataOverHttps](INFO): SBD MOMSN=8792556
2018-11-05T21:39:44.379Z,1541453984.379 [Default:CheckIn:Read_Iridium] Stopped
2018-11-05T21:39:44.379Z,1541453984.379 [Default:CheckIn:C.Wait] Running Loop=1
2018-11-05T21:39:44.379Z,1541453984.379 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-11-05T21:40:55.910Z,1541454055.910 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-11-05T21:40:55.910Z,1541454055.910 [Rowe_600LCM] Communications Fault, FailCount= 5
2018-11-05T21:40:55.910Z,1541454055.910 [Rowe_600LCM](ERROR): Communications Fault
2018-11-05T21:40:56.023Z,1541454056.023 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-11-05T21:40:56.024Z,1541454056.024 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM
2018-11-05T21:40:56.314Z,1541454056.314 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-05T21:40:56.514Z,1541454056.514 [Rowe_600LCM](INFO): Powering down
2018-11-05T21:43:14.823Z,1541454194.823 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-11-05T21:44:15.223Z,1541454255.223 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-11-05T21:44:44.883Z,1541454284.883 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-11-05T21:44:44.883Z,1541454284.883 [Default:CheckIn:C.Wait] Stopped
2018-11-05T21:44:44.883Z,1541454284.883 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-11-05T21:44:44.883Z,1541454284.883 [Default:CheckIn:D] Running Loop=1
2018-11-05T21:44:45.284Z,1541454285.284 [Default:CheckIn:D] Stopped
2018-11-05T21:44:45.284Z,1541454285.284 [Default:CheckIn:E] Running Loop=1
2018-11-05T21:44:45.678Z,1541454285.678 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 66.490796 min 
2018-11-05T21:44:45.678Z,1541454285.678 [Default:CheckIn:E] Stopped
2018-11-05T21:44:45.679Z,1541454285.679 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-11-05T21:44:45.679Z,1541454285.679 [Default:CheckIn] Stopped
2018-11-05T21:44:45.679Z,1541454285.679 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-11-05T21:44:45.679Z,1541454285.679 [Default:CheckIn](INFO): Running loop #10
2018-11-05T21:44:45.680Z,1541454285.680 [Default:CheckIn] Running Loop=10
2018-11-05T21:44:45.680Z,1541454285.680 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-11-05T21:44:45.680Z,1541454285.680 [Default:CheckIn:Read_GPS] Running Loop=1
2018-11-05T21:44:46.427Z,1541454286.427 [NAL9602](INFO): Powering up
2018-11-05T21:44:50.424Z,1541454290.424 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.399796
2018-11-05T21:44:57.632Z,1541454297.632 [NAL9602](INFO): NAL9602 initialized
2018-11-05T21:45:27.629Z,1541454327.629 [NAL9602](INFO): SBD MO Status=0, MOMSN=10468, MT Status=0, MTMSN=0
2018-11-05T21:45:27.629Z,1541454327.629 [NAL9602](INFO): No messages in MT queue
2018-11-05T21:45:28.839Z,1541454328.839 [NAL9602](INFO): GPS fix at 20181105T214502: (36.804424, -121.785679)
2018-11-05T21:45:28.873Z,1541454328.873 [Default:CheckIn:Read_GPS] Stopped
2018-11-05T21:45:28.873Z,1541454328.873 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-11-05T21:45:50.909Z,1541454350.909 [NAL9602](INFO): SBD MO Status=1, MOMSN=10469, MT Status=0, MTMSN=0
2018-11-05T21:45:50.963Z,1541454350.963 [NAL9602](INFO): Sent 64 bytes from file Logs/20181105T213126/Courier0009.lzma
2018-11-05T21:45:50.963Z,1541454350.963 [NAL9602](INFO): Packets left to send: 0
2018-11-05T21:45:50.964Z,1541454350.964 [NAL9602](DEBUG): Stored copy of sent data in Logs/20181105T213126/Courier0009.lzma.parts/0000.sbd
2018-11-05T21:45:50.964Z,1541454350.964 [NAL9602](DEBUG): Completed sending Logs/20181105T213126/Courier0009.lzma
2018-11-05T21:45:59.529Z,1541454359.529 [NAL9602](INFO): SBD MO Status=1, MOMSN=10470, MT Status=0, MTMSN=0
2018-11-05T21:45:59.579Z,1541454359.579 [NAL9602](INFO): Sent 278 bytes from file Logs/20181105T213126/Express0010.lzma
2018-11-05T21:45:59.579Z,1541454359.579 [NAL9602](INFO): Packets left to send: 0
2018-11-05T21:45:59.580Z,1541454359.580 [NAL9602](DEBUG): Stored copy of sent data in Logs/20181105T213126/Express0010.lzma.parts/0000.sbd
2018-11-05T21:45:59.581Z,1541454359.581 [NAL9602](DEBUG): Completed sending Logs/20181105T213126/Express0010.lzma
2018-11-05T21:46:11.125Z,1541454371.125 [NAL9602](INFO): SBD MO Status=0, MOMSN=10471, MT Status=0, MTMSN=0
2018-11-05T21:46:11.228Z,1541454371.228 [Default:CheckIn:Read_Iridium] Stopped
2018-11-05T21:46:11.228Z,1541454371.228 [Default:CheckIn:C.Wait] Running Loop=1
2018-11-05T21:46:11.228Z,1541454371.228 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-11-05T21:46:15.519Z,1541454375.519 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-11-05T21:46:41.923Z,1541454401.923 [NAL9602](INFO): Powering down
2018-11-05T21:47:15.919Z,1541454435.919 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-11-05T21:48:15.919Z,1541454495.919 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-11-05T21:49:16.319Z,1541454556.319 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-11-05T21:50:16.319Z,1541454616.319 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-11-05T21:50:56.011Z,1541454656.011 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-11-05T21:50:56.011Z,1541454656.011 [Rowe_600LCM] No Fault, FailCount= 5
2018-11-05T21:50:56.346Z,1541454656.346 [Rowe_600LCM](INFO): Initializing
2018-11-05T21:50:56.347Z,1541454656.347 [Rowe_600LCM](INFO): Checking LCM
2018-11-05T21:50:56.347Z,1541454656.347 [Rowe_600LCM](INFO): LCM OK
2018-11-05T21:50:56.347Z,1541454656.347 [Rowe_600LCM](INFO): Powering up
2018-11-05T21:51:00.520Z,1541454660.520 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-05T21:51:00.581Z,1541454660.581 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-11-05T21:51:00.582Z,1541454660.582 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-05T21:51:00.583Z,1541454660.583 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-05T21:51:00.583Z,1541454660.583 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-05T21:51:11.605Z,1541454671.605 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-11-05T21:51:11.606Z,1541454671.606 [Default:CheckIn:C.Wait] Stopped
2018-11-05T21:51:11.606Z,1541454671.606 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-11-05T21:51:11.606Z,1541454671.606 [Default:CheckIn:D] Running Loop=1
2018-11-05T21:51:11.964Z,1541454671.964 [Default:CheckIn:D] Stopped
2018-11-05T21:51:11.964Z,1541454671.964 [Default:CheckIn:E] Running Loop=1
2018-11-05T21:51:12.369Z,1541454672.369 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 72.935457 min 
2018-11-05T21:51:12.369Z,1541454672.369 [Default:CheckIn:E] Stopped
2018-11-05T21:51:12.369Z,1541454672.369 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-11-05T21:51:12.369Z,1541454672.369 [Default:CheckIn] Stopped
2018-11-05T21:51:12.369Z,1541454672.369 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-11-05T21:51:12.370Z,1541454672.370 [Default:CheckIn](INFO): Running loop #11
2018-11-05T21:51:12.370Z,1541454672.370 [Default:CheckIn] Running Loop=11
2018-11-05T21:51:12.370Z,1541454672.370 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-11-05T21:51:12.370Z,1541454672.370 [Default:CheckIn:Read_GPS] Running Loop=1
2018-11-05T21:51:13.124Z,1541454673.124 [NAL9602](INFO): Powering up
2018-11-05T21:51:16.333Z,1541454676.333 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-11-05T21:51:23.924Z,1541454683.924 [NAL9602](INFO): NAL9602 initialized
2018-11-05T21:51:39.925Z,1541454699.925 [NAL9602](INFO): SBD MO Status=0, MOMSN=10472, MT Status=0, MTMSN=0
2018-11-05T21:51:39.925Z,1541454699.925 [NAL9602](INFO): No messages in MT queue
2018-11-05T21:51:51.271Z,1541454711.271 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002820
2018-11-05T21:51:56.476Z,1541454716.476 [NAL9602](INFO): GPS fix at 20181105T215130: (36.802770, -121.786880)
2018-11-05T21:51:56.534Z,1541454716.534 [Default:CheckIn:Read_GPS] Stopped
2018-11-05T21:51:56.534Z,1541454716.534 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-11-05T21:52:01.819Z,1541454721.819 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20181105T213126/Courier0012.lzma
2018-11-05T21:52:02.617Z,1541454722.617 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Courier0012.lzma.bak
2018-11-05T21:52:02.617Z,1541454722.617 [DataOverHttps](INFO): SBD MOMSN=8792571
2018-11-05T21:52:12.903Z,1541454732.903 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20181105T213126/Express0013.lzma
2018-11-05T21:52:13.701Z,1541454733.701 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Express0013.lzma.bak
2018-11-05T21:52:13.701Z,1541454733.701 [DataOverHttps](INFO): SBD MOMSN=8792574
2018-11-05T21:52:14.364Z,1541454734.364 [Default:CheckIn:Read_Iridium] Stopped
2018-11-05T21:52:14.365Z,1541454734.365 [Default:CheckIn:C.Wait] Running Loop=1
2018-11-05T21:52:14.365Z,1541454734.365 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-11-05T21:52:31.735Z,1541454751.735 [NAL9602](INFO): Powering down
2018-11-05T21:53:14.122Z,1541454794.122 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-11-05T21:53:14.122Z,1541454794.122 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-11-05T21:53:14.122Z,1541454794.122 [Rowe_600LCM](ERROR): Communications Fault
2018-11-05T21:53:14.219Z,1541454794.219 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-11-05T21:53:14.536Z,1541454794.536 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-05T21:53:14.754Z,1541454794.754 [Rowe_600LCM](INFO): Powering down
2018-11-05T21:53:18.112Z,1541454798.112 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-11-05T21:53:18.113Z,1541454798.113 [Rowe_600LCM] No Fault, FailCount= 1
2018-11-05T21:53:18.390Z,1541454798.390 [Rowe_600LCM](INFO): Initializing
2018-11-05T21:53:18.391Z,1541454798.391 [Rowe_600LCM](INFO): Checking LCM
2018-11-05T21:53:18.391Z,1541454798.391 [Rowe_600LCM](INFO): LCM OK
2018-11-05T21:53:18.391Z,1541454798.391 [Rowe_600LCM](INFO): Powering up
2018-11-05T21:53:22.511Z,1541454802.511 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-05T21:53:22.671Z,1541454802.671 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-11-05T21:53:22.672Z,1541454802.672 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-05T21:53:22.672Z,1541454802.672 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-05T21:53:22.673Z,1541454802.673 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-05T21:57:14.938Z,1541455034.938 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-11-05T21:57:14.938Z,1541455034.938 [Default:CheckIn:C.Wait] Stopped
2018-11-05T21:57:14.938Z,1541455034.938 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-11-05T21:57:14.938Z,1541455034.938 [Default:CheckIn:D] Running Loop=1
2018-11-05T21:57:15.348Z,1541455035.348 [Default:CheckIn:D] Stopped
2018-11-05T21:57:15.348Z,1541455035.348 [Default:CheckIn:E] Running Loop=1
2018-11-05T21:57:15.744Z,1541455035.744 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 78.991862 min 
2018-11-05T21:57:15.744Z,1541455035.744 [Default:CheckIn:E] Stopped
2018-11-05T21:57:15.744Z,1541455035.744 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-11-05T21:57:15.745Z,1541455035.745 [Default:CheckIn] Stopped
2018-11-05T21:57:15.745Z,1541455035.745 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-11-05T21:57:15.745Z,1541455035.745 [Default:CheckIn](INFO): Running loop #12
2018-11-05T21:57:15.745Z,1541455035.745 [Default:CheckIn] Running Loop=12
2018-11-05T21:57:15.745Z,1541455035.745 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-11-05T21:57:15.745Z,1541455035.745 [Default:CheckIn:Read_GPS] Running Loop=1
2018-11-05T21:57:19.836Z,1541455039.836 [NAL9602](INFO): Powering up
2018-11-05T21:57:30.732Z,1541455050.732 [NAL9602](INFO): NAL9602 initialized
2018-11-05T21:57:53.542Z,1541455073.542 [NAL9602](INFO): SBD MO Status=2, MOMSN=10473, MT Status=2, MTMSN=0
2018-11-05T21:57:53.542Z,1541455073.542 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-11-05T21:58:03.134Z,1541455083.134 [NAL9602](INFO): SBD MO Status=0, MOMSN=10473, MT Status=0, MTMSN=0
2018-11-05T21:58:03.134Z,1541455083.134 [NAL9602](INFO): No messages in MT queue
2018-11-05T21:58:04.348Z,1541455084.348 [NAL9602](INFO): GPS fix at 20181105T215738: (36.802696, -121.786888)
2018-11-05T21:58:04.393Z,1541455084.393 [Default:CheckIn:Read_GPS] Stopped
2018-11-05T21:58:04.393Z,1541455084.393 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-11-05T21:58:09.248Z,1541455089.248 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20181105T213126/Courier0015.lzma
2018-11-05T21:58:10.049Z,1541455090.049 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Courier0015.lzma.bak
2018-11-05T21:58:10.049Z,1541455090.049 [DataOverHttps](INFO): SBD MOMSN=8792579
2018-11-05T21:58:20.538Z,1541455100.538 [DataOverHttps](INFO): Sending 195 bytes from file Logs/20181105T213126/Express0016.lzma
2018-11-05T21:58:21.329Z,1541455101.329 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Express0016.lzma.bak
2018-11-05T21:58:21.329Z,1541455101.329 [DataOverHttps](INFO): SBD MOMSN=8792582
2018-11-05T21:58:22.092Z,1541455102.092 [Default:CheckIn:Read_Iridium] Stopped
2018-11-05T21:58:22.092Z,1541455102.092 [Default:CheckIn:C.Wait] Running Loop=1
2018-11-05T21:58:22.092Z,1541455102.092 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-11-05T21:58:38.178Z,1541455118.178 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-11-05T21:58:38.178Z,1541455118.178 [Rowe_600LCM] Communications Fault, FailCount= 2
2018-11-05T21:58:38.178Z,1541455118.178 [Rowe_600LCM](ERROR): Communications Fault
2018-11-05T21:58:38.263Z,1541455118.263 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-11-05T21:58:38.582Z,1541455118.582 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-05T21:58:38.792Z,1541455118.792 [Rowe_600LCM](INFO): Powering down
2018-11-05T21:58:39.399Z,1541455119.399 [NAL9602](INFO): Powering down
2018-11-05T21:58:40.243Z,1541455120.243 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-11-05T21:58:40.244Z,1541455120.244 [Rowe_600LCM] No Fault, FailCount= 2
2018-11-05T21:58:40.410Z,1541455120.410 [Rowe_600LCM](INFO): Initializing
2018-11-05T21:58:40.411Z,1541455120.411 [Rowe_600LCM](INFO): Checking LCM
2018-11-05T21:58:40.411Z,1541455120.411 [Rowe_600LCM](INFO): LCM OK
2018-11-05T21:58:40.411Z,1541455120.411 [Rowe_600LCM](INFO): Powering up
2018-11-05T21:58:44.535Z,1541455124.535 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-05T21:58:44.658Z,1541455124.658 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-11-05T21:58:44.659Z,1541455124.659 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-05T21:58:44.660Z,1541455124.659 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-05T21:58:44.660Z,1541455124.660 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-05T22:00:57.658Z,1541455257.658 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-11-05T22:00:57.658Z,1541455257.658 [Rowe_600LCM] Communications Fault, FailCount= 3
2018-11-05T22:00:57.658Z,1541455257.658 [Rowe_600LCM](ERROR): Communications Fault
2018-11-05T22:00:57.747Z,1541455257.747 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-11-05T22:00:58.062Z,1541455258.062 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-05T22:00:58.273Z,1541455258.273 [Rowe_600LCM](INFO): Powering down
2018-11-05T22:00:59.719Z,1541455259.719 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-11-05T22:00:59.719Z,1541455259.719 [Rowe_600LCM] No Fault, FailCount= 3
2018-11-05T22:00:59.890Z,1541455259.890 [Rowe_600LCM](INFO): Initializing
2018-11-05T22:00:59.891Z,1541455259.891 [Rowe_600LCM](INFO): Checking LCM
2018-11-05T22:00:59.891Z,1541455259.891 [Rowe_600LCM](INFO): LCM OK
2018-11-05T22:00:59.891Z,1541455259.891 [Rowe_600LCM](INFO): Powering up
2018-11-05T22:01:04.018Z,1541455264.018 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-05T22:01:04.173Z,1541455264.173 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-11-05T22:01:04.174Z,1541455264.174 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-05T22:01:04.175Z,1541455264.175 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-05T22:01:04.176Z,1541455264.176 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-05T22:02:59.926Z,1541455379.926 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-11-05T22:02:59.926Z,1541455379.926 [Rowe_600LCM] Communications Fault, FailCount= 4
2018-11-05T22:02:59.926Z,1541455379.926 [Rowe_600LCM](ERROR): Communications Fault
2018-11-05T22:03:00.028Z,1541455380.028 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-11-05T22:03:00.348Z,1541455380.348 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-05T22:03:00.565Z,1541455380.565 [Rowe_600LCM](INFO): Powering down
2018-11-05T22:03:02.011Z,1541455382.011 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-11-05T22:03:02.011Z,1541455382.011 [Rowe_600LCM] No Fault, FailCount= 4
2018-11-05T22:03:02.182Z,1541455382.182 [Rowe_600LCM](INFO): Initializing
2018-11-05T22:03:02.183Z,1541455382.183 [Rowe_600LCM](INFO): Checking LCM
2018-11-05T22:03:02.183Z,1541455382.183 [Rowe_600LCM](INFO): LCM OK
2018-11-05T22:03:02.183Z,1541455382.183 [Rowe_600LCM](INFO): Powering up
2018-11-05T22:03:06.306Z,1541455386.306 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-05T22:03:06.452Z,1541455386.452 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-11-05T22:03:06.453Z,1541455386.453 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-05T22:03:06.454Z,1541455386.454 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-05T22:03:06.455Z,1541455386.455 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-05T22:03:22.388Z,1541455402.388 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-11-05T22:03:22.389Z,1541455402.389 [Default:CheckIn:C.Wait] Stopped
2018-11-05T22:03:22.389Z,1541455402.389 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-11-05T22:03:22.389Z,1541455402.389 [Default:CheckIn:D] Running Loop=1
2018-11-05T22:03:22.800Z,1541455402.800 [Default:CheckIn:D] Stopped
2018-11-05T22:03:22.800Z,1541455402.800 [Default:CheckIn:E] Running Loop=1
2018-11-05T22:03:23.176Z,1541455403.176 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 85.116064 min 
2018-11-05T22:03:23.176Z,1541455403.176 [Default:CheckIn:E] Stopped
2018-11-05T22:03:23.177Z,1541455403.177 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-11-05T22:03:23.177Z,1541455403.177 [Default:CheckIn] Stopped
2018-11-05T22:03:23.177Z,1541455403.177 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-11-05T22:03:23.177Z,1541455403.177 [Default:CheckIn](INFO): Running loop #13
2018-11-05T22:03:23.177Z,1541455403.177 [Default:CheckIn] Running Loop=13
2018-11-05T22:03:23.177Z,1541455403.177 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-11-05T22:03:23.177Z,1541455403.177 [Default:CheckIn:Read_GPS] Running Loop=1
2018-11-05T22:03:23.944Z,1541455403.944 [NAL9602](INFO): Powering up
2018-11-05T22:03:35.080Z,1541455415.080 [NAL9602](INFO): NAL9602 initialized
2018-11-05T22:04:01.482Z,1541455441.482 [NAL9602](INFO): SBD MO Status=0, MOMSN=10474, MT Status=0, MTMSN=0
2018-11-05T22:04:01.482Z,1541455441.482 [NAL9602](INFO): No messages in MT queue
2018-11-05T22:04:23.084Z,1541455463.084 [NAL9602](INFO): GPS fix at 20181105T220357: (36.802907, -121.787994)
2018-11-05T22:04:23.137Z,1541455463.137 [Default:CheckIn:Read_GPS] Stopped
2018-11-05T22:04:23.137Z,1541455463.137 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-11-05T22:04:28.627Z,1541455468.627 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20181105T213126/Courier0018.lzma
2018-11-05T22:04:29.425Z,1541455469.425 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Courier0018.lzma.bak
2018-11-05T22:04:29.425Z,1541455469.425 [DataOverHttps](INFO): SBD MOMSN=8792588
2018-11-05T22:04:39.340Z,1541455479.340 [DataOverHttps](INFO): Sending 219 bytes from file Logs/20181105T213126/Express0019.lzma
2018-11-05T22:04:40.123Z,1541455480.123 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Express0019.lzma.bak
2018-11-05T22:04:40.124Z,1541455480.124 [DataOverHttps](INFO): SBD MOMSN=8792591
2018-11-05T22:04:40.701Z,1541455480.701 [Default:CheckIn:Read_Iridium] Stopped
2018-11-05T22:04:40.701Z,1541455480.701 [Default:CheckIn:C.Wait] Running Loop=1
2018-11-05T22:04:40.701Z,1541455480.701 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-11-05T22:04:58.323Z,1541455498.323 [NAL9602](INFO): Powering down
2018-11-05T22:05:22.398Z,1541455522.398 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-11-05T22:05:22.398Z,1541455522.398 [Rowe_600LCM] Communications Fault, FailCount= 5
2018-11-05T22:05:22.399Z,1541455522.399 [Rowe_600LCM](ERROR): Communications Fault
2018-11-05T22:05:22.401Z,1541455522.401 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-11-05T22:05:22.402Z,1541455522.402 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM
2018-11-05T22:05:22.802Z,1541455522.802 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-05T22:05:22.925Z,1541455522.925 [Rowe_600LCM](INFO): Powering down
2018-11-05T22:05:49.913Z,1541455549.913 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2018-11-05T22:05:49.913Z,1541455549.913 [DropWeight] Hardware Fault, FailCount= 1
2018-11-05T22:05:49.913Z,1541455549.913 [DropWeight](ERROR): Hardware Fault
2018-11-05T22:05:49.954Z,1541455549.954 [CBIT](INFO): Critical error at 20181105T220549
2018-11-05T22:05:49.965Z,1541455549.965 [CBIT](ERROR): Hardware Fault in component: DropWeight
2018-11-05T22:05:49.965Z,1541455549.965 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2018-11-05T22:05:50.388Z,1541455550.388 [CBIT](INFO): Critical error at 20181105T220549
2018-11-05T22:09:41.294Z,1541455781.294 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-11-05T22:09:41.294Z,1541455781.294 [Default:CheckIn:C.Wait] Stopped
2018-11-05T22:09:41.294Z,1541455781.294 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-11-05T22:09:41.294Z,1541455781.294 [Default:CheckIn:D] Running Loop=1
2018-11-05T22:09:41.649Z,1541455781.649 [Default:CheckIn:D] Stopped
2018-11-05T22:09:41.649Z,1541455781.649 [Default:CheckIn:E] Running Loop=1
2018-11-05T22:09:42.045Z,1541455782.045 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 91.430208 min 
2018-11-05T22:09:42.045Z,1541455782.045 [Default:CheckIn:E] Stopped
2018-11-05T22:09:42.045Z,1541455782.045 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-11-05T22:09:42.045Z,1541455782.045 [Default:CheckIn] Stopped
2018-11-05T22:09:42.045Z,1541455782.045 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-11-05T22:09:42.045Z,1541455782.045 [Default:CheckIn](INFO): Running loop #14
2018-11-05T22:09:42.045Z,1541455782.045 [Default:CheckIn] Running Loop=14
2018-11-05T22:09:42.046Z,1541455782.046 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-11-05T22:09:42.046Z,1541455782.046 [Default:CheckIn:Read_GPS] Running Loop=1
2018-11-05T22:09:45.235Z,1541455785.235 [NAL9602](INFO): Powering up
2018-11-05T22:09:56.383Z,1541455796.383 [NAL9602](INFO): NAL9602 initialized
2018-11-05T22:13:42.257Z,1541456022.257 [NAL9602](INFO): SBD MO Status=0, MOMSN=10475, MT Status=0, MTMSN=0
2018-11-05T22:13:42.257Z,1541456022.257 [NAL9602](INFO): No messages in MT queue
2018-11-05T22:13:46.375Z,1541456026.375 [NAL9602](INFO): GPS fix at 20181105T221320: (36.802730, -121.787907)
2018-11-05T22:13:46.434Z,1541456026.434 [Default:CheckIn:Read_GPS] Stopped
2018-11-05T22:13:46.434Z,1541456026.434 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-11-05T22:13:51.575Z,1541456031.575 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20181105T213126/Courier0021.lzma
2018-11-05T22:13:52.373Z,1541456032.373 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Courier0021.lzma.bak
2018-11-05T22:13:52.373Z,1541456032.373 [DataOverHttps](INFO): SBD MOMSN=8792598
2018-11-05T22:14:01.593Z,1541456041.593 [DataOverHttps](INFO): Sending 239 bytes from file Logs/20181105T213126/Express0022.lzma
2018-11-05T22:14:02.385Z,1541456042.385 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Express0022.lzma.bak
2018-11-05T22:14:02.385Z,1541456042.385 [DataOverHttps](INFO): SBD MOMSN=8792603
2018-11-05T22:14:02.940Z,1541456042.940 [Default:CheckIn:Read_Iridium] Stopped
2018-11-05T22:14:02.940Z,1541456042.940 [Default:CheckIn:C.Wait] Running Loop=1
2018-11-05T22:14:02.940Z,1541456042.940 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-11-05T22:14:21.359Z,1541456061.359 [NAL9602](INFO): Powering down
2018-11-05T22:15:22.507Z,1541456122.507 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-11-05T22:15:22.508Z,1541456122.508 [Rowe_600LCM] No Fault, FailCount= 5
2018-11-05T22:15:22.730Z,1541456122.730 [Rowe_600LCM](INFO): Initializing
2018-11-05T22:15:22.731Z,1541456122.731 [Rowe_600LCM](INFO): Checking LCM
2018-11-05T22:15:22.731Z,1541456122.731 [Rowe_600LCM](INFO): LCM OK
2018-11-05T22:15:22.731Z,1541456122.731 [Rowe_600LCM](INFO): Powering up
2018-11-05T22:15:26.920Z,1541456126.920 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-05T22:15:27.058Z,1541456127.058 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-11-05T22:15:27.059Z,1541456127.059 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-05T22:15:27.060Z,1541456127.060 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-05T22:15:27.061Z,1541456127.061 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-05T22:19:03.617Z,1541456343.617 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-11-05T22:19:03.618Z,1541456343.618 [Default:CheckIn:C.Wait] Stopped
2018-11-05T22:19:03.618Z,1541456343.618 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-11-05T22:19:03.618Z,1541456343.618 [Default:CheckIn:D] Running Loop=1
2018-11-05T22:19:03.980Z,1541456343.980 [Default:CheckIn:D] Stopped
2018-11-05T22:19:03.980Z,1541456343.980 [Default:CheckIn:E] Running Loop=1
2018-11-05T22:19:04.386Z,1541456344.386 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 100.802401 min 
2018-11-05T22:19:04.386Z,1541456344.386 [Default:CheckIn:E] Stopped
2018-11-05T22:19:04.387Z,1541456344.387 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-11-05T22:19:04.387Z,1541456344.387 [Default:CheckIn] Stopped
2018-11-05T22:19:04.387Z,1541456344.387 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-11-05T22:19:04.387Z,1541456344.387 [Default:CheckIn](INFO): Running loop #15
2018-11-05T22:19:04.387Z,1541456344.387 [Default:CheckIn] Running Loop=15
2018-11-05T22:19:04.387Z,1541456344.387 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-11-05T22:19:04.387Z,1541456344.387 [Default:CheckIn:Read_GPS] Running Loop=1
2018-11-05T22:19:08.422Z,1541456348.422 [NAL9602](INFO): Powering up
2018-11-05T22:19:19.295Z,1541456359.295 [NAL9602](INFO): NAL9602 initialized
2018-11-05T22:20:35.583Z,1541456435.583 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-11-05T22:20:35.583Z,1541456435.583 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-11-05T22:20:35.583Z,1541456435.583 [Rowe_600LCM](ERROR): Communications Fault
2018-11-05T22:20:35.680Z,1541456435.680 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-11-05T22:20:35.986Z,1541456435.986 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-05T22:20:36.174Z,1541456436.174 [Rowe_600LCM](INFO): Powering down
2018-11-05T22:20:37.640Z,1541456437.640 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-11-05T22:20:37.640Z,1541456437.640 [Rowe_600LCM] No Fault, FailCount= 1
2018-11-05T22:20:37.790Z,1541456437.790 [Rowe_600LCM](INFO): Initializing
2018-11-05T22:20:37.791Z,1541456437.791 [Rowe_600LCM](INFO): Checking LCM
2018-11-05T22:20:37.791Z,1541456437.791 [Rowe_600LCM](INFO): LCM OK
2018-11-05T22:20:37.791Z,1541456437.791 [Rowe_600LCM](INFO): Powering up
2018-11-05T22:20:41.914Z,1541456441.914 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-05T22:20:42.057Z,1541456442.057 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-11-05T22:20:42.058Z,1541456442.058 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-05T22:20:42.058Z,1541456442.058 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-05T22:20:42.059Z,1541456442.059 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-05T22:20:50.039Z,1541456450.039 [CBIT](INFO): Clearing failed state for component DropWeight
2018-11-05T22:20:50.040Z,1541456450.040 [DropWeight] No Fault, FailCount= 1
2018-11-05T22:22:02.785Z,1541456522.785 [NAL9602](INFO): SBD MO Status=0, MOMSN=10476, MT Status=0, MTMSN=0
2018-11-05T22:22:02.785Z,1541456522.785 [NAL9602](INFO): No messages in MT queue
2018-11-05T22:22:03.987Z,1541456523.987 [NAL9602](INFO): GPS fix at 20181105T222138: (36.802714, -121.788061)
2018-11-05T22:22:04.058Z,1541456524.058 [Default:CheckIn:Read_GPS] Stopped
2018-11-05T22:22:04.059Z,1541456524.059 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-11-05T22:22:09.369Z,1541456529.369 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20181105T213126/Courier0024.lzma
2018-11-05T22:22:10.161Z,1541456530.161 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Courier0024.lzma.bak
2018-11-05T22:22:10.161Z,1541456530.161 [DataOverHttps](INFO): SBD MOMSN=8792609
2018-11-05T22:22:20.202Z,1541456540.202 [DataOverHttps](INFO): Sending 195 bytes from file Logs/20181105T213126/Express0025.lzma
2018-11-05T22:22:20.989Z,1541456540.989 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Express0025.lzma.bak
2018-11-05T22:22:20.989Z,1541456540.989 [DataOverHttps](INFO): SBD MOMSN=8792612
2018-11-05T22:22:21.637Z,1541456541.637 [Default:CheckIn:Read_Iridium] Stopped
2018-11-05T22:22:21.637Z,1541456541.637 [Default:CheckIn:C.Wait] Running Loop=1
2018-11-05T22:22:21.637Z,1541456541.637 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-11-05T22:22:39.412Z,1541456559.412 [NAL9602](INFO): Powering down
2018-11-05T22:27:22.311Z,1541456842.311 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-11-05T22:27:22.311Z,1541456842.311 [Default:CheckIn:C.Wait] Stopped
2018-11-05T22:27:22.311Z,1541456842.311 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-11-05T22:27:22.311Z,1541456842.311 [Default:CheckIn:D] Running Loop=1
2018-11-05T22:27:22.668Z,1541456842.668 [Default:CheckIn:D] Stopped
2018-11-05T22:27:22.668Z,1541456842.668 [Default:CheckIn:E] Running Loop=1
2018-11-05T22:27:23.076Z,1541456843.076 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 109.113859 min 
2018-11-05T22:27:23.076Z,1541456843.076 [Default:CheckIn:E] Stopped
2018-11-05T22:27:23.076Z,1541456843.076 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-11-05T22:27:23.077Z,1541456843.077 [Default:CheckIn] Stopped
2018-11-05T22:27:23.077Z,1541456843.077 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-11-05T22:27:23.077Z,1541456843.077 [Default:CheckIn](INFO): Running loop #16
2018-11-05T22:27:23.077Z,1541456843.077 [Default:CheckIn] Running Loop=16
2018-11-05T22:27:23.077Z,1541456843.077 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-11-05T22:27:23.077Z,1541456843.077 [Default:CheckIn:Read_GPS] Running Loop=1
2018-11-05T22:27:27.039Z,1541456847.039 [NAL9602](INFO): Powering up
2018-11-05T22:27:38.180Z,1541456858.180 [NAL9602](INFO): NAL9602 initialized
2018-11-05T22:31:07.558Z,1541457067.558 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-11-05T22:31:07.558Z,1541457067.558 [Rowe_600LCM] Communications Fault, FailCount= 2
2018-11-05T22:31:07.558Z,1541457067.558 [Rowe_600LCM](ERROR): Communications Fault
2018-11-05T22:31:07.655Z,1541457067.655 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-11-05T22:31:07.962Z,1541457067.962 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-05T22:31:08.206Z,1541457068.206 [Rowe_600LCM](INFO): Powering down
2018-11-05T22:31:09.015Z,1541457069.015 [Rowe_600LCM](FAULT): LCB fault:  Software Overcurrent.
2018-11-05T22:31:09.015Z,1541457069.015 [Rowe_600LCM] Hardware Fault, FailCount= 2
2018-11-05T22:31:09.015Z,1541457069.015 [Rowe_600LCM](ERROR): Hardware Fault
2018-11-05T22:31:09.628Z,1541457069.628 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-11-05T22:31:09.628Z,1541457069.628 [Rowe_600LCM] No Fault, FailCount= 2
2018-11-05T22:31:09.822Z,1541457069.822 [Rowe_600LCM](INFO): Initializing
2018-11-05T22:31:09.823Z,1541457069.823 [Rowe_600LCM](INFO): Checking LCM
2018-11-05T22:31:09.823Z,1541457069.823 [Rowe_600LCM](INFO): LCM OK
2018-11-05T22:31:09.823Z,1541457069.823 [Rowe_600LCM](INFO): Powering up
2018-11-05T22:31:14.155Z,1541457074.155 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-05T22:31:14.261Z,1541457074.261 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-11-05T22:31:14.262Z,1541457074.262 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-05T22:31:14.263Z,1541457074.263 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-05T22:31:14.263Z,1541457074.263 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-05T22:32:01.578Z,1541457121.578 [NAL9602](INFO): SBD MO Status=2, MOMSN=10477, MT Status=2, MTMSN=0
2018-11-05T22:32:01.579Z,1541457121.579 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-11-05T22:32:23.253Z,1541457143.253 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-11-05T22:27:23.1Z
2018-11-05T22:32:23.254Z,1541457143.254 [Default:CheckIn:Read_GPS] Stopped
2018-11-05T22:32:23.254Z,1541457143.254 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-11-05T22:32:27.326Z,1541457147.326 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20181105T213126/Courier0027.lzma
2018-11-05T22:32:28.125Z,1541457148.125 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Courier0027.lzma.bak
2018-11-05T22:32:28.126Z,1541457148.126 [DataOverHttps](INFO): SBD MOMSN=8792618
2018-11-05T22:32:32.443Z,1541457152.443 [NAL9602](INFO): SBD MO Status=2, MOMSN=10477, MT Status=2, MTMSN=0
2018-11-05T22:32:32.443Z,1541457152.443 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-11-05T22:32:38.005Z,1541457158.005 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20181105T213126/Express0028.lzma
2018-11-05T22:32:38.783Z,1541457158.783 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Express0028.lzma.bak
2018-11-05T22:32:38.783Z,1541457158.783 [DataOverHttps](INFO): SBD MOMSN=8792620
2018-11-05T22:32:39.649Z,1541457159.649 [Default:CheckIn:Read_Iridium] Stopped
2018-11-05T22:32:39.649Z,1541457159.649 [Default:CheckIn:C.Wait] Running Loop=1
2018-11-05T22:32:39.649Z,1541457159.649 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-11-05T22:32:44.649Z,1541457164.649 [NAL9602](INFO): SBD MO Status=2, MOMSN=10477, MT Status=2, MTMSN=0
2018-11-05T22:32:44.650Z,1541457164.650 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-11-05T22:32:45.040Z,1541457165.040 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-11-05T22:33:15.839Z,1541457195.839 [NAL9602](INFO): Powering down
2018-11-05T22:34:44.170Z,1541457284.170 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-11-05T22:34:44.170Z,1541457284.170 [Rowe_600LCM] Communications Fault, FailCount= 3
2018-11-05T22:34:44.171Z,1541457284.171 [Rowe_600LCM](ERROR): Communications Fault
2018-11-05T22:34:44.429Z,1541457284.429 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-11-05T22:34:44.574Z,1541457284.574 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-05T22:34:44.723Z,1541457284.723 [Rowe_600LCM](INFO): Powering down
2018-11-05T22:34:46.193Z,1541457286.193 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-11-05T22:34:46.193Z,1541457286.193 [Rowe_600LCM] No Fault, FailCount= 3
2018-11-05T22:34:46.338Z,1541457286.338 [Rowe_600LCM](INFO): Initializing
2018-11-05T22:34:46.339Z,1541457286.339 [Rowe_600LCM](INFO): Checking LCM
2018-11-05T22:34:46.339Z,1541457286.339 [Rowe_600LCM](INFO): LCM OK
2018-11-05T22:34:46.339Z,1541457286.339 [Rowe_600LCM](INFO): Powering up
2018-11-05T22:34:50.563Z,1541457290.563 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-05T22:34:50.653Z,1541457290.653 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-11-05T22:34:50.658Z,1541457290.658 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-05T22:34:50.659Z,1541457290.659 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-05T22:34:50.660Z,1541457290.660 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-05T22:37:06.502Z,1541457426.502 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-11-05T22:37:06.502Z,1541457426.502 [Rowe_600LCM] Communications Fault, FailCount= 4
2018-11-05T22:37:06.502Z,1541457426.502 [Rowe_600LCM](ERROR): Communications Fault
2018-11-05T22:37:06.865Z,1541457426.865 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-11-05T22:37:06.906Z,1541457426.906 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-05T22:37:07.015Z,1541457427.015 [Rowe_600LCM](INFO): Powering down
2018-11-05T22:37:08.473Z,1541457428.473 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-11-05T22:37:08.473Z,1541457428.473 [Rowe_600LCM] No Fault, FailCount= 4
2018-11-05T22:37:08.630Z,1541457428.630 [Rowe_600LCM](INFO): Initializing
2018-11-05T22:37:08.631Z,1541457428.631 [Rowe_600LCM](INFO): Checking LCM
2018-11-05T22:37:08.631Z,1541457428.631 [Rowe_600LCM](INFO): LCM OK
2018-11-05T22:37:08.631Z,1541457428.631 [Rowe_600LCM](INFO): Powering up
2018-11-05T22:37:12.754Z,1541457432.754 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-05T22:37:12.885Z,1541457432.885 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-11-05T22:37:12.886Z,1541457432.886 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-05T22:37:12.887Z,1541457432.887 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-05T22:37:12.887Z,1541457432.887 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-05T22:37:40.043Z,1541457460.043 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-11-05T22:37:40.043Z,1541457460.043 [Default:CheckIn:C.Wait] Stopped
2018-11-05T22:37:40.044Z,1541457460.044 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-11-05T22:37:40.044Z,1541457460.044 [Default:CheckIn:D] Running Loop=1
2018-11-05T22:37:40.449Z,1541457460.449 [Default:CheckIn:D] Stopped
2018-11-05T22:37:40.449Z,1541457460.449 [Default:CheckIn:E] Running Loop=1
2018-11-05T22:37:40.848Z,1541457460.848 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 119.410205 min 
2018-11-05T22:37:40.849Z,1541457460.849 [Default:CheckIn:E] Stopped
2018-11-05T22:37:40.849Z,1541457460.849 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-11-05T22:37:40.849Z,1541457460.849 [Default:CheckIn] Stopped
2018-11-05T22:37:40.849Z,1541457460.849 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-11-05T22:37:40.849Z,1541457460.849 [Default:CheckIn](INFO): Running loop #17
2018-11-05T22:37:40.849Z,1541457460.849 [Default:CheckIn] Running Loop=17
2018-11-05T22:37:40.849Z,1541457460.849 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-11-05T22:37:40.850Z,1541457460.850 [Default:CheckIn:Read_GPS] Running Loop=1
2018-11-05T22:37:44.885Z,1541457464.885 [NAL9602](INFO): Powering up
2018-11-05T22:37:55.788Z,1541457475.788 [NAL9602](INFO): NAL9602 initialized
2018-11-05T22:37:56.592Z,1541457476.592 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-11-05T22:37:56.592Z,1541457476.592 [NAL9602] Data Fault, FailCount= 1
2018-11-05T22:37:56.592Z,1541457476.592 [NAL9602](ERROR): Data Fault
2018-11-05T22:37:56.691Z,1541457476.691 [CBIT](ERROR): Data Fault in component: NAL9602
2018-11-05T22:37:56.988Z,1541457476.988 [NAL9602](INFO): Powering down
2018-11-05T22:37:57.883Z,1541457477.883 [CBIT](INFO): Clearing failed state for component NAL9602
2018-11-05T22:37:57.883Z,1541457477.883 [NAL9602] No Fault, FailCount= 1
2018-11-05T22:38:27.392Z,1541457507.392 [NAL9602](INFO): Powering up NAL9602
2018-11-05T22:38:38.588Z,1541457518.588 [NAL9602](INFO): NAL9602 initialized
2018-11-05T22:41:17.872Z,1541457677.872 [NAL9602](INFO): SBD MO Status=2, MOMSN=10477, MT Status=2, MTMSN=0
2018-11-05T22:41:17.873Z,1541457677.873 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-11-05T22:41:45.314Z,1541457705.314 [NAL9602](INFO): SBD MO Status=2, MOMSN=10477, MT Status=2, MTMSN=0
2018-11-05T22:41:45.315Z,1541457705.315 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-11-05T22:41:56.617Z,1541457716.617 [NAL9602](INFO): SBD MO Status=2, MOMSN=10477, MT Status=2, MTMSN=0
2018-11-05T22:41:56.617Z,1541457716.617 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-11-05T22:42:34.606Z,1541457754.606 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-11-05T22:42:34.606Z,1541457754.606 [Rowe_600LCM] Communications Fault, FailCount= 5
2018-11-05T22:42:34.606Z,1541457754.606 [Rowe_600LCM](ERROR): Communications Fault
2018-11-05T22:42:34.722Z,1541457754.722 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-11-05T22:42:34.726Z,1541457754.726 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM
2018-11-05T22:42:35.010Z,1541457755.010 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-05T22:42:35.282Z,1541457755.282 [Rowe_600LCM](INFO): Powering down
2018-11-05T22:42:41.064Z,1541457761.064 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-11-05T22:37:40.8Z
2018-11-05T22:42:41.064Z,1541457761.064 [Default:CheckIn:Read_GPS] Stopped
2018-11-05T22:42:41.064Z,1541457761.064 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-11-05T22:42:45.487Z,1541457765.487 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20181105T213126/Courier0030.lzma
2018-11-05T22:42:46.290Z,1541457766.290 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Courier0030.lzma.bak
2018-11-05T22:42:46.290Z,1541457766.290 [DataOverHttps](INFO): SBD MOMSN=8792625
2018-11-05T22:42:56.147Z,1541457776.147 [DataOverHttps](INFO): Sending 352 bytes from file Logs/20181105T213126/Express0031.lzma
2018-11-05T22:42:56.933Z,1541457776.933 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Express0031.lzma.bak
2018-11-05T22:42:56.933Z,1541457776.933 [DataOverHttps](INFO): SBD MOMSN=8792627
2018-11-05T22:42:57.496Z,1541457777.496 [Default:CheckIn:Read_Iridium] Stopped
2018-11-05T22:42:57.496Z,1541457777.496 [Default:CheckIn:C.Wait] Running Loop=1
2018-11-05T22:42:57.496Z,1541457777.496 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-11-05T22:43:46.673Z,1541457826.673 [NAL9602](INFO): SBD MO Status=2, MOMSN=10477, MT Status=2, MTMSN=0
2018-11-05T22:43:46.673Z,1541457826.673 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-11-05T22:43:47.076Z,1541457827.076 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-11-05T22:44:17.623Z,1541457857.623 [NAL9602](INFO): Powering down
2018-11-05T22:47:57.825Z,1541458077.825 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-11-05T22:47:57.825Z,1541458077.825 [Default:CheckIn:C.Wait] Stopped
2018-11-05T22:47:57.825Z,1541458077.825 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-11-05T22:47:57.825Z,1541458077.825 [Default:CheckIn:D] Running Loop=1
2018-11-05T22:47:58.231Z,1541458078.231 [Default:CheckIn:D] Stopped
2018-11-05T22:47:58.231Z,1541458078.231 [Default:CheckIn:E] Running Loop=1
2018-11-05T22:47:58.629Z,1541458078.629 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 129.706576 min 
2018-11-05T22:47:58.629Z,1541458078.629 [Default:CheckIn:E] Stopped
2018-11-05T22:47:58.629Z,1541458078.629 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-11-05T22:47:58.629Z,1541458078.629 [Default:CheckIn] Stopped
2018-11-05T22:47:58.630Z,1541458078.630 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-11-05T22:47:58.630Z,1541458078.630 [Default:CheckIn](INFO): Running loop #18
2018-11-05T22:47:58.630Z,1541458078.630 [Default:CheckIn] Running Loop=18
2018-11-05T22:47:58.630Z,1541458078.630 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-11-05T22:47:58.630Z,1541458078.630 [Default:CheckIn:Read_GPS] Running Loop=1
2018-11-05T22:48:01.975Z,1541458081.975 [NAL9602](INFO): Powering up
2018-11-05T22:48:13.127Z,1541458093.127 [NAL9602](INFO): NAL9602 initialized
2018-11-05T22:50:51.547Z,1541458251.547 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2018-11-05T22:50:51.547Z,1541458251.547 [DropWeight] Hardware Fault, FailCount= 1
2018-11-05T22:50:51.547Z,1541458251.547 [DropWeight](ERROR): Hardware Fault
2018-11-05T22:50:51.632Z,1541458251.632 [CBIT](INFO): Critical error at 20181105T225051
2018-11-05T22:50:51.639Z,1541458251.639 [CBIT](ERROR): Hardware Fault in component: DropWeight
2018-11-05T22:50:51.640Z,1541458251.640 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2018-11-05T22:50:52.003Z,1541458252.003 [CBIT](INFO): Critical error at 20181105T225051
2018-11-05T22:51:22.869Z,1541458282.869 [NAL9602](INFO): SBD MO Status=2, MOMSN=10477, MT Status=2, MTMSN=0
2018-11-05T22:51:22.869Z,1541458282.869 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-11-05T22:51:40.069Z,1541458300.069 [NAL9602](INFO): SBD MO Status=2, MOMSN=10477, MT Status=2, MTMSN=0
2018-11-05T22:51:40.069Z,1541458300.069 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-11-05T22:52:34.721Z,1541458354.721 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-11-05T22:52:34.721Z,1541458354.721 [Rowe_600LCM] No Fault, FailCount= 5
2018-11-05T22:52:34.770Z,1541458354.770 [Rowe_600LCM](INFO): Initializing
2018-11-05T22:52:34.771Z,1541458354.771 [Rowe_600LCM](INFO): Checking LCM
2018-11-05T22:52:34.771Z,1541458354.771 [Rowe_600LCM](INFO): LCM OK
2018-11-05T22:52:34.771Z,1541458354.771 [Rowe_600LCM](INFO): Powering up
2018-11-05T22:52:38.896Z,1541458358.896 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-05T22:52:38.961Z,1541458358.961 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-11-05T22:52:38.962Z,1541458358.962 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-05T22:52:38.963Z,1541458358.963 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-05T22:52:38.963Z,1541458358.963 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-05T22:52:58.716Z,1541458378.716 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-11-05T22:47:58.6Z
2018-11-05T22:52:58.717Z,1541458378.717 [Default:CheckIn:Read_GPS] Stopped
2018-11-05T22:52:58.717Z,1541458378.717 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-11-05T22:53:03.123Z,1541458383.123 [DataOverHttps](INFO): Sending 102 bytes from file Logs/20181105T213126/Courier0033.lzma
2018-11-05T22:53:03.909Z,1541458383.909 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Courier0033.lzma.bak
2018-11-05T22:53:03.909Z,1541458383.909 [DataOverHttps](INFO): SBD MOMSN=8792636
2018-11-05T22:53:14.042Z,1541458394.042 [DataOverHttps](INFO): Sending 197 bytes from file Logs/20181105T213126/Express0034.lzma
2018-11-05T22:53:14.793Z,1541458394.793 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Express0034.lzma.bak
2018-11-05T22:53:14.793Z,1541458394.793 [DataOverHttps](INFO): SBD MOMSN=8792640
2018-11-05T22:53:15.509Z,1541458395.509 [Default:CheckIn:Read_Iridium] Stopped
2018-11-05T22:53:15.512Z,1541458395.512 [Default:CheckIn:C.Wait] Running Loop=1
2018-11-05T22:53:15.534Z,1541458395.534 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-11-05T22:53:19.122Z,1541458399.122 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-11-05T22:53:49.643Z,1541458429.643 [NAL9602](INFO): Powering down
2018-11-05T22:57:47.546Z,1541458667.546 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-11-05T22:57:47.546Z,1541458667.546 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-11-05T22:57:47.546Z,1541458667.546 [Rowe_600LCM](ERROR): Communications Fault
2018-11-05T22:57:47.732Z,1541458667.732 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-11-05T22:57:47.950Z,1541458667.950 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-05T22:57:48.153Z,1541458668.153 [Rowe_600LCM](INFO): Powering down
2018-11-05T22:57:49.621Z,1541458669.621 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-11-05T22:57:49.621Z,1541458669.621 [Rowe_600LCM] No Fault, FailCount= 1
2018-11-05T22:57:49.766Z,1541458669.766 [Rowe_600LCM](INFO): Initializing
2018-11-05T22:57:49.767Z,1541458669.767 [Rowe_600LCM](INFO): Checking LCM
2018-11-05T22:57:49.767Z,1541458669.767 [Rowe_600LCM](INFO): LCM OK
2018-11-05T22:57:49.767Z,1541458669.767 [Rowe_600LCM](INFO): Powering up
2018-11-05T22:57:54.044Z,1541458674.044 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-05T22:57:54.149Z,1541458674.149 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-11-05T22:57:54.150Z,1541458674.150 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-05T22:57:54.151Z,1541458674.151 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-05T22:57:54.152Z,1541458674.152 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-05T22:58:16.006Z,1541458696.006 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-11-05T22:58:16.006Z,1541458696.006 [Default:CheckIn:C.Wait] Stopped
2018-11-05T22:58:16.006Z,1541458696.006 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-11-05T22:58:16.006Z,1541458696.006 [Default:CheckIn:D] Running Loop=1
2018-11-05T22:58:16.423Z,1541458696.423 [Default:CheckIn:D] Stopped
2018-11-05T22:58:16.424Z,1541458696.424 [Default:CheckIn:E] Running Loop=1
2018-11-05T22:58:16.800Z,1541458696.800 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 140.009782 min 
2018-11-05T22:58:16.800Z,1541458696.800 [Default:CheckIn:E] Stopped
2018-11-05T22:58:16.801Z,1541458696.801 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-11-05T22:58:16.801Z,1541458696.801 [Default:CheckIn] Stopped
2018-11-05T22:58:16.801Z,1541458696.801 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-11-05T22:58:16.801Z,1541458696.801 [Default:CheckIn](INFO): Running loop #19
2018-11-05T22:58:16.801Z,1541458696.801 [Default:CheckIn] Running Loop=19
2018-11-05T22:58:16.801Z,1541458696.801 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-11-05T22:58:16.801Z,1541458696.801 [Default:CheckIn:Read_GPS] Running Loop=1
2018-11-05T22:58:20.687Z,1541458700.687 [NAL9602](INFO): Powering up
2018-11-05T22:58:31.863Z,1541458711.863 [NAL9602](INFO): NAL9602 initialized
2018-11-05T22:58:32.664Z,1541458712.664 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-11-05T22:58:32.664Z,1541458712.664 [NAL9602] Data Fault, FailCount= 2
2018-11-05T22:58:32.664Z,1541458712.664 [NAL9602](ERROR): Data Fault
2018-11-05T22:58:32.758Z,1541458712.758 [CBIT](ERROR): Data Fault in component: NAL9602
2018-11-05T22:58:33.063Z,1541458713.063 [NAL9602](INFO): Powering down
2018-11-05T22:58:33.937Z,1541458713.937 [CBIT](INFO): Clearing failed state for component NAL9602
2018-11-05T22:58:33.937Z,1541458713.937 [NAL9602] No Fault, FailCount= 2
2018-11-05T22:59:03.463Z,1541458743.463 [NAL9602](INFO): Powering up NAL9602
2018-11-05T22:59:14.262Z,1541458754.262 [NAL9602](INFO): NAL9602 initialized
2018-11-05T22:59:46.481Z,1541458786.481 [NAL9602](INFO): SBD MO Status=2, MOMSN=10477, MT Status=2, MTMSN=0
2018-11-05T22:59:46.481Z,1541458786.481 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-11-05T23:01:14.612Z,1541458874.612 [NAL9602](INFO): SBD MO Status=2, MOMSN=10477, MT Status=2, MTMSN=0
2018-11-05T23:01:14.613Z,1541458874.613 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-11-05T23:03:17.063Z,1541458997.063 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-11-05T22:58:16.8Z
2018-11-05T23:03:17.063Z,1541458997.063 [Default:CheckIn:Read_GPS] Stopped
2018-11-05T23:03:17.063Z,1541458997.063 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-11-05T23:03:21.886Z,1541459001.886 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20181105T213126/Courier0036.lzma
2018-11-05T23:03:22.673Z,1541459002.673 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Courier0036.lzma.bak
2018-11-05T23:03:22.673Z,1541459002.673 [DataOverHttps](INFO): SBD MOMSN=8792644
2018-11-05T23:03:33.084Z,1541459013.084 [DataOverHttps](INFO): Sending 272 bytes from file Logs/20181105T213126/Express0037.lzma
2018-11-05T23:03:33.869Z,1541459013.869 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Express0037.lzma.bak
2018-11-05T23:03:33.869Z,1541459013.869 [DataOverHttps](INFO): SBD MOMSN=8792646
2018-11-05T23:03:34.428Z,1541459014.428 [Default:CheckIn:Read_Iridium] Stopped
2018-11-05T23:03:34.428Z,1541459014.428 [Default:CheckIn:C.Wait] Running Loop=1
2018-11-05T23:03:34.428Z,1541459014.428 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-11-05T23:03:58.926Z,1541459038.926 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-11-05T23:03:58.927Z,1541459038.927 [Rowe_600LCM] Communications Fault, FailCount= 2
2018-11-05T23:03:58.927Z,1541459038.927 [Rowe_600LCM](ERROR): Communications Fault
2018-11-05T23:03:58.943Z,1541459038.943 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-11-05T23:03:59.330Z,1541459039.330 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-05T23:03:59.483Z,1541459039.483 [Rowe_600LCM](INFO): Powering down
2018-11-05T23:04:00.933Z,1541459040.933 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-11-05T23:04:00.933Z,1541459040.933 [Rowe_600LCM] No Fault, FailCount= 2
2018-11-05T23:04:01.100Z,1541459041.100 [Rowe_600LCM](INFO): Initializing
2018-11-05T23:04:01.101Z,1541459041.101 [Rowe_600LCM](INFO): Checking LCM
2018-11-05T23:04:01.101Z,1541459041.101 [Rowe_600LCM](INFO): LCM OK
2018-11-05T23:04:01.101Z,1541459041.101 [Rowe_600LCM](INFO): Powering up
2018-11-05T23:04:05.221Z,1541459045.221 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-05T23:04:05.341Z,1541459045.341 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-11-05T23:04:05.342Z,1541459045.342 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-05T23:04:05.343Z,1541459045.343 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-05T23:04:05.343Z,1541459045.343 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-05T23:04:21.279Z,1541459061.279 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-11-05T23:04:51.883Z,1541459091.883 [NAL9602](INFO): Powering down
2018-11-05T23:05:51.594Z,1541459151.594 [CBIT](INFO): Clearing failed state for component DropWeight
2018-11-05T23:05:51.594Z,1541459151.594 [DropWeight] No Fault, FailCount= 1
2018-11-05T23:06:01.742Z,1541459161.742 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-11-05T23:06:01.742Z,1541459161.742 [Rowe_600LCM] Communications Fault, FailCount= 3
2018-11-05T23:06:01.742Z,1541459161.742 [Rowe_600LCM](ERROR): Communications Fault
2018-11-05T23:06:01.999Z,1541459161.999 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-11-05T23:06:02.146Z,1541459162.146 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-05T23:06:02.244Z,1541459162.244 [Rowe_600LCM](INFO): Powering down
2018-11-05T23:06:03.595Z,1541459163.595 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-11-05T23:06:03.595Z,1541459163.595 [Rowe_600LCM] No Fault, FailCount= 3
2018-11-05T23:06:03.858Z,1541459163.858 [Rowe_600LCM](INFO): Initializing
2018-11-05T23:06:03.859Z,1541459163.859 [Rowe_600LCM](INFO): Checking LCM
2018-11-05T23:06:03.859Z,1541459163.859 [Rowe_600LCM](INFO): LCM OK
2018-11-05T23:06:03.859Z,1541459163.859 [Rowe_600LCM](INFO): Powering up
2018-11-05T23:06:08.106Z,1541459168.106 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-05T23:06:08.173Z,1541459168.173 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-11-05T23:06:08.174Z,1541459168.174 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-05T23:06:08.175Z,1541459168.175 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-05T23:06:08.176Z,1541459168.176 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-05T23:08:34.861Z,1541459314.861 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-11-05T23:08:34.862Z,1541459314.862 [Default:CheckIn:C.Wait] Stopped
2018-11-05T23:08:34.862Z,1541459314.862 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-11-05T23:08:34.862Z,1541459314.862 [Default:CheckIn:D] Running Loop=1
2018-11-05T23:08:35.222Z,1541459315.222 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-11-05T23:08:35.222Z,1541459315.222 [Rowe_600LCM] Communications Fault, FailCount= 4
2018-11-05T23:08:35.222Z,1541459315.222 [Rowe_600LCM](ERROR): Communications Fault
2018-11-05T23:08:35.264Z,1541459315.264 [Default:CheckIn:D] Stopped
2018-11-05T23:08:35.264Z,1541459315.264 [Default:CheckIn:E] Running Loop=1
2018-11-05T23:08:35.287Z,1541459315.287 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-11-05T23:08:35.626Z,1541459315.626 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-05T23:08:35.701Z,1541459315.701 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 150.323796 min 
2018-11-05T23:08:35.702Z,1541459315.702 [Default:CheckIn:E] Stopped
2018-11-05T23:08:35.702Z,1541459315.702 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-11-05T23:08:35.702Z,1541459315.702 [Default:CheckIn] Stopped
2018-11-05T23:08:35.702Z,1541459315.702 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-11-05T23:08:35.703Z,1541459315.703 [Default:CheckIn](INFO): Running loop #20
2018-11-05T23:08:35.703Z,1541459315.703 [Default:CheckIn] Running Loop=20
2018-11-05T23:08:35.703Z,1541459315.703 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-11-05T23:08:35.703Z,1541459315.703 [Default:CheckIn:Read_GPS] Running Loop=1
2018-11-05T23:08:35.835Z,1541459315.835 [Rowe_600LCM](INFO): Powering down
2018-11-05T23:08:38.885Z,1541459318.885 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-11-05T23:08:38.885Z,1541459318.885 [Rowe_600LCM] No Fault, FailCount= 4
2018-11-05T23:08:38.990Z,1541459318.990 [NAL9602](INFO): Powering up
2018-11-05T23:08:39.066Z,1541459319.066 [Rowe_600LCM](INFO): Initializing
2018-11-05T23:08:39.067Z,1541459319.067 [Rowe_600LCM](INFO): Checking LCM
2018-11-05T23:08:39.067Z,1541459319.067 [Rowe_600LCM](INFO): LCM OK
2018-11-05T23:08:39.067Z,1541459319.067 [Rowe_600LCM](INFO): Powering up
2018-11-05T23:08:43.190Z,1541459323.190 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-05T23:08:43.253Z,1541459323.253 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-11-05T23:08:43.254Z,1541459323.254 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-05T23:08:43.255Z,1541459323.255 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-05T23:08:43.255Z,1541459323.255 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-05T23:08:50.135Z,1541459330.135 [NAL9602](INFO): NAL9602 initialized
2018-11-05T23:09:22.116Z,1541459362.116 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2018-11-05T23:09:22.190Z,1541459362.190 [NAL9602](FAULT): received: 
+CSQ:0

OK477, 2, 0, 0, 0

OK
2018-11-05T23:09:22.190Z,1541459362.190 [NAL9602] Data Fault, FailCount= 3
2018-11-05T23:09:22.191Z,1541459362.191 [NAL9602](ERROR): Data Fault
2018-11-05T23:09:22.272Z,1541459362.272 [CBIT](ERROR): Data Fault in component: NAL9602
2018-11-05T23:09:22.524Z,1541459362.524 [NAL9602](INFO): Powering down
2018-11-05T23:09:23.440Z,1541459363.440 [CBIT](INFO): Clearing failed state for component NAL9602
2018-11-05T23:09:23.440Z,1541459363.440 [NAL9602] No Fault, FailCount= 3
2018-11-05T23:09:52.912Z,1541459392.912 [NAL9602](INFO): Powering up NAL9602
2018-11-05T23:10:04.112Z,1541459404.112 [NAL9602](INFO): NAL9602 initialized
2018-11-05T23:10:04.912Z,1541459404.912 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-11-05T23:10:04.912Z,1541459404.912 [NAL9602] Data Fault, FailCount= 4
2018-11-05T23:10:04.912Z,1541459404.912 [NAL9602](ERROR): Data Fault
2018-11-05T23:10:05.004Z,1541459405.004 [CBIT](ERROR): Data Fault in component: NAL9602
2018-11-05T23:10:05.311Z,1541459405.311 [NAL9602](INFO): Powering down
2018-11-05T23:10:06.181Z,1541459406.181 [CBIT](INFO): Clearing failed state for component NAL9602
2018-11-05T23:10:06.181Z,1541459406.181 [NAL9602] No Fault, FailCount= 4
2018-11-05T23:10:35.720Z,1541459435.720 [NAL9602](INFO): Powering up NAL9602
2018-11-05T23:10:46.764Z,1541459446.764 [NAL9602](INFO): NAL9602 initialized
2018-11-05T23:11:09.966Z,1541459469.966 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-11-05T23:11:09.966Z,1541459469.966 [Rowe_600LCM] Communications Fault, FailCount= 5
2018-11-05T23:11:09.966Z,1541459469.966 [Rowe_600LCM](ERROR): Communications Fault
2018-11-05T23:11:10.062Z,1541459470.062 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-11-05T23:11:10.066Z,1541459470.066 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM
2018-11-05T23:11:10.371Z,1541459470.371 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-05T23:11:10.568Z,1541459470.568 [Rowe_600LCM](INFO): Powering down
2018-11-05T23:13:36.008Z,1541459616.008 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-11-05T23:08:35.7Z
2018-11-05T23:13:36.008Z,1541459616.008 [Default:CheckIn:Read_GPS] Stopped
2018-11-05T23:13:36.008Z,1541459616.008 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-11-05T23:13:40.069Z,1541459620.069 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20181105T213126/Courier0039.lzma
2018-11-05T23:13:40.891Z,1541459620.891 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Courier0039.lzma.bak
2018-11-05T23:13:40.891Z,1541459620.891 [DataOverHttps](INFO): SBD MOMSN=8792652
2018-11-05T23:13:49.765Z,1541459629.765 [DataOverHttps](INFO): Sending 374 bytes from file Logs/20181105T213126/Express0040.lzma
2018-11-05T23:13:50.565Z,1541459630.565 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Express0040.lzma.bak
2018-11-05T23:13:50.565Z,1541459630.565 [DataOverHttps](INFO): SBD MOMSN=8792654
2018-11-05T23:13:51.124Z,1541459631.124 [Default:CheckIn:Read_Iridium] Stopped
2018-11-05T23:13:51.124Z,1541459631.124 [Default:CheckIn:C.Wait] Running Loop=1
2018-11-05T23:13:51.124Z,1541459631.124 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-11-05T23:13:54.491Z,1541459634.491 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-11-05T23:14:24.975Z,1541459664.975 [NAL9602](INFO): Powering down
2018-11-05T23:18:51.647Z,1541459931.647 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-11-05T23:18:51.647Z,1541459931.647 [Default:CheckIn:C.Wait] Stopped
2018-11-05T23:18:51.647Z,1541459931.647 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-11-05T23:18:51.648Z,1541459931.648 [Default:CheckIn:D] Running Loop=1
2018-11-05T23:18:52.053Z,1541459932.053 [Default:CheckIn:D] Stopped
2018-11-05T23:18:52.053Z,1541459932.053 [Default:CheckIn:E] Running Loop=1
2018-11-05T23:18:52.458Z,1541459932.458 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 160.603597 min 
2018-11-05T23:18:52.459Z,1541459932.459 [Default:CheckIn:E] Stopped
2018-11-05T23:18:52.459Z,1541459932.459 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-11-05T23:18:52.459Z,1541459932.459 [Default:CheckIn] Stopped
2018-11-05T23:18:52.459Z,1541459932.459 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-11-05T23:18:52.460Z,1541459932.460 [Default:CheckIn](INFO): Running loop #21
2018-11-05T23:18:52.460Z,1541459932.460 [Default:CheckIn] Running Loop=21
2018-11-05T23:18:52.460Z,1541459932.460 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-11-05T23:18:52.460Z,1541459932.460 [Default:CheckIn:Read_GPS] Running Loop=1
2018-11-05T23:18:55.695Z,1541459935.695 [NAL9602](INFO): Powering up
2018-11-05T23:19:06.876Z,1541459946.876 [NAL9602](INFO): NAL9602 initialized
2018-11-05T23:19:38.872Z,1541459978.872 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2018-11-05T23:19:38.946Z,1541459978.946 [NAL9602](FAULT): received: 
+CSQ:0

OK477, 2, 0, 0, 0

OK
2018-11-05T23:19:38.946Z,1541459978.946 [NAL9602] Data Fault, FailCount= 5
2018-11-05T23:19:38.946Z,1541459978.946 [NAL9602](ERROR): Data Fault
2018-11-05T23:19:39.028Z,1541459979.028 [CBIT](ERROR): Data Fault in component: NAL9602
2018-11-05T23:19:39.028Z,1541459979.028 [CBIT](CRITICAL): Data Fault in component: NAL9602
2018-11-05T23:19:39.271Z,1541459979.271 [NAL9602](INFO): Powering down
2018-11-05T23:19:39.330Z,1541459979.330 [CBIT](INFO): Critical error at 20181105T231939
2018-11-05T23:21:10.287Z,1541460070.287 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-11-05T23:21:10.287Z,1541460070.287 [Rowe_600LCM] No Fault, FailCount= 5
2018-11-05T23:21:10.558Z,1541460070.558 [Rowe_600LCM](INFO): Initializing
2018-11-05T23:21:10.559Z,1541460070.559 [Rowe_600LCM](INFO): Checking LCM
2018-11-05T23:21:10.559Z,1541460070.559 [Rowe_600LCM](INFO): LCM OK
2018-11-05T23:21:10.559Z,1541460070.559 [Rowe_600LCM](INFO): Powering up
2018-11-05T23:21:14.807Z,1541460074.807 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-05T23:21:14.877Z,1541460074.877 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-11-05T23:21:14.878Z,1541460074.878 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-05T23:21:14.879Z,1541460074.879 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-05T23:21:14.879Z,1541460074.879 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-05T23:21:39.136Z,1541460099.136 [CBIT](INFO): Clearing failed state for component NAL9602
2018-11-05T23:21:39.136Z,1541460099.136 [NAL9602] No Fault, FailCount= 5
2018-11-05T23:21:39.440Z,1541460099.440 [NAL9602](INFO): Powering up NAL9602
2018-11-05T23:21:50.640Z,1541460110.640 [NAL9602](INFO): NAL9602 initialized
2018-11-05T23:21:51.432Z,1541460111.432 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-11-05T23:21:51.432Z,1541460111.432 [NAL9602] Data Fault, FailCount= 1
2018-11-05T23:21:51.432Z,1541460111.432 [NAL9602](ERROR): Data Fault
2018-11-05T23:21:51.537Z,1541460111.537 [CBIT](ERROR): Data Fault in component: NAL9602
2018-11-05T23:21:51.832Z,1541460111.832 [NAL9602](INFO): Powering down
2018-11-05T23:21:52.695Z,1541460112.695 [CBIT](INFO): Clearing failed state for component NAL9602
2018-11-05T23:21:52.695Z,1541460112.695 [NAL9602] No Fault, FailCount= 1
2018-11-05T23:22:21.920Z,1541460141.920 [NAL9602](INFO): Powering up NAL9602
2018-11-05T23:22:33.128Z,1541460153.128 [NAL9602](INFO): NAL9602 initialized
2018-11-05T23:23:52.657Z,1541460232.657 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-11-05T23:18:52.5Z
2018-11-05T23:23:52.657Z,1541460232.657 [Default:CheckIn:Read_GPS] Stopped
2018-11-05T23:23:52.657Z,1541460232.657 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-11-05T23:23:57.058Z,1541460237.058 [DataOverHttps](INFO): Sending 69 bytes from file Logs/20181105T213126/Courier0042.lzma
2018-11-05T23:23:57.847Z,1541460237.847 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Courier0042.lzma.bak
2018-11-05T23:23:57.847Z,1541460237.847 [DataOverHttps](INFO): SBD MOMSN=8792665
2018-11-05T23:24:00.198Z,1541460240.198 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-11-05T23:24:00.198Z,1541460240.198 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-11-05T23:24:00.198Z,1541460240.198 [Rowe_600LCM](ERROR): Communications Fault
2018-11-05T23:24:00.602Z,1541460240.602 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-05T23:24:00.756Z,1541460240.756 [Rowe_600LCM](INFO): Powering down
2018-11-05T23:24:02.336Z,1541460242.336 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-11-05T23:24:02.336Z,1541460242.336 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-11-05T23:24:02.336Z,1541460242.336 [Rowe_600LCM] No Fault, FailCount= 1
2018-11-05T23:24:02.370Z,1541460242.370 [Rowe_600LCM](INFO): Initializing
2018-11-05T23:24:02.371Z,1541460242.371 [Rowe_600LCM](INFO): Checking LCM
2018-11-05T23:24:02.371Z,1541460242.371 [Rowe_600LCM](INFO): LCM OK
2018-11-05T23:24:02.371Z,1541460242.371 [Rowe_600LCM](INFO): Powering up
2018-11-05T23:24:06.563Z,1541460246.563 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-05T23:24:06.673Z,1541460246.673 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-11-05T23:24:06.674Z,1541460246.674 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-05T23:24:06.683Z,1541460246.683 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-05T23:24:06.684Z,1541460246.684 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-05T23:24:07.587Z,1541460247.587 [DataOverHttps](INFO): Sending 256 bytes from file Logs/20181105T213126/Express0043.lzma
2018-11-05T23:24:08.386Z,1541460248.386 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Express0043.lzma.bak
2018-11-05T23:24:08.386Z,1541460248.386 [DataOverHttps](INFO): SBD MOMSN=8792668
2018-11-05T23:24:09.135Z,1541460249.135 [Default:CheckIn:Read_Iridium] Stopped
2018-11-05T23:24:09.135Z,1541460249.135 [Default:CheckIn:C.Wait] Running Loop=1
2018-11-05T23:24:09.135Z,1541460249.135 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-11-05T23:24:13.791Z,1541460253.791 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-11-05T23:24:44.304Z,1541460284.304 [NAL9602](INFO): Powering down
2018-11-05T23:28:04.278Z,1541460484.278 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-11-05T23:28:04.278Z,1541460484.278 [Rowe_600LCM] Communications Fault, FailCount= 2
2018-11-05T23:28:04.278Z,1541460484.278 [Rowe_600LCM](ERROR): Communications Fault
2018-11-05T23:28:04.547Z,1541460484.547 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-11-05T23:28:04.682Z,1541460484.682 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-05T23:28:04.770Z,1541460484.770 [Rowe_600LCM](INFO): Powering down
2018-11-05T23:28:06.124Z,1541460486.124 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-11-05T23:28:06.124Z,1541460486.124 [Rowe_600LCM] No Fault, FailCount= 2
2018-11-05T23:28:06.386Z,1541460486.386 [Rowe_600LCM](INFO): Initializing
2018-11-05T23:28:06.387Z,1541460486.387 [Rowe_600LCM](INFO): Checking LCM
2018-11-05T23:28:06.387Z,1541460486.387 [Rowe_600LCM](INFO): LCM OK
2018-11-05T23:28:06.387Z,1541460486.387 [Rowe_600LCM](INFO): Powering up
2018-11-05T23:28:10.628Z,1541460490.628 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-05T23:28:10.707Z,1541460490.707 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-11-05T23:28:10.708Z,1541460490.708 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-05T23:28:10.708Z,1541460490.708 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-05T23:28:10.709Z,1541460490.709 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-05T23:29:09.552Z,1541460549.552 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-11-05T23:29:09.553Z,1541460549.553 [Default:CheckIn:C.Wait] Stopped
2018-11-05T23:29:09.553Z,1541460549.553 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-11-05T23:29:09.553Z,1541460549.553 [Default:CheckIn:D] Running Loop=1
2018-11-05T23:29:09.922Z,1541460549.922 [Default:CheckIn:D] Stopped
2018-11-05T23:29:09.922Z,1541460549.922 [Default:CheckIn:E] Running Loop=1
2018-11-05T23:29:10.314Z,1541460550.314 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 170.901351 min 
2018-11-05T23:29:10.315Z,1541460550.315 [Default:CheckIn:E] Stopped
2018-11-05T23:29:10.315Z,1541460550.315 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-11-05T23:29:10.315Z,1541460550.315 [Default:CheckIn] Stopped
2018-11-05T23:29:10.315Z,1541460550.315 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-11-05T23:29:10.315Z,1541460550.315 [Default:CheckIn](INFO): Running loop #22
2018-11-05T23:29:10.315Z,1541460550.315 [Default:CheckIn] Running Loop=22
2018-11-05T23:29:10.315Z,1541460550.315 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-11-05T23:29:10.315Z,1541460550.315 [Default:CheckIn:Read_GPS] Running Loop=1
2018-11-05T23:29:14.176Z,1541460554.176 [NAL9602](INFO): Powering up
2018-11-05T23:29:25.056Z,1541460565.056 [NAL9602](INFO): NAL9602 initialized
2018-11-05T23:29:57.052Z,1541460597.052 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2018-11-05T23:29:57.131Z,1541460597.131 [NAL9602](FAULT): received: 
+CSQ:0

OK477, 2, 0, 0, 0

OK
2018-11-05T23:29:57.132Z,1541460597.132 [NAL9602] Data Fault, FailCount= 2
2018-11-05T23:29:57.132Z,1541460597.132 [NAL9602](ERROR): Data Fault
2018-11-05T23:29:57.231Z,1541460597.231 [CBIT](ERROR): Data Fault in component: NAL9602
2018-11-05T23:29:57.456Z,1541460597.456 [NAL9602](INFO): Powering down
2018-11-05T23:29:58.335Z,1541460598.335 [CBIT](INFO): Clearing failed state for component NAL9602
2018-11-05T23:29:58.335Z,1541460598.335 [NAL9602] No Fault, FailCount= 2
2018-11-05T23:30:27.688Z,1541460627.688 [NAL9602](INFO): Powering up NAL9602
2018-11-05T23:30:38.888Z,1541460638.888 [NAL9602](INFO): NAL9602 initialized
2018-11-05T23:31:59.518Z,1541460719.518 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-11-05T23:31:59.518Z,1541460719.518 [Rowe_600LCM] Communications Fault, FailCount= 3
2018-11-05T23:31:59.518Z,1541460719.518 [Rowe_600LCM](ERROR): Communications Fault
2018-11-05T23:31:59.921Z,1541460719.921 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-11-05T23:31:59.922Z,1541460719.922 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-05T23:32:00.079Z,1541460720.079 [Rowe_600LCM](INFO): Powering down
2018-11-05T23:32:01.452Z,1541460721.452 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-11-05T23:32:01.452Z,1541460721.452 [Rowe_600LCM] No Fault, FailCount= 3
2018-11-05T23:32:01.694Z,1541460721.694 [Rowe_600LCM](INFO): Initializing
2018-11-05T23:32:01.695Z,1541460721.695 [Rowe_600LCM](INFO): Checking LCM
2018-11-05T23:32:01.695Z,1541460721.695 [Rowe_600LCM](INFO): LCM OK
2018-11-05T23:32:01.695Z,1541460721.695 [Rowe_600LCM](INFO): Powering up
2018-11-05T23:32:05.936Z,1541460725.936 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-05T23:32:06.005Z,1541460726.005 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-11-05T23:32:06.006Z,1541460726.006 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-05T23:32:06.007Z,1541460726.007 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-05T23:32:06.007Z,1541460726.007 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-05T23:34:02.462Z,1541460842.462 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-11-05T23:34:02.462Z,1541460842.462 [Rowe_600LCM] Communications Fault, FailCount= 4
2018-11-05T23:34:02.462Z,1541460842.462 [Rowe_600LCM](ERROR): Communications Fault
2018-11-05T23:34:02.844Z,1541460842.844 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-11-05T23:34:02.866Z,1541460842.866 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-05T23:34:03.006Z,1541460843.006 [Rowe_600LCM](INFO): Powering down
2018-11-05T23:34:04.432Z,1541460844.432 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-11-05T23:34:04.432Z,1541460844.432 [Rowe_600LCM] No Fault, FailCount= 4
2018-11-05T23:34:04.622Z,1541460844.622 [Rowe_600LCM](INFO): Initializing
2018-11-05T23:34:04.623Z,1541460844.623 [Rowe_600LCM](INFO): Checking LCM
2018-11-05T23:34:04.623Z,1541460844.623 [Rowe_600LCM](INFO): LCM OK
2018-11-05T23:34:04.623Z,1541460844.623 [Rowe_600LCM](INFO): Powering up
2018-11-05T23:34:08.744Z,1541460848.744 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-05T23:34:08.894Z,1541460848.894 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-11-05T23:34:08.895Z,1541460848.895 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-05T23:34:08.895Z,1541460848.895 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-05T23:34:08.896Z,1541460848.896 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-05T23:34:10.468Z,1541460850.468 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-11-05T23:29:10.3Z
2018-11-05T23:34:10.468Z,1541460850.468 [Default:CheckIn:Read_GPS] Stopped
2018-11-05T23:34:10.468Z,1541460850.468 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-11-05T23:34:28.324Z,1541460868.324 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-11-05T23:34:41.916Z,1541460881.916 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-11-05T23:34:59.123Z,1541460899.123 [NAL9602](INFO): Powering down
2018-11-05T23:35:12.715Z,1541460912.715 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-11-05T23:35:43.516Z,1541460943.516 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-11-05T23:35:53.123Z,1541460953.123 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2018-11-05T23:35:53.123Z,1541460953.123 [DropWeight] Hardware Fault, FailCount= 1
2018-11-05T23:35:53.123Z,1541460953.123 [DropWeight](ERROR): Hardware Fault
2018-11-05T23:35:53.202Z,1541460953.202 [CBIT](INFO): Critical error at 20181105T233553
2018-11-05T23:35:53.205Z,1541460953.205 [CBIT](ERROR): Hardware Fault in component: DropWeight
2018-11-05T23:35:53.205Z,1541460953.205 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2018-11-05T23:35:53.583Z,1541460953.583 [CBIT](INFO): Critical error at 20181105T233553
2018-11-05T23:36:14.315Z,1541460974.315 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-11-05T23:36:16.717Z,1541460976.717 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.341385
2018-11-05T23:36:16.723Z,1541460976.723 [NAL9602](INFO): Powering up
2018-11-05T23:36:27.919Z,1541460987.919 [NAL9602](INFO): NAL9602 initialized
2018-11-05T23:36:47.115Z,1541461007.115 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-11-05T23:36:57.931Z,1541461017.931 [NAL9602](ERROR): Queried for signal strength and failed to receive proper response. 
2018-11-05T23:36:58.010Z,1541461018.010 [NAL9602](ERROR): received: 
COMMAND MODE: Started

COMMAND MODE: Ready for Input

2018-11-05T23:36:58.010Z,1541461018.010 [NAL9602] Data Fault, FailCount= 3
2018-11-05T23:36:58.011Z,1541461018.011 [NAL9602](ERROR): Data Fault
2018-11-05T23:36:58.087Z,1541461018.087 [CBIT](ERROR): Data Fault in component: NAL9602
2018-11-05T23:36:58.319Z,1541461018.319 [NAL9602](INFO): Powering down
2018-11-05T23:36:59.175Z,1541461019.175 [CBIT](INFO): Clearing failed state for component NAL9602
2018-11-05T23:36:59.175Z,1541461019.175 [NAL9602] No Fault, FailCount= 3
2018-11-05T23:37:28.719Z,1541461048.719 [NAL9602](INFO): Powering up NAL9602
2018-11-05T23:37:39.519Z,1541461059.519 [NAL9602](INFO): NAL9602 initialized
2018-11-05T23:37:47.116Z,1541461067.116 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-11-05T23:38:22.299Z,1541461102.299 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002800
2018-11-05T23:38:23.591Z,1541461103.591 [CommandLine](IMPORTANT): got command failComponent
2018-11-05T23:38:23.591Z,1541461103.591 [CommandLine](IMPORTANT): Failed components:
2018-11-05T23:38:23.592Z,1541461103.592 [CommandLine](IMPORTANT): DropWeight: Hardware Fault
2018-11-05T23:38:26.974Z,1541461106.974 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20181105T213126/Courier0045.lzma
2018-11-05T23:38:27.741Z,1541461107.741 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Courier0045.lzma.bak
2018-11-05T23:38:27.741Z,1541461107.741 [DataOverHttps](INFO): SBD MOMSN=8792674
2018-11-05T23:38:35.080Z,1541461115.080 [CommandLine](IMPORTANT): got command restart system
2018-11-05T23:38:37.815Z,1541461117.815 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-05T23:38:37.815Z,1541461117.815 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:38:37.831Z,1541461117.831 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2018-11-05T23:38:37.831Z,1541461117.831 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:38:37.832Z,1541461117.832 [CommandLine](INFO): Join timeout helper Thread ID is 1485
2018-11-05T23:38:37.841Z,1541461117.841 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-11-05T23:38:37.841Z,1541461117.841 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:38:37.842Z,1541461117.842 [NavChartDb](INFO): Join timeout helper Thread ID is 1486
2018-11-05T23:38:38.202Z,1541461118.202 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-05T23:38:38.203Z,1541461118.203 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:38:38.222Z,1541461118.222 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2018-11-05T23:38:38.222Z,1541461118.222 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:38:38.223Z,1541461118.223 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1487
2018-11-05T23:38:38.418Z,1541461118.418 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-05T23:38:38.419Z,1541461118.419 [WetLabsBB2FL](INFO): Powering down
2018-11-05T23:38:38.420Z,1541461118.420 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:38:38.430Z,1541461118.430 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2018-11-05T23:38:38.430Z,1541461118.430 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:38:38.431Z,1541461118.431 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1488
2018-11-05T23:38:38.512Z,1541461118.512 [DataOverHttps](INFO): Sending 314 bytes from file Logs/20181105T213126/Express0046.lzma
2018-11-05T23:38:38.731Z,1541461118.731 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-05T23:38:38.822Z,1541461118.822 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-11-05T23:38:38.822Z,1541461118.822 [CTD_Seabird](INFO): Powering down
2018-11-05T23:38:38.824Z,1541461118.824 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:38:38.842Z,1541461118.842 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2018-11-05T23:38:38.842Z,1541461118.842 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:38:38.843Z,1541461118.843 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 1490
2018-11-05T23:38:38.863Z,1541461118.863 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-05T23:38:38.863Z,1541461118.863 [CTD_NeilBrown](INFO): Powering down
2018-11-05T23:38:38.878Z,1541461118.878 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:38:38.884Z,1541461118.884 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2018-11-05T23:38:38.884Z,1541461118.884 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:38:38.884Z,1541461118.884 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 1491
2018-11-05T23:38:39.289Z,1541461119.289 [DataOverHttps](INFO): Moved sent file to Logs/20181105T213126/Express0046.lzma.bak
2018-11-05T23:38:39.289Z,1541461119.289 [DataOverHttps](INFO): SBD MOMSN=8792676
2018-11-05T23:38:39.416Z,1541461119.416 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-05T23:38:39.416Z,1541461119.416 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-05T23:38:39.503Z,1541461119.503 [Rowe_600LCM](INFO): Powering down
2018-11-05T23:38:39.505Z,1541461119.505 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:38:39.523Z,1541461119.523 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-11-05T23:38:39.523Z,1541461119.523 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:38:39.524Z,1541461119.524 [Radio_Surface](INFO): Join timeout helper Thread ID is 1493
2018-11-05T23:38:39.595Z,1541461119.595 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-05T23:38:39.595Z,1541461119.595 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:38:39.603Z,1541461119.603 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-11-05T23:38:39.603Z,1541461119.603 [logger ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:38:39.604Z,1541461119.604 [logger](INFO): Join timeout helper Thread ID is 1494
2018-11-05T23:38:39.614Z,1541461119.614 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-05T23:38:39.615Z,1541461119.615 [logger ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:38:39.623Z,1541461119.623 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-11-05T23:38:39.623Z,1541461119.623 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:38:39.623Z,1541461119.623 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-11-05T23:38:39.623Z,1541461119.623 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:38:39.624Z,1541461119.624 [controlThread](INFO): Join timeout helper Thread ID is 1495
2018-11-05T23:38:39.683Z,1541461119.683 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-05T23:38:39.683Z,1541461119.683 [controlThread](DEBUG): Uninitializing ControlThread
2018-11-05T23:38:39.684Z,1541461119.684 [NAL9602](INFO): Powering down
2018-11-05T23:38:39.685Z,1541461119.685 [PNI_TCM](INFO): Powering down
2018-11-05T23:38:39.775Z,1541461119.775 [Aanderaa_O2](INFO): Powering down
2018-11-05T23:38:39.776Z,1541461119.776 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-11-05T23:38:39.777Z,1541461119.777 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2018-11-05T23:38:39.778Z,1541461119.778 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-11-05T23:38:39.778Z,1541461119.778 [MissionManager](INFO): Uninitializing Mission Default
2018-11-05T23:38:39.779Z,1541461119.779 [Default] Stopped
2018-11-05T23:38:39.779Z,1541461119.779 [Default](DEBUG): Aggregate::uninitialize Default
2018-11-05T23:38:39.779Z,1541461119.779 [Default:B.GoToSurface] Stopped
2018-11-05T23:38:39.779Z,1541461119.779 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-11-05T23:38:39.779Z,1541461119.779 [Default:CheckIn] Stopped
2018-11-05T23:38:39.779Z,1541461119.779 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-11-05T23:38:39.779Z,1541461119.779 [Default:CheckIn:Read_Iridium] Stopped
2018-11-05T23:38:39.784Z,1541461119.784 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-11-05T23:38:39.784Z,1541461119.784 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-11-05T23:38:39.784Z,1541461119.784 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-11-05T23:38:39.785Z,1541461119.785 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-11-05T23:38:39.785Z,1541461119.785 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-11-05T23:38:39.785Z,1541461119.785 [BuoyancyServo](INFO): Powering down
2018-11-05T23:38:39.798Z,1541461119.798 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-11-05T23:38:39.799Z,1541461119.799 [ElevatorServo](INFO): Powering down
2018-11-05T23:38:39.800Z,1541461119.800 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-11-05T23:38:39.800Z,1541461119.800 [MassServo](INFO): Powering down
2018-11-05T23:38:39.801Z,1541461119.801 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-11-05T23:38:39.801Z,1541461119.801 [RudderServo](INFO): Powering down
2018-11-05T23:38:39.802Z,1541461119.802 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-11-05T23:38:39.802Z,1541461119.802 [ThrusterServo](INFO): Powering down
2018-11-05T23:38:39.803Z,1541461119.803 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-11-05T23:38:39.803Z,1541461119.803 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-11-05T23:38:39.804Z,1541461119.804 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-11-05T23:38:39.804Z,1541461119.804 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:38:39.877Z,1541461119.877 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:38:39.884Z,1541461119.884 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:38:39.924Z,1541461119.924 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:38:39.928Z,1541461119.928 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:38:39.931Z,1541461119.931 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:38:39.959Z,1541461119.959 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:38:40.024Z,1541461120.024 [logger ThreadHandler](INFO): Thread cancelled.