2020-01-25T22:18:53.531Z,1579990733.531 [Supervisor](DEBUG): Initializing supervisor.
2020-01-25T22:18:53.534Z,1579990733.534 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-01-25T22:18:53.534Z,1579990733.534 [SyncHandler](INFO): Protected caller Thread ID is 3251
2020-01-25T22:18:53.535Z,1579990733.535 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-01-25T22:18:53.536Z,1579990733.536 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-01-25T22:18:53.536Z,1579990733.536 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 3252
2020-01-25T22:18:53.538Z,1579990733.538 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-01-25T22:18:53.550Z,1579990733.550 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-01-25T22:18:53.551Z,1579990733.551 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-01-25T22:18:53.552Z,1579990733.552 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 3253
2020-01-25T22:18:53.552Z,1579990733.552 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-01-25T22:18:53.553Z,1579990733.553 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-01-25T22:18:53.554Z,1579990733.554 [logger ThreadHandler](INFO): Protected caller Thread ID is 3254
2020-01-25T22:18:53.555Z,1579990733.555 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-01-25T22:18:53.556Z,1579990733.556 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-01-25T22:18:53.557Z,1579990733.557 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-01-25T22:18:53.988Z,1579990733.988 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-01-25T22:18:53.988Z,1579990733.988 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-01-25T22:18:54.085Z,1579990734.085 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-01-25T22:18:54.086Z,1579990734.086 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-01-25T22:18:54.396Z,1579990734.396 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-01-25T22:18:54.397Z,1579990734.397 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-01-25T22:18:54.533Z,1579990734.533 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-01-25T22:18:54.534Z,1579990734.534 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-01-25T22:18:54.723Z,1579990734.723 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-01-25T22:18:54.724Z,1579990734.724 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-01-25T22:18:55.512Z,1579990735.512 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-01-25T22:18:55.512Z,1579990735.512 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-01-25T22:18:55.720Z,1579990735.720 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-01-25T22:18:55.721Z,1579990735.721 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-01-25T22:18:55.863Z,1579990735.863 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-01-25T22:18:55.863Z,1579990735.863 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-01-25T22:18:56.052Z,1579990736.052 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-01-25T22:18:56.052Z,1579990736.052 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-01-25T22:18:56.147Z,1579990736.147 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-01-25T22:18:56.148Z,1579990736.148 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-01-25T22:18:56.450Z,1579990736.450 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-01-25T22:18:56.450Z,1579990736.450 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-01-25T22:18:56.530Z,1579990736.530 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-01-25T22:18:56.632Z,1579990736.632 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-01-25T22:18:56.632Z,1579990736.632 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-01-25T22:18:57.262Z,1579990737.262 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-01-25T22:18:57.262Z,1579990737.262 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-01-25T22:18:57.666Z,1579990737.666 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-01-25T22:18:57.668Z,1579990737.668 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2020-01-25T22:18:57.668Z,1579990737.668 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2020-01-25T22:18:57.878Z,1579990737.878 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2020-01-25T22:18:57.978Z,1579990737.978 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2020-01-25T22:18:58.077Z,1579990738.077 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2020-01-25T22:18:58.302Z,1579990738.302 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-01-25T22:18:58.302Z,1579990738.302 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2020-01-25T22:18:58.387Z,1579990738.387 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2020-01-25T22:18:58.479Z,1579990738.479 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2020-01-25T22:18:58.575Z,1579990738.575 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2020-01-25T22:18:58.657Z,1579990738.657 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2020-01-25T22:18:58.764Z,1579990738.764 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/workSite.cfg
2020-01-25T22:18:58.856Z,1579990738.856 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2020-01-25T22:18:59.038Z,1579990739.038 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2020-01-25T22:18:59.166Z,1579990739.166 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-01-25T22:18:59.174Z,1579990739.174 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-01-25T22:18:59.473Z,1579990739.473 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-01-25T22:18:59.478Z,1579990739.478 [AHRS_M2](INFO): created writer for : platform_orientation
2020-01-25T22:18:59.480Z,1579990739.480 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-01-25T22:18:59.484Z,1579990739.484 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-01-25T22:18:59.485Z,1579990739.485 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-01-25T22:18:59.490Z,1579990739.490 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-01-25T22:18:59.490Z,1579990739.490 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-01-25T22:18:59.495Z,1579990739.495 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-01-25T22:18:59.562Z,1579990739.562 [AHRS_M2] Loaded
2020-01-25T22:18:59.562Z,1579990739.562 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-01-25T22:18:59.640Z,1579990739.640 [DataOverHttps] Loaded
2020-01-25T22:18:59.641Z,1579990739.641 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-01-25T22:18:59.642Z,1579990739.642 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407684E0
2020-01-25T22:18:59.642Z,1579990739.642 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 3336
2020-01-25T22:18:59.665Z,1579990739.665 [DDM] Loaded
2020-01-25T22:18:59.665Z,1579990739.665 [ComponentRegistry](DEBUG): SyncComponent "DDM" handled in the control thread.
2020-01-25T22:18:59.677Z,1579990739.677 [Depth_Keller] Loaded
2020-01-25T22:18:59.678Z,1579990739.678 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-01-25T22:18:59.736Z,1579990739.736 [DUSBL_Hydroid] Loaded
2020-01-25T22:18:59.736Z,1579990739.736 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2020-01-25T22:18:59.780Z,1579990739.780 [Micromodem] Loaded
2020-01-25T22:18:59.780Z,1579990739.780 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2020-01-25T22:18:59.872Z,1579990739.872 [NAL9602] Loaded
2020-01-25T22:18:59.873Z,1579990739.873 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-01-25T22:18:59.910Z,1579990739.910 [Onboard] Loaded
2020-01-25T22:18:59.910Z,1579990739.910 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2020-01-25T22:18:59.916Z,1579990739.916 [PowerOnly] Loaded
2020-01-25T22:18:59.916Z,1579990739.916 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2020-01-25T22:18:59.922Z,1579990739.922 [Radio_Surface] Loaded
2020-01-25T22:18:59.922Z,1579990739.922 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-01-25T22:18:59.923Z,1579990739.923 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407984E0
2020-01-25T22:18:59.924Z,1579990739.924 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 3337
2020-01-25T22:18:59.965Z,1579990739.965 [RDI_Pathfinder] Loaded
2020-01-25T22:18:59.965Z,1579990739.965 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2020-01-25T22:19:01.374Z,1579990741.374 [BPC1] Loaded
2020-01-25T22:19:01.374Z,1579990741.374 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-01-25T22:19:01.375Z,1579990741.375 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-01-25T22:19:01.375Z,1579990741.375 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-01-25T22:19:01.469Z,1579990741.469 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-01-25T22:19:01.469Z,1579990741.469 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-01-25T22:19:01.916Z,1579990741.916 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-01-25T22:19:01.917Z,1579990741.917 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-01-25T22:19:02.082Z,1579990742.082 [NavChart] Loaded
2020-01-25T22:19:02.083Z,1579990742.083 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-01-25T22:19:02.087Z,1579990742.087 [UniversalFixResidualReporter] Loaded
2020-01-25T22:19:02.087Z,1579990742.087 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-01-25T22:19:02.087Z,1579990742.087 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-01-25T22:19:02.088Z,1579990742.088 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-01-25T22:19:02.507Z,1579990742.507 [BuoyancyServo] Loaded
2020-01-25T22:19:02.507Z,1579990742.507 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-01-25T22:19:02.521Z,1579990742.521 [ElevatorServo] Loaded
2020-01-25T22:19:02.522Z,1579990742.522 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-01-25T22:19:02.536Z,1579990742.536 [MassServo] Loaded
2020-01-25T22:19:02.536Z,1579990742.536 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-01-25T22:19:02.550Z,1579990742.550 [RudderServo] Loaded
2020-01-25T22:19:02.551Z,1579990742.551 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-01-25T22:19:02.565Z,1579990742.565 [ThrusterServo] Loaded
2020-01-25T22:19:02.565Z,1579990742.565 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-01-25T22:19:02.565Z,1579990742.565 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-01-25T22:19:02.566Z,1579990742.566 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-01-25T22:19:02.749Z,1579990742.749 [PAR_Licor] Loaded
2020-01-25T22:19:02.750Z,1579990742.750 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-01-25T22:19:02.792Z,1579990742.792 [WetLabsSeaOWL_UV_A] Loaded
2020-01-25T22:19:02.792Z,1579990742.792 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2020-01-25T22:19:02.793Z,1579990742.793 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 408EC4E0
2020-01-25T22:19:02.793Z,1579990742.793 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 3338
2020-01-25T22:19:02.794Z,1579990742.794 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-01-25T22:19:02.794Z,1579990742.794 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-01-25T22:19:03.118Z,1579990743.118 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-01-25T22:19:03.118Z,1579990743.118 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-01-25T22:19:03.157Z,1579990743.157 [DepthRateCalculator] Loaded
2020-01-25T22:19:03.157Z,1579990743.157 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-01-25T22:19:03.163Z,1579990743.163 [PitchRateCalculator] Loaded
2020-01-25T22:19:03.163Z,1579990743.163 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-01-25T22:19:03.175Z,1579990743.175 [SpeedCalculator] Loaded
2020-01-25T22:19:03.175Z,1579990743.175 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-01-25T22:19:03.195Z,1579990743.195 [TempGradientCalculator] Loaded
2020-01-25T22:19:03.195Z,1579990743.195 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-01-25T22:19:03.200Z,1579990743.200 [YawRateCalculator] Loaded
2020-01-25T22:19:03.201Z,1579990743.201 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-01-25T22:19:03.239Z,1579990743.239 [ElevatorOffsetCalculator] Loaded
2020-01-25T22:19:03.239Z,1579990743.239 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-01-25T22:19:03.240Z,1579990743.240 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-01-25T22:19:03.240Z,1579990743.240 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-01-25T22:19:03.372Z,1579990743.372 [SBIT](DEBUG): Construct Startup Built In Test.
2020-01-25T22:19:03.393Z,1579990743.393 [SBIT] Loaded
2020-01-25T22:19:03.393Z,1579990743.393 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-01-25T22:19:03.394Z,1579990743.394 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-01-25T22:19:03.406Z,1579990743.406 [IBIT] Loaded
2020-01-25T22:19:03.406Z,1579990743.406 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-01-25T22:19:03.409Z,1579990743.409 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-01-25T22:19:03.540Z,1579990743.540 [CBIT] Loaded
2020-01-25T22:19:03.541Z,1579990743.541 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-01-25T22:19:03.541Z,1579990743.541 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-01-25T22:19:03.542Z,1579990743.542 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-01-25T22:19:03.619Z,1579990743.619 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-01-25T22:19:03.620Z,1579990743.620 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-01-25T22:19:03.713Z,1579990743.713 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-01-25T22:19:03.714Z,1579990743.714 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-01-25T22:19:03.760Z,1579990743.760 [VerticalControl](DEBUG): Construct VerticalControl.
2020-01-25T22:19:03.838Z,1579990743.838 [VerticalControl] Loaded
2020-01-25T22:19:03.839Z,1579990743.839 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-01-25T22:19:03.840Z,1579990743.840 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-01-25T22:19:03.906Z,1579990743.906 [HorizontalControl] Loaded
2020-01-25T22:19:03.906Z,1579990743.906 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-01-25T22:19:03.907Z,1579990743.907 [SpeedControl](DEBUG): Construct SpeedControl.
2020-01-25T22:19:03.909Z,1579990743.909 [SpeedControl] Loaded
2020-01-25T22:19:03.909Z,1579990743.909 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-01-25T22:19:03.909Z,1579990743.909 [LoopControl](DEBUG): Construct LoopControl.
2020-01-25T22:19:03.910Z,1579990743.910 [LoopControl] Loaded
2020-01-25T22:19:03.910Z,1579990743.910 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-01-25T22:19:03.911Z,1579990743.911 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-01-25T22:19:03.911Z,1579990743.911 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-01-25T22:19:03.942Z,1579990743.942 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-01-25T22:19:03.945Z,1579990743.945 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-01-25T22:19:03.946Z,1579990743.946 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-01-25T22:19:03.953Z,1579990743.953 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-01-25T22:19:03.954Z,1579990743.954 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40ACC4E0
2020-01-25T22:19:03.954Z,1579990743.954 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 3339
2020-01-25T22:19:03.958Z,1579990743.958 [Supervisor](INFO): Main Thread ID is 816
2020-01-25T22:19:03.959Z,1579990743.959 [Supervisor](DEBUG): Running supervisor.
2020-01-25T22:19:03.959Z,1579990743.959 [CommandLine ThreadHandler](INFO): Handler Thread ID is 3340
2020-01-25T22:19:03.961Z,1579990743.961 [controlThread ThreadHandler](INFO): Handler Thread ID is 3341
2020-01-25T22:19:03.962Z,1579990743.962 [controlThread](DEBUG): Initializing ControlThread
2020-01-25T22:19:03.968Z,1579990743.968 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-01-25T22:19:03.969Z,1579990743.969 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-01-25T22:19:03.974Z,1579990743.974 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-01-25T22:19:03.974Z,1579990743.974 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-01-25T22:19:03.975Z,1579990743.975 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-01-25T22:19:03.975Z,1579990743.975 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-01-25T22:19:03.975Z,1579990743.975 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-01-25T22:19:03.976Z,1579990743.976 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-01-25T22:19:03.976Z,1579990743.976 [SBIT](INFO): Initialize SBIT Component.
2020-01-25T22:19:03.977Z,1579990743.977 [SBIT](IMPORTANT): git: 2020-01-24-A
2020-01-25T22:19:03.977Z,1579990743.977 [SBIT](INFO): git hash: 637c65bcbd6d0880dfbd56c4760c0ba5e48e98aa
2020-01-25T22:19:03.977Z,1579990743.977 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-01-25T22:19:03.978Z,1579990743.978 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Nov 13 12:38:10 PST 2019
2020-01-25T22:19:03.979Z,1579990743.979 [SBIT](INFO): Beginning SBIT in 39.000000 seconds.
2020-01-25T22:19:03.980Z,1579990743.980 [IBIT](INFO): Initialize IBIT Component.
2020-01-25T22:19:03.981Z,1579990743.981 [CBIT](DEBUG): Initialize CBIT Component.
2020-01-25T22:19:03.982Z,1579990743.982 [logger ThreadHandler](INFO): Handler Thread ID is 3342
2020-01-25T22:19:03.994Z,1579990743.994 [CBIT](DEBUG): Initialized mux pins.
2020-01-25T22:19:03.994Z,1579990743.994 [CBIT](DEBUG): Initializing the watchdog timer.
2020-01-25T22:19:04.002Z,1579990744.002 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 3343
2020-01-25T22:19:04.003Z,1579990744.003 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-01-25T22:19:04.014Z,1579990744.014 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 3344
2020-01-25T22:19:04.018Z,1579990744.018 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-01-25T22:19:04.018Z,1579990744.018 [CBIT](DEBUG): Initializing heartbeat.
2020-01-25T22:19:04.026Z,1579990744.026 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 3345
2020-01-25T22:19:04.027Z,1579990744.027 [WetLabsSeaOWL_UV_A](INFO): Powering down
2020-01-25T22:19:04.054Z,1579990744.054 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 3346
2020-01-25T22:19:04.057Z,1579990744.057 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-01-25T22:19:04.057Z,1579990744.057 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-01-25T22:19:04.058Z,1579990744.058 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-01-25T22:19:04.058Z,1579990744.058 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-01-25T22:19:04.059Z,1579990744.059 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-01-25T22:19:04.059Z,1579990744.059 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-01-25T22:19:04.059Z,1579990744.059 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-01-25T22:19:04.059Z,1579990744.059 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-01-25T22:19:04.059Z,1579990744.059 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-01-25T22:19:04.059Z,1579990744.059 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-01-25T22:19:04.060Z,1579990744.060 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-01-25T22:19:04.060Z,1579990744.060 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-01-25T22:19:04.060Z,1579990744.060 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-01-25T22:19:04.060Z,1579990744.060 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-01-25T22:19:04.060Z,1579990744.060 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-01-25T22:19:04.060Z,1579990744.060 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-01-25T22:19:04.090Z,1579990744.090 [CBIT](DEBUG): Deactivating GF circuits.
2020-01-25T22:19:04.090Z,1579990744.090 [CBIT](DEBUG): Deactivating emergency mode.
2020-01-25T22:19:04.126Z,1579990744.126 [CBIT](DEBUG): Backplane powered.
2020-01-25T22:19:04.126Z,1579990744.126 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-01-25T22:19:04.128Z,1579990744.128 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-01-25T22:19:04.128Z,1579990744.128 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-01-25T22:19:04.129Z,1579990744.129 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-01-25T22:19:04.130Z,1579990744.130 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-01-25T22:19:04.139Z,1579990744.139 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-01-25T22:19:04.158Z,1579990744.158 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2020-01-25T22:19:04.159Z,1579990744.159 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-01-25T22:19:04.216Z,1579990744.216 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-01-25T22:19:04.217Z,1579990744.217 [Default:A.Wait](DEBUG): Construct Wait.
2020-01-25T22:19:04.235Z,1579990744.235 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-01-25T22:19:04.257Z,1579990744.257 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-01-25T22:19:04.276Z,1579990744.276 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-01-25T22:19:04.281Z,1579990744.281 [Default:E.Execute](DEBUG): Construct Execute.
2020-01-25T22:19:04.296Z,1579990744.296 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn on</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2020-01-25T22:19:04.306Z,1579990744.306 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,DDM,Depth_Keller,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,
2020-01-25T22:19:04.326Z,1579990744.326 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-01-25T22:19:04.358Z,1579990744.358 [DDM](INFO): Powering up
2020-01-25T22:19:04.358Z,1579990744.358 [DDM](DEBUG): Initializing DDM.
2020-01-25T22:19:04.384Z,1579990744.384 [DUSBL_Hydroid](INFO): Powering up
2020-01-25T22:19:04.384Z,1579990744.384 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2020-01-25T22:19:04.418Z,1579990744.418 [Radio_Surface](INFO): Powering up
2020-01-25T22:19:04.559Z,1579990744.559 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-01-25T22:19:04.566Z,1579990744.566 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-01-25T22:19:04.567Z,1579990744.567 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-01-25T22:19:04.574Z,1579990744.574 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-01-25T22:19:04.575Z,1579990744.575 [MassServo](DEBUG): Initializing EZServoServo.
2020-01-25T22:19:04.582Z,1579990744.582 [MassServo](DEBUG): Initializing MassServo.
2020-01-25T22:19:04.583Z,1579990744.583 [RudderServo](DEBUG): Initializing EZServoServo.
2020-01-25T22:19:04.590Z,1579990744.590 [RudderServo](DEBUG): Initializing RudderServo.
2020-01-25T22:19:04.591Z,1579990744.591 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-01-25T22:19:04.598Z,1579990744.598 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-01-25T22:19:04.824Z,1579990744.824 [Micromodem](INFO): Powering up
2020-01-25T22:19:04.825Z,1579990744.825 [Micromodem](DEBUG): Initializing Micromodem.
2020-01-25T22:19:05.490Z,1579990745.490 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2020-01-25T22:19:05.490Z,1579990745.490 [RudderServo](FAULT): Rudder failed to initialize
2020-01-25T22:19:05.490Z,1579990745.490 [RudderServo] Communications Fault, FailCount= 1
2020-01-25T22:19:05.490Z,1579990745.490 [RudderServo](ERROR): Communications Fault
2020-01-25T22:19:05.601Z,1579990745.601 [CBIT](ERROR): Communications Fault in component: RudderServo
2020-01-25T22:19:05.807Z,1579990745.807 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-01-25T22:19:05.807Z,1579990745.807 [RudderServo](INFO): Powering down
2020-01-25T22:19:06.460Z,1579990746.460 [RudderServo](DEBUG): Initializing EZServoServo.
2020-01-25T22:19:06.579Z,1579990746.579 [RudderServo](DEBUG): Initializing RudderServo.
2020-01-25T22:19:06.583Z,1579990746.583 [CBIT](INFO): Clearing failed state for component RudderServo
2020-01-25T22:19:06.583Z,1579990746.583 [RudderServo] No Fault, FailCount= 1
2020-01-25T22:19:09.688Z,1579990749.688 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2020-01-25T22:19:13.712Z,1579990753.712 [Micromodem](INFO): Nmea in: $CATMG,2020-01-25T22:19:12.940020Z,RTC,RTC*52

