2019-10-16T15:54:59.885Z,1571241299.885 [Supervisor](DEBUG): Initializing supervisor. 2019-10-16T15:54:59.888Z,1571241299.888 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2019-10-16T15:54:59.889Z,1571241299.889 [SyncHandler](INFO): Protected caller Thread ID is 806 2019-10-16T15:54:59.889Z,1571241299.889 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2019-10-16T15:54:59.890Z,1571241299.890 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2019-10-16T15:54:59.891Z,1571241299.891 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 807 2019-10-16T15:54:59.893Z,1571241299.893 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2019-10-16T15:54:59.904Z,1571241299.904 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2019-10-16T15:54:59.905Z,1571241299.905 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2019-10-16T15:54:59.906Z,1571241299.906 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 808 2019-10-16T15:54:59.906Z,1571241299.906 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2019-10-16T15:54:59.907Z,1571241299.907 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2019-10-16T15:54:59.908Z,1571241299.908 [logger ThreadHandler](INFO): Protected caller Thread ID is 809 2019-10-16T15:54:59.910Z,1571241299.910 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2019-10-16T15:54:59.910Z,1571241299.910 [Supervisor](INFO): Looking for Config files in directory: Config/ 2019-10-16T15:54:59.914Z,1571241299.914 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2019-10-16T15:55:00.315Z,1571241300.315 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2019-10-16T15:55:00.317Z,1571241300.317 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2019-10-16T15:55:00.412Z,1571241300.412 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2019-10-16T15:55:00.414Z,1571241300.414 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2019-10-16T15:55:00.712Z,1571241300.712 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2019-10-16T15:55:00.713Z,1571241300.713 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2019-10-16T15:55:00.848Z,1571241300.848 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2019-10-16T15:55:00.850Z,1571241300.850 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2019-10-16T15:55:01.035Z,1571241301.035 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2019-10-16T15:55:01.036Z,1571241301.036 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2019-10-16T15:55:01.471Z,1571241301.471 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2019-10-16T15:55:01.472Z,1571241301.472 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2019-10-16T15:55:01.669Z,1571241301.669 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2019-10-16T15:55:01.671Z,1571241301.671 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2019-10-16T15:55:01.810Z,1571241301.810 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2019-10-16T15:55:01.811Z,1571241301.811 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2019-10-16T15:55:02.007Z,1571241302.007 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2019-10-16T15:55:02.009Z,1571241302.009 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2019-10-16T15:55:02.104Z,1571241302.104 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2019-10-16T15:55:02.105Z,1571241302.105 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2019-10-16T15:55:02.389Z,1571241302.389 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2019-10-16T15:55:02.391Z,1571241302.391 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2019-10-16T15:55:02.472Z,1571241302.472 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2019-10-16T15:55:02.573Z,1571241302.573 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2019-10-16T15:55:02.573Z,1571241302.573 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2019-10-16T15:55:03.158Z,1571241303.158 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2019-10-16T15:55:03.160Z,1571241303.160 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2019-10-16T15:55:03.573Z,1571241303.573 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2019-10-16T15:55:03.575Z,1571241303.575 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/ 2019-10-16T15:55:03.874Z,1571241303.874 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg 2019-10-16T15:55:04.289Z,1571241304.289 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg 2019-10-16T15:55:04.386Z,1571241304.386 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg 2019-10-16T15:55:04.482Z,1571241304.482 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg 2019-10-16T15:55:04.701Z,1571241304.701 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2019-10-16T15:55:04.702Z,1571241304.702 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg 2019-10-16T15:55:04.787Z,1571241304.787 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg 2019-10-16T15:55:04.879Z,1571241304.879 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg 2019-10-16T15:55:04.975Z,1571241304.975 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg 2019-10-16T15:55:05.057Z,1571241305.057 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg 2019-10-16T15:55:05.163Z,1571241305.163 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg 2019-10-16T15:55:05.342Z,1571241305.342 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg 2019-10-16T15:55:05.470Z,1571241305.470 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2019-10-16T15:55:05.485Z,1571241305.485 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2019-10-16T15:55:05.993Z,1571241305.993 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation 2019-10-16T15:55:05.999Z,1571241305.999 [AHRS_M2](INFO): created writer for : platform_orientation 2019-10-16T15:55:06.000Z,1571241306.000 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation 2019-10-16T15:55:06.005Z,1571241306.005 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation 2019-10-16T15:55:06.006Z,1571241306.006 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle 2019-10-16T15:55:06.011Z,1571241306.011 [AHRS_M2](INFO): created writer for : platform_pitch_angle 2019-10-16T15:55:06.011Z,1571241306.011 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle 2019-10-16T15:55:06.016Z,1571241306.016 [AHRS_M2](INFO): created writer for : platform_roll_angle 2019-10-16T15:55:06.191Z,1571241306.191 [AHRS_M2] Loaded 2019-10-16T15:55:06.192Z,1571241306.192 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2019-10-16T15:55:06.332Z,1571241306.332 [DataOverHttps] Loaded 2019-10-16T15:55:06.332Z,1571241306.332 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2019-10-16T15:55:06.333Z,1571241306.333 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4075C4E0 2019-10-16T15:55:06.333Z,1571241306.333 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 888 2019-10-16T15:55:06.346Z,1571241306.346 [Depth_Keller] Loaded 2019-10-16T15:55:06.346Z,1571241306.346 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2019-10-16T15:55:06.351Z,1571241306.351 [DropWeight] Loaded 2019-10-16T15:55:06.351Z,1571241306.351 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2019-10-16T15:55:06.408Z,1571241306.408 [DUSBL_Hydroid] Loaded 2019-10-16T15:55:06.408Z,1571241306.408 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread. 2019-10-16T15:55:06.454Z,1571241306.454 [Micromodem] Loaded 2019-10-16T15:55:06.454Z,1571241306.454 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread. 2019-10-16T15:55:06.548Z,1571241306.548 [NAL9602] Loaded 2019-10-16T15:55:06.549Z,1571241306.549 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2019-10-16T15:55:06.564Z,1571241306.564 [Onboard] Loaded 2019-10-16T15:55:06.564Z,1571241306.564 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2019-10-16T15:55:06.570Z,1571241306.570 [PowerOnly] Loaded 2019-10-16T15:55:06.570Z,1571241306.570 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread. 2019-10-16T15:55:06.577Z,1571241306.577 [Radio_Surface] Loaded 2019-10-16T15:55:06.577Z,1571241306.577 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2019-10-16T15:55:06.578Z,1571241306.578 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4078C4E0 2019-10-16T15:55:06.578Z,1571241306.578 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 889 2019-10-16T15:55:06.621Z,1571241306.621 [RDI_Pathfinder] Loaded 2019-10-16T15:55:06.621Z,1571241306.621 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread. 2019-10-16T15:55:08.064Z,1571241308.064 [BPC1] Loaded 2019-10-16T15:55:08.064Z,1571241308.064 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2019-10-16T15:55:08.065Z,1571241308.065 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2019-10-16T15:55:08.065Z,1571241308.065 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2019-10-16T15:55:08.089Z,1571241308.089 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2019-10-16T15:55:08.089Z,1571241308.089 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2019-10-16T15:55:08.208Z,1571241308.208 [DeadReckonUsingMultipleVelocitySources] Loaded 2019-10-16T15:55:08.209Z,1571241308.209 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2019-10-16T15:55:08.228Z,1571241308.228 [NavChart] Loaded 2019-10-16T15:55:08.229Z,1571241308.229 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2019-10-16T15:55:08.233Z,1571241308.233 [UniversalFixResidualReporter] Loaded 2019-10-16T15:55:08.233Z,1571241308.233 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2019-10-16T15:55:08.233Z,1571241308.233 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2019-10-16T15:55:08.234Z,1571241308.234 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2019-10-16T15:55:08.360Z,1571241308.360 [BuoyancyServo] Loaded 2019-10-16T15:55:08.361Z,1571241308.361 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2019-10-16T15:55:08.376Z,1571241308.376 [ElevatorServo] Loaded 2019-10-16T15:55:08.376Z,1571241308.376 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2019-10-16T15:55:08.390Z,1571241308.390 [MassServo] Loaded 2019-10-16T15:55:08.391Z,1571241308.391 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2019-10-16T15:55:08.405Z,1571241308.405 [RudderServo] Loaded 2019-10-16T15:55:08.405Z,1571241308.405 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2019-10-16T15:55:08.419Z,1571241308.419 [ThrusterServo] Loaded 2019-10-16T15:55:08.420Z,1571241308.420 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2019-10-16T15:55:08.420Z,1571241308.420 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2019-10-16T15:55:08.421Z,1571241308.421 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2019-10-16T15:55:08.672Z,1571241308.672 [PAR_Licor] Loaded 2019-10-16T15:55:08.673Z,1571241308.673 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2019-10-16T15:55:08.716Z,1571241308.716 [WetLabsSeaOWL_UV_A] Loaded 2019-10-16T15:55:08.716Z,1571241308.716 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread. 2019-10-16T15:55:08.717Z,1571241308.717 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 408D74E0 2019-10-16T15:55:08.717Z,1571241308.717 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 890 2019-10-16T15:55:08.718Z,1571241308.718 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2019-10-16T15:55:08.719Z,1571241308.719 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2019-10-16T15:55:09.406Z,1571241309.406 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2019-10-16T15:55:09.408Z,1571241309.408 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2019-10-16T15:55:09.462Z,1571241309.462 [DepthRateCalculator] Loaded 2019-10-16T15:55:09.463Z,1571241309.463 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2019-10-16T15:55:09.468Z,1571241309.468 [PitchRateCalculator] Loaded 2019-10-16T15:55:09.468Z,1571241309.468 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2019-10-16T15:55:09.481Z,1571241309.481 [SpeedCalculator] Loaded 2019-10-16T15:55:09.481Z,1571241309.481 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2019-10-16T15:55:09.502Z,1571241309.502 [TempGradientCalculator] Loaded 2019-10-16T15:55:09.502Z,1571241309.502 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2019-10-16T15:55:09.508Z,1571241309.508 [YawRateCalculator] Loaded 2019-10-16T15:55:09.508Z,1571241309.508 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2019-10-16T15:55:09.547Z,1571241309.547 [ElevatorOffsetCalculator] Loaded 2019-10-16T15:55:09.547Z,1571241309.547 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2019-10-16T15:55:09.547Z,1571241309.547 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2019-10-16T15:55:09.549Z,1571241309.549 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2019-10-16T15:55:09.705Z,1571241309.705 [SBIT](DEBUG): Construct Startup Built In Test. 2019-10-16T15:55:09.726Z,1571241309.726 [SBIT] Loaded 2019-10-16T15:55:09.727Z,1571241309.727 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2019-10-16T15:55:09.727Z,1571241309.727 [IBIT](DEBUG): Construct Initiated Built In Test. 2019-10-16T15:55:09.738Z,1571241309.738 [IBIT] Loaded 2019-10-16T15:55:09.739Z,1571241309.739 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2019-10-16T15:55:09.742Z,1571241309.742 [CBIT](DEBUG): Construct Continuous Built In Test. 2019-10-16T15:55:09.876Z,1571241309.876 [CBIT] Loaded 2019-10-16T15:55:09.876Z,1571241309.876 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2019-10-16T15:55:09.877Z,1571241309.877 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2019-10-16T15:55:09.877Z,1571241309.877 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2019-10-16T15:55:09.999Z,1571241309.999 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2019-10-16T15:55:10.000Z,1571241310.000 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2019-10-16T15:55:10.122Z,1571241310.122 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2019-10-16T15:55:10.124Z,1571241310.124 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2019-10-16T15:55:10.247Z,1571241310.247 [VerticalControl](DEBUG): Construct VerticalControl. 2019-10-16T15:55:10.329Z,1571241310.329 [VerticalControl] Loaded 2019-10-16T15:55:10.330Z,1571241310.330 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2019-10-16T15:55:10.330Z,1571241310.330 [HorizontalControl](DEBUG): Construct HorizontalControl. 2019-10-16T15:55:10.386Z,1571241310.386 [HorizontalControl] Loaded 2019-10-16T15:55:10.386Z,1571241310.386 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2019-10-16T15:55:10.387Z,1571241310.387 [SpeedControl](DEBUG): Construct SpeedControl. 2019-10-16T15:55:10.388Z,1571241310.388 [SpeedControl] Loaded 2019-10-16T15:55:10.389Z,1571241310.389 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2019-10-16T15:55:10.389Z,1571241310.389 [LoopControl](DEBUG): Construct LoopControl. 2019-10-16T15:55:10.390Z,1571241310.390 [LoopControl] Loaded 2019-10-16T15:55:10.390Z,1571241310.390 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2019-10-16T15:55:10.391Z,1571241310.391 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2019-10-16T15:55:10.391Z,1571241310.391 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2019-10-16T15:55:10.440Z,1571241310.440 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2019-10-16T15:55:10.443Z,1571241310.443 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2019-10-16T15:55:10.444Z,1571241310.444 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2019-10-16T15:55:10.451Z,1571241310.451 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2019-10-16T15:55:10.452Z,1571241310.452 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AB44E0 2019-10-16T15:55:10.452Z,1571241310.452 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 892 2019-10-16T15:55:10.457Z,1571241310.457 [Supervisor](INFO): Main Thread ID is 802 2019-10-16T15:55:10.457Z,1571241310.457 [Supervisor](DEBUG): Running supervisor. 2019-10-16T15:55:10.457Z,1571241310.457 [CommandLine ThreadHandler](INFO): Handler Thread ID is 893 2019-10-16T15:55:10.460Z,1571241310.460 [controlThread ThreadHandler](INFO): Handler Thread ID is 894 2019-10-16T15:55:10.460Z,1571241310.460 [controlThread](DEBUG): Initializing ControlThread 2019-10-16T15:55:10.466Z,1571241310.466 [NavChart](DEBUG): Initialize NavChart Navigation. 2019-10-16T15:55:10.466Z,1571241310.466 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2019-10-16T15:55:10.471Z,1571241310.471 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2019-10-16T15:55:10.471Z,1571241310.471 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2019-10-16T15:55:10.471Z,1571241310.471 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2019-10-16T15:55:10.472Z,1571241310.472 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2019-10-16T15:55:10.472Z,1571241310.472 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2019-10-16T15:55:10.473Z,1571241310.473 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2019-10-16T15:55:10.473Z,1571241310.473 [SBIT](INFO): Initialize SBIT Component. 2019-10-16T15:55:10.474Z,1571241310.474 [SBIT](IMPORTANT): git: 2019-10-15 2019-10-16T15:55:10.474Z,1571241310.474 [SBIT](INFO): git hash: 5afd4984613942c073d284d94e598e25fc5569fb 2019-10-16T15:55:10.474Z,1571241310.474 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2019-10-16T15:55:10.476Z,1571241310.476 [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-10-16T15:55:10.477Z,1571241310.477 [SBIT](INFO): Beginning SBIT in 26.000000 seconds. 2019-10-16T15:55:10.477Z,1571241310.477 [IBIT](INFO): Initialize IBIT Component. 2019-10-16T15:55:10.478Z,1571241310.478 [CBIT](DEBUG): Initialize CBIT Component. 2019-10-16T15:55:10.479Z,1571241310.479 [logger ThreadHandler](INFO): Handler Thread ID is 895 2019-10-16T15:55:10.490Z,1571241310.490 [CBIT](DEBUG): Initialized mux pins. 2019-10-16T15:55:10.490Z,1571241310.490 [CBIT](DEBUG): Initializing the watchdog timer. 2019-10-16T15:55:10.499Z,1571241310.499 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 896 2019-10-16T15:55:10.500Z,1571241310.500 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2019-10-16T15:55:10.511Z,1571241310.511 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 897 2019-10-16T15:55:10.514Z,1571241310.514 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2019-10-16T15:55:10.514Z,1571241310.514 [CBIT](DEBUG): Initializing heartbeat. 2019-10-16T15:55:10.523Z,1571241310.523 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 898 2019-10-16T15:55:10.523Z,1571241310.523 [WetLabsSeaOWL_UV_A](INFO): Powering down 2019-10-16T15:55:10.551Z,1571241310.551 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 899 2019-10-16T15:55:10.560Z,1571241310.560 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2019-10-16T15:55:10.560Z,1571241310.560 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2019-10-16T15:55:10.560Z,1571241310.560 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2019-10-16T15:55:10.560Z,1571241310.560 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2019-10-16T15:55:10.560Z,1571241310.560 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2019-10-16T15:55:10.560Z,1571241310.560 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2019-10-16T15:55:10.561Z,1571241310.561 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2019-10-16T15:55:10.561Z,1571241310.561 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2019-10-16T15:55:10.561Z,1571241310.561 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2019-10-16T15:55:10.561Z,1571241310.561 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2019-10-16T15:55:10.561Z,1571241310.561 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2019-10-16T15:55:10.561Z,1571241310.561 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2019-10-16T15:55:10.562Z,1571241310.562 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2019-10-16T15:55:10.562Z,1571241310.562 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2019-10-16T15:55:10.562Z,1571241310.562 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2019-10-16T15:55:10.562Z,1571241310.562 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2019-10-16T15:55:10.586Z,1571241310.586 [CBIT](DEBUG): Deactivating GF circuits. 2019-10-16T15:55:10.586Z,1571241310.586 [CBIT](DEBUG): Deactivating emergency mode. 2019-10-16T15:55:10.622Z,1571241310.622 [CBIT](DEBUG): Backplane powered. 2019-10-16T15:55:10.623Z,1571241310.623 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2019-10-16T15:55:10.624Z,1571241310.624 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2019-10-16T15:55:10.625Z,1571241310.625 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2019-10-16T15:55:10.626Z,1571241310.626 [LoopControl](DEBUG): Initialize LoopControlComponent. 2019-10-16T15:55:10.627Z,1571241310.627 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2019-10-16T15:55:10.660Z,1571241310.660 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2019-10-16T15:55:10.671Z,1571241310.671 [MissionManager](DEBUG): 2019-10-16T15:55:10.671Z,1571241310.671 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2019-10-16T15:55:10.734Z,1571241310.734 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2019-10-16T15:55:10.751Z,1571241310.751 [Default:A.Wait](DEBUG): Construct Wait. 2019-10-16T15:55:10.753Z,1571241310.753 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2019-10-16T15:55:10.778Z,1571241310.778 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2019-10-16T15:55:10.788Z,1571241310.788 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2019-10-16T15:55:10.794Z,1571241310.794 [Default:E.Execute](DEBUG): Construct Execute. 2019-10-16T15:55:10.825Z,1571241310.825 [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-10-16T15:55:10.830Z,1571241310.830 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,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-10-16T15:55:10.849Z,1571241310.849 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-10-16T15:55:10.915Z,1571241310.915 [Radio_Surface](INFO): Powering up 2019-10-16T15:55:10.931Z,1571241310.931 [Depth_Keller](ERROR): Pressure reading out of range: 957.962097 decibar 2019-10-16T15:55:10.932Z,1571241310.932 [DUSBL_Hydroid](INFO): Powering up 2019-10-16T15:55:10.932Z,1571241310.932 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid. 2019-10-16T15:55:11.108Z,1571241311.108 [DepthRateCalculator](ERROR): Depth measurement is not active 2019-10-16T15:55:11.167Z,1571241311.167 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2019-10-16T15:55:11.175Z,1571241311.175 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2019-10-16T15:55:11.175Z,1571241311.175 [ElevatorServo](DEBUG): Initializing EZServoServo. 2019-10-16T15:55:11.183Z,1571241311.183 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2019-10-16T15:55:11.183Z,1571241311.183 [MassServo](DEBUG): Initializing EZServoServo. 2019-10-16T15:55:11.191Z,1571241311.191 [MassServo](DEBUG): Initializing MassServo. 2019-10-16T15:55:11.191Z,1571241311.191 [RudderServo](DEBUG): Initializing EZServoServo. 2019-10-16T15:55:11.200Z,1571241311.200 [RudderServo](DEBUG): Initializing RudderServo. 2019-10-16T15:55:11.200Z,1571241311.200 [ThrusterServo](DEBUG): Initializing EZServoServo. 2019-10-16T15:55:11.207Z,1571241311.207 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2019-10-16T15:55:11.258Z,1571241311.258 [Micromodem](INFO): Powering up 2019-10-16T15:55:11.258Z,1571241311.258 [Micromodem](DEBUG): Initializing Micromodem. 2019-10-16T15:55:16.129Z,1571241316.129 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33 2019-10-16T15:55:20.473Z,1571241320.473 [Micromodem](INFO): Nmea in: $CATMG,2019-10-16T15:55:29.772232Z,RTC,RTC*52 2019-10-16T15:55:20.473Z,1571241320.473 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2019-10-16T15:55:29.772232Z,RTC,RTC*52 2019-10-16T15:55:24.538Z,1571241324.538 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder 2019-10-16T15:55:27.344Z,1571241327.344 [Micromodem](ERROR): Nmea resend: $CCCFG,ALL,0*33 2019-10-16T15:55:27.744Z,1571241327.744 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31 2019-10-16T15:55:27.745Z,1571241327.745 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31 2019-10-16T15:55:28.148Z,1571241328.148 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33 2019-10-16T15:55:28.149Z,1571241328.149 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64 2019-10-16T15:55:28.554Z,1571241328.554 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66 2019-10-16T15:55:28.554Z,1571241328.554 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F 2019-10-16T15:55:28.956Z,1571241328.956 [DUSBL_Hydroid](INFO): DUSBL Version:O 2019-10-16T15:55:29.764Z,1571241329.764 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D 2019-10-16T15:55:29.764Z,1571241329.764 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E 2019-10-16T15:55:30.168Z,1571241330.168 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C 2019-10-16T15:55:30.168Z,1571241330.168 [Micromodem](INFO): Nmea out: $CCCFG,FC0,10000*46 2019-10-16T15:55:30.568Z,1571241330.568 [Micromodem](INFO): Nmea in: $CACFG,FC0,10000*44 2019-10-16T15:55:30.569Z,1571241330.569 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63 2019-10-16T15:55:30.976Z,1571241330.976 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61 2019-10-16T15:55:30.976Z,1571241330.976 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A 2019-10-16T15:55:31.384Z,1571241331.384 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38 2019-10-16T15:55:31.385Z,1571241331.385 [Micromodem](INFO): Nmea out: $CCCLK,2019,10,16,15,55,32*4D 2019-10-16T15:55:31.781Z,1571241331.781 [Micromodem](INFO): Nmea in: $CACLK,2019,10,16,15,55,32*4F 2019-10-16T15:55:31.782Z,1571241331.782 [Micromodem](INFO): Nmea in: $CATMS,0,2019-10-16T15:55:33Z*7E 2019-10-16T15:55:31.784Z,1571241331.784 [Micromodem](INFO): Nmea in: $CATMG,2019-10-16T15:55:33.026221Z,USER_CMD,RTC*1C 2019-10-16T15:55:36.629Z,1571241336.629 [NAL9602](INFO): Powering up NAL9602 2019-10-16T15:55:37.085Z,1571241337.085 [SBIT](IMPORTANT): Beginning Startup BIT 2019-10-16T15:55:37.089Z,1571241337.089 [CBIT](IMPORTANT): Beginning ground fault scan 2019-10-16T15:55:47.637Z,1571241347.637 [NAL9602](INFO): NAL9602 initialized 2019-10-16T15:55:48.176Z,1571241348.176 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.018832 CHAN A1 (24V): -0.017148 CHAN A2 (12V): -0.002983 CHAN A3 (5V): -0.001760 CHAN B0 (3.3V): 0.000288 CHAN B1 (3.15aV): -0.000260 CHAN B2 (3.15bV): 0.000305 CHAN B3 (GND): 0.000767 OPEN: 0.007268 Full Scale Calc: 4.765 mA, -1.589 mA 2019-10-16T15:55:48.462Z,1571241348.462 [NAL9602](DEBUG): Fix Requested 2019-10-16T15:56:23.933Z,1571241383.933 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-10-16T15:56:23.933Z,1571241383.933 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-10-16T15:56:30.428Z,1571241390.428 [SBIT](IMPORTANT): SBIT PASSED 2019-10-16T15:56:30.472Z,1571241390.472 [CommandLine](IMPORTANT): got command configSet list 2019-10-16T15:56:30.472Z,1571241390.472 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2019-10-16T15:56:30.473Z,1571241390.473 [CommandLine](IMPORTANT): Aanderaa_O2.loadAtStartup=0 bool; 2019-10-16T15:56:30.473Z,1571241390.473 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup=0 bool; 2019-10-16T15:56:30.473Z,1571241390.473 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold=20 count; 2019-10-16T15:56:30.473Z,1571241390.473 [CommandLine](IMPORTANT): Express linearApproximation TrackAcousticContact.heading_to_contact 45.000000 degree; 2019-10-16T15:56:30.473Z,1571241390.473 [CommandLine](IMPORTANT): Express linearApproximation TrackAcousticContact.range_to_contact 5.000000 meter; 2019-10-16T15:56:30.473Z,1571241390.473 [CommandLine](IMPORTANT): Micromodem.surfaceThreshold=2 meter; 2019-10-16T15:56:30.473Z,1571241390.473 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=348 cubic_centimeter; 2019-10-16T15:56:30.473Z,1571241390.473 [CommandLine](IMPORTANT): VerticalControl.massDefault=-1.6 millimeter; 2019-10-16T15:56:30.800Z,1571241390.800 [MissionManager](IMPORTANT): Started mission Startup 2019-10-16T15:56:30.801Z,1571241390.801 [Startup] Running Loop=1 2019-10-16T15:56:30.801Z,1571241390.801 [Startup](DEBUG): Aggregate::initialize Startup 2019-10-16T15:56:30.801Z,1571241390.801 [Startup:A.GoToSurface] Running Loop=1 2019-10-16T15:56:30.801Z,1571241390.801 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-10-16T15:56:30.802Z,1571241390.802 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-10-16T15:56:30.802Z,1571241390.802 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-10-16T15:56:30.803Z,1571241390.803 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-10-16T15:56:30.803Z,1571241390.803 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-10-16T15:56:30.803Z,1571241390.803 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-10-16T15:56:30.805Z,1571241390.805 [Startup:StartupSatComms] Running Loop=1 2019-10-16T15:56:30.805Z,1571241390.805 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2019-10-16T15:56:30.805Z,1571241390.805 [Startup:StartupSatComms:A] Running Loop=1 2019-10-16T15:56:31.273Z,1571241391.273 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2019-10-16T15:57:31.000Z,1571241451.000 [Startup:StartupSatComms:A](INFO): Timed out from 2019-10-16T15:56:30.8Z 2019-10-16T15:57:31.001Z,1571241451.001 [Startup:StartupSatComms:A] Stopped 2019-10-16T15:57:31.001Z,1571241451.001 [Startup:StartupSatComms:B] Running Loop=1 2019-10-16T15:57:31.424Z,1571241451.424 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-10-16T15:58:10.608Z,1571241490.608 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2019-10-16T15:58:10.608Z,1571241490.608 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-10-16T15:58:10.630Z,1571241490.630 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-10-16T15:58:10.997Z,1571241490.997 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-10-16T15:58:10.997Z,1571241490.997 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2019-10-16T15:58:31.210Z,1571241511.210 [Startup:StartupSatComms:B](INFO): Timed out from 2019-10-16T15:57:31.0Z 2019-10-16T15:58:31.210Z,1571241511.210 [Startup:StartupSatComms:B] Stopped 2019-10-16T15:58:31.210Z,1571241511.210 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2019-10-16T15:58:31.210Z,1571241511.210 [Startup:StartupSatComms] Stopped 2019-10-16T15:58:31.210Z,1571241511.210 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2019-10-16T15:58:31.211Z,1571241511.211 [Startup](INFO): Completed Startup 2019-10-16T15:58:31.211Z,1571241511.211 [MissionManager](INFO): Startup is completed. 2019-10-16T15:58:31.212Z,1571241511.212 [MissionManager](INFO): Uninitializing Mission Startup 2019-10-16T15:58:31.212Z,1571241511.212 [Startup] Stopped 2019-10-16T15:58:31.212Z,1571241511.212 [Startup](DEBUG): Aggregate::uninitialize Startup 2019-10-16T15:58:31.212Z,1571241511.212 [Startup:A.GoToSurface] Stopped 2019-10-16T15:58:31.212Z,1571241511.212 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-10-16T15:58:31.693Z,1571241511.693 [MissionManager](IMPORTANT): Started mission Default 2019-10-16T15:58:31.693Z,1571241511.693 [Default] Running Loop=1 2019-10-16T15:58:31.693Z,1571241511.693 [Default](DEBUG): Aggregate::initialize Default 2019-10-16T15:58:31.693Z,1571241511.693 [Default:B.GoToSurface] Running Loop=1 2019-10-16T15:58:31.693Z,1571241511.693 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-10-16T15:58:31.693Z,1571241511.693 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-10-16T15:58:31.694Z,1571241511.694 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-10-16T15:58:31.694Z,1571241511.694 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-10-16T15:58:31.695Z,1571241511.695 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-10-16T15:58:31.695Z,1571241511.695 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-10-16T15:58:31.695Z,1571241511.695 [Default:A.Wait] Running Loop=1 2019-10-16T15:58:31.695Z,1571241511.695 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-10-16T15:58:44.934Z,1571241524.934 [Default:A.Wait](INFO): Done Waiting. 2019-10-16T15:58:44.934Z,1571241524.934 [Default:A.Wait] Stopped 2019-10-16T15:58:44.934Z,1571241524.934 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-10-16T15:58:45.361Z,1571241525.361 [Default:CheckIn] Running Loop=1 2019-10-16T15:58:45.361Z,1571241525.361 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-16T15:58:45.361Z,1571241525.361 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-16T15:58:45.748Z,1571241525.748 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2019-10-16T15:58:46.965Z,1571241526.965 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004968 2019-10-16T15:59:32.224Z,1571241572.224 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2019-10-16T15:59:32.224Z,1571241572.224 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-32768,-3268,V 2019-10-16T15:59:38.659Z,1571241578.659 [RDI_Pathfinder](ERROR): Failed to parse:2768,V 2019-10-16T16:00:35.620Z,1571241635.620 [RDI_Pathfinder](ERROR): Failed to parse: :B, +28, -30,A 2019-10-16T16:00:50.951Z,1571241650.951 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-10-16T16:00:51.766Z,1571241651.766 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:00:55.406Z,1571241655.406 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:00:58.630Z,1571241658.630 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:01:01.462Z,1571241661.462 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:01:04.290Z,1571241664.290 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:01:07.518Z,1571241667.518 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:01:10.350Z,1571241670.350 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:01:11.659Z,1571241671.659 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2019-10-16T16:01:11.659Z,1571241671.659 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-10-16T16:01:11.674Z,1571241671.674 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-10-16T16:01:12.005Z,1571241672.005 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-10-16T16:01:12.005Z,1571241672.005 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2019-10-16T16:01:13.578Z,1571241673.578 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:01:16.410Z,1571241676.410 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:01:19.654Z,1571241679.654 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:01:20.870Z,1571241680.870 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2019-10-16T16:01:20.877Z,1571241680.877 [BPC1](INFO): Received data from all battery sticks. 2019-10-16T16:01:22.482Z,1571241682.482 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:01:25.298Z,1571241685.298 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:01:28.542Z,1571241688.542 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:01:31.371Z,1571241691.371 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:01:34.586Z,1571241694.586 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:01:37.414Z,1571241697.414 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:01:40.270Z,1571241700.270 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:01:43.478Z,1571241703.478 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:01:46.308Z,1571241706.308 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:01:49.538Z,1571241709.538 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:01:52.362Z,1571241712.362 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:01:55.594Z,1571241715.594 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:01:58.430Z,1571241718.430 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:02:01.258Z,1571241721.258 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:02:04.486Z,1571241724.486 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:02:07.318Z,1571241727.318 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:02:10.542Z,1571241730.542 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:02:13.370Z,1571241733.370 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:02:15.431Z,1571241735.431 [RDI_Pathfinder](ERROR): Failed to parse: : -0.21, +0.01, +0.04, 0.00, 99.00 2019-10-16T16:02:16.606Z,1571241736.606 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:02:19.434Z,1571241739.434 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:02:22.262Z,1571241742.262 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:02:25.498Z,1571241745.498 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:02:28.318Z,1571241748.318 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:02:31.550Z,1571241751.550 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:02:34.385Z,1571241754.385 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:02:37.614Z,1571241757.614 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:02:40.446Z,1571241760.446 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:02:43.270Z,1571241763.270 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:02:46.502Z,1571241766.502 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:02:49.334Z,1571241769.334 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:02:52.574Z,1571241772.574 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:02:55.390Z,1571241775.390 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:02:58.626Z,1571241778.626 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:03:01.450Z,1571241781.450 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:03:04.278Z,1571241784.278 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:03:07.510Z,1571241787.510 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:03:10.338Z,1571241790.338 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:03:13.570Z,1571241793.570 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:03:16.403Z,1571241796.403 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:03:19.630Z,1571241799.630 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:03:22.458Z,1571241802.458 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:03:25.282Z,1571241805.282 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:03:28.518Z,1571241808.519 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:03:31.350Z,1571241811.350 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:03:34.578Z,1571241814.578 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:03:37.402Z,1571241817.402 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:03:40.638Z,1571241820.638 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:03:43.466Z,1571241823.466 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:03:45.536Z,1571241825.536 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-10-16T15:58:45.4Z 2019-10-16T16:03:45.536Z,1571241825.536 [Default:CheckIn:Read_GPS] Stopped 2019-10-16T16:03:45.536Z,1571241825.536 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-16T16:03:45.935Z,1571241825.935 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-10-16T16:03:46.414Z,1571241826.414 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:03:49.646Z,1571241829.646 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:03:52.478Z,1571241832.478 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:03:55.297Z,1571241835.297 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:03:56.886Z,1571241836.886 [DataOverHttps](INFO): Sending 186 bytes from file Logs/20191016T155459/Courier0004.lzma 2019-10-16T16:03:58.527Z,1571241838.527 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:03:58.888Z,1571241838.888 [DataOverHttps](INFO): Moved sent file to Logs/20191016T155459/Courier0004.lzma.bak 2019-10-16T16:03:58.888Z,1571241838.888 [DataOverHttps](INFO): SBD MOMSN=11915938 2019-10-16T16:04:01.393Z,1571241841.393 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:04:04.586Z,1571241844.586 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:04:07.429Z,1571241847.429 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:04:10.278Z,1571241850.278 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:04:12.712Z,1571241852.712 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2019-10-16T16:04:12.712Z,1571241852.712 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-10-16T16:04:12.730Z,1571241852.730 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-10-16T16:04:13.096Z,1571241853.096 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-10-16T16:04:13.096Z,1571241853.096 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2019-10-16T16:04:13.473Z,1571241853.473 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:04:16.306Z,1571241856.306 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:04:19.533Z,1571241859.533 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:04:22.362Z,1571241862.362 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:04:24.013Z,1571241864.013 [DataOverHttps](INFO): Sending 629 bytes from file Logs/20191015T233211/Express0491.lzma 2019-10-16T16:04:25.590Z,1571241865.590 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:04:26.016Z,1571241866.016 [DataOverHttps](INFO): Moved sent file to Logs/20191015T233211/Express0491.lzma.bak 2019-10-16T16:04:26.016Z,1571241866.016 [DataOverHttps](INFO): SBD MOMSN=11915941 2019-10-16T16:04:28.430Z,1571241868.430 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:04:31.650Z,1571241871.650 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:04:34.482Z,1571241874.482 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:04:37.310Z,1571241877.310 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:04:40.538Z,1571241880.538 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:04:43.375Z,1571241883.375 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:04:46.602Z,1571241886.602 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:04:47.931Z,1571241887.931 [DataOverHttps](INFO): Sending 801 bytes from file Logs/20191016T155459/Express0001.lzma 2019-10-16T16:04:49.438Z,1571241889.438 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:04:49.936Z,1571241889.936 [DataOverHttps](INFO): Moved sent file to Logs/20191016T155459/Express0001.lzma.bak 2019-10-16T16:04:49.936Z,1571241889.936 [DataOverHttps](INFO): SBD MOMSN=11915970 2019-10-16T16:04:52.259Z,1571241892.259 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:04:55.490Z,1571241895.490 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:04:55.887Z,1571241895.887 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160456.00,A,3648.16445,N,12147.28178,W,1.283,0.00,161019,,,A*74 2019-10-16T16:04:55.890Z,1571241895.890 [NAL9602](INFO): GPS fix at 20191016T160456: (36.802741, -121.788030) 2019-10-16T16:05:16.366Z,1571241916.366 [DataOverHttps](INFO): Sending 176 bytes from file Logs/20191016T155459/Express0005.lzma 2019-10-16T16:05:18.372Z,1571241918.372 [DataOverHttps](INFO): Moved sent file to Logs/20191016T155459/Express0005.lzma.bak 2019-10-16T16:05:18.372Z,1571241918.372 [DataOverHttps](INFO): SBD MOMSN=11915990 2019-10-16T16:05:24.216Z,1571241924.216 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-10-16T16:05:24.216Z,1571241924.216 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19101609165571,35.0, -0.1, 0.0,10 2019-10-16T16:05:24.617Z,1571241924.617 [Default:CheckIn:Read_Iridium] Stopped 2019-10-16T16:05:24.617Z,1571241924.617 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-16T16:05:24.618Z,1571241924.618 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-16T16:05:28.215Z,1571241928.215 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-16T16:06:04.594Z,1571241964.594 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2019-10-16T16:06:04.594Z,1571241964.594 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-32768,-3268,V 2019-10-16T16:10:25.203Z,1571242225.203 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-10-16T16:10:25.203Z,1571242225.203 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19101609215671,35, 0.0,1448.9, 0 2019-10-16T16:10:25.236Z,1571242225.236 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-16T16:10:25.236Z,1571242225.236 [Default:CheckIn:C.Wait] Stopped 2019-10-16T16:10:25.236Z,1571242225.236 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-16T16:10:25.236Z,1571242225.236 [Default:CheckIn:D] Running Loop=1 2019-10-16T16:10:25.601Z,1571242225.601 [Default:CheckIn:D] Stopped 2019-10-16T16:10:25.602Z,1571242225.602 [Default:CheckIn:E] Running Loop=1 2019-10-16T16:10:25.987Z,1571242225.987 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.898476 min 2019-10-16T16:10:25.987Z,1571242225.987 [Default:CheckIn:E] Stopped 2019-10-16T16:10:25.987Z,1571242225.987 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-16T16:10:25.987Z,1571242225.987 [Default:CheckIn] Stopped 2019-10-16T16:10:25.987Z,1571242225.987 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-16T16:10:25.987Z,1571242225.987 [Default:CheckIn](INFO): Running loop #2 2019-10-16T16:10:25.987Z,1571242225.987 [Default:CheckIn] Running Loop=2 2019-10-16T16:10:25.988Z,1571242225.988 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-16T16:10:25.988Z,1571242225.988 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-16T16:10:27.586Z,1571242227.586 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:10:27.978Z,1571242227.978 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161028.00,A,3648.16174,N,12147.28069,W,0.058,0.00,161019,,,A*7B 2019-10-16T16:10:27.980Z,1571242227.980 [NAL9602](INFO): GPS fix at 20191016T161028: (36.802696, -121.788011) 2019-10-16T16:10:28.028Z,1571242228.028 [Default:CheckIn:Read_GPS] Stopped 2019-10-16T16:10:28.028Z,1571242228.028 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-16T16:10:32.019Z,1571242232.019 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20191016T155459/Courier0007.lzma 2019-10-16T16:10:34.028Z,1571242234.028 [DataOverHttps](INFO): Moved sent file to Logs/20191016T155459/Courier0007.lzma.bak 2019-10-16T16:10:34.028Z,1571242234.028 [DataOverHttps](INFO): SBD MOMSN=11916001 2019-10-16T16:10:56.718Z,1571242256.718 [DataOverHttps](INFO): Sending 270 bytes from file Logs/20191016T155459/Express0008.lzma 2019-10-16T16:10:58.392Z,1571242258.392 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-10-16T16:10:58.471Z,1571242258.471 [NAL9602](FAULT): received: +CSQ:0 OK 2019-10-16T16:10:58.471Z,1571242258.471 [NAL9602] Data Fault, FailCount= 1 2019-10-16T16:10:58.472Z,1571242258.472 [NAL9602](ERROR): Data Fault 2019-10-16T16:10:58.533Z,1571242258.533 [CBIT](ERROR): Data Fault in component: NAL9602 2019-10-16T16:10:58.724Z,1571242258.724 [DataOverHttps](INFO): Moved sent file to Logs/20191016T155459/Express0008.lzma.bak 2019-10-16T16:10:58.724Z,1571242258.724 [DataOverHttps](INFO): SBD MOMSN=11916004 2019-10-16T16:10:58.805Z,1571242258.805 [NAL9602](INFO): Powering down 2019-10-16T16:10:59.643Z,1571242259.643 [CBIT](INFO): Clearing failed state for component NAL9602 2019-10-16T16:10:59.643Z,1571242259.643 [NAL9602] No Fault, FailCount= 1 2019-10-16T16:11:05.312Z,1571242265.312 [Default:CheckIn:Read_Iridium] Stopped 2019-10-16T16:11:05.312Z,1571242265.312 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-16T16:11:05.312Z,1571242265.312 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-16T16:11:29.096Z,1571242289.096 [NAL9602](INFO): Powering up NAL9602 2019-10-16T16:11:40.004Z,1571242300.004 [NAL9602](INFO): NAL9602 initialized 2019-10-16T16:12:11.112Z,1571242331.112 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-16T16:15:35.572Z,1571242535.572 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-10-16T16:15:35.572Z,1571242535.572 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-10-16T16:16:05.889Z,1571242565.889 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-16T16:16:05.889Z,1571242565.889 [Default:CheckIn:C.Wait] Stopped 2019-10-16T16:16:05.889Z,1571242565.889 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-16T16:16:05.889Z,1571242565.889 [Default:CheckIn:D] Running Loop=1 2019-10-16T16:16:06.300Z,1571242566.300 [Default:CheckIn:D] Stopped 2019-10-16T16:16:06.300Z,1571242566.300 [Default:CheckIn:E] Running Loop=1 2019-10-16T16:16:06.699Z,1571242566.699 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.576784 min 2019-10-16T16:16:06.699Z,1571242566.699 [Default:CheckIn:E] Stopped 2019-10-16T16:16:06.699Z,1571242566.699 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-16T16:16:06.699Z,1571242566.699 [Default:CheckIn] Stopped 2019-10-16T16:16:06.699Z,1571242566.699 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-16T16:16:06.699Z,1571242566.699 [Default:CheckIn](INFO): Running loop #3 2019-10-16T16:16:06.699Z,1571242566.699 [Default:CheckIn] Running Loop=3 2019-10-16T16:16:06.700Z,1571242566.700 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-16T16:16:06.700Z,1571242566.700 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-16T16:16:08.290Z,1571242568.290 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:16:11.108Z,1571242571.108 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-10-16T16:16:11.938Z,1571242571.938 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:16:14.358Z,1571242574.358 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:16:17.202Z,1571242577.202 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:16:20.418Z,1571242580.418 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:16:23.246Z,1571242583.246 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:16:26.474Z,1571242586.474 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:16:29.306Z,1571242589.306 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:16:32.562Z,1571242592.562 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:16:35.358Z,1571242595.358 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:16:38.206Z,1571242598.206 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:16:41.417Z,1571242601.417 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:16:44.246Z,1571242604.246 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:16:47.482Z,1571242607.482 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:16:50.310Z,1571242610.310 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:16:53.572Z,1571242613.572 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:16:56.370Z,1571242616.370 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:16:59.230Z,1571242619.230 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:17:02.434Z,1571242622.434 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:17:05.255Z,1571242625.255 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:17:08.490Z,1571242628.490 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:17:11.314Z,1571242631.314 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:17:14.142Z,1571242634.142 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:17:16.179Z,1571242636.179 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:17:18.587Z,1571242638.587 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:17:21.414Z,1571242641.414 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:17:24.646Z,1571242644.646 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:17:27.482Z,1571242647.482 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:17:30.298Z,1571242650.298 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:17:33.562Z,1571242653.562 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:17:36.362Z,1571242656.362 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:17:39.207Z,1571242659.207 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:17:42.418Z,1571242662.418 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:17:45.250Z,1571242665.250 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:17:48.486Z,1571242668.486 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:17:51.314Z,1571242671.314 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:17:54.542Z,1571242674.542 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:17:57.370Z,1571242677.370 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:18:00.610Z,1571242680.610 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:18:03.434Z,1571242683.434 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:18:06.666Z,1571242686.666 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:18:09.506Z,1571242689.506 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:18:12.730Z,1571242692.730 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:18:15.558Z,1571242695.558 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:18:18.378Z,1571242698.378 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:18:21.210Z,1571242701.210 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:18:24.442Z,1571242704.442 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:18:27.274Z,1571242707.274 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:18:30.498Z,1571242710.498 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:18:33.326Z,1571242713.326 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:18:36.561Z,1571242716.561 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:18:39.390Z,1571242719.390 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:18:42.622Z,1571242722.622 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:18:45.466Z,1571242725.466 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:18:48.694Z,1571242728.694 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:18:51.510Z,1571242731.510 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:18:54.346Z,1571242734.346 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:18:57.190Z,1571242737.190 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:19:00.402Z,1571242740.402 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:19:03.226Z,1571242743.226 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:19:06.466Z,1571242746.466 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:19:09.282Z,1571242749.282 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:19:12.530Z,1571242752.530 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:19:15.342Z,1571242755.342 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:19:18.598Z,1571242758.598 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:19:21.413Z,1571242761.413 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:19:24.634Z,1571242764.634 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:19:27.470Z,1571242767.470 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:19:30.702Z,1571242770.702 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:19:33.535Z,1571242773.535 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:19:36.354Z,1571242776.354 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:19:39.187Z,1571242779.187 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:19:42.410Z,1571242782.410 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:19:45.243Z,1571242785.243 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:19:48.482Z,1571242788.482 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:19:51.298Z,1571242791.298 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:19:54.530Z,1571242794.530 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:19:57.362Z,1571242797.362 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:20:00.590Z,1571242800.590 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:20:03.422Z,1571242803.422 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:20:06.654Z,1571242806.654 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:20:09.491Z,1571242809.491 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:20:12.722Z,1571242812.722 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:20:15.538Z,1571242815.538 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:20:18.370Z,1571242818.370 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:20:21.606Z,1571242821.606 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:20:24.430Z,1571242824.430 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:20:27.254Z,1571242827.254 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:20:30.502Z,1571242830.502 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:20:33.322Z,1571242833.322 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:20:36.542Z,1571242836.542 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:20:39.378Z,1571242839.378 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:20:42.610Z,1571242842.610 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:20:45.438Z,1571242845.438 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:20:48.670Z,1571242848.670 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:20:51.502Z,1571242851.502 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:20:54.733Z,1571242854.733 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:20:57.562Z,1571242857.562 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:21:00.790Z,1571242860.790 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:21:03.618Z,1571242863.618 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:21:06.438Z,1571242866.438 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:21:06.898Z,1571242866.898 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-10-16T16:16:06.7Z 2019-10-16T16:21:06.898Z,1571242866.898 [Default:CheckIn:Read_GPS] Stopped 2019-10-16T16:21:06.898Z,1571242866.898 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-16T16:21:20.550Z,1571242880.550 [DataOverHttps](INFO): Sending 227 bytes from file Logs/20191016T155459/Express0011.lzma 2019-10-16T16:21:22.556Z,1571242882.556 [DataOverHttps](INFO): Moved sent file to Logs/20191016T155459/Express0011.lzma.bak 2019-10-16T16:21:22.556Z,1571242882.556 [DataOverHttps](INFO): SBD MOMSN=11916021 2019-10-16T16:21:29.106Z,1571242889.106 [Default:CheckIn:Read_Iridium] Stopped 2019-10-16T16:21:29.110Z,1571242889.110 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-16T16:21:29.110Z,1571242889.110 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-16T16:21:39.162Z,1571242899.162 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-16T16:22:19.578Z,1571242939.578 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-10-16T16:22:19.578Z,1571242939.578 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19101609335071,35.0, -0.1, 0.0, 0 2019-10-16T16:23:39.575Z,1571243019.575 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-10-16T16:23:39.576Z,1571243019.576 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19101609351071,35.0, -0.1, 0.0,1448.RA, 0.00, 0.00, 0.00, 0.00, 0.00 2019-10-16T16:25:37.536Z,1571243137.536 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00, 0.00 2019-10-16T16:26:29.671Z,1571243189.671 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-16T16:26:29.671Z,1571243189.671 [Default:CheckIn:C.Wait] Stopped 2019-10-16T16:26:29.671Z,1571243189.671 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-16T16:26:29.671Z,1571243189.671 [Default:CheckIn:D] Running Loop=1 2019-10-16T16:26:30.060Z,1571243190.060 [Default:CheckIn:D] Stopped 2019-10-16T16:26:30.061Z,1571243190.061 [Default:CheckIn:E] Running Loop=1 2019-10-16T16:26:30.509Z,1571243190.509 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 27.972793 min 2019-10-16T16:26:30.509Z,1571243190.509 [Default:CheckIn:E] Stopped 2019-10-16T16:26:30.510Z,1571243190.510 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-16T16:26:30.510Z,1571243190.510 [Default:CheckIn] Stopped 2019-10-16T16:26:30.510Z,1571243190.510 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-16T16:26:30.510Z,1571243190.510 [Default:CheckIn](INFO): Running loop #4 2019-10-16T16:26:30.510Z,1571243190.510 [Default:CheckIn] Running Loop=4 2019-10-16T16:26:30.518Z,1571243190.518 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-16T16:26:30.518Z,1571243190.518 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-16T16:26:32.053Z,1571243192.053 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-10-16T16:26:32.053Z,1571243192.053 [NAL9602] Data Fault, FailCount= 1 2019-10-16T16:26:32.053Z,1571243192.053 [NAL9602](ERROR): Data Fault 2019-10-16T16:26:32.094Z,1571243192.094 [CBIT](ERROR): Data Fault in component: NAL9602 2019-10-16T16:26:32.457Z,1571243192.457 [NAL9602](INFO): Powering down 2019-10-16T16:26:33.338Z,1571243193.338 [CBIT](INFO): Clearing failed state for component NAL9602 2019-10-16T16:26:33.338Z,1571243193.338 [NAL9602] No Fault, FailCount= 1 2019-10-16T16:26:36.879Z,1571243196.879 [DataOverHttps](IMPORTANT): SBD MTMSN=20191016T162635 2019-10-16T16:26:44.714Z,1571243204.714 [DataOverHttps](INFO): Received command:ibit 2019-10-16T16:26:44.735Z,1571243204.735 [CommandLine](IMPORTANT): got command ibit 2019-10-16T16:26:45.024Z,1571243205.024 [IBIT](IMPORTANT): Beginning Initiated BIT 2019-10-16T16:26:45.024Z,1571243205.024 [IBIT](IMPORTANT): Beginning control surface checks. 2019-10-16T16:26:45.027Z,1571243205.027 [CBIT](IMPORTANT): Beginning ground fault scan 2019-10-16T16:26:55.929Z,1571243215.929 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.018899 CHAN A1 (24V): -0.018355 CHAN A2 (12V): -0.003210 CHAN A3 (5V): -0.001693 CHAN B0 (3.3V): 0.000310 CHAN B1 (3.15aV): 0.000175 CHAN B2 (3.15bV): 0.000317 CHAN B3 (GND): 0.000900 OPEN: 0.004929 Full Scale Calc: 4.765 mA, -1.589 mA 2019-10-16T16:27:02.755Z,1571243222.755 [NAL9602](INFO): Powering up NAL9602 2019-10-16T16:27:13.665Z,1571243233.665 [NAL9602](INFO): NAL9602 initialized 2019-10-16T16:27:14.490Z,1571243234.490 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:27:29.422Z,1571243249.422 [NAL9602](INFO): SBD MO Status=0, MOMSN=9428, MT Status=0, MTMSN=0 2019-10-16T16:27:29.422Z,1571243249.422 [NAL9602](INFO): No messages in MT queue 2019-10-16T16:27:30.266Z,1571243250.266 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:27:33.478Z,1571243253.478 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:27:36.310Z,1571243256.310 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:27:39.134Z,1571243259.134 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:27:41.158Z,1571243261.158 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:27:44.382Z,1571243264.382 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:27:47.210Z,1571243267.210 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:27:50.453Z,1571243270.453 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:27:53.270Z,1571243273.270 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:27:56.510Z,1571243276.510 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:27:59.338Z,1571243279.338 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:28:02.158Z,1571243282.158 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:28:05.398Z,1571243285.398 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:28:08.218Z,1571243288.218 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:28:11.450Z,1571243291.450 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:28:14.299Z,1571243294.299 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:28:17.514Z,1571243297.514 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:28:20.351Z,1571243300.351 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:28:23.174Z,1571243303.174 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:28:26.406Z,1571243306.406 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:28:29.234Z,1571243309.234 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:28:32.458Z,1571243312.458 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:28:35.290Z,1571243315.290 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:28:36.135Z,1571243316.135 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired. 2019-10-16T16:28:36.531Z,1571243316.531 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 0.000000 Voltage: 0.000000 2019-10-16T16:28:36.531Z,1571243316.531 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah 2019-10-16T16:28:36.531Z,1571243316.531 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V 2019-10-16T16:28:36.921Z,1571243316.921 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2019-10-16T16:28:36.922Z,1571243316.922 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2019-10-16T16:28:36.922Z,1571243316.922 [IBIT](IMPORTANT): Pressure:9.354916 PSI 2019-10-16T16:28:36.938Z,1571243316.938 [IBIT](IMPORTANT): Humidity:10.523746 % 2019-10-16T16:28:37.331Z,1571243317.331 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2019-10-16T16:28:37.331Z,1571243317.331 [IBIT](IMPORTANT): buoyancyNeutral: 348.000000 cc 2019-10-16T16:28:37.331Z,1571243317.331 [IBIT](IMPORTANT): massDefault: -0.160000 cm 2019-10-16T16:28:37.332Z,1571243317.332 [IBIT](IMPORTANT): stopDepth: 215.000000 m 2019-10-16T16:28:37.332Z,1571243317.332 [IBIT](IMPORTANT): abortDepth: 255.000000 m 2019-10-16T16:28:37.332Z,1571243317.332 [IBIT](IMPORTANT): IBIT FAILED 2019-10-16T16:28:38.522Z,1571243318.522 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:28:41.374Z,1571243321.374 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:28:44.582Z,1571243324.582 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:28:47.410Z,1571243327.410 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:28:50.258Z,1571243330.258 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:28:53.470Z,1571243333.470 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:28:56.294Z,1571243336.294 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:28:59.526Z,1571243339.526 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:29:02.362Z,1571243342.362 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:29:05.589Z,1571243345.589 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:29:08.418Z,1571243348.418 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:29:11.246Z,1571243351.246 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:29:14.474Z,1571243354.474 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:29:17.315Z,1571243357.315 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:29:20.542Z,1571243360.542 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:29:23.367Z,1571243363.367 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:29:24.213Z,1571243364.213 [RDI_Pathfinder](ERROR): Failed to parse: :BE,-32768,-3268,V 2019-10-16T16:29:26.606Z,1571243366.606 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:29:29.422Z,1571243369.422 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:29:32.246Z,1571243372.246 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:29:32.646Z,1571243372.646 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162932.00,A,3648.17799,N,12147.26748,W,0.039,0.00,161019,,,A*73 2019-10-16T16:29:32.648Z,1571243372.648 [NAL9602](INFO): GPS fix at 20191016T162932: (36.802966, -121.787791) 2019-10-16T16:29:32.703Z,1571243372.703 [Default:CheckIn:Read_GPS] Stopped 2019-10-16T16:29:32.703Z,1571243372.703 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-16T16:29:43.386Z,1571243383.386 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191016T155459/Courier0013.lzma 2019-10-16T16:29:45.392Z,1571243385.392 [DataOverHttps](INFO): Moved sent file to Logs/20191016T155459/Courier0013.lzma.bak 2019-10-16T16:29:45.392Z,1571243385.392 [DataOverHttps](INFO): SBD MOMSN=11916124 2019-10-16T16:30:05.368Z,1571243405.368 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-16T16:30:10.963Z,1571243410.963 [DataOverHttps](INFO): Sending 746 bytes from file Logs/20191016T155459/Express0014.lzma 2019-10-16T16:30:12.968Z,1571243412.968 [DataOverHttps](INFO): Moved sent file to Logs/20191016T155459/Express0014.lzma.bak 2019-10-16T16:30:12.968Z,1571243412.968 [DataOverHttps](INFO): SBD MOMSN=11916132 2019-10-16T16:30:37.658Z,1571243437.658 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20191016T155459/Express0017.lzma 2019-10-16T16:30:39.664Z,1571243439.664 [DataOverHttps](INFO): Moved sent file to Logs/20191016T155459/Express0017.lzma.bak 2019-10-16T16:30:39.664Z,1571243439.664 [DataOverHttps](INFO): SBD MOMSN=11916187 2019-10-16T16:30:45.830Z,1571243445.830 [Default:CheckIn:Read_Iridium] Stopped 2019-10-16T16:30:45.830Z,1571243445.830 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-16T16:30:45.830Z,1571243445.830 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-16T16:35:46.399Z,1571243746.399 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-16T16:35:46.399Z,1571243746.399 [Default:CheckIn:C.Wait] Stopped 2019-10-16T16:35:46.399Z,1571243746.399 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-16T16:35:46.399Z,1571243746.399 [Default:CheckIn:D] Running Loop=1 2019-10-16T16:35:46.779Z,1571243746.779 [Default:CheckIn:D] Stopped 2019-10-16T16:35:46.779Z,1571243746.779 [Default:CheckIn:E] Running Loop=1 2019-10-16T16:35:47.268Z,1571243747.268 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 37.251428 min 2019-10-16T16:35:47.269Z,1571243747.269 [Default:CheckIn:E] Stopped 2019-10-16T16:35:47.269Z,1571243747.269 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-16T16:35:47.269Z,1571243747.269 [Default:CheckIn] Stopped 2019-10-16T16:35:47.269Z,1571243747.269 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-16T16:35:47.269Z,1571243747.269 [Default:CheckIn](INFO): Running loop #5 2019-10-16T16:35:47.269Z,1571243747.269 [Default:CheckIn] Running Loop=5 2019-10-16T16:35:47.269Z,1571243747.269 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-16T16:35:47.269Z,1571243747.269 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-16T16:35:48.778Z,1571243748.778 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:35:49.209Z,1571243749.209 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163549.00,A,3648.16348,N,12147.21603,W,0.039,25.83,161019,,,D*4B 2019-10-16T16:35:49.215Z,1571243749.215 [NAL9602](INFO): GPS fix at 20191016T163549: (36.802725, -121.786934) 2019-10-16T16:35:49.287Z,1571243749.287 [Default:CheckIn:Read_GPS] Stopped 2019-10-16T16:35:49.287Z,1571243749.287 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-16T16:35:54.713Z,1571243754.713 [DataOverHttps](INFO): Sending 65 bytes from file Logs/20191016T155459/Courier0019.lzma 2019-10-16T16:35:56.732Z,1571243756.732 [DataOverHttps](INFO): Moved sent file to Logs/20191016T155459/Courier0019.lzma.bak 2019-10-16T16:35:56.732Z,1571243756.732 [DataOverHttps](INFO): SBD MOMSN=11916196 2019-10-16T16:36:02.178Z,1571243762.178 [NAL9602](INFO): SBD MO Status=0, MOMSN=9429, MT Status=0, MTMSN=0 2019-10-16T16:36:02.178Z,1571243762.178 [NAL9602](INFO): No messages in MT queue 2019-10-16T16:36:21.510Z,1571243781.510 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20191016T155459/Express0020.lzma 2019-10-16T16:36:23.519Z,1571243783.519 [DataOverHttps](INFO): Moved sent file to Logs/20191016T155459/Express0020.lzma.bak 2019-10-16T16:36:23.519Z,1571243783.519 [DataOverHttps](INFO): SBD MOMSN=11916199 2019-10-16T16:36:29.697Z,1571243789.697 [Default:CheckIn:Read_Iridium] Stopped 2019-10-16T16:36:29.697Z,1571243789.697 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-16T16:36:29.697Z,1571243789.697 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-16T16:36:32.876Z,1571243792.876 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-16T16:41:30.283Z,1571244090.283 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-16T16:41:30.283Z,1571244090.283 [Default:CheckIn:C.Wait] Stopped 2019-10-16T16:41:30.283Z,1571244090.283 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-16T16:41:30.283Z,1571244090.283 [Default:CheckIn:D] Running Loop=1 2019-10-16T16:41:30.675Z,1571244090.675 [Default:CheckIn:D] Stopped 2019-10-16T16:41:30.675Z,1571244090.675 [Default:CheckIn:E] Running Loop=1 2019-10-16T16:41:31.063Z,1571244091.063 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.983028 min 2019-10-16T16:41:31.063Z,1571244091.063 [Default:CheckIn:E] Stopped 2019-10-16T16:41:31.063Z,1571244091.063 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-16T16:41:31.063Z,1571244091.063 [Default:CheckIn] Stopped 2019-10-16T16:41:31.063Z,1571244091.063 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-16T16:41:31.064Z,1571244091.064 [Default:CheckIn](INFO): Running loop #6 2019-10-16T16:41:31.064Z,1571244091.064 [Default:CheckIn] Running Loop=6 2019-10-16T16:41:31.064Z,1571244091.064 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-16T16:41:31.064Z,1571244091.064 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-16T16:41:32.662Z,1571244092.662 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:41:33.054Z,1571244093.054 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164133.00,A,3648.16553,N,12147.21537,W,0.019,66.52,161019,,,D*44 2019-10-16T16:41:33.056Z,1571244093.056 [NAL9602](INFO): GPS fix at 20191016T164133: (36.802759, -121.786923) 2019-10-16T16:41:33.126Z,1571244093.126 [Default:CheckIn:Read_GPS] Stopped 2019-10-16T16:41:33.126Z,1571244093.126 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-16T16:41:37.844Z,1571244097.844 [DataOverHttps](INFO): Sending 65 bytes from file Logs/20191016T155459/Courier0022.lzma 2019-10-16T16:41:38.406Z,1571244098.406 [NAL9602](INFO): SBD MO Status=0, MOMSN=9430, MT Status=0, MTMSN=0 2019-10-16T16:41:38.406Z,1571244098.406 [NAL9602](INFO): No messages in MT queue 2019-10-16T16:41:39.852Z,1571244099.852 [DataOverHttps](INFO): Moved sent file to Logs/20191016T155459/Courier0022.lzma.bak 2019-10-16T16:41:39.852Z,1571244099.852 [DataOverHttps](INFO): SBD MOMSN=11916256 2019-10-16T16:42:05.550Z,1571244125.550 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20191016T155459/Express0023.lzma 2019-10-16T16:42:07.556Z,1571244127.556 [DataOverHttps](INFO): Moved sent file to Logs/20191016T155459/Express0023.lzma.bak 2019-10-16T16:42:07.556Z,1571244127.556 [DataOverHttps](INFO): SBD MOMSN=11916259 2019-10-16T16:42:09.131Z,1571244129.131 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-16T16:42:13.630Z,1571244133.630 [Default:CheckIn:Read_Iridium] Stopped 2019-10-16T16:42:13.630Z,1571244133.630 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-16T16:42:13.630Z,1571244133.630 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-16T16:44:50.426Z,1571244290.426 [CommandLine](IMPORTANT): got command ibit 2019-10-16T16:44:50.758Z,1571244290.758 [IBIT](IMPORTANT): Beginning Initiated BIT 2019-10-16T16:44:50.758Z,1571244290.758 [IBIT](IMPORTANT): Beginning control surface checks. 2019-10-16T16:44:50.761Z,1571244290.761 [CBIT](IMPORTANT): Beginning ground fault scan 2019-10-16T16:44:51.942Z,1571244291.942 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:44:52.334Z,1571244292.334 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164452.00,A,3648.30972,N,12147.12093,W,5.482,2.92,161019,,,D*7B 2019-10-16T16:44:52.336Z,1571244292.336 [NAL9602](INFO): GPS fix at 20191016T164452: (36.805162, -121.785349) 2019-10-16T16:45:01.697Z,1571244301.697 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.019332 CHAN A1 (24V): -0.018368 CHAN A2 (12V): -0.003512 CHAN A3 (5V): -0.001509 CHAN B0 (3.3V): 0.000119 CHAN B1 (3.15aV): 0.000196 CHAN B2 (3.15bV): 0.000042 CHAN B3 (GND): 0.000918 OPEN: 0.005158 Full Scale Calc: 4.765 mA, -1.589 mA 2019-10-16T16:45:21.831Z,1571244321.831 [NAL9602](INFO): SBD MO Status=0, MOMSN=9431, MT Status=0, MTMSN=0 2019-10-16T16:45:21.831Z,1571244321.831 [NAL9602](INFO): No messages in MT queue 2019-10-16T16:45:22.657Z,1571244322.657 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:45:23.043Z,1571244323.043 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164523.00,A,3648.35593,N,12147.11703,W,5.307,359.58,161019,,,D*76 2019-10-16T16:45:23.045Z,1571244323.045 [NAL9602](INFO): GPS fix at 20191016T164523: (36.805932, -121.785284) 2019-10-16T16:45:25.482Z,1571244325.482 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:45:25.868Z,1571244325.868 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164526.00,A,3648.36032,N,12147.11711,W,5.307,358.63,161019,,,D*74 2019-10-16T16:45:25.870Z,1571244325.870 [NAL9602](INFO): GPS fix at 20191016T164526: (36.806005, -121.785285) 2019-10-16T16:45:28.710Z,1571244328.710 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:45:29.104Z,1571244329.104 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164529.00,A,3648.36473,N,12147.11738,W,5.307,357.35,161019,,,D*7D 2019-10-16T16:45:29.106Z,1571244329.106 [NAL9602](INFO): GPS fix at 20191016T164529: (36.806079, -121.785290) 2019-10-16T16:45:31.542Z,1571244331.542 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:45:31.934Z,1571244331.934 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164532.00,A,3648.36920,N,12147.11773,W,5.365,355.95,161019,,,D*7F 2019-10-16T16:45:31.936Z,1571244331.936 [NAL9602](INFO): GPS fix at 20191016T164532: (36.806153, -121.785296) 2019-10-16T16:45:34.774Z,1571244334.774 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:45:35.187Z,1571244335.187 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164535.00,A,3648.37365,N,12147.11824,W,5.326,354.01,161019,,,D*74 2019-10-16T16:45:35.189Z,1571244335.189 [NAL9602](INFO): GPS fix at 20191016T164535: (36.806227, -121.785304) 2019-10-16T16:45:37.257Z,1571244337.257 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 3 Latitude: 36.806229 Longitude: -121.785301 2019-10-16T16:45:37.606Z,1571244337.606 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:45:37.655Z,1571244337.655 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 0.000000 Voltage: 0.000000 2019-10-16T16:45:37.655Z,1571244337.655 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah 2019-10-16T16:45:37.656Z,1571244337.656 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V 2019-10-16T16:45:37.988Z,1571244337.988 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164538.00,A,3648.37811,N,12147.11890,W,5.307,353.49,161019,,,D*76 2019-10-16T16:45:37.990Z,1571244337.990 [NAL9602](INFO): GPS fix at 20191016T164538: (36.806302, -121.785315) 2019-10-16T16:45:38.069Z,1571244338.069 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2019-10-16T16:45:38.069Z,1571244338.069 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2019-10-16T16:45:38.070Z,1571244338.070 [IBIT](IMPORTANT): Pressure:9.318788 PSI 2019-10-16T16:45:38.070Z,1571244338.070 [IBIT](IMPORTANT): Humidity:10.267366 % 2019-10-16T16:45:38.458Z,1571244338.458 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2019-10-16T16:45:38.458Z,1571244338.458 [IBIT](IMPORTANT): buoyancyNeutral: 348.000000 cc 2019-10-16T16:45:38.459Z,1571244338.459 [IBIT](IMPORTANT): massDefault: -0.160000 cm 2019-10-16T16:45:38.459Z,1571244338.459 [IBIT](IMPORTANT): stopDepth: 215.000000 m 2019-10-16T16:45:38.459Z,1571244338.459 [IBIT](IMPORTANT): abortDepth: 255.000000 m 2019-10-16T16:45:38.459Z,1571244338.459 [IBIT](IMPORTANT): IBIT PASSED 2019-10-16T16:46:10.312Z,1571244370.312 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-16T16:47:14.206Z,1571244434.206 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-16T16:47:14.206Z,1571244434.206 [Default:CheckIn:C.Wait] Stopped 2019-10-16T16:47:14.206Z,1571244434.206 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-16T16:47:14.206Z,1571244434.206 [Default:CheckIn:D] Running Loop=1 2019-10-16T16:47:14.616Z,1571244434.616 [Default:CheckIn:D] Stopped 2019-10-16T16:47:14.616Z,1571244434.616 [Default:CheckIn:E] Running Loop=1 2019-10-16T16:47:14.999Z,1571244434.999 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.715385 min 2019-10-16T16:47:14.999Z,1571244434.999 [Default:CheckIn:E] Stopped 2019-10-16T16:47:14.999Z,1571244434.999 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-16T16:47:14.999Z,1571244434.999 [Default:CheckIn] Stopped 2019-10-16T16:47:14.999Z,1571244434.999 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-16T16:47:14.999Z,1571244434.999 [Default:CheckIn](INFO): Running loop #7 2019-10-16T16:47:14.999Z,1571244434.999 [Default:CheckIn] Running Loop=7 2019-10-16T16:47:14.000Z,1571244435.000 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-16T16:47:14.000Z,1571244435.000 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-16T16:47:16.578Z,1571244436.578 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:47:16.970Z,1571244436.970 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164717.00,A,3648.50056,N,12147.23449,W,18.836,238.40,161019,,,A*4F 2019-10-16T16:47:16.972Z,1571244436.972 [NAL9602](INFO): GPS fix at 20191016T164717: (36.808343, -121.787241) 2019-10-16T16:47:17.034Z,1571244437.034 [Default:CheckIn:Read_GPS] Stopped 2019-10-16T16:47:17.034Z,1571244437.034 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-16T16:47:21.107Z,1571244441.107 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20191016T155459/Courier0025.lzma 2019-10-16T16:47:23.116Z,1571244443.116 [DataOverHttps](INFO): Moved sent file to Logs/20191016T155459/Courier0025.lzma.bak 2019-10-16T16:47:23.116Z,1571244443.116 [DataOverHttps](INFO): SBD MOMSN=11916270 2019-10-16T16:47:28.810Z,1571244448.810 [NAL9602](INFO): SBD MO Status=0, MOMSN=9432, MT Status=0, MTMSN=0 2019-10-16T16:47:28.810Z,1571244448.810 [NAL9602](INFO): No messages in MT queue 2019-10-16T16:47:39.745Z,1571244459.745 [CommandLine](IMPORTANT): got command get BPC1.platform_battery_voltage 2019-10-16T16:47:39.746Z,1571244459.746 [CommandLine](IMPORTANT): BPC1.platform_battery_voltage 15.111911 V 2019-10-16T16:47:50.791Z,1571244470.791 [DataOverHttps](INFO): Sending 670 bytes from file Logs/20191016T155459/Express0026.lzma 2019-10-16T16:47:52.796Z,1571244472.796 [DataOverHttps](INFO): Moved sent file to Logs/20191016T155459/Express0026.lzma.bak 2019-10-16T16:47:52.796Z,1571244472.796 [DataOverHttps](INFO): SBD MOMSN=11916278 2019-10-16T16:47:59.208Z,1571244479.208 [Default:CheckIn:Read_Iridium] Stopped 2019-10-16T16:47:59.208Z,1571244479.208 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-16T16:47:59.208Z,1571244479.208 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-16T16:47:59.513Z,1571244479.513 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-16T16:50:46.383Z,1571244646.383 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-10-16T16:50:46.383Z,1571244646.383 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19101610021771,35.0, -0.1, 0.0,1448:RA, 0.00, 0.00, 0.00, 0.00, 0.00 2019-10-16T16:51:02.588Z,1571244662.588 [RDI_Pathfinder](ERROR): Failed to parse: :SA, +0.00, +0.00, 0.00 2019-10-16T16:52:59.718Z,1571244779.718 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-16T16:52:59.718Z,1571244779.718 [Default:CheckIn:C.Wait] Stopped 2019-10-16T16:52:59.718Z,1571244779.718 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-16T16:52:59.718Z,1571244779.718 [Default:CheckIn:D] Running Loop=1 2019-10-16T16:53:00.130Z,1571244780.130 [Default:CheckIn:D] Stopped 2019-10-16T16:53:00.130Z,1571244780.130 [Default:CheckIn:E] Running Loop=1 2019-10-16T16:53:00.557Z,1571244780.557 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 54.473954 min 2019-10-16T16:53:00.557Z,1571244780.557 [Default:CheckIn:E] Stopped 2019-10-16T16:53:00.557Z,1571244780.557 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-16T16:53:00.557Z,1571244780.557 [Default:CheckIn] Stopped 2019-10-16T16:53:00.557Z,1571244780.557 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-16T16:53:00.558Z,1571244780.558 [Default:CheckIn](INFO): Running loop #8 2019-10-16T16:53:00.558Z,1571244780.558 [Default:CheckIn] Running Loop=8 2019-10-16T16:53:00.558Z,1571244780.558 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-16T16:53:00.558Z,1571244780.558 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-16T16:53:02.122Z,1571244782.122 [NAL9602](DEBUG): Fix Requested 2019-10-16T16:53:02.544Z,1571244782.544 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165302.00,A,3648.82184,N,12149.24341,W,1.205,245.10,161019,,,A*74 2019-10-16T16:53:02.551Z,1571244782.551 [NAL9602](INFO): GPS fix at 20191016T165302: (36.813697, -121.820723) 2019-10-16T16:53:02.641Z,1571244782.641 [Default:CheckIn:Read_GPS] Stopped 2019-10-16T16:53:02.641Z,1571244782.641 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-16T16:53:15.198Z,1571244795.198 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20191016T155459/Courier0028.lzma 2019-10-16T16:53:17.204Z,1571244797.204 [DataOverHttps](INFO): Moved sent file to Logs/20191016T155459/Courier0028.lzma.bak 2019-10-16T16:53:17.204Z,1571244797.204 [DataOverHttps](INFO): SBD MOMSN=11916354 2019-10-16T16:53:26.030Z,1571244806.030 [NAL9602](INFO): SBD MO Status=2, MOMSN=9433, MT Status=2, MTMSN=0 2019-10-16T16:53:26.030Z,1571244806.030 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-16T16:53:43.534Z,1571244823.534 [DataOverHttps](INFO): Sending 200 bytes from file Logs/20191016T155459/Express0029.lzma 2019-10-16T16:53:45.540Z,1571244825.540 [DataOverHttps](INFO): Moved sent file to Logs/20191016T155459/Express0029.lzma.bak 2019-10-16T16:53:45.540Z,1571244825.540 [DataOverHttps](INFO): SBD MOMSN=11916362 2019-10-16T16:53:49.535Z,1571244829.535 [NAL9602](INFO): SBD MO Status=2, MOMSN=9433, MT Status=2, MTMSN=0 2019-10-16T16:53:49.535Z,1571244829.535 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-16T16:53:52.382Z,1571244832.382 [Default:CheckIn:Read_Iridium] Stopped 2019-10-16T16:53:52.382Z,1571244832.382 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-16T16:53:52.382Z,1571244832.382 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-16T16:54:04.882Z,1571244844.882 [NAL9602](INFO): SBD MO Status=2, MOMSN=9433, MT Status=2, MTMSN=0 2019-10-16T16:54:04.882Z,1571244844.882 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-16T16:54:08.545Z,1571244848.545 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-10-16T16:54:08.545Z,1571244848.545 [RDI_Pathfinder](ERROR): Failed to parse: :TS,1.0, -0.1, 0.0,1448.9, 0 2019-10-16T16:54:34.772Z,1571244874.772 [NAL9602](INFO): SBD MO Status=2, MOMSN=9433, MT Status=2, MTMSN=0 2019-10-16T16:54:34.772Z,1571244874.772 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-16T16:54:53.773Z,1571244893.773 [NAL9602](INFO): SBD MO Status=0, MOMSN=9433, MT Status=0, MTMSN=0 2019-10-16T16:54:53.773Z,1571244893.773 [NAL9602](INFO): No messages in MT queue 2019-10-16T16:55:21.664Z,1571244921.664 [RDI_Pathfinder](ERROR): Failed to parse: :BI, +25, +105, -139,-32768,A 2019-10-16T16:55:24.466Z,1571244924.466 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-16T16:55:27.163Z,1571244927.163 [DataOverHttps](IMPORTANT): SBD MTMSN=20191016T165526 2019-10-16T16:55:35.070Z,1571244935.070 [DataOverHttps](INFO): Received command:restart logs