2019-11-18T22:52:56.886Z,1574117576.886 [Supervisor](DEBUG): Initializing supervisor.
2019-11-18T22:52:56.889Z,1574117576.889 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-11-18T22:52:56.889Z,1574117576.889 [SyncHandler](INFO): Protected caller Thread ID is 5632
2019-11-18T22:52:56.890Z,1574117576.890 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-11-18T22:52:56.891Z,1574117576.891 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-11-18T22:52:56.891Z,1574117576.891 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 5633
2019-11-18T22:52:56.894Z,1574117576.894 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-11-18T22:52:56.906Z,1574117576.906 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-11-18T22:52:56.907Z,1574117576.907 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-11-18T22:52:56.907Z,1574117576.907 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 5634
2019-11-18T22:52:56.908Z,1574117576.908 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-11-18T22:52:56.909Z,1574117576.909 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-11-18T22:52:56.909Z,1574117576.909 [logger ThreadHandler](INFO): Protected caller Thread ID is 5635
2019-11-18T22:52:56.911Z,1574117576.911 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-11-18T22:52:56.911Z,1574117576.911 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-11-18T22:52:56.943Z,1574117576.943 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-11-18T22:52:57.374Z,1574117577.374 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-11-18T22:52:57.375Z,1574117577.375 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-11-18T22:52:57.471Z,1574117577.471 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-11-18T22:52:57.472Z,1574117577.472 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-11-18T22:52:57.785Z,1574117577.785 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-11-18T22:52:57.786Z,1574117577.786 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-11-18T22:52:57.956Z,1574117577.956 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-11-18T22:52:57.956Z,1574117577.956 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-11-18T22:52:58.187Z,1574117578.187 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-11-18T22:52:58.188Z,1574117578.188 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-11-18T22:52:58.634Z,1574117578.634 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-11-18T22:52:58.635Z,1574117578.635 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-11-18T22:52:58.838Z,1574117578.838 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-11-18T22:52:58.839Z,1574117578.839 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-11-18T22:52:58.981Z,1574117578.981 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-11-18T22:52:58.981Z,1574117578.981 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-11-18T22:52:59.168Z,1574117579.168 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-11-18T22:52:59.169Z,1574117579.169 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-11-18T22:52:59.263Z,1574117579.263 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-11-18T22:52:59.264Z,1574117579.264 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-11-18T22:52:59.560Z,1574117579.560 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-11-18T22:52:59.561Z,1574117579.561 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-11-18T22:52:59.640Z,1574117579.640 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-11-18T22:52:59.740Z,1574117579.740 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-11-18T22:52:59.741Z,1574117579.741 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-11-18T22:53:00.386Z,1574117580.386 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-11-18T22:53:00.387Z,1574117580.387 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-11-18T22:53:00.790Z,1574117580.790 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-11-18T22:53:00.792Z,1574117580.792 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2019-11-18T22:53:00.793Z,1574117580.793 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2019-11-18T22:53:00.996Z,1574117580.996 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2019-11-18T22:53:01.092Z,1574117581.092 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2019-11-18T22:53:01.188Z,1574117581.188 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2019-11-18T22:53:01.416Z,1574117581.416 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-11-18T22:53:01.416Z,1574117581.416 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2019-11-18T22:53:01.499Z,1574117581.499 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2019-11-18T22:53:01.590Z,1574117581.590 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2019-11-18T22:53:01.685Z,1574117581.685 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2019-11-18T22:53:01.766Z,1574117581.766 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2019-11-18T22:53:01.912Z,1574117581.912 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2019-11-18T22:53:02.260Z,1574117582.260 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2019-11-18T22:53:02.506Z,1574117582.506 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/root/
2019-11-18T22:53:02.507Z,1574117582.507 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-11-18T22:53:02.523Z,1574117582.523 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-11-18T22:53:03.117Z,1574117583.117 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2019-11-18T22:53:03.123Z,1574117583.123 [AHRS_M2](INFO): created writer for : platform_orientation
2019-11-18T22:53:03.125Z,1574117583.125 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2019-11-18T22:53:03.130Z,1574117583.130 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2019-11-18T22:53:03.131Z,1574117583.131 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2019-11-18T22:53:03.136Z,1574117583.136 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2019-11-18T22:53:03.137Z,1574117583.137 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2019-11-18T22:53:03.142Z,1574117583.142 [AHRS_M2](INFO): created writer for : platform_roll_angle
2019-11-18T22:53:03.215Z,1574117583.215 [AHRS_M2] Loaded
2019-11-18T22:53:03.216Z,1574117583.216 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-11-18T22:53:03.294Z,1574117583.294 [DataOverHttps] Loaded
2019-11-18T22:53:03.294Z,1574117583.294 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-11-18T22:53:03.295Z,1574117583.295 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407684E0
2019-11-18T22:53:03.295Z,1574117583.295 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 5715
2019-11-18T22:53:03.315Z,1574117583.315 [DDM] Loaded
2019-11-18T22:53:03.316Z,1574117583.316 [ComponentRegistry](DEBUG): SyncComponent "DDM" handled in the control thread.
2019-11-18T22:53:03.329Z,1574117583.329 [Depth_Keller] Loaded
2019-11-18T22:53:03.330Z,1574117583.330 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-11-18T22:53:03.335Z,1574117583.335 [DropWeight] Loaded
2019-11-18T22:53:03.335Z,1574117583.335 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-11-18T22:53:03.398Z,1574117583.398 [DUSBL_Hydroid] Loaded
2019-11-18T22:53:03.399Z,1574117583.399 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2019-11-18T22:53:03.447Z,1574117583.447 [Micromodem] Loaded
2019-11-18T22:53:03.447Z,1574117583.447 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2019-11-18T22:53:03.548Z,1574117583.548 [NAL9602] Loaded
2019-11-18T22:53:03.549Z,1574117583.549 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-11-18T22:53:03.565Z,1574117583.565 [Onboard] Loaded
2019-11-18T22:53:03.565Z,1574117583.565 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-11-18T22:53:03.571Z,1574117583.571 [PowerOnly] Loaded
2019-11-18T22:53:03.571Z,1574117583.571 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2019-11-18T22:53:03.578Z,1574117583.578 [Radio_Surface] Loaded
2019-11-18T22:53:03.578Z,1574117583.578 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-11-18T22:53:03.579Z,1574117583.579 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407984E0
2019-11-18T22:53:03.579Z,1574117583.579 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 5716
2019-11-18T22:53:03.625Z,1574117583.625 [RDI_Pathfinder] Loaded
2019-11-18T22:53:03.625Z,1574117583.625 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2019-11-18T22:53:05.170Z,1574117585.170 [BPC1] Loaded
2019-11-18T22:53:05.170Z,1574117585.170 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-11-18T22:53:05.171Z,1574117585.171 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-11-18T22:53:05.171Z,1574117585.171 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-11-18T22:53:05.185Z,1574117585.185 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-11-18T22:53:05.186Z,1574117585.186 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-11-18T22:53:05.293Z,1574117585.293 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-11-18T22:53:05.293Z,1574117585.293 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-11-18T22:53:05.314Z,1574117585.314 [NavChart] Loaded
2019-11-18T22:53:05.314Z,1574117585.314 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-11-18T22:53:05.318Z,1574117585.318 [UniversalFixResidualReporter] Loaded
2019-11-18T22:53:05.318Z,1574117585.318 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-11-18T22:53:05.319Z,1574117585.319 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-11-18T22:53:05.319Z,1574117585.319 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-11-18T22:53:05.433Z,1574117585.433 [BuoyancyServo] Loaded
2019-11-18T22:53:05.434Z,1574117585.434 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-11-18T22:53:05.449Z,1574117585.449 [ElevatorServo] Loaded
2019-11-18T22:53:05.450Z,1574117585.450 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-11-18T22:53:05.465Z,1574117585.465 [MassServo] Loaded
2019-11-18T22:53:05.465Z,1574117585.465 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-11-18T22:53:05.480Z,1574117585.480 [RudderServo] Loaded
2019-11-18T22:53:05.480Z,1574117585.480 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-11-18T22:53:05.495Z,1574117585.495 [ThrusterServo] Loaded
2019-11-18T22:53:05.495Z,1574117585.495 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-11-18T22:53:05.495Z,1574117585.495 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-11-18T22:53:05.496Z,1574117585.496 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-11-18T22:53:05.758Z,1574117585.758 [CTD_NeilBrown] Loaded
2019-11-18T22:53:05.758Z,1574117585.758 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-11-18T22:53:05.759Z,1574117585.759 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408E34E0
2019-11-18T22:53:05.760Z,1574117585.760 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 5717
2019-11-18T22:53:05.775Z,1574117585.775 [PAR_Licor] Loaded
2019-11-18T22:53:05.775Z,1574117585.775 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-11-18T22:53:05.820Z,1574117585.820 [WetLabsSeaOWL_UV_A] Loaded
2019-11-18T22:53:05.820Z,1574117585.820 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2019-11-18T22:53:05.821Z,1574117585.821 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409134E0
2019-11-18T22:53:05.821Z,1574117585.821 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 5718
2019-11-18T22:53:05.822Z,1574117585.822 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-11-18T22:53:05.822Z,1574117585.822 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-11-18T22:53:06.156Z,1574117586.156 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-11-18T22:53:06.157Z,1574117586.157 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-11-18T22:53:06.199Z,1574117586.199 [DepthRateCalculator] Loaded
2019-11-18T22:53:06.200Z,1574117586.200 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-11-18T22:53:06.205Z,1574117586.205 [PitchRateCalculator] Loaded
2019-11-18T22:53:06.206Z,1574117586.206 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-11-18T22:53:06.218Z,1574117586.218 [SpeedCalculator] Loaded
2019-11-18T22:53:06.218Z,1574117586.218 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-11-18T22:53:06.239Z,1574117586.239 [TempGradientCalculator] Loaded
2019-11-18T22:53:06.239Z,1574117586.239 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-11-18T22:53:06.245Z,1574117586.245 [YawRateCalculator] Loaded
2019-11-18T22:53:06.245Z,1574117586.245 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-11-18T22:53:06.286Z,1574117586.286 [ElevatorOffsetCalculator] Loaded
2019-11-18T22:53:06.286Z,1574117586.286 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-11-18T22:53:06.286Z,1574117586.286 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-11-18T22:53:06.287Z,1574117586.287 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-11-18T22:53:06.435Z,1574117586.435 [SBIT](DEBUG): Construct Startup Built In Test.
2019-11-18T22:53:06.457Z,1574117586.457 [SBIT] Loaded
2019-11-18T22:53:06.458Z,1574117586.458 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-11-18T22:53:06.458Z,1574117586.458 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-11-18T22:53:06.470Z,1574117586.470 [IBIT] Loaded
2019-11-18T22:53:06.471Z,1574117586.471 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-11-18T22:53:06.474Z,1574117586.474 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-11-18T22:53:06.612Z,1574117586.612 [CBIT] Loaded
2019-11-18T22:53:06.612Z,1574117586.612 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-11-18T22:53:06.612Z,1574117586.612 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-11-18T22:53:06.613Z,1574117586.613 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-11-18T22:53:06.702Z,1574117586.702 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-11-18T22:53:06.703Z,1574117586.703 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-11-18T22:53:06.811Z,1574117586.811 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-11-18T22:53:06.811Z,1574117586.811 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-11-18T22:53:06.883Z,1574117586.883 [VerticalControl](DEBUG): Construct VerticalControl.
2019-11-18T22:53:06.966Z,1574117586.966 [VerticalControl] Loaded
2019-11-18T22:53:06.967Z,1574117586.967 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-11-18T22:53:06.967Z,1574117586.967 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-11-18T22:53:07.025Z,1574117587.025 [HorizontalControl] Loaded
2019-11-18T22:53:07.025Z,1574117587.025 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-11-18T22:53:07.026Z,1574117587.026 [SpeedControl](DEBUG): Construct SpeedControl.
2019-11-18T22:53:07.028Z,1574117587.028 [SpeedControl] Loaded
2019-11-18T22:53:07.028Z,1574117587.028 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-11-18T22:53:07.029Z,1574117587.029 [LoopControl](DEBUG): Construct LoopControl.
2019-11-18T22:53:07.029Z,1574117587.029 [LoopControl] Loaded
2019-11-18T22:53:07.030Z,1574117587.030 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-11-18T22:53:07.030Z,1574117587.030 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-11-18T22:53:07.031Z,1574117587.031 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-11-18T22:53:07.092Z,1574117587.092 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-11-18T22:53:07.095Z,1574117587.095 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-11-18T22:53:07.096Z,1574117587.096 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-11-18T22:53:07.102Z,1574117587.102 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-11-18T22:53:07.104Z,1574117587.104 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AF74E0
2019-11-18T22:53:07.104Z,1574117587.104 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 5719
2019-11-18T22:53:07.108Z,1574117587.108 [Supervisor](INFO): Main Thread ID is 5631
2019-11-18T22:53:07.108Z,1574117587.108 [Supervisor](DEBUG): Running supervisor.
2019-11-18T22:53:07.109Z,1574117587.109 [CommandLine ThreadHandler](INFO): Handler Thread ID is 5720
2019-11-18T22:53:07.112Z,1574117587.112 [controlThread ThreadHandler](INFO): Handler Thread ID is 5721
2019-11-18T22:53:07.112Z,1574117587.112 [controlThread](DEBUG): Initializing ControlThread
2019-11-18T22:53:07.118Z,1574117587.118 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-11-18T22:53:07.119Z,1574117587.119 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-11-18T22:53:07.123Z,1574117587.123 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-11-18T22:53:07.124Z,1574117587.124 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-11-18T22:53:07.124Z,1574117587.124 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-11-18T22:53:07.124Z,1574117587.124 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-11-18T22:53:07.125Z,1574117587.125 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-11-18T22:53:07.125Z,1574117587.125 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-11-18T22:53:07.126Z,1574117587.126 [SBIT](INFO): Initialize SBIT Component.
2019-11-18T22:53:07.126Z,1574117587.126 [SBIT](IMPORTANT): git: 2019-11-13-3-ge29a3b2
2019-11-18T22:53:07.126Z,1574117587.126 [SBIT](INFO): git hash: e29a3b2fb0608240c94b4b893f361a3ce971c194
2019-11-18T22:53:07.127Z,1574117587.127 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-11-18T22:53:07.128Z,1574117587.128 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #2 PREEMPT Wed May 15 08:34:03 PDT 2019
2019-11-18T22:53:07.129Z,1574117587.129 [SBIT](INFO): Beginning SBIT in 34.000000 seconds.
2019-11-18T22:53:07.130Z,1574117587.130 [IBIT](INFO): Initialize IBIT Component.
2019-11-18T22:53:07.130Z,1574117587.130 [CBIT](DEBUG): Initialize CBIT Component.
2019-11-18T22:53:07.131Z,1574117587.131 [logger ThreadHandler](INFO): Handler Thread ID is 5722
2019-11-18T22:53:07.143Z,1574117587.143 [CBIT](DEBUG): Initialized mux pins.
2019-11-18T22:53:07.143Z,1574117587.143 [CBIT](DEBUG): Initializing the watchdog timer.
2019-11-18T22:53:07.151Z,1574117587.151 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 5723
2019-11-18T22:53:07.152Z,1574117587.152 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-11-18T22:53:07.163Z,1574117587.163 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 5724
2019-11-18T22:53:07.167Z,1574117587.167 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-11-18T22:53:07.167Z,1574117587.167 [CBIT](DEBUG): Initializing heartbeat.
2019-11-18T22:53:07.175Z,1574117587.175 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 5725
2019-11-18T22:53:07.176Z,1574117587.176 [CTD_NeilBrown](INFO): Powering down
2019-11-18T22:53:07.204Z,1574117587.204 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 5726
2019-11-18T22:53:07.204Z,1574117587.204 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-11-18T22:53:07.231Z,1574117587.231 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 5727
2019-11-18T22:53:07.234Z,1574117587.234 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-11-18T22:53:07.235Z,1574117587.235 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-11-18T22:53:07.235Z,1574117587.235 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-11-18T22:53:07.235Z,1574117587.235 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-11-18T22:53:07.235Z,1574117587.235 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-11-18T22:53:07.236Z,1574117587.236 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-11-18T22:53:07.236Z,1574117587.236 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-11-18T22:53:07.236Z,1574117587.236 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-11-18T22:53:07.236Z,1574117587.236 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-11-18T22:53:07.236Z,1574117587.236 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-11-18T22:53:07.236Z,1574117587.236 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-11-18T22:53:07.237Z,1574117587.237 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-11-18T22:53:07.237Z,1574117587.237 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-11-18T22:53:07.237Z,1574117587.237 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-11-18T22:53:07.237Z,1574117587.237 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-11-18T22:53:07.237Z,1574117587.237 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-11-18T22:53:07.239Z,1574117587.239 [CBIT](DEBUG): Deactivating GF circuits.
2019-11-18T22:53:07.239Z,1574117587.239 [CBIT](DEBUG): Deactivating emergency mode.
2019-11-18T22:53:07.275Z,1574117587.275 [CBIT](DEBUG): Backplane powered.
2019-11-18T22:53:07.276Z,1574117587.276 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-11-18T22:53:07.277Z,1574117587.277 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-11-18T22:53:07.278Z,1574117587.278 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-11-18T22:53:07.278Z,1574117587.278 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-11-18T22:53:07.279Z,1574117587.279 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-11-18T22:53:07.289Z,1574117587.289 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-11-18T22:53:07.300Z,1574117587.300 [MissionManager](DEBUG):
2019-11-18T22:53:07.301Z,1574117587.301 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-11-18T22:53:07.368Z,1574117587.368 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-11-18T22:53:07.369Z,1574117587.369 [Default:A.Wait](DEBUG): Construct Wait.
2019-11-18T22:53:07.387Z,1574117587.387 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-11-18T22:53:07.414Z,1574117587.414 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-11-18T22:53:07.416Z,1574117587.416 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-11-18T22:53:07.438Z,1574117587.438 [Default:E.Execute](DEBUG): Construct Execute.
2019-11-18T22:53:07.441Z,1574117587.441 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2019-11-18T22:53:07.457Z,1574117587.457 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,DDM,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-11-18T22:53:07.477Z,1574117587.477 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-11-18T22:53:07.514Z,1574117587.514 [DDM](INFO): Powering up
2019-11-18T22:53:07.514Z,1574117587.514 [DDM](DEBUG): Initializing DDM.
2019-11-18T22:53:07.541Z,1574117587.541 [DUSBL_Hydroid](INFO): Powering up
2019-11-18T22:53:07.542Z,1574117587.542 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2019-11-18T22:53:07.568Z,1574117587.568 [Radio_Surface](INFO): Powering up
2019-11-18T22:53:07.737Z,1574117587.737 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-11-18T22:53:07.743Z,1574117587.743 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-11-18T22:53:07.744Z,1574117587.744 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-11-18T22:53:07.751Z,1574117587.751 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-11-18T22:53:07.752Z,1574117587.752 [MassServo](DEBUG): Initializing EZServoServo.
2019-11-18T22:53:07.759Z,1574117587.759 [MassServo](DEBUG): Initializing MassServo.
2019-11-18T22:53:07.760Z,1574117587.760 [RudderServo](DEBUG): Initializing EZServoServo.
2019-11-18T22:53:07.771Z,1574117587.771 [RudderServo](DEBUG): Initializing RudderServo.
2019-11-18T22:53:07.772Z,1574117587.772 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-11-18T22:53:07.779Z,1574117587.779 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-11-18T22:53:07.882Z,1574117587.882 [Micromodem](INFO): Powering up
2019-11-18T22:53:07.882Z,1574117587.882 [Micromodem](DEBUG): Initializing Micromodem.
2019-11-18T22:53:08.631Z,1574117588.631 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-11-18T22:53:08.631Z,1574117588.631 [RudderServo](FAULT): Rudder failed to initialize
2019-11-18T22:53:08.631Z,1574117588.631 [RudderServo] Communications Fault, FailCount= 1
2019-11-18T22:53:08.631Z,1574117588.631 [RudderServo](ERROR): Communications Fault
2019-11-18T22:53:08.742Z,1574117588.742 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-11-18T22:53:08.956Z,1574117588.956 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-11-18T22:53:08.956Z,1574117588.956 [RudderServo](INFO): Powering down
2019-11-18T22:53:09.619Z,1574117589.619 [RudderServo](DEBUG): Initializing EZServoServo.
2019-11-18T22:53:09.752Z,1574117589.752 [RudderServo](DEBUG): Initializing RudderServo.
2019-11-18T22:53:09.756Z,1574117589.756 [CBIT](INFO): Clearing failed state for component RudderServo
2019-11-18T22:53:09.756Z,1574117589.756 [RudderServo] No Fault, FailCount= 1
2019-11-18T22:53:12.835Z,1574117592.835 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33
2019-11-18T22:53:13.238Z,1574117593.238 [Micromodem](INFO): Nmea in: $CATMG,2019-11-18T22:53:11.905012Z,RTC,RTC*5A
2019-11-18T22:53:13.238Z,1574117593.238 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2019-11-18T22:53:11.905012Z,RTC,RTC*5A
2019-11-18T22:53:13.641Z,1574117593.641 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31
2019-11-18T22:53:13.642Z,1574117593.642 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31
2019-11-18T22:53:14.053Z,1574117594.053 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33
2019-11-18T22:53:14.053Z,1574117594.053 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64
2019-11-18T22:53:14.454Z,1574117594.454 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66
2019-11-18T22:53:14.454Z,1574117594.454 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F
2019-11-18T22:53:14.854Z,1574117594.854 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D
2019-11-18T22:53:14.854Z,1574117594.854 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E
2019-11-18T22:53:15.269Z,1574117595.269 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C
2019-11-18T22:53:15.269Z,1574117595.269 [Micromodem](INFO): Nmea out: $CCCFG,FC0,10000*46
2019-11-18T22:53:15.662Z,1574117595.662 [Micromodem](INFO): Nmea in: $CACFG,FC0,10000*44
2019-11-18T22:53:15.662Z,1574117595.662 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63
2019-11-18T22:53:16.075Z,1574117596.075 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61
2019-11-18T22:53:16.076Z,1574117596.076 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A
2019-11-18T22:53:16.446Z,1574117596.446 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38
2019-11-18T22:53:16.446Z,1574117596.446 [Micromodem](INFO): Nmea out: $CCCLK,2019,11,18,22,53,17*47
2019-11-18T22:53:16.851Z,1574117596.851 [Micromodem](INFO): Nmea in: $CACLK,2019,11,18,22,53,17*45
2019-11-18T22:53:17.254Z,1574117597.254 [Micromodem](INFO): Nmea in: $CATMS,0,2019-11-18T22:53:18Z*7A
2019-11-18T22:53:17.255Z,1574117597.255 [Micromodem](INFO): Nmea in: $CATMG,2019-11-18T22:53:18.027106Z,USER_CMD,RTC*1F
2019-11-18T22:53:18.061Z,1574117598.061 [DDM](INFO): Dynamic Docking Module:E
2019-11-18T22:53:18.850Z,1574117598.850 [DDM](INFO): Retracting Whiskers.
2019-11-18T22:53:20.915Z,1574117600.915 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-11-18T22:53:25.469Z,1574117605.469 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004443
2019-11-18T22:53:25.725Z,1574117605.725 [DUSBL_Hydroid](INFO): DUSBL Version:O
2019-11-18T22:53:26.168Z,1574117606.168 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-11-18T22:53:26.168Z,1574117606.168 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,191118160524 -0.1, 0.0,1448.9, 0
2019-11-18T22:53:33.805Z,1574117613.805 [NAL9602](INFO): Powering up NAL9602
2019-11-18T22:53:41.542Z,1574117621.542 [SBIT](IMPORTANT): Beginning Startup BIT
2019-11-18T22:53:41.551Z,1574117621.551 [CBIT](IMPORTANT): Beginning ground fault scan
2019-11-18T22:53:44.869Z,1574117624.869 [NAL9602](INFO): NAL9602 initialized
2019-11-18T22:53:52.652Z,1574117632.652 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.021783
CHAN A1 (24V): -0.027896
CHAN A2 (12V): -0.006680
CHAN A3 (5V): -0.002131
CHAN B0 (3.3V): 0.000358
CHAN B1 (3.15aV): 0.000092
CHAN B2 (3.15bV): -0.000096
CHAN B3 (GND): 0.001909
OPEN: 0.005561
Full Scale Calc: 4.765 mA, -1.589 mA
2019-11-18T22:54:35.258Z,1574117675.258 [SBIT](IMPORTANT): SBIT PASSED
2019-11-18T22:54:35.299Z,1574117675.299 [CommandLine](IMPORTANT): got command configSet list
2019-11-18T22:54:35.300Z,1574117675.300 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-11-18T22:54:35.301Z,1574117675.301 [CommandLine](IMPORTANT): DDM.loadAtStartup=1 bool;
2019-11-18T22:54:35.301Z,1574117675.301 [CommandLine](IMPORTANT): DDM.verbosity=3 count;
2019-11-18T22:54:35.301Z,1574117675.301 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold=75 count;
2019-11-18T22:54:35.301Z,1574117675.301 [CommandLine](IMPORTANT): DUSBL_Hydroid.transmitLockout=40 millisecond;
2019-11-18T22:54:35.301Z,1574117675.301 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.acoustic_contact_range 1.000000 meter;
2019-11-18T22:54:35.301Z,1574117675.301 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.xAngle 2.000000 degree;
2019-11-18T22:54:35.301Z,1574117675.301 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.height_above_sea_floor 2.000000 meter;
2019-11-18T22:54:35.301Z,1574117675.301 [CommandLine](IMPORTANT): Express linearApproximation platform_orientation 5.000000 degree;
2019-11-18T22:54:35.301Z,1574117675.301 [CommandLine](IMPORTANT): Express linearApproximation platform_x_velocity_wrt_ground 0.100000 meter_per_second;
2019-11-18T22:54:35.302Z,1574117675.302 [CommandLine](IMPORTANT): Express linearApproximation platform_y_velocity_wrt_ground 0.100000 meter_per_second;
2019-11-18T22:54:35.302Z,1574117675.302 [CommandLine](IMPORTANT): HorizontalControl.kiHeading=0.002 reciprocal_second;
2019-11-18T22:54:35.302Z,1574117675.302 [CommandLine](IMPORTANT): HorizontalControl.kpHeading=0.8 none;
2019-11-18T22:54:35.302Z,1574117675.302 [CommandLine](IMPORTANT): HorizontalControl.rudDeadband=0.05 degree;
2019-11-18T22:54:35.302Z,1574117675.302 [CommandLine](IMPORTANT): PowerOnly.sampleTime=90 second;
2019-11-18T22:54:35.302Z,1574117675.302 [CommandLine](IMPORTANT): RDI_Pathfinder.loadAtStartup=1 bool;
2019-11-18T22:54:35.302Z,1574117675.302 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=350 cubic_centimeter;
2019-11-18T22:54:35.302Z,1574117675.302 [CommandLine](IMPORTANT): VerticalControl.massDefault=3.6 millimeter;
2019-11-18T22:54:35.654Z,1574117675.654 [MissionManager](IMPORTANT): Started mission Startup
2019-11-18T22:54:35.655Z,1574117675.655 [Startup] Running Loop=1
2019-11-18T22:54:35.655Z,1574117675.655 [Startup](DEBUG): Aggregate::initialize Startup
2019-11-18T22:54:35.655Z,1574117675.655 [Startup:A.GoToSurface] Running Loop=1
2019-11-18T22:54:35.655Z,1574117675.655 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-11-18T22:54:35.656Z,1574117675.656 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-11-18T22:54:35.656Z,1574117675.656 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-11-18T22:54:35.657Z,1574117675.657 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-11-18T22:54:35.657Z,1574117675.657 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-11-18T22:54:35.657Z,1574117675.657 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-11-18T22:54:35.659Z,1574117675.659 [Startup:StartupSatComms] Running Loop=1
2019-11-18T22:54:35.659Z,1574117675.659 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-11-18T22:54:35.659Z,1574117675.659 [Startup:StartupSatComms:A] Running Loop=1
2019-11-18T22:54:36.080Z,1574117676.080 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-11-18T22:55:36.006Z,1574117736.006 [Startup:StartupSatComms:A](INFO): Timed out from 2019-11-18T22:54:35.7Z
2019-11-18T22:55:36.006Z,1574117736.006 [Startup:StartupSatComms:A] Stopped
2019-11-18T22:55:36.006Z,1574117736.006 [Startup:StartupSatComms:B] Running Loop=1
2019-11-18T22:55:36.240Z,1574117736.240 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-11-18T22:55:39.249Z,1574117739.249 [DataOverHttps](INFO): Sending 237 bytes from file Logs/20191114T234619/Express0034.lzma
2019-11-18T22:55:40.730Z,1574117740.730 [DataOverHttps](INFO): Moved sent file to Logs/20191114T234619/Express0034.lzma.bak
2019-11-18T22:55:40.730Z,1574117740.730 [DataOverHttps](INFO): SBD MOMSN=12070140
2019-11-18T22:56:00.927Z,1574117760.927 [DataOverHttps](INFO): Sending 581 bytes from file Logs/20191118T224243/Express0001.lzma
2019-11-18T22:56:02.933Z,1574117762.933 [DataOverHttps](INFO): Moved sent file to Logs/20191118T224243/Express0001.lzma.bak
2019-11-18T22:56:02.933Z,1574117762.933 [DataOverHttps](INFO): SBD MOMSN=12070145
2019-11-18T22:56:07.359Z,1574117767.359 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-11-18T22:56:07.359Z,1574117767.359 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-18T22:56:07.401Z,1574117767.401 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-18T22:56:07.769Z,1574117767.769 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-18T22:56:07.769Z,1574117767.769 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-11-18T22:56:23.100Z,1574117783.100 [DataOverHttps](INFO): Sending 1112 bytes from file Logs/20191118T225256/Express0001.lzma
2019-11-18T22:56:25.104Z,1574117785.104 [DataOverHttps](INFO): Moved sent file to Logs/20191118T225256/Express0001.lzma.bak
2019-11-18T22:56:25.105Z,1574117785.105 [DataOverHttps](INFO): SBD MOMSN=12070156
2019-11-18T22:56:26.741Z,1574117786.741 [Startup:StartupSatComms:B] Stopped
2019-11-18T22:56:26.741Z,1574117786.741 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-11-18T22:56:26.741Z,1574117786.741 [Startup:StartupSatComms] Stopped
2019-11-18T22:56:26.741Z,1574117786.741 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-11-18T22:56:26.742Z,1574117786.742 [Startup](INFO): Completed Startup
2019-11-18T22:56:26.742Z,1574117786.742 [MissionManager](INFO): Startup is completed.
2019-11-18T22:56:26.742Z,1574117786.742 [MissionManager](INFO): Uninitializing Mission Startup
2019-11-18T22:56:26.743Z,1574117786.743 [Startup] Stopped
2019-11-18T22:56:26.743Z,1574117786.743 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-11-18T22:56:26.743Z,1574117786.743 [Startup:A.GoToSurface] Stopped
2019-11-18T22:56:26.743Z,1574117786.743 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-11-18T22:56:27.155Z,1574117787.155 [MissionManager](IMPORTANT): Started mission Default
2019-11-18T22:56:27.155Z,1574117787.155 [Default] Running Loop=1
2019-11-18T22:56:27.155Z,1574117787.155 [Default](DEBUG): Aggregate::initialize Default
2019-11-18T22:56:27.155Z,1574117787.155 [Default:B.GoToSurface] Running Loop=1
2019-11-18T22:56:27.155Z,1574117787.155 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-11-18T22:56:27.156Z,1574117787.156 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-11-18T22:56:27.156Z,1574117787.156 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-11-18T22:56:27.156Z,1574117787.156 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-11-18T22:56:27.157Z,1574117787.157 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-11-18T22:56:27.157Z,1574117787.157 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-11-18T22:56:27.157Z,1574117787.157 [Default:A.Wait] Running Loop=1
2019-11-18T22:56:27.157Z,1574117787.157 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-11-18T22:56:40.492Z,1574117800.492 [Default:A.Wait](INFO): Done Waiting.
2019-11-18T22:56:40.492Z,1574117800.492 [Default:A.Wait] Stopped
2019-11-18T22:56:40.492Z,1574117800.492 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-11-18T22:56:40.978Z,1574117800.978 [Default:CheckIn] Running Loop=1
2019-11-18T22:56:40.978Z,1574117800.978 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-11-18T22:56:40.978Z,1574117800.978 [Default:CheckIn:Read_GPS] Running Loop=1
2019-11-18T22:56:41.299Z,1574117801.299 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-11-18T22:58:48.109Z,1574117928.109 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-11-18T22:59:08.388Z,1574117948.388 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2019-11-18T22:59:08.388Z,1574117948.388 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-18T22:59:08.402Z,1574117948.402 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-18T22:59:08.796Z,1574117948.796 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-18T22:59:08.796Z,1574117948.796 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2019-11-18T23:00:34.805Z,1574118034.805 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2019-11-18T23:00:34.808Z,1574118034.808 [BPC1](INFO): Received data from all battery sticks.
2019-11-18T23:00:51.777Z,1574118051.777 [RDI_Pathfinder](ERROR): Failed to parse:
:BE,-32768,-32768,-32768,V
2019-11-18T23:01:41.070Z,1574118101.070 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-11-18T22:56:40.0Z
2019-11-18T23:01:41.070Z,1574118101.070 [Default:CheckIn:Read_GPS] Stopped
2019-11-18T23:01:41.070Z,1574118101.070 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-11-18T23:01:41.473Z,1574118101.473 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-11-18T23:01:50.874Z,1574118110.874 [DataOverHttps](INFO): Sending 186 bytes from file Logs/20191118T225256/Courier0004.lzma
2019-11-18T23:01:52.880Z,1574118112.880 [DataOverHttps](INFO): Moved sent file to Logs/20191118T225256/Courier0004.lzma.bak
2019-11-18T23:01:52.881Z,1574118112.881 [DataOverHttps](INFO): SBD MOMSN=12070187
2019-11-18T23:02:09.357Z,1574118129.357 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2019-11-18T23:02:09.357Z,1574118129.357 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-18T23:02:09.391Z,1574118129.391 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-18T23:02:09.765Z,1574118129.765 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-18T23:02:09.765Z,1574118129.765 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2019-11-18T23:02:10.907Z,1574118130.907 [DataOverHttps](INFO): Sending 200 bytes from file Logs/20191118T225256/Express0005.lzma
2019-11-18T23:02:12.912Z,1574118132.912 [DataOverHttps](INFO): Moved sent file to Logs/20191118T225256/Express0005.lzma.bak
2019-11-18T23:02:12.913Z,1574118132.913 [DataOverHttps](INFO): SBD MOMSN=12070191
2019-11-18T23:02:14.609Z,1574118134.609 [Default:CheckIn:Read_Iridium] Stopped
2019-11-18T23:02:14.609Z,1574118134.609 [Default:CheckIn:C.Wait] Running Loop=1
2019-11-18T23:02:14.609Z,1574118134.609 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-11-18T23:03:48.283Z,1574118228.283 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-11-18T23:03:48.283Z,1574118228.283 [NAL9602] Data Fault, FailCount= 1
2019-11-18T23:03:48.283Z,1574118228.283 [NAL9602](ERROR): Data Fault
2019-11-18T23:03:48.324Z,1574118228.324 [CBIT](ERROR): Data Fault in component: NAL9602
2019-11-18T23:03:48.685Z,1574118228.685 [NAL9602](INFO): Powering down
2019-11-18T23:03:49.541Z,1574118229.541 [CBIT](INFO): Clearing failed state for component NAL9602
2019-11-18T23:03:49.541Z,1574118229.541 [NAL9602] No Fault, FailCount= 1
2019-11-18T23:04:14.982Z,1574118254.982 [RDI_Pathfinder](ERROR): Failed to parse:
:SA, +0.00, +0.00, 0.00
2019-11-18T23:04:18.985Z,1574118258.985 [NAL9602](INFO): Powering up NAL9602
2019-11-18T23:04:29.885Z,1574118269.885 [NAL9602](INFO): NAL9602 initialized
2019-11-18T23:04:32.772Z,1574118272.772 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2019-11-18T23:04:32.772Z,1574118272.772 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-32768,-3268,V
2019-11-18T23:05:10.340Z,1574118310.340 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2019-11-18T23:05:10.340Z,1574118310.340 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-18T23:05:10.350Z,1574118310.350 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-18T23:05:10.781Z,1574118310.781 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-18T23:05:10.781Z,1574118310.781 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2019-11-18T23:07:15.153Z,1574118435.153 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-11-18T23:07:15.153Z,1574118435.153 [Default:CheckIn:C.Wait] Stopped
2019-11-18T23:07:15.153Z,1574118435.153 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-11-18T23:07:15.153Z,1574118435.153 [Default:CheckIn:D] Running Loop=1
2019-11-18T23:07:15.558Z,1574118435.558 [Default:CheckIn:D] Stopped
2019-11-18T23:07:15.558Z,1574118435.558 [Default:CheckIn:E] Running Loop=1
2019-11-18T23:07:15.978Z,1574118435.978 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.806713 min
2019-11-18T23:07:15.978Z,1574118435.978 [Default:CheckIn:E] Stopped
2019-11-18T23:07:15.978Z,1574118435.978 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-11-18T23:07:15.978Z,1574118435.978 [Default:CheckIn] Stopped
2019-11-18T23:07:15.978Z,1574118435.978 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-11-18T23:07:15.978Z,1574118435.978 [Default:CheckIn](INFO): Running loop #2
2019-11-18T23:07:15.978Z,1574118435.978 [Default:CheckIn] Running Loop=2
2019-11-18T23:07:15.978Z,1574118435.978 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-11-18T23:07:15.979Z,1574118435.979 [Default:CheckIn:Read_GPS] Running Loop=1
2019-11-18T23:08:11.320Z,1574118491.320 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2019-11-18T23:08:11.320Z,1574118491.320 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-18T23:08:11.330Z,1574118491.330 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-18T23:08:11.763Z,1574118491.763 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-18T23:08:11.763Z,1574118491.763 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2019-11-18T23:10:50.488Z,1574118650.488 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-11-18T23:10:50.488Z,1574118650.488 [RDI_Pathfinder](ERROR): Failed to parse:
:RA, 0.00, 0.00, 0.00, 0.00
2019-11-18T23:11:12.328Z,1574118672.328 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2019-11-18T23:11:12.328Z,1574118672.328 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-18T23:11:12.338Z,1574118672.338 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-18T23:11:12.772Z,1574118672.772 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-18T23:11:12.772Z,1574118672.772 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2019-11-18T23:12:16.148Z,1574118736.148 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-11-18T23:07:15.0Z
2019-11-18T23:12:16.148Z,1574118736.148 [Default:CheckIn:Read_GPS] Stopped
2019-11-18T23:12:16.148Z,1574118736.148 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-11-18T23:12:24.427Z,1574118744.427 [DataOverHttps](INFO): Sending 195 bytes from file Logs/20191118T225256/Express0008.lzma
2019-11-18T23:12:26.432Z,1574118746.432 [DataOverHttps](INFO): Moved sent file to Logs/20191118T225256/Express0008.lzma.bak
2019-11-18T23:12:26.433Z,1574118746.433 [DataOverHttps](INFO): SBD MOMSN=12070199
2019-11-18T23:12:28.279Z,1574118748.279 [Default:CheckIn:Read_Iridium] Stopped
2019-11-18T23:12:28.279Z,1574118748.279 [Default:CheckIn:C.Wait] Running Loop=1
2019-11-18T23:12:28.279Z,1574118748.279 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-11-18T23:13:15.117Z,1574118795.117 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2019-11-18T23:13:15.117Z,1574118795.117 [RDI_Pathfinder](ERROR): Failed to parse:
:RA, 0.00, 0.00, 0.-32768,-32768,-32768,-32768,V
2019-11-18T23:14:13.304Z,1574118853.304 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2019-11-18T23:14:13.304Z,1574118853.304 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-18T23:14:13.314Z,1574118853.314 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-18T23:14:13.764Z,1574118853.764 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-18T23:14:13.765Z,1574118853.765 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2019-11-18T23:14:31.038Z,1574118871.038 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-11-18T23:14:31.038Z,1574118871.038 [NAL9602] Data Fault, FailCount= 2
2019-11-18T23:14:31.038Z,1574118871.038 [NAL9602](ERROR): Data Fault
2019-11-18T23:14:31.114Z,1574118871.114 [CBIT](ERROR): Data Fault in component: NAL9602
2019-11-18T23:14:31.449Z,1574118871.450 [NAL9602](INFO): Powering down
2019-11-18T23:14:32.285Z,1574118872.285 [CBIT](INFO): Clearing failed state for component NAL9602
2019-11-18T23:14:32.285Z,1574118872.285 [NAL9602] No Fault, FailCount= 2
2019-11-18T23:15:01.760Z,1574118901.760 [NAL9602](INFO): Powering up NAL9602
2019-11-18T23:15:12.658Z,1574118912.658 [NAL9602](INFO): NAL9602 initialized
2019-11-18T23:17:14.304Z,1574119034.304 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2019-11-18T23:17:14.304Z,1574119034.304 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-18T23:17:14.314Z,1574119034.314 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-18T23:17:14.765Z,1574119034.765 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-18T23:17:14.765Z,1574119034.765 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2019-11-18T23:17:28.853Z,1574119048.853 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-11-18T23:17:28.853Z,1574119048.853 [Default:CheckIn:C.Wait] Stopped
2019-11-18T23:17:28.853Z,1574119048.853 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-11-18T23:17:28.853Z,1574119048.853 [Default:CheckIn:D] Running Loop=1
2019-11-18T23:17:29.267Z,1574119049.267 [Default:CheckIn:D] Stopped
2019-11-18T23:17:29.267Z,1574119049.267 [Default:CheckIn:E] Running Loop=1
2019-11-18T23:17:29.639Z,1574119049.639 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.035203 min
2019-11-18T23:17:29.639Z,1574119049.639 [Default:CheckIn:E] Stopped
2019-11-18T23:17:29.640Z,1574119049.640 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-11-18T23:17:29.640Z,1574119049.640 [Default:CheckIn] Stopped
2019-11-18T23:17:29.640Z,1574119049.640 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-11-18T23:17:29.640Z,1574119049.640 [Default:CheckIn](INFO): Running loop #3
2019-11-18T23:17:29.640Z,1574119049.640 [Default:CheckIn] Running Loop=3
2019-11-18T23:17:29.640Z,1574119049.640 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-11-18T23:17:29.640Z,1574119049.640 [Default:CheckIn:Read_GPS] Running Loop=1
2019-11-18T23:20:15.307Z,1574119215.307 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2019-11-18T23:20:15.308Z,1574119215.308 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-18T23:20:15.325Z,1574119215.325 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-18T23:20:15.704Z,1574119215.704 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-18T23:20:15.704Z,1574119215.704 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2019-11-18T23:22:29.808Z,1574119349.808 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-11-18T23:17:29.6Z
2019-11-18T23:22:29.808Z,1574119349.808 [Default:CheckIn:Read_GPS] Stopped
2019-11-18T23:22:29.808Z,1574119349.808 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-11-18T23:22:39.642Z,1574119359.642 [DataOverHttps](INFO): Sending 170 bytes from file Logs/20191118T225256/Express0011.lzma
2019-11-18T23:22:41.648Z,1574119361.648 [DataOverHttps](INFO): Moved sent file to Logs/20191118T225256/Express0011.lzma.bak
2019-11-18T23:22:41.649Z,1574119361.649 [DataOverHttps](INFO): SBD MOMSN=12070205
2019-11-18T23:22:43.577Z,1574119363.577 [Default:CheckIn:Read_Iridium] Stopped
2019-11-18T23:22:43.577Z,1574119363.577 [Default:CheckIn:C.Wait] Running Loop=1
2019-11-18T23:22:43.577Z,1574119363.577 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-11-18T23:23:16.333Z,1574119396.333 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2019-11-18T23:23:16.333Z,1574119396.333 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-18T23:23:16.424Z,1574119396.424 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-18T23:23:16.693Z,1574119396.693 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-18T23:23:16.694Z,1574119396.694 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2019-11-18T23:23:43.756Z,1574119423.756 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2019-11-18T23:23:43.756Z,1574119423.756 [RDI_Pathfinder](ERROR): Failed to parse:
:BD, +0.0 +0.00, +0.00, 0.00,1822.86
2019-11-18T23:23:59.112Z,1574119439.112 [RDI_Pathfinder](ERROR): Failed to parse:
00, 0.00, 0.00, 0.00, 0.00
2019-11-18T23:24:22.123Z,1574119462.123 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-11-18T23:24:22.123Z,1574119462.123 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19111816362079,35.0, 0.0,1448.9, 0
2019-11-18T23:24:43.137Z,1574119483.137 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-11-18T23:24:43.137Z,1574119483.137 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19111816364179,35.0, -0.11448.9, 0
2019-11-18T23:25:14.206Z,1574119514.206 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-11-18T23:25:14.206Z,1574119514.206 [NAL9602] Data Fault, FailCount= 3
2019-11-18T23:25:14.206Z,1574119514.206 [NAL9602](ERROR): Data Fault
2019-11-18T23:25:14.241Z,1574119514.241 [CBIT](ERROR): Data Fault in component: NAL9602
2019-11-18T23:25:14.619Z,1574119514.619 [NAL9602](INFO): Powering down
2019-11-18T23:25:15.462Z,1574119515.462 [CBIT](INFO): Clearing failed state for component NAL9602
2019-11-18T23:25:15.462Z,1574119515.462 [NAL9602] No Fault, FailCount= 3
2019-11-18T23:25:23.133Z,1574119523.133 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-11-18T23:25:23.133Z,1574119523.133 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19111816372179,35.0, -0.1, 0.0, 0
2019-11-18T23:25:44.917Z,1574119544.917 [NAL9602](INFO): Powering up NAL9602
2019-11-18T23:25:55.825Z,1574119555.825 [NAL9602](INFO): NAL9602 initialized
2019-11-18T23:26:17.284Z,1574119577.284 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2019-11-18T23:26:17.284Z,1574119577.284 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-18T23:26:17.294Z,1574119577.294 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-18T23:26:17.691Z,1574119577.691 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-18T23:26:17.691Z,1574119577.691 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2019-11-18T23:26:24.952Z,1574119584.952 [RDI_Pathfinder](ERROR): Failed to parse:
:SA, +0.00, +0.00, 0.00
2019-11-18T23:27:44.146Z,1574119664.146 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2019-11-18T23:27:44.146Z,1574119664.146 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-32768,-3768,V
2019-11-18T23:27:44.161Z,1574119664.161 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-11-18T23:27:44.161Z,1574119664.161 [Default:CheckIn:C.Wait] Stopped
2019-11-18T23:27:44.161Z,1574119664.161 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-11-18T23:27:44.161Z,1574119664.161 [Default:CheckIn:D] Running Loop=1
2019-11-18T23:27:44.542Z,1574119664.542 [Default:CheckIn:D] Stopped
2019-11-18T23:27:44.542Z,1574119664.542 [Default:CheckIn:E] Running Loop=1
2019-11-18T23:27:44.944Z,1574119664.944 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.289775 min
2019-11-18T23:27:44.944Z,1574119664.944 [Default:CheckIn:E] Stopped
2019-11-18T23:27:44.944Z,1574119664.944 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-11-18T23:27:44.944Z,1574119664.944 [Default:CheckIn] Stopped
2019-11-18T23:27:44.944Z,1574119664.944 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-11-18T23:27:44.945Z,1574119664.945 [Default:CheckIn](INFO): Running loop #4
2019-11-18T23:27:44.945Z,1574119664.945 [Default:CheckIn] Running Loop=4
2019-11-18T23:27:44.945Z,1574119664.945 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-11-18T23:27:44.945Z,1574119664.945 [Default:CheckIn:Read_GPS] Running Loop=1
2019-11-18T23:28:20.501Z,1574119700.501 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2019-11-18T23:28:20.501Z,1574119700.501 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-2768,-32768,V
2019-11-18T23:28:25.778Z,1574119705.778 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-32768,-32768,-32768,V
2019-11-18T23:29:18.262Z,1574119758.262 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12
2019-11-18T23:29:18.262Z,1574119758.262 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-18T23:29:18.272Z,1574119758.272 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-18T23:29:18.673Z,1574119758.673 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-18T23:29:18.673Z,1574119758.673 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12
2019-11-18T23:29:24.749Z,1574119764.749 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2019-11-18T23:29:24.749Z,1574119764.749 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-3276,-32768,V
2019-11-18T23:32:19.289Z,1574119939.289 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13
2019-11-18T23:32:19.289Z,1574119939.289 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-18T23:32:19.307Z,1574119939.307 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-18T23:32:19.672Z,1574119939.672 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-18T23:32:19.673Z,1574119939.673 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13
2019-11-18T23:32:45.139Z,1574119965.139 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-11-18T23:27:44.9Z
2019-11-18T23:32:45.139Z,1574119965.139 [Default:CheckIn:Read_GPS] Stopped
2019-11-18T23:32:45.139Z,1574119965.139 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-11-18T23:32:54.891Z,1574119974.891 [DataOverHttps](INFO): Sending 171 bytes from file Logs/20191118T225256/Express0014.lzma
2019-11-18T23:32:56.896Z,1574119976.896 [DataOverHttps](INFO): Moved sent file to Logs/20191118T225256/Express0014.lzma.bak
2019-11-18T23:32:56.897Z,1574119976.897 [DataOverHttps](INFO): SBD MOMSN=12070213
2019-11-18T23:32:58.845Z,1574119978.845 [Default:CheckIn:Read_Iridium] Stopped
2019-11-18T23:32:58.845Z,1574119978.845 [Default:CheckIn:C.Wait] Running Loop=1
2019-11-18T23:32:58.845Z,1574119978.845 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-11-18T23:35:20.242Z,1574120120.242 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 14
2019-11-18T23:35:20.242Z,1574120120.242 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-18T23:35:20.272Z,1574120120.272 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-18T23:35:20.733Z,1574120120.733 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-18T23:35:20.734Z,1574120120.734 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 14
2019-11-18T23:35:30.777Z,1574120130.777 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2019-11-18T23:35:30.777Z,1574120130.777 [RDI_Pathfinder](ERROR): Failed to parse:
:BD, , +0.00, +0.00, 29.72
2019-11-18T23:35:58.191Z,1574120158.191 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-11-18T23:35:58.191Z,1574120158.191 [NAL9602] Data Fault, FailCount= 4
2019-11-18T23:35:58.191Z,1574120158.191 [NAL9602](ERROR): Data Fault
2019-11-18T23:35:58.244Z,1574120158.244 [CBIT](ERROR): Data Fault in component: NAL9602
2019-11-18T23:35:58.590Z,1574120158.590 [NAL9602](INFO): Powering down
2019-11-18T23:35:59.470Z,1574120159.470 [CBIT](INFO): Clearing failed state for component NAL9602
2019-11-18T23:35:59.470Z,1574120159.470 [NAL9602] No Fault, FailCount= 4
2019-11-18T23:36:28.894Z,1574120188.894 [NAL9602](INFO): Powering up NAL9602
2019-11-18T23:36:39.798Z,1574120199.798 [NAL9602](INFO): NAL9602 initialized
2019-11-18T23:37:59.439Z,1574120279.439 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-11-18T23:37:59.439Z,1574120279.439 [Default:CheckIn:C.Wait] Stopped
2019-11-18T23:37:59.439Z,1574120279.439 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-11-18T23:37:59.440Z,1574120279.440 [Default:CheckIn:D] Running Loop=1
2019-11-18T23:37:59.821Z,1574120279.821 [Default:CheckIn:D] Stopped
2019-11-18T23:37:59.821Z,1574120279.821 [Default:CheckIn:E] Running Loop=1
2019-11-18T23:38:00.232Z,1574120280.232 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 41.544434 min
2019-11-18T23:38:00.232Z,1574120280.232 [Default:CheckIn:E] Stopped
2019-11-18T23:38:00.232Z,1574120280.232 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-11-18T23:38:00.232Z,1574120280.232 [Default:CheckIn] Stopped
2019-11-18T23:38:00.232Z,1574120280.232 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-11-18T23:38:00.233Z,1574120280.233 [Default:CheckIn](INFO): Running loop #5
2019-11-18T23:38:00.233Z,1574120280.233 [Default:CheckIn] Running Loop=5
2019-11-18T23:38:00.233Z,1574120280.233 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-11-18T23:38:00.233Z,1574120280.233 [Default:CheckIn:Read_GPS] Running Loop=1
2019-11-18T23:38:21.259Z,1574120301.259 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 15
2019-11-18T23:38:21.259Z,1574120301.259 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-18T23:38:21.277Z,1574120301.277 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-18T23:38:21.680Z,1574120301.680 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-18T23:38:21.681Z,1574120301.681 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 15
2019-11-18T23:38:47.923Z,1574120327.923 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-11-18T23:38:47.923Z,1574120327.923 [RDI_Pathfinder](ERROR): Failed to parse:
:RA, 0.00, 0.00, 0.00, 0.00,
2019-11-18T23:39:11.759Z,1574120351.759 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-11-18T23:39:11.759Z,1574120351.759 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-32768,-32768,-3:BE,-32768,-32768,-32768,V
2019-11-18T23:40:48.284Z,1574120448.284 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-11-18T23:40:48.284Z,1574120448.284 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19111816524679,35.0, -0.11448.9, 0
2019-11-18T23:41:22.250Z,1574120482.250 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 16
2019-11-18T23:41:22.250Z,1574120482.250 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-18T23:41:22.266Z,1574120482.266 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-18T23:41:22.645Z,1574120482.645 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-18T23:41:22.645Z,1574120482.645 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 16
2019-11-18T23:41:28.305Z,1574120488.305 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2019-11-18T23:41:28.305Z,1574120488.305 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-32768,-3276,V
2019-11-18T23:43:00.408Z,1574120580.408 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-11-18T23:38:00.2Z
2019-11-18T23:43:00.408Z,1574120580.408 [Default:CheckIn:Read_GPS] Stopped
2019-11-18T23:43:00.408Z,1574120580.408 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-11-18T23:43:08.502Z,1574120588.502 [DataOverHttps](INFO): Sending 164 bytes from file Logs/20191118T225256/Express0017.lzma
2019-11-18T23:43:10.509Z,1574120590.509 [DataOverHttps](INFO): Moved sent file to Logs/20191118T225256/Express0017.lzma.bak
2019-11-18T23:43:10.509Z,1574120590.509 [DataOverHttps](INFO): SBD MOMSN=12070221
2019-11-18T23:43:12.129Z,1574120592.129 [Default:CheckIn:Read_Iridium] Stopped
2019-11-18T23:43:12.129Z,1574120592.129 [Default:CheckIn:C.Wait] Running Loop=1
2019-11-18T23:43:12.129Z,1574120592.129 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-11-18T23:44:12.744Z,1574120652.744 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-11-18T23:44:12.744Z,1574120652.744 [RDI_Pathfinder](ERROR): Failed to parse:
:RA, 0.00, 0.00, 0.00, 0.00
2019-11-18T23:44:23.236Z,1574120663.236 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 17
2019-11-18T23:44:23.236Z,1574120663.236 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-18T23:44:23.251Z,1574120663.251 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-18T23:44:23.668Z,1574120663.668 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-18T23:44:23.668Z,1574120663.668 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 17
2019-11-18T23:44:32.124Z,1574120672.124 [RDI_Pathfinder](ERROR): Failed to parse:
:BE,-32768,-32768,-32768,V
2019-11-18T23:45:55.765Z,1574120755.765 [RDI_Pathfinder](ERROR): Failed to parse:
:BE,-32768,-32768,-32768,V
2019-11-18T23:46:12.742Z,1574120772.742 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2019-11-18T23:46:12.742Z,1574120772.742 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-3268,-32768,V
2019-11-18T23:46:41.358Z,1574120801.358 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-11-18T23:46:41.358Z,1574120801.358 [NAL9602] Data Fault, FailCount= 5
2019-11-18T23:46:41.358Z,1574120801.358 [NAL9602](ERROR): Data Fault
2019-11-18T23:46:41.402Z,1574120801.402 [CBIT](ERROR): Data Fault in component: NAL9602
2019-11-18T23:46:41.402Z,1574120801.402 [CBIT](CRITICAL): Data Fault in component: NAL9602
2019-11-18T23:46:41.765Z,1574120801.765 [NAL9602](INFO): Powering down
2019-11-18T23:46:41.819Z,1574120801.819 [CommandLine](FAULT): Scheduling is paused
2019-11-18T23:46:41.819Z,1574120801.819 [CBIT](INFO): Critical error at 20191118T234641
2019-11-18T23:46:41.820Z,1574120801.820 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-11-18T23:46:49.469Z,1574120809.469 [RDI_Pathfinder](ERROR): Failed to parse:
:BE,-32768,-32768,-32768,V
2019-11-18T23:47:24.224Z,1574120844.224 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 18
2019-11-18T23:47:24.224Z,1574120844.224 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-18T23:47:24.234Z,1574120844.234 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-18T23:47:24.630Z,1574120844.630 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-18T23:47:24.630Z,1574120844.630 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 18
2019-11-18T23:47:50.469Z,1574120870.469 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-32768,-32768,-32768,-32768,V
2019-11-18T23:47:54.095Z,1574120874.095 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-11-18T23:47:54.102Z,1574120874.102 [RDI_Pathfinder](ERROR): Failed to parse:
:TS6595279,35.0, -0.1, 0.0,1448.9, 0
2019-11-18T23:48:12.732Z,1574120892.732 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-11-18T23:48:12.732Z,1574120892.732 [Default:CheckIn:C.Wait] Stopped
2019-11-18T23:48:12.732Z,1574120892.732 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-11-18T23:48:12.733Z,1574120892.733 [Default:CheckIn:D] Running Loop=1
2019-11-18T23:48:13.108Z,1574120893.108 [Default:CheckIn:D] Stopped
2019-11-18T23:48:13.108Z,1574120893.108 [Default:CheckIn:E] Running Loop=1
2019-11-18T23:48:13.508Z,1574120893.508 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.765877 min
2019-11-18T23:48:13.508Z,1574120893.508 [Default:CheckIn:E] Stopped
2019-11-18T23:48:13.508Z,1574120893.508 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-11-18T23:48:13.508Z,1574120893.508 [Default:CheckIn] Stopped
2019-11-18T23:48:13.509Z,1574120893.509 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-11-18T23:48:13.509Z,1574120893.509 [Default:CheckIn](INFO): Running loop #6
2019-11-18T23:48:13.509Z,1574120893.509 [Default:CheckIn] Running Loop=6
2019-11-18T23:48:13.509Z,1574120893.509 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-11-18T23:48:13.509Z,1574120893.509 [Default:CheckIn:Read_GPS] Running Loop=1
2019-11-18T23:48:41.380Z,1574120921.380 [CBIT](INFO): Clearing failed state for component NAL9602
2019-11-18T23:48:41.380Z,1574120921.380 [NAL9602] No Fault, FailCount= 5
2019-11-18T23:48:41.759Z,1574120921.759 [NAL9602](INFO): Powering up NAL9602
2019-11-18T23:48:52.663Z,1574120932.663 [NAL9602](INFO): NAL9602 initialized
2019-11-18T23:49:16.142Z,1574120956.142 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-11-18T23:49:16.142Z,1574120956.142 [RDI_Pathfinder](ERROR): Failed to parse:
:RA, 0.00, 0.00, 0.00, 0.00
2019-11-18T23:49:31.082Z,1574120971.082 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-11-18T23:49:31.082Z,1574120971.082 [RDI_Pathfinder](ERROR): Failed to parse:
:RA, 0.00, 0.00, 0.00, 0.00
2019-11-18T23:50:25.207Z,1574121025.207 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 19
2019-11-18T23:50:25.207Z,1574121025.207 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-18T23:50:25.245Z,1574121025.245 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-18T23:50:25.655Z,1574121025.655 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-18T23:50:25.659Z,1574121025.659 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 19
2019-11-18T23:51:35.117Z,1574121095.117 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-11-18T23:51:35.117Z,1574121095.117 [RDI_Pathfinder](ERROR): Failed to parse:
:RA, 0.00, 0.00, 0.00, 0.00
2019-11-18T23:53:13.700Z,1574121193.700 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-11-18T23:48:13.5Z
2019-11-18T23:53:13.701Z,1574121193.701 [Default:CheckIn:Read_GPS] Stopped
2019-11-18T23:53:13.701Z,1574121193.701 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-11-18T23:53:23.696Z,1574121203.696 [DataOverHttps](INFO): Sending 93 bytes from file Logs/20191118T225256/Courier0019.lzma
2019-11-18T23:53:25.698Z,1574121205.698 [DataOverHttps](INFO): Moved sent file to Logs/20191118T225256/Courier0019.lzma.bak
2019-11-18T23:53:25.698Z,1574121205.698 [DataOverHttps](INFO): SBD MOMSN=12070229
2019-11-18T23:53:26.208Z,1574121206.208 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 20
2019-11-18T23:53:26.208Z,1574121206.208 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-18T23:53:26.218Z,1574121206.218 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-18T23:53:26.624Z,1574121206.624 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-18T23:53:26.624Z,1574121206.624 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 20
2019-11-18T23:53:43.935Z,1574121223.935 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20191118T225256/Express0020.lzma
2019-11-18T23:53:45.941Z,1574121225.941 [DataOverHttps](INFO): Moved sent file to Logs/20191118T225256/Express0020.lzma.bak
2019-11-18T23:53:45.941Z,1574121225.941 [DataOverHttps](INFO): SBD MOMSN=12070232
2019-11-18T23:53:47.625Z,1574121227.625 [Default:CheckIn:Read_Iridium] Stopped
2019-11-18T23:53:47.625Z,1574121227.625 [Default:CheckIn:C.Wait] Running Loop=1
2019-11-18T23:53:47.625Z,1574121227.625 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-11-18T23:55:01.151Z,1574121301.151 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2019-11-18T23:55:01.152Z,1574121301.152 [RDI_Pathfinder](ERROR): Failed to parse:
:RA, 0.00, 0.00, 0.00, BI,-32768,-32768,-32768,-32768,V
2019-11-18T23:56:27.196Z,1574121387.196 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 21
2019-11-18T23:56:27.196Z,1574121387.196 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-18T23:56:27.206Z,1574121387.206 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-18T23:56:27.620Z,1574121387.620 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-18T23:56:27.620Z,1574121387.620 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 21
2019-11-18T23:58:48.221Z,1574121528.221 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-11-18T23:58:48.221Z,1574121528.221 [Default:CheckIn:C.Wait] Stopped
2019-11-18T23:58:48.221Z,1574121528.221 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-11-18T23:58:48.221Z,1574121528.221 [Default:CheckIn:D] Running Loop=1
2019-11-18T23:58:48.597Z,1574121528.597 [Default:CheckIn:D] Stopped
2019-11-18T23:58:48.597Z,1574121528.597 [Default:CheckIn:E] Running Loop=1
2019-11-18T23:58:49.004Z,1574121529.004 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.357369 min
2019-11-18T23:58:49.004Z,1574121529.004 [Default:CheckIn:E] Stopped
2019-11-18T23:58:49.004Z,1574121529.004 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-11-18T23:58:49.004Z,1574121529.004 [Default:CheckIn] Stopped
2019-11-18T23:58:49.004Z,1574121529.004 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-11-18T23:58:49.004Z,1574121529.004 [Default:CheckIn](INFO): Running loop #7
2019-11-18T23:58:49.004Z,1574121529.004 [Default:CheckIn] Running Loop=7
2019-11-18T23:58:49.004Z,1574121529.004 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-11-18T23:58:49.005Z,1574121529.005 [Default:CheckIn:Read_GPS] Running Loop=1
2019-11-18T23:58:56.241Z,1574121536.241 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-11-18T23:58:56.241Z,1574121536.241 [NAL9602] Data Fault, FailCount= 1
2019-11-18T23:58:56.241Z,1574121536.241 [NAL9602](ERROR): Data Fault
2019-11-18T23:58:56.329Z,1574121536.329 [CBIT](ERROR): Data Fault in component: NAL9602
2019-11-18T23:58:56.654Z,1574121536.654 [NAL9602](INFO): Powering down
2019-11-18T23:58:57.541Z,1574121537.541 [CBIT](INFO): Clearing failed state for component NAL9602
2019-11-18T23:58:57.541Z,1574121537.541 [NAL9602] No Fault, FailCount= 1
2019-11-18T23:59:26.942Z,1574121566.942 [NAL9602](INFO): Powering up NAL9602
2019-11-18T23:59:28.198Z,1574121568.198 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 22
2019-11-18T23:59:28.198Z,1574121568.198 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-18T23:59:28.208Z,1574121568.208 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-18T23:59:28.616Z,1574121568.616 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-18T23:59:28.617Z,1574121568.617 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 22
2019-11-18T23:59:37.858Z,1574121577.858 [NAL9602](INFO): NAL9602 initialized
2019-11-19T00:00:41.749Z,1574121641.749 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2019-11-19T00:00:41.749Z,1574121641.749 [RDI_Pathfinder](ERROR): Failed to parse:
:BD, +0.00, +0.00, , 0.00,4040.35
2019-11-19T00:01:47.165Z,1574121707.165 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-11-19T00:01:47.165Z,1574121707.165 [RDI_Pathfinder](ERROR): Failed to parse:
:RA, 0.00, 0.00, 0.00, 0.00,
2019-11-19T00:02:23.953Z,1574121743.953 [RDI_Pathfinder](ERROR): Failed to parse:
+0.00, +0.00, +0.00, 0.00,4141.31
2019-11-19T00:02:29.206Z,1574121749.206 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 23
2019-11-19T00:02:29.206Z,1574121749.206 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-19T00:02:29.216Z,1574121749.216 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-19T00:02:29.615Z,1574121749.615 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-19T00:02:29.615Z,1574121749.615 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 23
2019-11-19T00:03:25.768Z,1574121805.768 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2019-11-19T00:03:25.768Z,1574121805.768 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-32768,-3268,V
2019-11-19T00:03:38.262Z,1574121818.262 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-11-19T00:03:38.262Z,1574121818.262 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19111817153679,35.0 0.0,1448.9, 0
2019-11-19T00:03:39.473Z,1574121819.473 [RDI_Pathfinder](ERROR): Failed to parse:
:BE,-32768,-32768,-32768,V
2019-11-19T00:03:49.208Z,1574121829.208 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-11-18T23:58:49.0Z
2019-11-19T00:03:49.208Z,1574121829.208 [Default:CheckIn:Read_GPS] Stopped
2019-11-19T00:03:49.208Z,1574121829.208 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-11-19T00:03:59.394Z,1574121839.394 [DataOverHttps](INFO): Sending 158 bytes from file Logs/20191118T225256/Express0023.lzma
2019-11-19T00:04:00.099Z,1574121840.099 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2019-11-19T00:04:00.099Z,1574121840.099 [RDI_Pathfinder](ERROR): Failed to parse:
:BD, , +0.00, +0.00, 0.00,4238.26
2019-11-19T00:04:01.401Z,1574121841.401 [DataOverHttps](INFO): Moved sent file to Logs/20191118T225256/Express0023.lzma.bak
2019-11-19T00:04:01.401Z,1574121841.401 [DataOverHttps](INFO): SBD MOMSN=12070241
2019-11-19T00:04:03.332Z,1574121843.332 [Default:CheckIn:Read_Iridium] Stopped
2019-11-19T00:04:03.332Z,1574121843.332 [Default:CheckIn:C.Wait] Running Loop=1
2019-11-19T00:04:03.332Z,1574121843.332 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-11-19T00:04:23.112Z,1574121863.112 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-11-19T00:04:23.113Z,1574121863.113 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19111817162179,35.0, -0.1, 09, 0
2019-11-19T00:05:30.180Z,1574121930.180 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 24
2019-11-19T00:05:30.180Z,1574121930.180 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-19T00:05:30.202Z,1574121930.202 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-19T00:05:30.668Z,1574121930.668 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-19T00:05:30.668Z,1574121930.668 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 24
2019-11-19T00:07:46.407Z,1574122066.407 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-11-19T00:08:01.729Z,1574122081.729 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-11-19T00:08:01.730Z,1574122081.730 [RDI_Pathfinder](ERROR): Failed to parse:
:RA, 0.00, 0.00, 0.00, 0.00
2019-11-19T00:08:03.308Z,1574122083.308 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2019-11-19T00:08:03.310Z,1574122083.310 [BPC1](INFO): Received data from all battery sticks.
2019-11-19T00:08:30.058Z,1574122110.058 [CommandLine](IMPORTANT): got command restart application
2019-11-19T00:08:31.075Z,1574122111.075 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-11-19T00:08:31.075Z,1574122111.075 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-11-19T00:08:31.123Z,1574122111.123 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2019-11-19T00:08:31.123Z,1574122111.123 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-11-19T00:08:31.124Z,1574122111.124 [CommandLine](INFO): Join timeout helper Thread ID is 5816
2019-11-19T00:08:31.124Z,1574122111.124 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-11-19T00:08:31.124Z,1574122111.124 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-11-19T00:08:31.125Z,1574122111.125 [NavChartDb](INFO): Join timeout helper Thread ID is 5817
2019-11-19T00:08:31.198Z,1574122111.198 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 25
2019-11-19T00:08:31.198Z,1574122111.198 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-19T00:08:31.208Z,1574122111.208 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-19T00:08:31.403Z,1574122111.403 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-11-19T00:08:31.403Z,1574122111.403 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-11-19T00:08:31.415Z,1574122111.415 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2019-11-19T00:08:31.415Z,1574122111.415 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-11-19T00:08:31.415Z,1574122111.415 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 5818
2019-11-19T00:08:31.597Z,1574122111.597 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-19T00:08:31.597Z,1574122111.597 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 25
2019-11-19T00:08:31.811Z,1574122111.811 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2019-11-19T00:08:31.811Z,1574122111.811 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-11-19T00:08:31.812Z,1574122111.812 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-11-19T00:08:31.819Z,1574122111.819 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-11-19T00:08:31.819Z,1574122111.819 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-11-19T00:08:31.819Z,1574122111.819 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 5819
2019-11-19T00:08:31.895Z,1574122111.895 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-11-19T00:08:31.896Z,1574122111.896 [CTD_NeilBrown](INFO): Powering down
2019-11-19T00:08:31.907Z,1574122111.907 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-11-19T00:08:31.923Z,1574122111.923 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-11-19T00:08:31.923Z,1574122111.923 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-11-19T00:08:31.923Z,1574122111.923 [Radio_Surface](INFO): Join timeout helper Thread ID is 5820
2019-11-19T00:08:32.199Z,1574122112.199 [Radio_Surface](INFO): Powering down
2019-11-19T00:08:32.200Z,1574122112.200 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-11-19T00:08:32.200Z,1574122112.200 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-11-19T00:08:32.204Z,1574122112.204 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-11-19T00:08:32.204Z,1574122112.204 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-11-19T00:08:32.204Z,1574122112.204 [DataOverHttps](INFO): Join timeout helper Thread ID is 5821
2019-11-19T00:08:32.607Z,1574122112.607 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-11-19T00:08:32.607Z,1574122112.607 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-11-19T00:08:32.628Z,1574122112.628 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-11-19T00:08:32.628Z,1574122112.628 [logger ThreadHandler](INFO): Thread cancelled.
2019-11-19T00:08:32.628Z,1574122112.628 [logger](INFO): Join timeout helper Thread ID is 5822
2019-11-19T00:08:32.629Z,1574122112.629 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-11-19T00:08:32.629Z,1574122112.629 [logger ThreadHandler](INFO): Thread cancelled.
2019-11-19T00:08:32.630Z,1574122112.630 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-11-19T00:08:32.630Z,1574122112.630 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-11-19T00:08:32.630Z,1574122112.630 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-11-19T00:08:32.631Z,1574122112.631 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-11-19T00:08:32.631Z,1574122112.631 [controlThread](INFO): Join timeout helper Thread ID is 5823
2019-11-19T00:08:32.755Z,1574122112.755 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-11-19T00:08:32.755Z,1574122112.755 [controlThread](DEBUG): Uninitializing ControlThread
2019-11-19T00:08:32.756Z,1574122112.756 [AHRS_M2](INFO): Powering down
2019-11-19T00:08:32.827Z,1574122112.827 [DDM](INFO): Powering down
2019-11-19T00:08:32.920Z,1574122112.920 [DUSBL_Hydroid](INFO): Powering down
2019-11-19T00:08:33.011Z,1574122113.011 [Micromodem](INFO): Powering down
2019-11-19T00:08:33.107Z,1574122113.107 [NAL9602](INFO): Powering down
2019-11-19T00:08:33.179Z,1574122113.179 [RDI_Pathfinder](INFO): Powering down
2019-11-19T00:08:33.181Z,1574122113.181 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-11-19T00:08:33.182Z,1574122113.182 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-11-19T00:08:33.182Z,1574122113.182 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-11-19T00:08:33.182Z,1574122113.182 [MissionManager](INFO): Uninitializing Mission Default
2019-11-19T00:08:33.183Z,1574122113.183 [Default] Stopped
2019-11-19T00:08:33.183Z,1574122113.183 [Default](DEBUG): Aggregate::uninitialize Default
2019-11-19T00:08:33.183Z,1574122113.183 [Default:B.GoToSurface] Stopped
2019-11-19T00:08:33.183Z,1574122113.183 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-11-19T00:08:33.183Z,1574122113.183 [Default:CheckIn] Stopped
2019-11-19T00:08:33.183Z,1574122113.183 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-11-19T00:08:33.183Z,1574122113.183 [Default:CheckIn:C.Wait] Stopped
2019-11-19T00:08:33.183Z,1574122113.183 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-11-19T00:08:33.186Z,1574122113.186 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-11-19T00:08:33.186Z,1574122113.186 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-11-19T00:08:33.186Z,1574122113.186 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-11-19T00:08:33.187Z,1574122113.187 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-11-19T00:08:33.187Z,1574122113.187 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-11-19T00:08:33.187Z,1574122113.187 [BuoyancyServo](INFO): Powering down
2019-11-19T00:08:33.199Z,1574122113.199 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-11-19T00:08:33.199Z,1574122113.199 [ElevatorServo](INFO): Powering down
2019-11-19T00:08:33.200Z,1574122113.200 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-11-19T00:08:33.200Z,1574122113.200 [MassServo](INFO): Powering down
2019-11-19T00:08:33.201Z,1574122113.201 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-11-19T00:08:33.201Z,1574122113.201 [RudderServo](INFO): Powering down
2019-11-19T00:08:33.202Z,1574122113.202 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-11-19T00:08:33.202Z,1574122113.202 [ThrusterServo](INFO): Powering down
2019-11-19T00:08:33.202Z,1574122113.202 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-11-19T00:08:33.203Z,1574122113.203 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-11-19T00:08:33.203Z,1574122113.203 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-11-19T00:08:33.203Z,1574122113.203 [CBIT](DEBUG): Powering off loads.
2019-11-19T00:08:33.215Z,1574122113.215 [CBIT](DEBUG): Disabling WDT.
2019-11-19T00:08:33.227Z,1574122113.227 [CBIT](DEBUG): Opening all GF detection circuits.
2019-11-19T00:08:33.228Z,1574122113.228 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-11-19T00:08:33.273Z,1574122113.273 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-11-19T00:08:33.283Z,1574122113.283 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-11-19T00:08:33.333Z,1574122113.333 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-11-19T00:08:33.336Z,1574122113.336 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-11-19T00:08:33.409Z,1574122113.409 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-11-19T00:08:33.469Z,1574122113.469 [logger ThreadHandler](INFO): Thread cancelled.