2020-01-25T22:19:13.713Z,1579990753.713 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2020-01-25T22:19:12.940020Z,RTC,RTC*52

2020-01-25T22:19:14.915Z,1579990754.915 [DDM](INFO): Dynamic Docking Module:
2020-01-25T22:19:17.761Z,1579990757.761 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2020-01-25T22:19:20.967Z,1579990760.967 [Micromodem](ERROR): Nmea resend: $CCCFG,ALL,0*33

2020-01-25T22:19:21.372Z,1579990761.372 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31

2020-01-25T22:19:21.373Z,1579990761.373 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31

2020-01-25T22:19:21.777Z,1579990761.777 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33

2020-01-25T22:19:21.777Z,1579990761.777 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64

2020-01-25T22:19:22.180Z,1579990762.180 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66

2020-01-25T22:19:22.180Z,1579990762.180 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F

2020-01-25T22:19:22.583Z,1579990762.583 [DUSBL_Hydroid](INFO): DUSBL Version:O
2020-01-25T22:19:23.392Z,1579990763.392 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D

2020-01-25T22:19:23.392Z,1579990763.392 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E

2020-01-25T22:19:23.795Z,1579990763.795 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C

2020-01-25T22:19:23.796Z,1579990763.796 [Micromodem](INFO): Nmea out: $CCCFG,FC0,10000*46

