2017-09-06T16:42:58.213Z,1504716178.213 [CommandLine](IMPORTANT): got command restart logs 2017-09-06T16:43:00.795Z,1504716180.795 [PNI_TCM](ERROR): CRC does not match. Expected:0x64639 got:0x41 2017-09-06T16:43:01.195Z,1504716181.195 [PNI_TCM](ERROR): CRC does not match. Expected:0x10589 got:0x1857 2017-09-06T16:43:08.803Z,1504716188.803 [PNI_TCM](ERROR): CRC does not match. Expected:0x42838 got:0x16811 2017-09-06T16:43:10.402Z,1504716190.402 [PNI_TCM](ERROR): CRC does not match. Expected:0x29777 got:0x239 2017-09-06T16:43:15.208Z,1504716195.208 [PNI_TCM](ERROR): CRC does not match. Expected:0x13764 got:0x10501 2017-09-06T16:43:16.812Z,1504716196.812 [PNI_TCM](ERROR): CRC does not match. Expected:0x51605 got:0x32768 2017-09-06T16:43:18.804Z,1504716198.804 [PNI_TCM](ERROR): CRC does not match. Expected:0x45431 got:0x7451 2017-09-06T16:43:26.419Z,1504716206.419 [PNI_TCM](ERROR): CRC does not match. Expected:0x2523 got:0x7489 2017-09-06T16:43:28.003Z,1504716208.003 [PNI_TCM](ERROR): CRC does not match. Expected:0x20242 got:0x7105 2017-09-06T16:44:44.942Z,1504716284.942 [Default:CheckIn:Read_GPS](INFO): Timed out from 2017-09-06T16:39:44.9Z 2017-09-06T16:44:44.942Z,1504716284.942 [Default:CheckIn:Read_GPS] Stopped 2017-09-06T16:44:44.943Z,1504716284.943 [Default:CheckIn:Read_Iridium] Running Loop=1 2017-09-06T16:44:49.602Z,1504716289.602 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20170906T162656/Courier0008.lzma 2017-09-06T16:44:50.377Z,1504716290.377 [DataOverHttps](INFO): Moved sent file to Logs/20170906T162656/Courier0008.lzma.bak 2017-09-06T16:44:50.377Z,1504716290.377 [DataOverHttps](INFO): SBD MOMSN=5072629 2017-09-06T16:44:59.647Z,1504716299.647 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20170906T164258/Courier0000.lzma 2017-09-06T16:45:00.436Z,1504716300.436 [DataOverHttps](INFO): Moved sent file to Logs/20170906T164258/Courier0000.lzma.bak 2017-09-06T16:45:00.436Z,1504716300.436 [DataOverHttps](INFO): SBD MOMSN=5072631 2017-09-06T16:45:09.701Z,1504716309.701 [DataOverHttps](INFO): Sending 1562 bytes from file Logs/20170906T162656/Express0009.lzma 2017-09-06T16:45:10.492Z,1504716310.492 [DataOverHttps](INFO): Moved sent file to Logs/20170906T162656/Express0009.lzma.bak 2017-09-06T16:45:10.492Z,1504716310.492 [DataOverHttps](INFO): SBD MOMSN=5072634 2017-09-06T16:45:19.618Z,1504716319.618 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2017-09-06T16:45:19.749Z,1504716319.749 [DataOverHttps](INFO): Sending 256 bytes from file Logs/20170906T164258/Express0001.lzma 2017-09-06T16:45:20.543Z,1504716320.543 [DataOverHttps](INFO): Moved sent file to Logs/20170906T164258/Express0001.lzma.bak 2017-09-06T16:45:20.544Z,1504716320.544 [DataOverHttps](INFO): SBD MOMSN=5072731 2017-09-06T16:45:21.106Z,1504716321.106 [Default:CheckIn:Read_Iridium] Stopped 2017-09-06T16:45:21.106Z,1504716321.106 [Default:CheckIn:C.Wait] Running Loop=1 2017-09-06T16:45:21.107Z,1504716321.107 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2017-09-06T16:45:25.120Z,1504716325.120 [NAL9602](INFO): Powering down 2017-09-06T16:48:08.367Z,1504716488.367 [CBIT](DEBUG): EFC running - data check-sum false 2017-09-06T16:50:21.525Z,1504716621.525 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2017-09-06T16:50:21.525Z,1504716621.525 [Default:CheckIn:C.Wait] Stopped 2017-09-06T16:50:21.525Z,1504716621.525 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2017-09-06T16:50:21.526Z,1504716621.526 [Default:CheckIn:D] Running Loop=1 2017-09-06T16:50:21.931Z,1504716621.931 [Default:CheckIn:D] Stopped 2017-09-06T16:50:21.931Z,1504716621.931 [Default:CheckIn:E] Running Loop=1 2017-09-06T16:50:22.335Z,1504716622.335 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.846228 min 2017-09-06T16:50:22.335Z,1504716622.335 [Default:CheckIn:E] Stopped 2017-09-06T16:50:22.335Z,1504716622.335 [Default:CheckIn](INFO): Completed Default:CheckIn 2017-09-06T16:50:22.335Z,1504716622.335 [Default:CheckIn] Stopped 2017-09-06T16:50:22.335Z,1504716622.335 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2017-09-06T16:50:22.335Z,1504716622.335 [Default:CheckIn](INFO): Running loop #2 2017-09-06T16:50:22.336Z,1504716622.336 [Default:CheckIn] Running Loop=2 2017-09-06T16:50:22.336Z,1504716622.336 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2017-09-06T16:50:22.336Z,1504716622.336 [Default:CheckIn:Read_GPS] Running Loop=1 2017-09-06T16:50:25.854Z,1504716625.854 [NAL9602](INFO): Powering up 2017-09-06T16:50:36.999Z,1504716636.999 [NAL9602](INFO): NAL9602 initialized 2017-09-06T16:50:37.801Z,1504716637.801 [NAL9602](FAULT): GPS failed to acquire within timeout. 2017-09-06T16:50:37.801Z,1504716637.801 [NAL9602] Data Fault, FailCount= 2 2017-09-06T16:50:37.801Z,1504716637.801 [NAL9602](ERROR): Data Fault 2017-09-06T16:50:37.882Z,1504716637.882 [CBIT](ERROR): Data Fault in component: NAL9602 2017-09-06T16:50:38.201Z,1504716638.201 [NAL9602](INFO): Powering down 2017-09-06T16:50:39.105Z,1504716639.105 [CBIT](INFO): Clearing failed state for component NAL9602 2017-09-06T16:50:39.105Z,1504716639.105 [NAL9602] No Fault, FailCount= 2 2017-09-06T16:50:43.399Z,1504716643.399 [NAL9602](INFO): Powering up NAL9602 2017-09-06T16:50:54.206Z,1504716654.206 [NAL9602](INFO): NAL9602 initialized 2017-09-06T16:52:36.740Z,1504716756.740 [PNI_TCM](ERROR): CRC does not match. Expected:0x10722 got:0x37403 2017-09-06T16:52:38.328Z,1504716758.328 [PNI_TCM](ERROR): CRC does not match. Expected:0x3223 got:0x49334 2017-09-06T16:52:44.719Z,1504716764.719 [PNI_TCM](ERROR): CRC does not match. Expected:0x48771 got:0x1287 2017-09-06T16:52:47.920Z,1504716767.920 [PNI_TCM](ERROR): CRC does not match. Expected:0x50072 got:0x49335 2017-09-06T16:52:49.516Z,1504716769.516 [PNI_TCM](ERROR): CRC does not match. Expected:0x47784 got:0x16384 2017-09-06T16:52:51.126Z,1504716771.126 [PNI_TCM](ERROR): CRC does not match. Expected:0x23555 got:0x16863 2017-09-06T16:53:26.844Z,1504716806.844 [DataOverHttps](IMPORTANT): SBD MTMSN=20170906T165211 2017-09-06T16:53:31.122Z,1504716811.122 [DataOverHttps](INFO): Received command:restart app 2017-09-06T16:53:31.163Z,1504716811.163 [CommandLine](IMPORTANT): got command restart application 2017-09-06T16:53:32.186Z,1504716812.186 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2017-09-06T16:53:32.186Z,1504716812.186 [CommandLine ThreadHandler](INFO): Thread cancelled. 2017-09-06T16:53:32.276Z,1504716812.276 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2017-09-06T16:53:32.276Z,1504716812.276 [CommandLine ThreadHandler](INFO): Thread cancelled. 2017-09-06T16:53:32.277Z,1504716812.277 [CommandLine](INFO): Join timeout helper Thread ID is 2206 2017-09-06T16:53:32.277Z,1504716812.277 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2017-09-06T16:53:32.277Z,1504716812.277 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2017-09-06T16:53:32.278Z,1504716812.278 [NavChartDb](INFO): Join timeout helper Thread ID is 2207 2017-09-06T16:53:32.652Z,1504716812.652 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2017-09-06T16:53:32.652Z,1504716812.652 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2017-09-06T16:53:32.664Z,1504716812.664 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2017-09-06T16:53:32.664Z,1504716812.664 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2017-09-06T16:53:32.664Z,1504716812.664 [Radio_Surface](INFO): Join timeout helper Thread ID is 2208 2017-09-06T16:53:32.728Z,1504716812.728 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2017-09-06T16:53:32.728Z,1504716812.728 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2017-09-06T16:53:32.748Z,1504716812.748 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2017-09-06T16:53:32.748Z,1504716812.748 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2017-09-06T16:53:32.748Z,1504716812.748 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 2209 2017-09-06T16:53:32.976Z,1504716812.976 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2017-09-06T16:53:32.976Z,1504716812.976 [WetLabsBB2FL](INFO): Powering down 2017-09-06T16:53:32.977Z,1504716812.977 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2017-09-06T16:53:33.004Z,1504716813.004 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2017-09-06T16:53:33.004Z,1504716813.004 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2017-09-06T16:53:33.004Z,1504716813.004 [CTD_Seabird](INFO): Join timeout helper Thread ID is 2210 2017-09-06T16:53:33.213Z,1504716813.213 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2017-09-06T16:53:33.318Z,1504716813.318 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface 2017-09-06T16:53:33.318Z,1504716813.318 [CTD_Seabird](INFO): Powering down 2017-09-06T16:53:33.320Z,1504716813.320 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2017-09-06T16:53:33.334Z,1504716813.334 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler 2017-09-06T16:53:33.334Z,1504716813.334 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2017-09-06T16:53:33.334Z,1504716813.334 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 2212 2017-09-06T16:53:33.657Z,1504716813.657 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread. 2017-09-06T16:53:33.658Z,1504716813.658 [CTD_NeilBrown](INFO): Powering down 2017-09-06T16:53:33.659Z,1504716813.659 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2017-09-06T16:53:33.678Z,1504716813.678 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2017-09-06T16:53:33.678Z,1504716813.678 [logger ThreadHandler](INFO): Thread cancelled. 2017-09-06T16:53:33.679Z,1504716813.679 [logger](INFO): Join timeout helper Thread ID is 2213 2017-09-06T16:53:33.697Z,1504716813.697 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2017-09-06T16:53:33.698Z,1504716813.698 [logger ThreadHandler](INFO): Thread cancelled. 2017-09-06T16:53:33.718Z,1504716813.718 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2017-09-06T16:53:33.718Z,1504716813.718 [CommandLine ThreadHandler](INFO): Thread cancelled. 2017-09-06T16:53:33.718Z,1504716813.718 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2017-09-06T16:53:33.718Z,1504716813.718 [controlThread ThreadHandler](INFO): Thread cancelled. 2017-09-06T16:53:33.719Z,1504716813.719 [controlThread](INFO): Join timeout helper Thread ID is 2214 2017-09-06T16:53:33.854Z,1504716813.854 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2017-09-06T16:53:33.854Z,1504716813.854 [controlThread](DEBUG): Uninitializing ControlThread 2017-09-06T16:53:33.854Z,1504716813.854 [Aanderaa_O2](INFO): Powering down 2017-09-06T16:53:33.857Z,1504716813.857 [NAL9602](INFO): Powering down 2017-09-06T16:53:33.858Z,1504716813.858 [PNI_TCM](INFO): Powering down 2017-09-06T16:53:33.946Z,1504716813.946 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2017-09-06T16:53:33.948Z,1504716813.948 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2017-09-06T16:53:33.948Z,1504716813.948 [MissionManager](INFO): Uninitializing Mission Default 2017-09-06T16:53:33.948Z,1504716813.948 [Default] Stopped 2017-09-06T16:53:33.949Z,1504716813.949 [Default](DEBUG): Aggregate::uninitialize Default 2017-09-06T16:53:33.949Z,1504716813.949 [Default:B.GoToSurface] Stopped 2017-09-06T16:53:33.949Z,1504716813.949 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2017-09-06T16:53:33.949Z,1504716813.949 [Default:CheckIn] Stopped 2017-09-06T16:53:33.949Z,1504716813.949 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2017-09-06T16:53:33.949Z,1504716813.949 [Default:CheckIn:Read_GPS] Stopped 2017-09-06T16:53:33.952Z,1504716813.952 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2017-09-06T16:53:33.953Z,1504716813.953 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2017-09-06T16:53:33.953Z,1504716813.953 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2017-09-06T16:53:33.953Z,1504716813.953 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2017-09-06T16:53:33.953Z,1504716813.953 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2017-09-06T16:53:33.954Z,1504716813.954 [BuoyancyServo](INFO): Powering down 2017-09-06T16:53:33.966Z,1504716813.966 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2017-09-06T16:53:33.966Z,1504716813.966 [ElevatorServo](INFO): Powering down 2017-09-06T16:53:33.967Z,1504716813.967 [MassServo](DEBUG): Uninitialize Mass Servo. 2017-09-06T16:53:33.967Z,1504716813.967 [MassServo](INFO): Powering down 2017-09-06T16:53:33.968Z,1504716813.968 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2017-09-06T16:53:33.968Z,1504716813.968 [RudderServo](INFO): Powering down 2017-09-06T16:53:33.969Z,1504716813.969 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2017-09-06T16:53:33.969Z,1504716813.969 [ThrusterServo](INFO): Powering down 2017-09-06T16:53:33.970Z,1504716813.970 [SBIT](DEBUG): Uninitialize SBIT Component. 2017-09-06T16:53:33.970Z,1504716813.970 [IBIT](DEBUG): Uninitialize IBIT Component. 2017-09-06T16:53:33.970Z,1504716813.970 [CBIT](DEBUG): Uninitialize CBIT Component. 2017-09-06T16:53:33.972Z,1504716813.972 [controlThread ThreadHandler](INFO): Thread cancelled. 2017-09-06T16:53:34.054Z,1504716814.054 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2017-09-06T16:53:34.059Z,1504716814.059 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2017-09-06T16:53:34.061Z,1504716814.061 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2017-09-06T16:53:34.078Z,1504716814.078 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2017-09-06T16:53:34.141Z,1504716814.141 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2017-09-06T16:53:34.206Z,1504716814.206 [logger ThreadHandler](INFO): Thread cancelled.