2020-01-25T22:19:24.199Z,1579990764.199 [Micromodem](INFO): Nmea in: $CACFG,FC0,10000*44

2020-01-25T22:19:24.200Z,1579990764.200 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63

2020-01-25T22:19:24.604Z,1579990764.604 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61

2020-01-25T22:19:24.604Z,1579990764.604 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A

2020-01-25T22:19:25.007Z,1579990765.007 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38

2020-01-25T22:19:25.008Z,1579990765.008 [Micromodem](INFO): Nmea out: $CCCLK,2020,01,25,22,19,26*4E

2020-01-25T22:19:25.412Z,1579990765.412 [Micromodem](INFO): Nmea in: $CACLK,2020,1,25,22,19,26*7C

2020-01-25T22:19:26.216Z,1579990766.216 [Micromodem](INFO): Nmea in: $CATMS,0,2020-01-25T22:19:27Z*7D

2020-01-25T22:19:26.255Z,1579990766.255 [Micromodem](INFO): Nmea in: $CATMG,2020-01-25T22:19:27.028721Z,USER_CMD,RTC*14

2020-01-25T22:19:30.256Z,1579990770.256 [NAL9602](INFO): Powering up NAL9602
2020-01-25T22:19:36.780Z,1579990776.780 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-01-25T22:19:36.780Z,1579990776.780 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00, 338.45, 313.02, 317.51
2020-01-25T22:19:41.164Z,1579990781.164 [NAL9602](INFO): NAL9602 initialized
2020-01-25T22:19:43.652Z,1579990783.652 [SBIT](IMPORTANT): Beginning Startup BIT
2020-01-25T22:19:43.660Z,1579990783.660 [CBIT](IMPORTANT): Beginning ground fault scan
2020-01-25T22:19:54.853Z,1579990794.853 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.009006
CHAN A1 (24V): -0.028264
CHAN A2 (12V): -0.007142
CHAN A3 (5V): -0.002422
CHAN B0 (3.3V): 0.000611
CHAN B1 (3.15aV): -0.000104
CHAN B2 (3.15bV): 0.000236
CHAN B3 (GND): 0.002239
OPEN: 0.006048
Full Scale Calc: 4.765 mA, -1.589 mA
2020-01-25T22:20:10.948Z,1579990810.948 [NAL9602](INFO): SBD MO Status=2, MOMSN=10280, MT Status=2, MTMSN=0
2020-01-25T22:20:10.948Z,1579990810.948 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-01-25T22:20:21.853Z,1579990821.853 [NAL9602](INFO): SBD MO Status=0, MOMSN=10280, MT Status=0, MTMSN=0
2020-01-25T22:20:21.854Z,1579990821.854 [NAL9602](INFO): No messages in MT queue
2020-01-25T22:20:36.125Z,1579990836.125 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00, 359.43, 292.06, 317.51,   0.00
2020-01-25T22:20:37.797Z,1579990837.797 [SBIT](IMPORTANT): SBIT PASSED
2020-01-25T22:20:37.797Z,1579990837.797 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-01-25T22:20:37.798Z,1579990837.798 [SBIT](IMPORTANT): DUSBL_Hydroid.detectionThreshold=75 count;

2020-01-25T22:20:37.798Z,1579990837.798 [SBIT](IMPORTANT): DUSBL_Hydroid.verbosity=3 enum;

2020-01-25T22:20:37.798Z,1579990837.798 [SBIT](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2020-01-25T22:20:37.799Z,1579990837.799 [SBIT](IMPORTANT): Express none DDM.cablePresent;

2020-01-25T22:20:37.799Z,1579990837.799 [SBIT](IMPORTANT): Express linearApproximation acoustic_contact_range 10.000000 meter;

2020-01-25T22:20:37.799Z,1579990837.799 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=105 cubic_centimeter;

2020-01-25T22:20:37.799Z,1579990837.799 [SBIT](IMPORTANT): VerticalControl.massDefault=0.5 centimeter;

2020-01-25T22:20:38.240Z,1579990838.240 [MissionManager](IMPORTANT): Started mission Startup
2020-01-25T22:20:38.241Z,1579990838.241 [Startup] Running Loop=1
2020-01-25T22:20:38.241Z,1579990838.241 [Startup](DEBUG): Aggregate::initialize Startup
2020-01-25T22:20:38.241Z,1579990838.241 [Startup:A.GoToSurface] Running Loop=1
2020-01-25T22:20:38.241Z,1579990838.241 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-01-25T22:20:38.241Z,1579990838.241 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-01-25T22:20:38.242Z,1579990838.242 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-01-25T22:20:38.242Z,1579990838.242 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-01-25T22:20:38.243Z,1579990838.243 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-01-25T22:20:38.243Z,1579990838.243 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-01-25T22:20:38.245Z,1579990838.245 [Startup:StartupSatComms] Running Loop=1
2020-01-25T22:20:38.245Z,1579990838.245 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-01-25T22:20:38.245Z,1579990838.245 [Startup:StartupSatComms:A] Running Loop=1
2020-01-25T22:20:38.586Z,1579990838.586 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-01-25T22:21:35.098Z,1579990895.098 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222125.00,A,3648.48541,N,12148.56924,W,0.700,104.92,250120,,,A*72
2020-01-25T22:21:35.101Z,1579990895.101 [NAL9602](INFO): GPS fix at 20200125T222125: (36.808090, -121.809487)
2020-01-25T22:21:35.168Z,1579990895.168 [Startup:StartupSatComms:A] Stopped
2020-01-25T22:21:35.168Z,1579990895.168 [Startup:StartupSatComms:B] Running Loop=1
2020-01-25T22:21:35.550Z,1579990895.550 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-01-25T22:22:07.420Z,1579990927.420 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-25T22:22:29.908Z,1579990949.908 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004878
2020-01-25T22:22:35.367Z,1579990955.367 [Startup:StartupSatComms:B](INFO): Timed out from 2020-01-25T22:21:35.2Z
2020-01-25T22:22:35.367Z,1579990955.367 [Startup:StartupSatComms:B] Stopped
2020-01-25T22:22:35.367Z,1579990955.367 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-01-25T22:22:35.367Z,1579990955.367 [Startup:StartupSatComms] Stopped
2020-01-25T22:22:35.368Z,1579990955.368 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-01-25T22:22:35.368Z,1579990955.368 [Startup](INFO): Completed Startup
2020-01-25T22:22:35.368Z,1579990955.368 [MissionManager](INFO): Startup is completed.
2020-01-25T22:22:35.369Z,1579990955.369 [MissionManager](INFO): Uninitializing Mission Startup
2020-01-25T22:22:35.369Z,1579990955.369 [Startup] Stopped
2020-01-25T22:22:35.369Z,1579990955.369 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-01-25T22:22:35.369Z,1579990955.369 [Startup:A.GoToSurface] Stopped
2020-01-25T22:22:35.369Z,1579990955.369 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-01-25T22:22:35.792Z,1579990955.792 [MissionManager](IMPORTANT): Started mission Default
2020-01-25T22:22:35.793Z,1579990955.793 [Default] Running Loop=1
2020-01-25T22:22:35.793Z,1579990955.793 [Default](DEBUG): Aggregate::initialize Default
2020-01-25T22:22:35.793Z,1579990955.793 [Default:B.GoToSurface] Running Loop=1
2020-01-25T22:22:35.793Z,1579990955.793 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-01-25T22:22:35.793Z,1579990955.793 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-01-25T22:22:35.793Z,1579990955.793 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-01-25T22:22:35.798Z,1579990955.798 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-01-25T22:22:35.798Z,1579990955.798 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-01-25T22:22:35.799Z,1579990955.799 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-01-25T22:22:35.799Z,1579990955.799 [Default:A.Wait] Running Loop=1
2020-01-25T22:22:35.799Z,1579990955.799 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-01-25T22:22:40.417Z,1579990960.417 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200125T220733/Courier0009.lzma
2020-01-25T22:22:42.423Z,1579990962.423 [DataOverHttps](INFO): Moved sent file to Logs/20200125T220733/Courier0009.lzma.bak
2020-01-25T22:22:42.424Z,1579990962.424 [DataOverHttps](INFO): SBD MOMSN=12204092
2020-01-25T22:22:49.069Z,1579990969.069 [Default:A.Wait](INFO): Done Waiting.
2020-01-25T22:22:49.069Z,1579990969.069 [Default:A.Wait] Stopped
2020-01-25T22:22:49.069Z,1579990969.069 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-01-25T22:22:49.469Z,1579990969.469 [Default:CheckIn] Running Loop=1
2020-01-25T22:22:49.470Z,1579990969.470 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-25T22:22:49.470Z,1579990969.470 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-25T22:22:49.895Z,1579990969.895 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-01-25T22:22:51.457Z,1579990971.457 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222241.00,A,3648.47723,N,12148.56201,W,1.400,109.29,250120,,,A*79
2020-01-25T22:22:51.460Z,1579990971.460 [NAL9602](INFO): GPS fix at 20200125T222241: (36.807954, -121.809367)
2020-01-25T22:22:51.505Z,1579990971.505 [Default:CheckIn:Read_GPS] Stopped
2020-01-25T22:22:51.505Z,1579990971.505 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-25T22:22:51.949Z,1579990971.949 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-01-25T22:22:59.966Z,1579990979.966 [DataOverHttps](INFO): Sending 267 bytes from file Logs/20200125T221853/Courier0000.lzma
2020-01-25T22:23:01.972Z,1579990981.972 [DataOverHttps](INFO): Moved sent file to Logs/20200125T221853/Courier0000.lzma.bak
2020-01-25T22:23:01.973Z,1579990981.973 [DataOverHttps](INFO): SBD MOMSN=12204095
2020-01-25T22:23:10.144Z,1579990990.144 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-25T22:23:10.145Z,1579990990.145 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,20012515360683,35.0, -0.1,   09,  0
2020-01-25T22:23:25.553Z,1579991005.553 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20200125T221853/Courier0004.lzma
2020-01-25T22:23:27.559Z,1579991007.559 [DataOverHttps](INFO): Moved sent file to Logs/20200125T221853/Courier0004.lzma.bak
2020-01-25T22:23:27.560Z,1579991007.560 [DataOverHttps](INFO): SBD MOMSN=12204099
2020-01-25T22:23:28.293Z,1579991008.293 [NAL9602](INFO): SBD MO Status=2, MOMSN=10281, MT Status=2, MTMSN=0
2020-01-25T22:23:28.293Z,1579991008.293 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-01-25T22:23:45.257Z,1579991025.257 [NAL9602](INFO): SBD MO Status=2, MOMSN=10281, MT Status=2, MTMSN=0
2020-01-25T22:23:45.257Z,1579991025.257 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-01-25T22:23:53.014Z,1579991033.014 [DataOverHttps](INFO): Sending 122 bytes from file Logs/20200125T220733/Express0006.lzma
2020-01-25T22:23:55.019Z,1579991035.019 [DataOverHttps](INFO): Moved sent file to Logs/20200125T220733/Express0006.lzma.bak
2020-01-25T22:23:55.019Z,1579991035.019 [DataOverHttps](INFO): SBD MOMSN=12204085
2020-01-25T22:24:02.233Z,1579991042.233 [NAL9602](INFO): SBD MO Status=2, MOMSN=10281, MT Status=2, MTMSN=0
2020-01-25T22:24:02.233Z,1579991042.233 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-01-25T22:24:14.973Z,1579991054.973 [DataOverHttps](INFO): Sending 165 bytes from file Logs/20200125T220733/Express0010.lzma
2020-01-25T22:24:16.979Z,1579991056.979 [DataOverHttps](INFO): Moved sent file to Logs/20200125T220733/Express0010.lzma.bak
2020-01-25T22:24:16.979Z,1579991056.979 [DataOverHttps](INFO): SBD MOMSN=12204103
2020-01-25T22:24:20.405Z,1579991060.405 [NAL9602](INFO): SBD MO Status=2, MOMSN=10281, MT Status=2, MTMSN=0
2020-01-25T22:24:20.405Z,1579991060.405 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-01-25T22:24:32.140Z,1579991072.140 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-01-25T22:24:32.140Z,1579991072.140 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00, 317.51, 311.52, 317.51
2020-01-25T22:24:35.649Z,1579991075.649 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200125T220733/Express0013.lzma
2020-01-25T22:24:37.655Z,1579991077.655 [DataOverHttps](INFO): Moved sent file to Logs/20200125T220733/Express0013.lzma.bak
2020-01-25T22:24:37.655Z,1579991077.655 [DataOverHttps](INFO): SBD MOMSN=12204107
2020-01-25T22:24:44.245Z,1579991084.245 [NAL9602](INFO): SBD MO Status=0, MOMSN=10281, MT Status=0, MTMSN=0
2020-01-25T22:24:44.245Z,1579991084.245 [NAL9602](INFO): No messages in MT queue
2020-01-25T22:25:12.143Z,1579991112.143 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-25T22:25:12.143Z,1579991112.143 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,20012515380, -0.1,   0.0,1448.9,  0
2020-01-25T22:25:14.951Z,1579991114.951 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-25T22:25:24.348Z,1579991124.348 [DataOverHttps](INFO): Sending 860 bytes from file Logs/20200125T221853/Express0001.lzma
2020-01-25T22:25:25.347Z,1579991125.347 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting.
2020-01-25T22:25:34.111Z,1579991134.111 [DataOverHttps](INFO): Sending 860 bytes from file Logs/20200125T221853/Express0001.lzma
2020-01-25T22:25:39.128Z,1579991139.128 [DataOverHttps](INFO): Moved sent file to Logs/20200125T221853/Express0001.lzma.bak
2020-01-25T22:25:39.128Z,1579991139.128 [DataOverHttps](INFO): SBD MOMSN=12204109
2020-01-25T22:26:07.701Z,1579991167.701 [DataOverHttps](INFO): Sending 94 bytes from file Logs/20200125T221853/Express0005.lzma
2020-01-25T22:26:09.707Z,1579991169.707 [DataOverHttps](INFO): Moved sent file to Logs/20200125T221853/Express0005.lzma.bak
2020-01-25T22:26:09.707Z,1579991169.707 [DataOverHttps](INFO): SBD MOMSN=12204129
2020-01-25T22:26:11.142Z,1579991171.142 [Default:CheckIn:Read_Iridium] Stopped
2020-01-25T22:26:11.142Z,1579991171.142 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-25T22:26:11.142Z,1579991171.142 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-25T22:26:27.285Z,1579991187.285 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-01-25T22:26:27.289Z,1579991187.289 [BPC1](INFO): Received data from all battery sticks.
2020-01-25T22:27:13.771Z,1579991233.771 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-25T22:27:13.771Z,1579991233.771 [RDI_Pathfinder](ERROR): Failed to parse:
:TS5401083,35.0, -0.1,   0.0,1448.9,  0
2020-01-25T22:27:34.784Z,1579991254.784 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2020-01-25T22:27:34.784Z,1579991254.784 [RDI_Pathfinder](ERROR): Failed to parse:
:BD,      -47.51,     -      -5.54,  32.09,  0.00
2020-01-25T22:29:54.128Z,1579991394.128 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-25T22:29:54.128Z,1579991394.128 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,20012515420, -0.1,   0.0,1448.9,  0
2020-01-25T22:31:11.782Z,1579991471.782 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-01-25T22:31:11.783Z,1579991471.783 [Default:CheckIn:C.Wait] Stopped
2020-01-25T22:31:11.783Z,1579991471.783 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-25T22:31:11.783Z,1579991471.783 [Default:CheckIn:D] Running Loop=1
2020-01-25T22:31:12.133Z,1579991472.133 [Default:CheckIn:D] Stopped
2020-01-25T22:31:12.133Z,1579991472.133 [Default:CheckIn:E] Running Loop=1
2020-01-25T22:31:12.528Z,1579991472.528 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 8.605672 min 
2020-01-25T22:31:12.528Z,1579991472.528 [Default:CheckIn:E] Stopped
2020-01-25T22:31:12.528Z,1579991472.528 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-01-25T22:31:12.528Z,1579991472.528 [Default:CheckIn] Stopped
2020-01-25T22:31:12.528Z,1579991472.528 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-25T22:31:12.528Z,1579991472.528 [Default:CheckIn](INFO): Running loop #2
2020-01-25T22:31:12.528Z,1579991472.528 [Default:CheckIn] Running Loop=2
2020-01-25T22:31:12.528Z,1579991472.528 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-25T22:31:12.528Z,1579991472.528 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-25T22:31:14.521Z,1579991474.521 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223105.00,A,3648.42911,N,12148.50650,W,0.661,210.56,250120,,,A*70
2020-01-25T22:31:14.524Z,1579991474.524 [NAL9602](INFO): GPS fix at 20200125T223105: (36.807152, -121.808442)
2020-01-25T22:31:14.567Z,1579991474.567 [Default:CheckIn:Read_GPS] Stopped
2020-01-25T22:31:14.567Z,1579991474.567 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-25T22:31:22.513Z,1579991482.513 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20200125T221853/Courier0007.lzma
2020-01-25T22:31:24.519Z,1579991484.519 [DataOverHttps](INFO): Moved sent file to Logs/20200125T221853/Courier0007.lzma.bak
2020-01-25T22:31:24.519Z,1579991484.519 [DataOverHttps](INFO): SBD MOMSN=12204134
2020-01-25T22:31:35.148Z,1579991495.148 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-01-25T22:31:35.148Z,1579991495.148 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00, 362.43, 295.05, 317.51,

2020-01-25T22:31:39.161Z,1579991499.161 [NAL9602](INFO): SBD MO Status=2, MOMSN=10282, MT Status=2, MTMSN=0
2020-01-25T22:31:39.161Z,1579991499.161 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-01-25T22:31:41.953Z,1579991501.953 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20200125T221853/Express0008.lzma
2020-01-25T22:31:43.959Z,1579991503.959 [DataOverHttps](INFO): Moved sent file to Logs/20200125T221853/Express0008.lzma.bak
2020-01-25T22:31:43.959Z,1579991503.959 [DataOverHttps](INFO): SBD MOMSN=12204137
2020-01-25T22:31:45.258Z,1579991505.258 [Default:CheckIn:Read_Iridium] Stopped
2020-01-25T22:31:45.258Z,1579991505.258 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-25T22:31:45.258Z,1579991505.258 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-25T22:31:56.542Z,1579991516.542 [NAL9602](INFO): SBD MO Status=2, MOMSN=10282, MT Status=2, MTMSN=0
2020-01-25T22:31:56.542Z,1579991516.542 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-01-25T22:32:12.697Z,1579991532.697 [NAL9602](INFO): SBD MO Status=2, MOMSN=10282, MT Status=2, MTMSN=0
2020-01-25T22:32:12.697Z,1579991532.697 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-01-25T22:32:30.074Z,1579991550.074 [NAL9602](INFO): SBD MO Status=0, MOMSN=10282, MT Status=0, MTMSN=0
2020-01-25T22:32:30.074Z,1579991550.074 [NAL9602](INFO): No messages in MT queue
2020-01-25T22:32:35.771Z,1579991555.771 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-01-25T22:32:35.771Z,1579991555.771 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00, 363.92, 307.49, 330.99
2020-01-25T22:32:57.972Z,1579991577.972 [RDI_Pathfinder](ERROR): Failed to parse:
:SA,   +0.00,   +0.00,  0.00
2020-01-25T22:33:00.776Z,1579991580.776 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-25T22:34:57.136Z,1579991697.136 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-25T22:34:57.136Z,1579991697.136 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,20012515475383,35.0  0.0,1448.9,  0
2020-01-25T22:35:38.778Z,1579991738.778 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-01-25T22:35:38.779Z,1579991738.779 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00, 389.53, 342.80, 347.79
2020-01-25T22:35:57.798Z,1579991757.798 [RDI_Pathfinder](ERROR): Failed to parse:
:BE,  -164,  +140,  -419,A
2020-01-25T22:36:45.852Z,1579991805.852 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-01-25T22:36:45.852Z,1579991805.852 [Default:CheckIn:C.Wait] Stopped
2020-01-25T22:36:45.852Z,1579991805.852 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-25T22:36:45.852Z,1579991805.852 [Default:CheckIn:D] Running Loop=1
2020-01-25T22:36:46.244Z,1579991806.244 [Default:CheckIn:D] Stopped
2020-01-25T22:36:46.244Z,1579991806.244 [Default:CheckIn:E] Running Loop=1
2020-01-25T22:36:46.649Z,1579991806.649 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 14.174191 min 
2020-01-25T22:36:46.649Z,1579991806.649 [Default:CheckIn:E] Stopped
2020-01-25T22:36:46.649Z,1579991806.649 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-01-25T22:36:46.649Z,1579991806.649 [Default:CheckIn] Stopped
2020-01-25T22:36:46.649Z,1579991806.649 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-25T22:36:46.649Z,1579991806.649 [Default:CheckIn](INFO): Running loop #3
2020-01-25T22:36:46.649Z,1579991806.649 [Default:CheckIn] Running Loop=3
2020-01-25T22:36:46.649Z,1579991806.649 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-25T22:36:46.649Z,1579991806.649 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-25T22:36:48.638Z,1579991808.638 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223639.00,A,3648.40010,N,12148.46895,W,1.263,134.99,250120,,,D*76
2020-01-25T22:36:48.640Z,1579991808.640 [NAL9602](INFO): GPS fix at 20200125T223639: (36.806668, -121.807816)
2020-01-25T22:36:48.687Z,1579991808.687 [Default:CheckIn:Read_GPS] Stopped
2020-01-25T22:36:48.687Z,1579991808.687 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-25T22:36:56.829Z,1579991816.829 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200125T221853/Courier0010.lzma
2020-01-25T22:36:58.835Z,1579991818.835 [DataOverHttps](INFO): Moved sent file to Logs/20200125T221853/Courier0010.lzma.bak
2020-01-25T22:36:58.835Z,1579991818.835 [DataOverHttps](INFO): SBD MOMSN=12204142
2020-01-25T22:37:03.185Z,1579991823.185 [NAL9602](INFO): SBD MO Status=0, MOMSN=10283, MT Status=0, MTMSN=0
2020-01-25T22:37:03.185Z,1579991823.185 [NAL9602](INFO): No messages in MT queue
2020-01-25T22:37:16.269Z,1579991836.269 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20200125T221853/Express0011.lzma
2020-01-25T22:37:18.275Z,1579991838.275 [DataOverHttps](INFO): Moved sent file to Logs/20200125T221853/Express0011.lzma.bak
2020-01-25T22:37:18.276Z,1579991838.276 [DataOverHttps](INFO): SBD MOMSN=12204145
2020-01-25T22:37:19.804Z,1579991839.804 [Default:CheckIn:Read_Iridium] Stopped
2020-01-25T22:37:19.804Z,1579991839.804 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-25T22:37:19.804Z,1579991839.804 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-25T22:37:33.884Z,1579991853.884 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-25T22:37:37.144Z,1579991857.144 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,  -290,  +391,  -311,-32768,A
2020-01-25T22:40:38.154Z,1579992038.154 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-01-25T22:40:38.154Z,1579992038.154 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00, 322.83, 339.47, 344.46
2020-01-25T22:42:20.357Z,1579992140.357 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-01-25T22:42:20.357Z,1579992140.357 [Default:CheckIn:C.Wait] Stopped
2020-01-25T22:42:20.357Z,1579992140.357 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-25T22:42:20.357Z,1579992140.357 [Default:CheckIn:D] Running Loop=1
2020-01-25T22:42:20.787Z,1579992140.787 [Default:CheckIn:D] Stopped
2020-01-25T22:42:20.787Z,1579992140.787 [Default:CheckIn:E] Running Loop=1
2020-01-25T22:42:21.169Z,1579992141.169 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 19.749910 min 
2020-01-25T22:42:21.169Z,1579992141.169 [Default:CheckIn:E] Stopped
2020-01-25T22:42:21.169Z,1579992141.169 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-01-25T22:42:21.169Z,1579992141.169 [Default:CheckIn] Stopped
2020-01-25T22:42:21.169Z,1579992141.169 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-25T22:42:21.169Z,1579992141.169 [Default:CheckIn](INFO): Running loop #4
2020-01-25T22:42:21.169Z,1579992141.169 [Default:CheckIn] Running Loop=4
2020-01-25T22:42:21.169Z,1579992141.169 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-25T22:42:21.169Z,1579992141.169 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-25T22:42:23.170Z,1579992143.170 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224214.00,A,3648.37420,N,12148.43922,W,0.214,142.44,250120,,,D*75
2020-01-25T22:42:23.172Z,1579992143.172 [NAL9602](INFO): GPS fix at 20200125T224214: (36.806237, -121.807320)
2020-01-25T22:42:23.201Z,1579992143.201 [Default:CheckIn:Read_GPS] Stopped
2020-01-25T22:42:23.201Z,1579992143.201 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-25T22:42:36.146Z,1579992156.146 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00, 369.41, 337.81, 342.80, 354.44
2020-01-25T22:42:37.779Z,1579992157.779 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-25T22:42:37.779Z,1579992157.779 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,20012515553483,35.0, -0.,1448.9,  0
2020-01-25T22:42:37.829Z,1579992157.829 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200125T221853/Courier0013.lzma
2020-01-25T22:42:39.835Z,1579992159.835 [DataOverHttps](INFO): Moved sent file to Logs/20200125T221853/Courier0013.lzma.bak
2020-01-25T22:42:39.835Z,1579992159.835 [DataOverHttps](INFO): SBD MOMSN=12204150
2020-01-25T22:42:44.189Z,1579992164.189 [NAL9602](INFO): SBD MO Status=0, MOMSN=10284, MT Status=0, MTMSN=0
2020-01-25T22:42:44.189Z,1579992164.189 [NAL9602](INFO): No messages in MT queue
2020-01-25T22:42:57.293Z,1579992177.293 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20200125T221853/Express0014.lzma
2020-01-25T22:42:59.299Z,1579992179.299 [DataOverHttps](INFO): Moved sent file to Logs/20200125T221853/Express0014.lzma.bak
2020-01-25T22:42:59.299Z,1579992179.299 [DataOverHttps](INFO): SBD MOMSN=12204153
2020-01-25T22:43:00.826Z,1579992180.826 [Default:CheckIn:Read_Iridium] Stopped
2020-01-25T22:43:00.826Z,1579992180.826 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-25T22:43:00.826Z,1579992180.826 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-25T22:43:14.891Z,1579992194.891 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-25T22:43:59.774Z,1579992239.774 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-01-25T22:43:59.775Z,1579992239.775 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00, 434.29, 314.52, 371.08
2020-01-25T22:44:59.144Z,1579992299.144 [RDI_Pathfinder](ERROR): Failed to parse:
:R, 404.35, 346.12, 369.41, 372.74
2020-01-25T22:48:01.373Z,1579992481.373 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-01-25T22:48:01.373Z,1579992481.373 [Default:CheckIn:C.Wait] Stopped
2020-01-25T22:48:01.373Z,1579992481.373 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-25T22:48:01.373Z,1579992481.373 [Default:CheckIn:D] Running Loop=1
2020-01-25T22:48:01.790Z,1579992481.790 [Default:CheckIn:D] Stopped
2020-01-25T22:48:01.790Z,1579992481.790 [Default:CheckIn:E] Running Loop=1
2020-01-25T22:48:02.191Z,1579992482.191 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 25.433289 min 
2020-01-25T22:48:02.191Z,1579992482.191 [Default:CheckIn:E] Stopped
2020-01-25T22:48:02.191Z,1579992482.191 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-01-25T22:48:02.191Z,1579992482.191 [Default:CheckIn] Stopped
2020-01-25T22:48:02.191Z,1579992482.191 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-25T22:48:02.191Z,1579992482.191 [Default:CheckIn](INFO): Running loop #5
2020-01-25T22:48:02.191Z,1579992482.191 [Default:CheckIn] Running Loop=5
2020-01-25T22:48:02.191Z,1579992482.191 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-25T22:48:02.192Z,1579992482.192 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-25T22:48:04.165Z,1579992484.165 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224755.00,A,3648.35181,N,12148.41314,W,0.486,184.70,250120,,,D*74
2020-01-25T22:48:04.168Z,1579992484.168 [NAL9602](INFO): GPS fix at 20200125T224755: (36.805864, -121.806886)
2020-01-25T22:48:04.192Z,1579992484.192 [Default:CheckIn:Read_GPS] Stopped
2020-01-25T22:48:04.192Z,1579992484.192 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-25T22:48:11.437Z,1579992491.437 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200125T221853/Courier0016.lzma
2020-01-25T22:48:13.443Z,1579992493.443 [DataOverHttps](INFO): Moved sent file to Logs/20200125T221853/Courier0016.lzma.bak
2020-01-25T22:48:13.444Z,1579992493.444 [DataOverHttps](INFO): SBD MOMSN=12204158
2020-01-25T22:48:30.446Z,1579992510.446 [NAL9602](INFO): SBD MO Status=0, MOMSN=10285, MT Status=0, MTMSN=0
2020-01-25T22:48:30.447Z,1579992510.447 [NAL9602](INFO): No messages in MT queue
2020-01-25T22:48:30.858Z,1579992510.858 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20200125T221853/Express0017.lzma
2020-01-25T22:48:32.875Z,1579992512.875 [DataOverHttps](INFO): Moved sent file to Logs/20200125T221853/Express0017.lzma.bak
2020-01-25T22:48:32.875Z,1579992512.875 [DataOverHttps](INFO): SBD MOMSN=12204161
2020-01-25T22:48:34.552Z,1579992514.552 [Default:CheckIn:Read_Iridium] Stopped
2020-01-25T22:48:34.552Z,1579992514.552 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-25T22:48:34.552Z,1579992514.552 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-25T22:49:01.157Z,1579992541.157 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-25T22:49:32.720Z,1579992572.720 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2020-01-25T22:49:32.720Z,1579992572.720 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-32768,-3276,V
2020-01-25T22:51:26.233Z,1579992686.233 [RDI_Pathfinder](ERROR): Failed to parse:
:BE,-32768,-32768,-32768,V
2020-01-25T22:53:05.651Z,1579992785.651 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2020-01-25T22:53:05.651Z,1579992785.651 [RDI_Pathfinder](ERROR): Failed to parse:
:BD,     -168.93,     -294.1016.65,   0.00,104.00
2020-01-25T22:53:25.052Z,1579992805.052 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00,   0.00
2020-01-25T22:53:31.072Z,1579992811.072 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-25T22:53:31.072Z,1579992811.072 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,20012516062, -0.1,   0.0,1448.9,  0
2020-01-25T22:53:35.137Z,1579992815.137 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-01-25T22:53:35.137Z,1579992815.137 [Default:CheckIn:C.Wait] Stopped
2020-01-25T22:53:35.137Z,1579992815.137 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-25T22:53:35.137Z,1579992815.137 [Default:CheckIn:D] Running Loop=1
2020-01-25T22:53:35.518Z,1579992815.518 [Default:CheckIn:D] Stopped
2020-01-25T22:53:35.518Z,1579992815.518 [Default:CheckIn:E] Running Loop=1
2020-01-25T22:53:35.935Z,1579992815.935 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 30.995422 min 
2020-01-25T22:53:35.935Z,1579992815.935 [Default:CheckIn:E] Stopped
2020-01-25T22:53:35.935Z,1579992815.935 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-01-25T22:53:35.935Z,1579992815.935 [Default:CheckIn] Stopped
2020-01-25T22:53:35.935Z,1579992815.935 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-25T22:53:35.936Z,1579992815.936 [Default:CheckIn](INFO): Running loop #6
2020-01-25T22:53:35.936Z,1579992815.936 [Default:CheckIn] Running Loop=6
2020-01-25T22:53:35.936Z,1579992815.936 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-25T22:53:35.936Z,1579992815.936 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-25T22:53:37.915Z,1579992817.915 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225329.00,A,3648.33271,N,12148.38636,W,0.447,122.80,250120,,,D*75
2020-01-25T22:53:37.917Z,1579992817.917 [NAL9602](INFO): GPS fix at 20200125T225329: (36.805545, -121.806439)
2020-01-25T22:53:37.969Z,1579992817.969 [Default:CheckIn:Read_GPS] Stopped
2020-01-25T22:53:37.969Z,1579992817.969 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-25T22:53:46.057Z,1579992826.057 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200125T221853/Courier0019.lzma
2020-01-25T22:53:48.063Z,1579992828.063 [DataOverHttps](INFO): Moved sent file to Logs/20200125T221853/Courier0019.lzma.bak
2020-01-25T22:53:48.063Z,1579992828.063 [DataOverHttps](INFO): SBD MOMSN=12204166
2020-01-25T22:53:52.866Z,1579992832.866 [NAL9602](INFO): SBD MO Status=0, MOMSN=10286, MT Status=0, MTMSN=0
2020-01-25T22:53:52.866Z,1579992832.866 [NAL9602](INFO): No messages in MT queue
2020-01-25T22:54:05.509Z,1579992845.509 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20200125T221853/Express0020.lzma
2020-01-25T22:54:07.515Z,1579992847.515 [DataOverHttps](INFO): Moved sent file to Logs/20200125T221853/Express0020.lzma.bak
2020-01-25T22:54:07.515Z,1579992847.515 [DataOverHttps](INFO): SBD MOMSN=12204169
2020-01-25T22:54:09.050Z,1579992849.050 [Default:CheckIn:Read_Iridium] Stopped
2020-01-25T22:54:09.050Z,1579992849.050 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-25T22:54:09.050Z,1579992849.050 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-25T22:54:23.565Z,1579992863.565 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-25T22:55:46.004Z,1579992946.004 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-25T22:55:46.004Z,1579992946.004 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,200125135.0, -0.1,   0.0,1448.9,  0
2020-01-25T22:57:49.649Z,1579993069.649 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2020-01-25T22:57:49.649Z,1579993069.649 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-32768,-3278,V
2020-01-25T22:58:44.179Z,1579993124.179 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-25T22:58:44.179Z,1579993124.179 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,20012516113983,35.0, -0.1,   BD,     -168.93,     -294.11,      -16.65,   0.00,440.99
2020-01-25T22:59:09.671Z,1579993149.671 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-01-25T22:59:09.671Z,1579993149.671 [Default:CheckIn:C.Wait] Stopped
2020-01-25T22:59:09.671Z,1579993149.671 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-25T22:59:09.671Z,1579993149.671 [Default:CheckIn:D] Running Loop=1
2020-01-25T22:59:10.042Z,1579993150.042 [Default:CheckIn:D] Stopped
2020-01-25T22:59:10.042Z,1579993150.042 [Default:CheckIn:E] Running Loop=1
2020-01-25T22:59:10.446Z,1579993150.446 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 36.570821 min 
2020-01-25T22:59:10.446Z,1579993150.446 [Default:CheckIn:E] Stopped
2020-01-25T22:59:10.447Z,1579993150.447 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-01-25T22:59:10.447Z,1579993150.447 [Default:CheckIn] Stopped
2020-01-25T22:59:10.447Z,1579993150.447 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-25T22:59:10.447Z,1579993150.447 [Default:CheckIn](INFO): Running loop #7
2020-01-25T22:59:10.447Z,1579993150.447 [Default:CheckIn] Running Loop=7
2020-01-25T22:59:10.447Z,1579993150.447 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-25T22:59:10.447Z,1579993150.447 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-25T22:59:12.435Z,1579993152.435 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225903.00,A,3648.31520,N,12148.36276,W,1.108,110.98,250120,,,D*7F
2020-01-25T22:59:12.437Z,1579993152.437 [NAL9602](INFO): GPS fix at 20200125T225903: (36.805253, -121.806046)
2020-01-25T22:59:12.489Z,1579993152.489 [Default:CheckIn:Read_GPS] Stopped
2020-01-25T22:59:12.489Z,1579993152.489 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-25T22:59:20.365Z,1579993160.365 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200125T221853/Courier0022.lzma
2020-01-25T22:59:22.371Z,1579993162.371 [DataOverHttps](INFO): Moved sent file to Logs/20200125T221853/Courier0022.lzma.bak
2020-01-25T22:59:22.371Z,1579993162.371 [DataOverHttps](INFO): SBD MOMSN=12204174
2020-01-25T22:59:38.289Z,1579993178.289 [NAL9602](INFO): SBD MO Status=0, MOMSN=10287, MT Status=0, MTMSN=0
2020-01-25T22:59:38.289Z,1579993178.289 [NAL9602](INFO): No messages in MT queue
2020-01-25T22:59:39.977Z,1579993179.977 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20200125T221853/Express0023.lzma
2020-01-25T22:59:41.983Z,1579993181.983 [DataOverHttps](INFO): Moved sent file to Logs/20200125T221853/Express0023.lzma.bak
2020-01-25T22:59:41.984Z,1579993181.984 [DataOverHttps](INFO): SBD MOMSN=12204177
2020-01-25T22:59:43.195Z,1579993183.195 [Default:CheckIn:Read_Iridium] Stopped
2020-01-25T22:59:43.195Z,1579993183.195 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-25T22:59:43.195Z,1579993183.195 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-25T23:00:08.992Z,1579993208.992 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-25T23:00:30.024Z,1579993230.024 [RDI_Pathfinder](ERROR): Failed to parse:
:BE,-32768,-32768,-32768,V
2020-01-25T23:01:10.863Z,1579993270.863 [RDI_Pathfinder](ERROR): Failed to parse:
:-168.93,     -294.11,      -16.65,   0.00,587.98
2020-01-25T23:02:47.003Z,1579993367.003 [RDI_Pathfinder](ERROR): Failed to parse:
:BE,-32768,-32768,-32768,V
2020-01-25T23:03:43.988Z,1579993423.988 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2020-01-25T23:03:43.988Z,1579993423.988 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-3768,-32768,V
2020-01-25T23:04:23.987Z,1579993463.987 [RDI_Pathfinder](ERROR): Failed to parse:
:BE,-32768,-32768,-32768,V
2020-01-25T23:04:30.022Z,1579993470.022 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-01-25T23:04:30.022Z,1579993470.022 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00
2020-01-25T23:04:43.797Z,1579993483.797 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-01-25T23:04:43.797Z,1579993483.797 [Default:CheckIn:C.Wait] Stopped
2020-01-25T23:04:43.798Z,1579993483.798 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-25T23:04:43.798Z,1579993483.798 [Default:CheckIn:D] Running Loop=1
2020-01-25T23:04:44.210Z,1579993484.210 [Default:CheckIn:D] Stopped
2020-01-25T23:04:44.210Z,1579993484.210 [Default:CheckIn:E] Running Loop=1
2020-01-25T23:04:44.635Z,1579993484.635 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.140291 min 
2020-01-25T23:04:44.635Z,1579993484.635 [Default:CheckIn:E] Stopped
2020-01-25T23:04:44.636Z,1579993484.636 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-01-25T23:04:44.636Z,1579993484.636 [Default:CheckIn] Stopped
2020-01-25T23:04:44.636Z,1579993484.636 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-25T23:04:44.636Z,1579993484.636 [Default:CheckIn](INFO): Running loop #8
2020-01-25T23:04:44.637Z,1579993484.637 [Default:CheckIn] Running Loop=8
2020-01-25T23:04:44.637Z,1579993484.637 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-25T23:04:44.637Z,1579993484.637 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-25T23:04:46.596Z,1579993486.596 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230437.00,A,3648.29854,N,12148.33722,W,0.311,140.92,250120,,,D*73
2020-01-25T23:04:46.622Z,1579993486.622 [NAL9602](INFO): GPS fix at 20200125T230437: (36.804976, -121.805620)
2020-01-25T23:04:46.674Z,1579993486.674 [Default:CheckIn:Read_GPS] Stopped
2020-01-25T23:04:46.674Z,1579993486.674 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-25T23:04:54.209Z,1579993494.209 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200125T221853/Courier0025.lzma
2020-01-25T23:04:56.215Z,1579993496.215 [DataOverHttps](INFO): Moved sent file to Logs/20200125T221853/Courier0025.lzma.bak
2020-01-25T23:04:56.215Z,1579993496.215 [DataOverHttps](INFO): SBD MOMSN=12204182
2020-01-25T23:05:08.825Z,1579993508.825 [NAL9602](INFO): SBD MO Status=0, MOMSN=10288, MT Status=0, MTMSN=0
2020-01-25T23:05:08.825Z,1579993508.825 [NAL9602](INFO): No messages in MT queue
2020-01-25T23:05:13.674Z,1579993513.674 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20200125T221853/Express0026.lzma
2020-01-25T23:05:15.679Z,1579993515.679 [DataOverHttps](INFO): Moved sent file to Logs/20200125T221853/Express0026.lzma.bak
2020-01-25T23:05:15.680Z,1579993515.680 [DataOverHttps](INFO): SBD MOMSN=12204185
2020-01-25T23:05:16.945Z,1579993516.945 [Default:CheckIn:Read_Iridium] Stopped
2020-01-25T23:05:16.945Z,1579993516.945 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-25T23:05:16.945Z,1579993516.945 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-25T23:05:39.534Z,1579993539.534 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-25T23:06:02.177Z,1579993562.177 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-25T23:06:02.177Z,1579993562.177 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,20012516185883,35.0, -0.1,   0.0,1448.9,,  0.00,   0.00,   0.00,   0.00,   0.00
2020-01-25T23:06:41.809Z,1579993601.809 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2020-01-25T23:06:41.809Z,1579993601.809 [RDI_Pathfinder](ERROR): Failed to parse::BD68.93,     -294.11,      -16.65,   0.00,919.96
2020-01-25T23:06:51.073Z,1579993611.073 [RDI_Pathfinder](ERROR): Failed to parse:
:BE,-32768,-32768,-32768,V
2020-01-25T23:08:02.180Z,1579993682.180 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-01-25T23:08:02.180Z,1579993682.180 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00,   I,-32768,-32768,-32768,-32768,V
2020-01-25T23:08:11.073Z,1579993691.073 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-01-25T23:08:11.073Z,1579993691.073 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00
2020-01-25T23:08:41.802Z,1579993721.802 [RDI_Pathfinder](ERROR): Failed to parse:
:B,-32768,-32768,V
2020-01-25T23:08:45.003Z,1579993725.003 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-01-25T23:08:45.003Z,1579993725.003 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00
2020-01-25T23:09:35.131Z,1579993775.131 [DataOverHttps](IMPORTANT): SBD MTMSN=20200125T230925
2020-01-25T23:09:43.090Z,1579993783.090 [DataOverHttps](INFO): Received command:restart sys
2020-01-25T23:09:43.110Z,1579993783.110 [CommandLine](IMPORTANT): got command restart system
2020-01-25T23:09:45.170Z,1579993785.170 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2020-01-25T23:09:45.171Z,1579993785.171 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-25T23:09:45.171Z,1579993785.171 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-01-25T23:09:45.318Z,1579993785.318 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2020-01-25T23:09:45.318Z,1579993785.318 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-01-25T23:09:45.319Z,1579993785.319 [CommandLine](INFO): Join timeout helper Thread ID is 3571
2020-01-25T23:09:45.319Z,1579993785.319 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2020-01-25T23:09:45.319Z,1579993785.319 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-01-25T23:09:45.320Z,1579993785.320 [NavChartDb](INFO): Join timeout helper Thread ID is 3572
2020-01-25T23:09:45.710Z,1579993785.710 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-25T23:09:45.710Z,1579993785.710 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-01-25T23:09:45.722Z,1579993785.722 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2020-01-25T23:09:45.722Z,1579993785.722 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-01-25T23:09:45.722Z,1579993785.722 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 3573
2020-01-25T23:09:45.758Z,1579993785.758 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-25T23:09:45.758Z,1579993785.758 [WetLabsSeaOWL_UV_A](INFO): Powering down
2020-01-25T23:09:45.759Z,1579993785.759 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-01-25T23:09:45.762Z,1579993785.762 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2020-01-25T23:09:45.762Z,1579993785.762 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-01-25T23:09:45.762Z,1579993785.762 [Radio_Surface](INFO): Join timeout helper Thread ID is 3574
2020-01-25T23:09:46.150Z,1579993786.150 [Radio_Surface](INFO): Powering down
2020-01-25T23:09:46.151Z,1579993786.151 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-25T23:09:46.151Z,1579993786.151 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-01-25T23:09:46.173Z,1579993786.173 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2020-01-25T23:09:46.173Z,1579993786.173 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-01-25T23:09:46.173Z,1579993786.173 [DataOverHttps](INFO): Join timeout helper Thread ID is 3575
2020-01-25T23:09:47.103Z,1579993787.103 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-25T23:09:47.103Z,1579993787.103 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-01-25T23:09:47.114Z,1579993787.114 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2020-01-25T23:09:47.114Z,1579993787.114 [logger ThreadHandler](INFO): Thread cancelled.
2020-01-25T23:09:47.114Z,1579993787.114 [logger](INFO): Join timeout helper Thread ID is 3576
2020-01-25T23:09:47.115Z,1579993787.115 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-25T23:09:47.115Z,1579993787.115 [logger ThreadHandler](INFO): Thread cancelled.
2020-01-25T23:09:47.116Z,1579993787.116 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2020-01-25T23:09:47.116Z,1579993787.116 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-01-25T23:09:47.116Z,1579993787.116 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2020-01-25T23:09:47.116Z,1579993787.116 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-01-25T23:09:47.117Z,1579993787.117 [controlThread](INFO): Join timeout helper Thread ID is 3577
2020-01-25T23:09:47.178Z,1579993787.178 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-25T23:09:47.178Z,1579993787.178 [controlThread](DEBUG): Uninitializing ControlThread
2020-01-25T23:09:47.178Z,1579993787.178 [AHRS_M2](INFO): Powering down
2020-01-25T23:09:47.250Z,1579993787.250 [DDM](INFO): Powering down
2020-01-25T23:09:47.342Z,1579993787.342 [DUSBL_Hydroid](INFO): Powering down
2020-01-25T23:09:47.434Z,1579993787.434 [Micromodem](INFO): Powering down
2020-01-25T23:09:47.530Z,1579993787.530 [NAL9602](INFO): Powering down
2020-01-25T23:09:47.602Z,1579993787.602 [RDI_Pathfinder](INFO): Powering down
2020-01-25T23:09:47.604Z,1579993787.604 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2020-01-25T23:09:47.605Z,1579993787.605 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2020-01-25T23:09:47.605Z,1579993787.605 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2020-01-25T23:09:47.605Z,1579993787.605 [MissionManager](INFO): Uninitializing Mission Default
2020-01-25T23:09:47.605Z,1579993787.605 [Default] Stopped
2020-01-25T23:09:47.606Z,1579993787.606 [Default](DEBUG): Aggregate::uninitialize Default
2020-01-25T23:09:47.606Z,1579993787.606 [Default:B.GoToSurface] Stopped
2020-01-25T23:09:47.606Z,1579993787.606 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-01-25T23:09:47.606Z,1579993787.606 [Default:CheckIn] Stopped
2020-01-25T23:09:47.606Z,1579993787.606 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-25T23:09:47.606Z,1579993787.606 [Default:CheckIn:C.Wait] Stopped
2020-01-25T23:09:47.606Z,1579993787.606 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-25T23:09:47.609Z,1579993787.609 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2020-01-25T23:09:47.609Z,1579993787.609 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2020-01-25T23:09:47.609Z,1579993787.609 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2020-01-25T23:09:47.609Z,1579993787.609 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2020-01-25T23:09:47.610Z,1579993787.610 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2020-01-25T23:09:47.610Z,1579993787.610 [BuoyancyServo](INFO): Powering down
2020-01-25T23:09:47.622Z,1579993787.622 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2020-01-25T23:09:47.622Z,1579993787.622 [ElevatorServo](INFO): Powering down
2020-01-25T23:09:47.623Z,1579993787.623 [MassServo](DEBUG): Uninitialize Mass Servo.
2020-01-25T23:09:47.623Z,1579993787.623 [MassServo](INFO): Powering down
2020-01-25T23:09:47.624Z,1579993787.624 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-01-25T23:09:47.624Z,1579993787.624 [RudderServo](INFO): Powering down
2020-01-25T23:09:47.625Z,1579993787.625 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2020-01-25T23:09:47.625Z,1579993787.625 [ThrusterServo](INFO): Powering down
2020-01-25T23:09:47.626Z,1579993787.626 [SBIT](DEBUG): Uninitialize SBIT Component.
2020-01-25T23:09:47.626Z,1579993787.626 [IBIT](DEBUG): Uninitialize IBIT Component.
2020-01-25T23:09:47.626Z,1579993787.626 [CBIT](DEBUG): Uninitialize CBIT Component.
2020-01-25T23:09:47.626Z,1579993787.626 [CBIT](DEBUG): Powering off loads.
2020-01-25T23:09:47.638Z,1579993787.638 [CBIT](DEBUG): Disabling WDT.
2020-01-25T23:09:47.650Z,1579993787.650 [CBIT](DEBUG): Opening all GF detection circuits.
2020-01-25T23:09:47.651Z,1579993787.651 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-01-25T23:09:47.697Z,1579993787.697 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-01-25T23:09:47.709Z,1579993787.709 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-01-25T23:09:47.753Z,1579993787.753 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-01-25T23:09:47.817Z,1579993787.817 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-01-25T23:09:47.893Z,1579993787.893 [logger ThreadHandler](INFO): Thread cancelled.