2021-05-14T19:50:34.054Z,1621021834.054 [Supervisor](DEBUG): Initializing supervisor.
2021-05-14T19:50:34.058Z,1621021834.058 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2021-05-14T19:50:34.059Z,1621021834.059 [SyncHandler](INFO): Protected caller Thread ID is 7214
2021-05-14T19:50:34.059Z,1621021834.059 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2021-05-14T19:50:34.060Z,1621021834.060 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2021-05-14T19:50:34.060Z,1621021834.060 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 7215
2021-05-14T19:50:34.064Z,1621021834.064 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2021-05-14T19:50:34.083Z,1621021834.083 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2021-05-14T19:50:34.084Z,1621021834.084 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2021-05-14T19:50:34.084Z,1621021834.084 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 7216
2021-05-14T19:50:34.087Z,1621021834.087 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2021-05-14T19:50:34.087Z,1621021834.087 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2021-05-14T19:50:34.088Z,1621021834.088 [logger ThreadHandler](INFO): Protected caller Thread ID is 7217
2021-05-14T19:50:34.092Z,1621021834.092 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2021-05-14T19:50:34.092Z,1621021834.092 [Supervisor](INFO): Looking for Config files in directory: Config/
2021-05-14T19:50:34.094Z,1621021834.094 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2021-05-14T19:50:34.324Z,1621021834.324 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2021-05-14T19:50:34.325Z,1621021834.325 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2021-05-14T19:50:34.403Z,1621021834.403 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2021-05-14T19:50:34.895Z,1621021834.895 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2021-05-14T19:50:34.896Z,1621021834.896 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2021-05-14T19:50:35.224Z,1621021835.224 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2021-05-14T19:50:35.224Z,1621021835.224 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2021-05-14T19:50:35.319Z,1621021835.319 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2021-05-14T19:50:35.320Z,1621021835.320 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2021-05-14T19:50:35.679Z,1621021835.679 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2021-05-14T19:50:35.680Z,1621021835.680 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2021-05-14T19:50:35.876Z,1621021835.876 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2021-05-14T19:50:35.877Z,1621021835.877 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2021-05-14T19:50:36.310Z,1621021836.310 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2021-05-14T19:50:36.311Z,1621021836.311 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2021-05-14T19:50:36.435Z,1621021836.435 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2021-05-14T19:50:36.435Z,1621021836.435 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2021-05-14T19:50:36.584Z,1621021836.584 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2021-05-14T19:50:37.262Z,1621021837.262 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2021-05-14T19:50:37.262Z,1621021837.262 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2021-05-14T19:50:37.619Z,1621021837.619 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2021-05-14T19:50:37.619Z,1621021837.619 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2021-05-14T19:50:37.810Z,1621021837.810 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2021-05-14T19:50:37.811Z,1621021837.811 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2021-05-14T19:50:37.911Z,1621021837.911 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2021-05-14T19:50:37.912Z,1621021837.912 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2021-05-14T19:50:38.061Z,1621021838.061 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2021-05-14T19:50:38.062Z,1621021838.062 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2021-05-14T19:50:38.283Z,1621021838.283 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2021-05-14T19:50:38.285Z,1621021838.285 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2021-05-14T19:50:38.286Z,1621021838.286 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2021-05-14T19:50:38.376Z,1621021838.376 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2021-05-14T19:50:38.461Z,1621021838.461 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2021-05-14T19:50:38.562Z,1621021838.562 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2021-05-14T19:50:38.644Z,1621021838.644 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2021-05-14T19:50:38.738Z,1621021838.738 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2021-05-14T19:50:38.855Z,1621021838.855 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2021-05-14T19:50:39.597Z,1621021839.597 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2021-05-14T19:50:39.702Z,1621021839.702 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2021-05-14T19:50:40.029Z,1621021840.029 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2021-05-14T19:50:40.169Z,1621021840.169 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2021-05-14T19:50:40.287Z,1621021840.287 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2021-05-14T19:50:40.542Z,1621021840.542 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2021-05-14T19:50:40.543Z,1621021840.543 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2021-05-14T19:50:40.544Z,1621021840.544 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2021-05-14T19:50:40.548Z,1621021840.548 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2021-05-14T19:50:40.600Z,1621021840.600 [VerticalControl](DEBUG): Construct VerticalControl.
2021-05-14T19:50:40.658Z,1621021840.658 [VerticalControl] Loaded
2021-05-14T19:50:40.658Z,1621021840.658 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2021-05-14T19:50:40.661Z,1621021840.661 [HorizontalControl](DEBUG): Construct HorizontalControl.
2021-05-14T19:50:40.698Z,1621021840.698 [HorizontalControl] Loaded
2021-05-14T19:50:40.698Z,1621021840.698 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2021-05-14T19:50:40.701Z,1621021840.701 [SpeedControl](DEBUG): Construct SpeedControl.
2021-05-14T19:50:40.703Z,1621021840.703 [SpeedControl] Loaded
2021-05-14T19:50:40.704Z,1621021840.704 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2021-05-14T19:50:40.706Z,1621021840.706 [LoopControl](DEBUG): Construct LoopControl.
2021-05-14T19:50:40.707Z,1621021840.707 [LoopControl] Loaded
2021-05-14T19:50:40.707Z,1621021840.707 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2021-05-14T19:50:40.707Z,1621021840.707 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2021-05-14T19:50:40.708Z,1621021840.708 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2021-05-14T19:50:40.718Z,1621021840.718 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2021-05-14T19:50:40.719Z,1621021840.719 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2021-05-14T19:50:40.817Z,1621021840.817 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2021-05-14T19:50:40.817Z,1621021840.817 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2021-05-14T19:50:40.923Z,1621021840.923 [BuoyancyServo] Loaded
2021-05-14T19:50:40.923Z,1621021840.923 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2021-05-14T19:50:40.942Z,1621021840.942 [ElevatorServo] Loaded
2021-05-14T19:50:40.942Z,1621021840.942 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2021-05-14T19:50:40.959Z,1621021840.959 [MassServo] Loaded
2021-05-14T19:50:40.959Z,1621021840.959 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2021-05-14T19:50:40.977Z,1621021840.977 [RudderServo] Loaded
2021-05-14T19:50:40.977Z,1621021840.977 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2021-05-14T19:50:40.994Z,1621021840.994 [ThrusterServo] Loaded
2021-05-14T19:50:40.994Z,1621021840.994 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2021-05-14T19:50:40.995Z,1621021840.995 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2021-05-14T19:50:40.995Z,1621021840.995 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2021-05-14T19:50:41.072Z,1621021841.072 [DeadReckonUsingMultipleVelocitySources] Loaded
2021-05-14T19:50:41.073Z,1621021841.073 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2021-05-14T19:50:41.085Z,1621021841.085 [NavChart] Loaded
2021-05-14T19:50:41.085Z,1621021841.085 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2021-05-14T19:50:41.091Z,1621021841.091 [UniversalFixResidualReporter] Loaded
2021-05-14T19:50:41.091Z,1621021841.091 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2021-05-14T19:50:41.092Z,1621021841.092 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2021-05-14T19:50:41.092Z,1621021841.092 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2021-05-14T19:50:41.146Z,1621021841.146 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2021-05-14T19:50:41.146Z,1621021841.146 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2021-05-14T19:50:41.491Z,1621021841.491 [AHRS_M2] Loaded
2021-05-14T19:50:41.491Z,1621021841.491 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2021-05-14T19:50:42.256Z,1621021842.256 [BPC1] Loaded
2021-05-14T19:50:42.256Z,1621021842.256 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2021-05-14T19:50:42.327Z,1621021842.327 [DataOverHttps] Loaded
2021-05-14T19:50:42.327Z,1621021842.327 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2021-05-14T19:50:42.329Z,1621021842.329 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4087D4E0
2021-05-14T19:50:42.329Z,1621021842.329 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 7303
2021-05-14T19:50:42.348Z,1621021842.348 [Depth_Keller] Loaded
2021-05-14T19:50:42.348Z,1621021842.348 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2021-05-14T19:50:42.404Z,1621021842.404 [NAL9602] Loaded
2021-05-14T19:50:42.405Z,1621021842.405 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2021-05-14T19:50:42.433Z,1621021842.433 [Onboard] Loaded
2021-05-14T19:50:42.433Z,1621021842.433 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2021-05-14T19:50:42.434Z,1621021842.434 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408AD4E0
2021-05-14T19:50:42.434Z,1621021842.434 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 7304
2021-05-14T19:50:42.446Z,1621021842.446 [Power24vConverter] Loaded
2021-05-14T19:50:42.446Z,1621021842.446 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2021-05-14T19:50:42.459Z,1621021842.459 [Radio_Surface] Loaded
2021-05-14T19:50:42.459Z,1621021842.459 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2021-05-14T19:50:42.460Z,1621021842.460 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408DD4E0
2021-05-14T19:50:42.460Z,1621021842.460 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 7305
2021-05-14T19:50:42.480Z,1621021842.480 [AMEcho] Loaded
2021-05-14T19:50:42.480Z,1621021842.480 [ComponentRegistry](DEBUG): SyncComponent "AMEcho" handled in the control thread.
2021-05-14T19:50:42.558Z,1621021842.558 [DAT] Loaded
2021-05-14T19:50:42.558Z,1621021842.558 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2021-05-14T19:50:42.559Z,1621021842.559 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2021-05-14T19:50:42.559Z,1621021842.559 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2021-05-14T19:50:42.599Z,1621021842.599 [DepthRateCalculator] Loaded
2021-05-14T19:50:42.600Z,1621021842.600 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2021-05-14T19:50:42.604Z,1621021842.604 [PitchRateCalculator] Loaded
2021-05-14T19:50:42.604Z,1621021842.604 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2021-05-14T19:50:42.613Z,1621021842.613 [SpeedCalculator] Loaded
2021-05-14T19:50:42.613Z,1621021842.613 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2021-05-14T19:50:42.627Z,1621021842.627 [TempGradientCalculator] Loaded
2021-05-14T19:50:42.627Z,1621021842.627 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2021-05-14T19:50:42.631Z,1621021842.631 [YawRateCalculator] Loaded
2021-05-14T19:50:42.631Z,1621021842.631 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2021-05-14T19:50:42.648Z,1621021842.648 [ElevatorOffsetCalculator] Loaded
2021-05-14T19:50:42.649Z,1621021842.649 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2021-05-14T19:50:42.649Z,1621021842.649 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2021-05-14T19:50:42.650Z,1621021842.650 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2021-05-14T19:50:42.818Z,1621021842.818 [CTD_Seabird] Loaded
2021-05-14T19:50:42.819Z,1621021842.819 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2021-05-14T19:50:42.820Z,1621021842.820 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409904E0
2021-05-14T19:50:42.820Z,1621021842.820 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 7306
2021-05-14T19:50:42.839Z,1621021842.839 [PAR_Licor] Loaded
2021-05-14T19:50:42.839Z,1621021842.839 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2021-05-14T19:50:42.870Z,1621021842.870 [WetLabsBB2FL] Loaded
2021-05-14T19:50:42.870Z,1621021842.870 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2021-05-14T19:50:42.871Z,1621021842.871 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409C04E0
2021-05-14T19:50:42.871Z,1621021842.871 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 7307
2021-05-14T19:50:42.872Z,1621021842.872 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2021-05-14T19:50:42.873Z,1621021842.873 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2021-05-14T19:50:42.899Z,1621021842.899 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2021-05-14T19:50:42.900Z,1621021842.900 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2021-05-14T19:50:43.204Z,1621021843.204 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2021-05-14T19:50:43.205Z,1621021843.205 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2021-05-14T19:50:43.344Z,1621021843.344 [SBIT](DEBUG): Construct Startup Built In Test.
2021-05-14T19:50:43.353Z,1621021843.353 [SBIT] Loaded
2021-05-14T19:50:43.354Z,1621021843.354 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2021-05-14T19:50:43.356Z,1621021843.356 [IBIT](DEBUG): Construct Initiated Built In Test.
2021-05-14T19:50:43.369Z,1621021843.369 [IBIT] Loaded
2021-05-14T19:50:43.369Z,1621021843.369 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2021-05-14T19:50:43.375Z,1621021843.375 [CBIT](DEBUG): Construct Continuous Built In Test.
2021-05-14T19:50:43.472Z,1621021843.472 [CBIT] Loaded
2021-05-14T19:50:43.472Z,1621021843.472 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2021-05-14T19:50:43.473Z,1621021843.473 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2021-05-14T19:50:43.473Z,1621021843.473 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2021-05-14T19:50:43.558Z,1621021843.558 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2021-05-14T19:50:43.564Z,1621021843.564 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2021-05-14T19:50:43.567Z,1621021843.567 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2021-05-14T19:50:43.577Z,1621021843.577 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2021-05-14T19:50:43.578Z,1621021843.578 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AF14E0
2021-05-14T19:50:43.578Z,1621021843.578 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 7308
2021-05-14T19:50:43.583Z,1621021843.583 [Supervisor](INFO): Main Thread ID is 7213
2021-05-14T19:50:43.583Z,1621021843.583 [Supervisor](DEBUG): Running supervisor.
2021-05-14T19:50:43.584Z,1621021843.584 [CommandLine ThreadHandler](INFO): Handler Thread ID is 7309
2021-05-14T19:50:43.597Z,1621021843.597 [CommandLine](IMPORTANT): got command strobe off
2021-05-14T19:50:43.597Z,1621021843.597 [CommandLine](IMPORTANT): Deactivating strobe
2021-05-14T19:50:43.602Z,1621021843.602 [controlThread ThreadHandler](INFO): Handler Thread ID is 7310
2021-05-14T19:50:43.602Z,1621021843.602 [controlThread](DEBUG): Initializing ControlThread
2021-05-14T19:50:43.603Z,1621021843.603 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2021-05-14T19:50:43.605Z,1621021843.605 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2021-05-14T19:50:43.605Z,1621021843.605 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2021-05-14T19:50:43.606Z,1621021843.606 [LoopControl](DEBUG): Initialize LoopControlComponent.
2021-05-14T19:50:43.608Z,1621021843.608 [NavChart](DEBUG): Initialize NavChart Navigation.
2021-05-14T19:50:43.608Z,1621021843.608 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2021-05-14T19:50:43.614Z,1621021843.614 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2021-05-14T19:50:43.614Z,1621021843.614 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2021-05-14T19:50:43.615Z,1621021843.615 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2021-05-14T19:50:43.615Z,1621021843.615 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2021-05-14T19:50:43.615Z,1621021843.615 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2021-05-14T19:50:43.616Z,1621021843.616 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2021-05-14T19:50:43.621Z,1621021843.621 [SBIT](INFO): Initialize SBIT Component.
2021-05-14T19:50:43.622Z,1621021843.622 [SBIT](IMPORTANT): git: 2021-05-10
2021-05-14T19:50:43.622Z,1621021843.622 [SBIT](INFO): git hash: 03112e3e75aba085c15f5826cf8e252bb5a4e5aa
2021-05-14T19:50:43.622Z,1621021843.622 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2021-05-14T19:50:43.623Z,1621021843.623 [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
2021-05-14T19:50:43.624Z,1621021843.624 [SBIT](INFO): Beginning SBIT in 57.000000 seconds.
2021-05-14T19:50:43.625Z,1621021843.625 [IBIT](INFO): Initialize IBIT Component.
2021-05-14T19:50:43.626Z,1621021843.626 [CBIT](DEBUG): Initialize CBIT Component.
2021-05-14T19:50:43.627Z,1621021843.627 [logger ThreadHandler](INFO): Handler Thread ID is 7311
2021-05-14T19:50:43.637Z,1621021843.637 [CBIT](DEBUG): Initialized mux pins.
2021-05-14T19:50:43.637Z,1621021843.637 [CBIT](DEBUG): Initializing the watchdog timer.
2021-05-14T19:50:43.645Z,1621021843.645 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 7312
2021-05-14T19:50:43.646Z,1621021843.646 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2021-05-14T19:50:43.657Z,1621021843.657 [Onboard ThreadHandler](INFO): Handler Thread ID is 7313
2021-05-14T19:50:43.662Z,1621021843.662 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2021-05-14T19:50:43.662Z,1621021843.662 [CBIT](DEBUG): Initializing heartbeat.
2021-05-14T19:50:43.678Z,1621021843.678 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 7314
2021-05-14T19:50:43.693Z,1621021843.693 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 7315
2021-05-14T19:50:43.694Z,1621021843.694 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2021-05-14T19:50:43.699Z,1621021843.699 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 7317
2021-05-14T19:50:43.702Z,1621021843.702 [WetLabsBB2FL](INFO): Powering up
2021-05-14T19:50:43.703Z,1621021843.703 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 7319
2021-05-14T19:50:43.706Z,1621021843.706 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2021-05-14T19:50:43.706Z,1621021843.706 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2021-05-14T19:50:43.706Z,1621021843.706 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2021-05-14T19:50:43.706Z,1621021843.706 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2021-05-14T19:50:43.707Z,1621021843.707 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2021-05-14T19:50:43.707Z,1621021843.707 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2021-05-14T19:50:43.707Z,1621021843.707 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2021-05-14T19:50:43.707Z,1621021843.707 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2021-05-14T19:50:43.707Z,1621021843.707 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2021-05-14T19:50:43.707Z,1621021843.707 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2021-05-14T19:50:43.708Z,1621021843.708 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2021-05-14T19:50:43.708Z,1621021843.708 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2021-05-14T19:50:43.708Z,1621021843.708 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2021-05-14T19:50:43.708Z,1621021843.708 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2021-05-14T19:50:43.708Z,1621021843.708 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2021-05-14T19:50:43.708Z,1621021843.708 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2021-05-14T19:50:43.733Z,1621021843.733 [CBIT](DEBUG): Deactivating GF circuits.
2021-05-14T19:50:43.733Z,1621021843.733 [CBIT](DEBUG): Deactivating emergency mode.
2021-05-14T19:50:43.769Z,1621021843.769 [CBIT](DEBUG): Backplane powered.
2021-05-14T19:50:43.770Z,1621021843.770 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2021-05-14T19:50:43.783Z,1621021843.783 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2021-05-14T19:50:43.805Z,1621021843.805 [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>


2021-05-14T19:50:43.806Z,1621021843.806 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2021-05-14T19:50:43.887Z,1621021843.887 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2021-05-14T19:50:43.888Z,1621021843.888 [Default:A.Wait](DEBUG): Construct Wait.
2021-05-14T19:50:43.903Z,1621021843.903 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-05-14T19:50:43.938Z,1621021843.938 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-05-14T19:50:43.940Z,1621021843.940 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-05-14T19:50:43.978Z,1621021843.978 [Default:E.Execute](DEBUG): Construct Execute.
2021-05-14T19:50:43.997Z,1621021843.997 [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>


2021-05-14T19:50:44.002Z,1621021844.002 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,NAL9602,Power24vConverter,AMEcho,DAT,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,
2021-05-14T19:50:44.018Z,1621021844.018 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2021-05-14T19:50:44.081Z,1621021844.081 [Radio_Surface](INFO): Powering up
2021-05-14T19:50:44.130Z,1621021844.130 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2021-05-14T19:50:44.130Z,1621021844.130 [Power24vConverter](INFO): Powering down.
2021-05-14T19:50:44.131Z,1621021844.131 [AMEcho](INFO): Powering up.
2021-05-14T19:50:44.149Z,1621021844.149 [DAT](INFO): Powering up
2021-05-14T19:50:44.150Z,1621021844.150 [DAT](DEBUG): Initializing DAT.
2021-05-14T19:50:44.194Z,1621021844.194 [DepthRateCalculator](ERROR): Depth measurement is not active
2021-05-14T19:50:44.248Z,1621021844.248 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2021-05-14T19:50:44.257Z,1621021844.257 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2021-05-14T19:50:44.258Z,1621021844.258 [ElevatorServo](DEBUG): Initializing EZServoServo.
2021-05-14T19:50:44.265Z,1621021844.265 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2021-05-14T19:50:44.266Z,1621021844.266 [MassServo](DEBUG): Initializing EZServoServo.
2021-05-14T19:50:44.274Z,1621021844.274 [MassServo](DEBUG): Initializing MassServo.
2021-05-14T19:50:44.274Z,1621021844.274 [RudderServo](DEBUG): Initializing EZServoServo.
2021-05-14T19:50:44.281Z,1621021844.281 [RudderServo](DEBUG): Initializing RudderServo.
2021-05-14T19:50:44.282Z,1621021844.282 [ThrusterServo](DEBUG): Initializing EZServoServo.
2021-05-14T19:50:44.289Z,1621021844.289 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2021-05-14T19:50:44.593Z,1621021844.593 [AMEcho](INFO): Powering down.
2021-05-14T19:50:44.818Z,1621021844.818 [Power24vConverter](INFO): Powering up.
2021-05-14T19:50:45.137Z,1621021845.137 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2021-05-14T19:50:45.137Z,1621021845.137 [RudderServo](FAULT): Rudder failed to initialize
2021-05-14T19:50:45.137Z,1621021845.137 [RudderServo] Communications Fault, FailCount= 1
2021-05-14T19:50:45.137Z,1621021845.137 [RudderServo](ERROR): Communications Fault
2021-05-14T19:50:45.237Z,1621021845.237 [CBIT](ERROR): Communications Fault in component: RudderServo
2021-05-14T19:50:45.247Z,1621021845.247 [AMEcho](IMPORTANT): Setting 'depthThreshold' to 20.000000
2021-05-14T19:50:45.402Z,1621021845.402 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-05-14T19:50:45.402Z,1621021845.402 [RudderServo](INFO): Powering down
2021-05-14T19:50:45.809Z,1621021845.809 [WetLabsBB2FL](INFO): Powering down
2021-05-14T19:50:46.096Z,1621021846.096 [RudderServo](DEBUG): Initializing EZServoServo.
2021-05-14T19:50:46.214Z,1621021846.214 [RudderServo](DEBUG): Initializing RudderServo.
2021-05-14T19:50:46.218Z,1621021846.218 [CBIT](INFO): Clearing failed state for component RudderServo
2021-05-14T19:50:46.218Z,1621021846.218 [RudderServo] No Fault, FailCount= 1
2021-05-14T19:50:57.943Z,1621021857.943 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004698
2021-05-14T19:50:58.177Z,1621021858.177 [DAT](INFO): commRate: 800
2021-05-14T19:51:00.195Z,1621021860.195 [DAT](INFO): entering command mode
2021-05-14T19:51:00.599Z,1621021860.599 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:01.003Z,1621021861.003 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:01.407Z,1621021861.407 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:01.815Z,1621021861.815 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:02.215Z,1621021862.215 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:02.619Z,1621021862.619 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:03.027Z,1621021863.027 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:03.427Z,1621021863.427 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:03.831Z,1621021863.831 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:04.239Z,1621021864.239 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:04.643Z,1621021864.643 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:05.044Z,1621021865.044 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:05.447Z,1621021865.447 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:05.851Z,1621021865.851 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:06.255Z,1621021866.255 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:06.659Z,1621021866.659 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:07.063Z,1621021867.063 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:07.467Z,1621021867.467 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:07.871Z,1621021867.871 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:08.275Z,1621021868.275 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:08.698Z,1621021868.698 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:09.083Z,1621021869.083 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:09.487Z,1621021869.487 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:09.891Z,1621021869.891 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:10.306Z,1621021870.306 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:10.699Z,1621021870.699 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:11.103Z,1621021871.103 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:11.507Z,1621021871.507 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:11.915Z,1621021871.915 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:12.315Z,1621021872.315 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:12.718Z,1621021872.718 [NAL9602](INFO): Powering up NAL9602
2021-05-14T19:51:12.720Z,1621021872.720 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:13.123Z,1621021873.123 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:13.527Z,1621021873.527 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:13.931Z,1621021873.931 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:14.335Z,1621021874.335 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:14.739Z,1621021874.739 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:15.143Z,1621021875.143 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:15.553Z,1621021875.553 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T19:51:15.553Z,1621021875.553 [DAT](FAULT): failed to enter command mode
2021-05-14T19:51:15.951Z,1621021875.951 [DAT](INFO): entering command mode
2021-05-14T19:51:16.356Z,1621021876.356 [DAT](INFO): setting verbose to 3
2021-05-14T19:51:16.760Z,1621021876.760 [DAT](INFO): set verbose to 3
2021-05-14T19:51:16.761Z,1621021876.761 [DAT](INFO): setting DatVerbose to 27440
2021-05-14T19:51:17.171Z,1621021877.171 [DAT](INFO): set DatVerbose to 27440
2021-05-14T19:51:17.171Z,1621021877.171 [DAT](INFO): setting transmit power to 8
2021-05-14T19:51:17.568Z,1621021877.568 [DAT](INFO): set transmit power to 8
2021-05-14T19:51:17.568Z,1621021877.568 [DAT](INFO): setting local address to 7
2021-05-14T19:51:17.972Z,1621021877.972 [DAT](INFO): set local address to 7
2021-05-14T19:51:23.633Z,1621021883.633 [NAL9602](INFO): NAL9602 initialized
2021-05-14T19:51:41.434Z,1621021901.434 [SBIT](IMPORTANT): Beginning Startup BIT
2021-05-14T19:51:41.438Z,1621021901.438 [CBIT](IMPORTANT): Beginning ground fault scan
2021-05-14T19:51:52.378Z,1621021912.378 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.016070
CHAN A1 (24V): 4.610929
CHAN A2 (12V): -0.002089
CHAN A3 (5V): 4.753929
CHAN B0 (3.3V): 0.001726
CHAN B1 (3.15aV): -0.000061
CHAN B2 (3.15bV): -0.000437
CHAN B3 (GND): -0.000222
OPEN: -0.000436
Full Scale Calc: 4.765 mA, -1.589 mA
2021-05-14T19:52:35.576Z,1621021955.576 [SBIT](IMPORTANT): SBIT PASSED
2021-05-14T19:52:35.577Z,1621021955.577 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2021-05-14T19:52:35.578Z,1621021955.578 [SBIT](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2021-05-14T19:52:35.578Z,1621021955.578 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=282 cubic_centimeter;

2021-05-14T19:52:35.578Z,1621021955.578 [SBIT](IMPORTANT): VerticalControl.massDefault=9.25 millimeter;

2021-05-14T19:52:35.978Z,1621021955.978 [MissionManager](IMPORTANT): Started mission Startup
2021-05-14T19:52:35.979Z,1621021955.979 [Startup] Running Loop=1
2021-05-14T19:52:35.979Z,1621021955.979 [Startup](DEBUG): Aggregate::initialize Startup
2021-05-14T19:52:35.979Z,1621021955.979 [Startup:A.GoToSurface] Running Loop=1
2021-05-14T19:52:35.979Z,1621021955.979 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-05-14T19:52:35.980Z,1621021955.980 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-05-14T19:52:35.980Z,1621021955.980 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-05-14T19:52:35.980Z,1621021955.980 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-05-14T19:52:35.981Z,1621021955.981 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-05-14T19:52:35.981Z,1621021955.981 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-05-14T19:52:35.983Z,1621021955.983 [Startup:StartupSatComms] Running Loop=1
2021-05-14T19:52:35.983Z,1621021955.983 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2021-05-14T19:52:35.983Z,1621021955.983 [Startup:StartupSatComms:A] Running Loop=1
2021-05-14T19:52:36.363Z,1621021956.363 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2021-05-14T19:52:36.757Z,1621021956.757 [AMEcho](INFO): Powering up.
2021-05-14T19:53:36.160Z,1621022016.160 [Startup:StartupSatComms:A](INFO): Timed out from 2021-05-14T19:52:35.0Z
2021-05-14T19:53:36.160Z,1621022016.160 [Startup:StartupSatComms:A] Stopped
2021-05-14T19:53:36.160Z,1621022016.160 [Startup:StartupSatComms:B] Running Loop=1
2021-05-14T19:53:36.563Z,1621022016.563 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-05-14T19:53:43.360Z,1621022023.360 [DataOverHttps](INFO): Sending 111 bytes from file Logs/20210514T190221/Courier0004.lzma
2021-05-14T19:53:43.879Z,1621022023.879 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2021-05-14T19:53:43.879Z,1621022023.879 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T19:53:43.889Z,1621022023.889 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T19:53:44.251Z,1621022024.251 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T19:53:44.251Z,1621022024.251 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2021-05-14T19:53:44.363Z,1621022024.363 [DataOverHttps](INFO): Moved sent file to Logs/20210514T190221/Courier0004.lzma.bak
2021-05-14T19:53:44.363Z,1621022024.363 [DataOverHttps](INFO): SBD MOMSN=15646747
2021-05-14T19:54:00.000Z,1621022040.000 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20210514T195034/Courier0000.lzma
2021-05-14T19:54:01.003Z,1621022041.003 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Courier0000.lzma.bak
2021-05-14T19:54:01.003Z,1621022041.003 [DataOverHttps](INFO): SBD MOMSN=15646750
2021-05-14T19:54:18.708Z,1621022058.708 [DataOverHttps](INFO): Sending 292 bytes from file Logs/20210514T190221/Express0005.lzma
2021-05-14T19:54:18.919Z,1621022058.919 [DataOverHttps](INFO): Moved sent file to Logs/20210514T190221/Express0005.lzma.bak
2021-05-14T19:54:18.919Z,1621022058.919 [DataOverHttps](INFO): SBD MOMSN=15646753
2021-05-14T19:54:35.898Z,1621022075.898 [DataOverHttps](INFO): Sending 828 bytes from file Logs/20210514T195034/Express0001.lzma
2021-05-14T19:54:36.368Z,1621022076.368 [Startup:StartupSatComms:B](INFO): Timed out from 2021-05-14T19:53:36.2Z
2021-05-14T19:54:36.368Z,1621022076.368 [Startup:StartupSatComms:B] Stopped
2021-05-14T19:54:36.368Z,1621022076.368 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2021-05-14T19:54:36.368Z,1621022076.368 [Startup:StartupSatComms] Stopped
2021-05-14T19:54:36.368Z,1621022076.368 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2021-05-14T19:54:36.369Z,1621022076.369 [Startup](INFO): Completed Startup
2021-05-14T19:54:36.369Z,1621022076.369 [MissionManager](INFO): Startup is completed.
2021-05-14T19:54:36.369Z,1621022076.369 [MissionManager](INFO): Uninitializing Mission Startup
2021-05-14T19:54:36.369Z,1621022076.369 [Startup] Stopped
2021-05-14T19:54:36.369Z,1621022076.369 [Startup](DEBUG): Aggregate::uninitialize Startup
2021-05-14T19:54:36.370Z,1621022076.370 [Startup:A.GoToSurface] Stopped
2021-05-14T19:54:36.370Z,1621022076.370 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-05-14T19:54:36.755Z,1621022076.755 [MissionManager](IMPORTANT): Started mission Default
2021-05-14T19:54:36.755Z,1621022076.755 [Default] Running Loop=1
2021-05-14T19:54:36.755Z,1621022076.755 [Default](DEBUG): Aggregate::initialize Default
2021-05-14T19:54:36.756Z,1621022076.756 [Default:B.GoToSurface] Running Loop=1
2021-05-14T19:54:36.756Z,1621022076.756 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-05-14T19:54:36.756Z,1621022076.756 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-05-14T19:54:36.756Z,1621022076.756 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-05-14T19:54:36.757Z,1621022076.757 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-05-14T19:54:36.757Z,1621022076.757 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-05-14T19:54:36.757Z,1621022076.757 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-05-14T19:54:36.758Z,1621022076.758 [Default:A.Wait] Running Loop=1
2021-05-14T19:54:36.758Z,1621022076.758 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-05-14T19:54:36.899Z,1621022076.899 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Express0001.lzma.bak
2021-05-14T19:54:36.899Z,1621022076.899 [DataOverHttps](INFO): SBD MOMSN=15646762
2021-05-14T19:54:37.309Z,1621022077.309 [AMEcho](INFO): Powering down.
2021-05-14T19:54:38.359Z,1621022078.359 [AMEcho](INFO): Powering up.
2021-05-14T19:54:50.088Z,1621022090.088 [Default:A.Wait](INFO): Done Waiting.
2021-05-14T19:54:50.088Z,1621022090.088 [Default:A.Wait] Stopped
2021-05-14T19:54:50.088Z,1621022090.088 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-05-14T19:54:50.479Z,1621022090.479 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2021-05-14T19:54:50.480Z,1621022090.480 [AMEcho] Communications Fault, FailCount= 1
2021-05-14T19:54:50.480Z,1621022090.480 [AMEcho](ERROR): Communications Fault
2021-05-14T19:54:50.508Z,1621022090.508 [Default:CheckIn] Running Loop=1
2021-05-14T19:54:50.508Z,1621022090.508 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-05-14T19:54:50.508Z,1621022090.508 [Default:CheckIn:Read_GPS] Running Loop=1
2021-05-14T19:54:50.529Z,1621022090.529 [CBIT](ERROR): Communications Fault in component: AMEcho
2021-05-14T19:54:51.066Z,1621022091.066 [AMEcho](INFO): Powering down.
2021-05-14T19:54:51.080Z,1621022091.080 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2021-05-14T19:54:51.744Z,1621022091.744 [CBIT](INFO): Clearing failed state for component AMEcho
2021-05-14T19:54:51.744Z,1621022091.744 [AMEcho] No Fault, FailCount= 1
2021-05-14T19:54:52.109Z,1621022092.109 [AMEcho](INFO): Powering up.
2021-05-14T19:55:04.219Z,1621022104.219 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2021-05-14T19:55:04.219Z,1621022104.219 [AMEcho] Communications Fault, FailCount= 2
2021-05-14T19:55:04.219Z,1621022104.219 [AMEcho](ERROR): Communications Fault
2021-05-14T19:55:04.269Z,1621022104.269 [CBIT](ERROR): Communications Fault in component: AMEcho
2021-05-14T19:55:04.782Z,1621022104.782 [AMEcho](INFO): Powering down.
2021-05-14T19:55:05.448Z,1621022105.448 [CBIT](INFO): Clearing failed state for component AMEcho
2021-05-14T19:55:05.448Z,1621022105.448 [AMEcho] No Fault, FailCount= 2
2021-05-14T19:55:05.827Z,1621022105.827 [AMEcho](INFO): Powering up.
2021-05-14T19:55:17.964Z,1621022117.964 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2021-05-14T19:55:17.964Z,1621022117.964 [AMEcho] Communications Fault, FailCount= 3
2021-05-14T19:55:17.964Z,1621022117.964 [AMEcho](ERROR): Communications Fault
2021-05-14T19:55:18.101Z,1621022118.101 [CBIT](ERROR): Communications Fault in component: AMEcho
2021-05-14T19:55:18.102Z,1621022118.102 [CBIT](CRITICAL): Communications Fault in component: AMEcho
2021-05-14T19:55:18.521Z,1621022118.521 [AMEcho](INFO): Powering down.
2021-05-14T19:55:18.542Z,1621022118.542 [CommandLine](FAULT): Scheduling is paused
2021-05-14T19:55:18.543Z,1621022118.543 [CBIT](INFO): Critical error at 20210514T195518
2021-05-14T19:55:18.543Z,1621022118.543 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2021-05-14T19:56:27.034Z,1621022187.034 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-05-14T19:56:44.838Z,1621022204.838 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2021-05-14T19:56:44.838Z,1621022204.838 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T19:56:44.849Z,1621022204.849 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T19:56:45.236Z,1621022205.236 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T19:56:45.236Z,1621022205.236 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2021-05-14T19:58:07.228Z,1621022287.228 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2021-05-14T19:58:07.231Z,1621022287.231 [BPC1](INFO): Received data from all battery sticks.
2021-05-14T19:58:18.173Z,1621022298.173 [CBIT](INFO): Clearing failed state for component AMEcho
2021-05-14T19:58:18.173Z,1621022298.173 [AMEcho] No Fault, FailCount= 3
2021-05-14T19:58:18.553Z,1621022298.553 [AMEcho](INFO): Powering up.
2021-05-14T19:59:26.413Z,1621022366.413 [AMEcho](INFO): Failure count cleared after critical for AMEcho
2021-05-14T19:59:45.830Z,1621022385.830 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2021-05-14T19:59:45.830Z,1621022385.830 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T19:59:45.852Z,1621022385.852 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T19:59:46.258Z,1621022386.258 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T19:59:46.258Z,1621022386.258 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2021-05-14T19:59:50.674Z,1621022390.674 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-05-14T19:54:50.5Z
2021-05-14T19:59:50.674Z,1621022390.674 [Default:CheckIn:Read_GPS] Stopped
2021-05-14T19:59:50.675Z,1621022390.675 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-05-14T19:59:51.064Z,1621022391.064 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-05-14T19:59:57.701Z,1621022397.701 [DataOverHttps](INFO): Sending 228 bytes from file Logs/20210514T195034/Courier0004.lzma
2021-05-14T19:59:58.703Z,1621022398.703 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Courier0004.lzma.bak
2021-05-14T19:59:58.703Z,1621022398.703 [DataOverHttps](INFO): SBD MOMSN=15646789
2021-05-14T20:00:20.812Z,1621022420.812 [DataOverHttps](INFO): Sending 210 bytes from file Logs/20210514T195034/Express0005.lzma
2021-05-14T20:00:21.831Z,1621022421.831 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Express0005.lzma.bak
2021-05-14T20:00:21.831Z,1621022421.831 [DataOverHttps](INFO): SBD MOMSN=15646792
2021-05-14T20:00:24.235Z,1621022424.234 [Default:CheckIn:Read_Iridium] Stopped
2021-05-14T20:00:24.235Z,1621022424.235 [Default:CheckIn:C.Wait] Running Loop=1
2021-05-14T20:00:24.235Z,1621022424.235 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-05-14T20:01:26.026Z,1621022486.026 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-05-14T20:01:26.026Z,1621022486.026 [NAL9602] Data Fault, FailCount= 1
2021-05-14T20:01:26.026Z,1621022486.026 [NAL9602](ERROR): Data Fault
2021-05-14T20:01:26.044Z,1621022486.044 [CBIT](ERROR): Data Fault in component: NAL9602
2021-05-14T20:01:26.426Z,1621022486.426 [NAL9602](INFO): Powering down
2021-05-14T20:01:27.270Z,1621022487.270 [CBIT](INFO): Clearing failed state for component NAL9602
2021-05-14T20:01:27.270Z,1621022487.270 [NAL9602] No Fault, FailCount= 1
2021-05-14T20:01:56.730Z,1621022516.730 [NAL9602](INFO): Powering up NAL9602
2021-05-14T20:02:07.634Z,1621022527.634 [NAL9602](INFO): NAL9602 initialized
2021-05-14T20:02:46.849Z,1621022566.849 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2021-05-14T20:02:46.850Z,1621022566.850 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T20:02:46.860Z,1621022566.860 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T20:02:47.251Z,1621022567.251 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T20:02:47.251Z,1621022567.251 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2021-05-14T20:05:24.822Z,1621022724.822 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-05-14T20:05:24.823Z,1621022724.823 [Default:CheckIn:C.Wait] Stopped
2021-05-14T20:05:24.823Z,1621022724.823 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-05-14T20:05:24.823Z,1621022724.823 [Default:CheckIn:D] Running Loop=1
2021-05-14T20:05:25.229Z,1621022725.229 [Default:CheckIn:D] Stopped
2021-05-14T20:05:25.229Z,1621022725.229 [Default:CheckIn:E] Running Loop=1
2021-05-14T20:05:25.610Z,1621022725.610 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.807886 min 
2021-05-14T20:05:25.610Z,1621022725.610 [Default:CheckIn:E] Stopped
2021-05-14T20:05:25.610Z,1621022725.610 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-05-14T20:05:25.610Z,1621022725.610 [Default:CheckIn] Stopped
2021-05-14T20:05:25.610Z,1621022725.610 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-05-14T20:05:25.610Z,1621022725.610 [Default:CheckIn](INFO): Running loop #2
2021-05-14T20:05:25.610Z,1621022725.610 [Default:CheckIn] Running Loop=2
2021-05-14T20:05:25.611Z,1621022725.611 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-05-14T20:05:25.611Z,1621022725.611 [Default:CheckIn:Read_GPS] Running Loop=1
2021-05-14T20:05:47.836Z,1621022747.836 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2021-05-14T20:05:47.836Z,1621022747.836 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T20:05:47.877Z,1621022747.877 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T20:05:48.241Z,1621022748.241 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T20:05:48.241Z,1621022748.241 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2021-05-14T20:08:48.834Z,1621022928.834 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2021-05-14T20:08:48.834Z,1621022928.834 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T20:08:48.869Z,1621022928.869 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T20:08:49.235Z,1621022929.235 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T20:08:49.236Z,1621022929.236 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2021-05-14T20:10:25.788Z,1621023025.788 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-05-14T20:05:25.6Z
2021-05-14T20:10:25.788Z,1621023025.788 [Default:CheckIn:Read_GPS] Stopped
2021-05-14T20:10:25.788Z,1621023025.788 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-05-14T20:10:34.820Z,1621023034.820 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210514T195034/Courier0007.lzma
2021-05-14T20:10:35.823Z,1621023035.823 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Courier0007.lzma.bak
2021-05-14T20:10:35.823Z,1621023035.823 [DataOverHttps](INFO): SBD MOMSN=15646811
2021-05-14T20:10:52.997Z,1621023052.997 [DataOverHttps](INFO): Sending 182 bytes from file Logs/20210514T195034/Express0008.lzma
2021-05-14T20:10:53.999Z,1621023053.999 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Express0008.lzma.bak
2021-05-14T20:10:53.999Z,1621023053.999 [DataOverHttps](INFO): SBD MOMSN=15646813
2021-05-14T20:10:56.515Z,1621023056.515 [Default:CheckIn:Read_Iridium] Stopped
2021-05-14T20:10:56.515Z,1621023056.515 [Default:CheckIn:C.Wait] Running Loop=1
2021-05-14T20:10:56.516Z,1621023056.516 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-05-14T20:11:49.840Z,1621023109.840 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2021-05-14T20:11:49.840Z,1621023109.840 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T20:11:49.851Z,1621023109.851 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T20:11:50.246Z,1621023110.246 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T20:11:50.246Z,1621023110.246 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2021-05-14T20:12:09.206Z,1621023129.206 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-05-14T20:12:09.206Z,1621023129.206 [NAL9602] Data Fault, FailCount= 2
2021-05-14T20:12:09.206Z,1621023129.206 [NAL9602](ERROR): Data Fault
2021-05-14T20:12:09.280Z,1621023129.280 [CBIT](ERROR): Data Fault in component: NAL9602
2021-05-14T20:12:09.617Z,1621023129.617 [NAL9602](INFO): Powering down
2021-05-14T20:12:10.473Z,1621023130.473 [CBIT](INFO): Clearing failed state for component NAL9602
2021-05-14T20:12:10.473Z,1621023130.473 [NAL9602] No Fault, FailCount= 2
2021-05-14T20:12:39.910Z,1621023159.910 [NAL9602](INFO): Powering up NAL9602
2021-05-14T20:12:50.825Z,1621023170.825 [NAL9602](INFO): NAL9602 initialized
2021-05-14T20:14:50.818Z,1621023290.818 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2021-05-14T20:14:50.818Z,1621023290.818 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T20:14:50.829Z,1621023290.829 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T20:14:51.252Z,1621023291.252 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T20:14:51.252Z,1621023291.252 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2021-05-14T20:15:57.121Z,1621023357.121 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-05-14T20:15:57.121Z,1621023357.121 [Default:CheckIn:C.Wait] Stopped
2021-05-14T20:15:57.121Z,1621023357.121 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-05-14T20:15:57.121Z,1621023357.121 [Default:CheckIn:D] Running Loop=1
2021-05-14T20:15:57.537Z,1621023357.537 [Default:CheckIn:D] Stopped
2021-05-14T20:15:57.537Z,1621023357.537 [Default:CheckIn:E] Running Loop=1
2021-05-14T20:15:57.932Z,1621023357.932 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.346366 min 
2021-05-14T20:15:57.932Z,1621023357.932 [Default:CheckIn:E] Stopped
2021-05-14T20:15:57.932Z,1621023357.932 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-05-14T20:15:57.933Z,1621023357.933 [Default:CheckIn] Stopped
2021-05-14T20:15:57.933Z,1621023357.933 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-05-14T20:15:57.933Z,1621023357.933 [Default:CheckIn](INFO): Running loop #3
2021-05-14T20:15:57.933Z,1621023357.933 [Default:CheckIn] Running Loop=3
2021-05-14T20:15:57.933Z,1621023357.933 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-05-14T20:15:57.933Z,1621023357.933 [Default:CheckIn:Read_GPS] Running Loop=1
2021-05-14T20:17:51.857Z,1621023471.857 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2021-05-14T20:17:51.857Z,1621023471.857 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T20:17:51.868Z,1621023471.868 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T20:17:52.255Z,1621023472.255 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T20:17:52.256Z,1621023472.256 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2021-05-14T20:20:52.845Z,1621023652.845 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2021-05-14T20:20:52.846Z,1621023652.846 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T20:20:52.856Z,1621023652.856 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T20:20:53.276Z,1621023653.276 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T20:20:53.276Z,1621023653.276 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2021-05-14T20:20:58.091Z,1621023658.091 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-05-14T20:15:57.9Z
2021-05-14T20:20:58.091Z,1621023658.091 [Default:CheckIn:Read_GPS] Stopped
2021-05-14T20:20:58.091Z,1621023658.091 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-05-14T20:21:05.528Z,1621023665.528 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210514T195034/Courier0010.lzma
2021-05-14T20:21:06.531Z,1621023666.531 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Courier0010.lzma.bak
2021-05-14T20:21:06.531Z,1621023666.531 [DataOverHttps](INFO): SBD MOMSN=15646824
2021-05-14T20:21:23.229Z,1621023683.229 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20210514T195034/Express0011.lzma
2021-05-14T20:21:24.231Z,1621023684.231 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Express0011.lzma.bak
2021-05-14T20:21:24.231Z,1621023684.231 [DataOverHttps](INFO): SBD MOMSN=15646828
2021-05-14T20:21:26.783Z,1621023686.783 [Default:CheckIn:Read_Iridium] Stopped
2021-05-14T20:21:26.783Z,1621023686.783 [Default:CheckIn:C.Wait] Running Loop=1
2021-05-14T20:21:26.783Z,1621023686.783 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-05-14T20:22:53.221Z,1621023773.221 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-05-14T20:22:53.221Z,1621023773.221 [NAL9602] Data Fault, FailCount= 3
2021-05-14T20:22:53.221Z,1621023773.221 [NAL9602](ERROR): Data Fault
2021-05-14T20:22:53.244Z,1621023773.244 [CBIT](ERROR): Data Fault in component: NAL9602
2021-05-14T20:22:53.618Z,1621023773.618 [NAL9602](INFO): Powering down
2021-05-14T20:22:54.448Z,1621023774.448 [CBIT](INFO): Clearing failed state for component NAL9602
2021-05-14T20:22:54.448Z,1621023774.448 [NAL9602] No Fault, FailCount= 3
2021-05-14T20:23:23.928Z,1621023803.928 [NAL9602](INFO): Powering up NAL9602
2021-05-14T20:23:34.830Z,1621023814.830 [NAL9602](INFO): NAL9602 initialized
2021-05-14T20:23:53.857Z,1621023833.857 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2021-05-14T20:23:53.857Z,1621023833.857 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T20:23:53.868Z,1621023833.868 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T20:23:54.252Z,1621023834.252 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T20:23:54.252Z,1621023834.252 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2021-05-14T20:26:27.366Z,1621023987.366 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-05-14T20:26:27.366Z,1621023987.366 [Default:CheckIn:C.Wait] Stopped
2021-05-14T20:26:27.366Z,1621023987.366 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-05-14T20:26:27.366Z,1621023987.366 [Default:CheckIn:D] Running Loop=1
2021-05-14T20:26:27.763Z,1621023987.763 [Default:CheckIn:D] Stopped
2021-05-14T20:26:27.763Z,1621023987.763 [Default:CheckIn:E] Running Loop=1
2021-05-14T20:26:28.156Z,1621023988.156 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.850130 min 
2021-05-14T20:26:28.156Z,1621023988.156 [Default:CheckIn:E] Stopped
2021-05-14T20:26:28.156Z,1621023988.156 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-05-14T20:26:28.156Z,1621023988.156 [Default:CheckIn] Stopped
2021-05-14T20:26:28.156Z,1621023988.156 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-05-14T20:26:28.156Z,1621023988.156 [Default:CheckIn](INFO): Running loop #4
2021-05-14T20:26:28.156Z,1621023988.156 [Default:CheckIn] Running Loop=4
2021-05-14T20:26:28.156Z,1621023988.156 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-05-14T20:26:28.156Z,1621023988.156 [Default:CheckIn:Read_GPS] Running Loop=1
2021-05-14T20:26:54.842Z,1621024014.842 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12
2021-05-14T20:26:54.842Z,1621024014.842 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T20:26:54.852Z,1621024014.852 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T20:26:55.252Z,1621024015.252 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T20:26:55.252Z,1621024015.252 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12
2021-05-14T20:29:55.810Z,1621024195.810 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13
2021-05-14T20:29:55.810Z,1621024195.810 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T20:29:55.821Z,1621024195.821 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T20:29:56.240Z,1621024196.240 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T20:29:56.240Z,1621024196.240 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13
2021-05-14T20:31:28.384Z,1621024288.384 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-05-14T20:26:28.2Z
2021-05-14T20:31:28.384Z,1621024288.384 [Default:CheckIn:Read_GPS] Stopped
2021-05-14T20:31:28.384Z,1621024288.384 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-05-14T20:31:35.044Z,1621024295.044 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210514T195034/Courier0013.lzma
2021-05-14T20:31:36.047Z,1621024296.047 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Courier0013.lzma.bak
2021-05-14T20:31:36.047Z,1621024296.047 [DataOverHttps](INFO): SBD MOMSN=15646900
2021-05-14T20:31:52.769Z,1621024312.769 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20210514T195034/Express0014.lzma
2021-05-14T20:31:53.771Z,1621024313.771 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Express0014.lzma.bak
2021-05-14T20:31:53.771Z,1621024313.771 [DataOverHttps](INFO): SBD MOMSN=15646903
2021-05-14T20:31:56.279Z,1621024316.279 [Default:CheckIn:Read_Iridium] Stopped
2021-05-14T20:31:56.280Z,1621024316.280 [Default:CheckIn:C.Wait] Running Loop=1
2021-05-14T20:31:56.280Z,1621024316.280 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-05-14T20:32:56.858Z,1621024376.858 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 14
2021-05-14T20:32:56.859Z,1621024376.859 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T20:32:56.869Z,1621024376.869 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T20:32:57.284Z,1621024377.284 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T20:32:57.284Z,1621024377.284 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 14
2021-05-14T20:33:35.639Z,1621024415.639 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-05-14T20:33:35.639Z,1621024415.639 [NAL9602] Data Fault, FailCount= 4
2021-05-14T20:33:35.639Z,1621024415.639 [NAL9602](ERROR): Data Fault
2021-05-14T20:33:35.656Z,1621024415.656 [CBIT](ERROR): Data Fault in component: NAL9602
2021-05-14T20:33:36.042Z,1621024416.042 [NAL9602](INFO): Powering down
2021-05-14T20:33:36.880Z,1621024416.880 [CBIT](INFO): Clearing failed state for component NAL9602
2021-05-14T20:33:36.880Z,1621024416.880 [NAL9602] No Fault, FailCount= 4
2021-05-14T20:34:06.338Z,1621024446.338 [NAL9602](INFO): Powering up NAL9602
2021-05-14T20:34:17.250Z,1621024457.250 [NAL9602](INFO): NAL9602 initialized
2021-05-14T20:35:57.859Z,1621024557.859 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 15
2021-05-14T20:35:57.859Z,1621024557.859 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T20:35:57.869Z,1621024557.869 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T20:35:58.283Z,1621024558.283 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T20:35:58.283Z,1621024558.283 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 15
2021-05-14T20:36:56.839Z,1621024616.839 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-05-14T20:36:56.840Z,1621024616.840 [Default:CheckIn:C.Wait] Stopped
2021-05-14T20:36:56.840Z,1621024616.840 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-05-14T20:36:56.840Z,1621024616.840 [Default:CheckIn:D] Running Loop=1
2021-05-14T20:36:57.256Z,1621024617.256 [Default:CheckIn:D] Stopped
2021-05-14T20:36:57.256Z,1621024617.256 [Default:CheckIn:E] Running Loop=1
2021-05-14T20:36:57.666Z,1621024617.666 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.341679 min 
2021-05-14T20:36:57.666Z,1621024617.666 [Default:CheckIn:E] Stopped
2021-05-14T20:36:57.666Z,1621024617.666 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-05-14T20:36:57.666Z,1621024617.666 [Default:CheckIn] Stopped
2021-05-14T20:36:57.666Z,1621024617.666 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-05-14T20:36:57.666Z,1621024617.666 [Default:CheckIn](INFO): Running loop #5
2021-05-14T20:36:57.667Z,1621024617.667 [Default:CheckIn] Running Loop=5
2021-05-14T20:36:57.667Z,1621024617.667 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-05-14T20:36:57.667Z,1621024617.667 [Default:CheckIn:Read_GPS] Running Loop=1
2021-05-14T20:38:58.850Z,1621024738.850 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 16
2021-05-14T20:38:58.850Z,1621024738.850 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T20:38:58.888Z,1621024738.888 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T20:38:59.264Z,1621024739.264 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T20:38:59.264Z,1621024739.264 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 16
2021-05-14T20:41:57.820Z,1621024917.820 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-05-14T20:36:57.7Z
2021-05-14T20:41:57.820Z,1621024917.820 [Default:CheckIn:Read_GPS] Stopped
2021-05-14T20:41:57.820Z,1621024917.820 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-05-14T20:41:59.841Z,1621024919.841 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 17
2021-05-14T20:41:59.841Z,1621024919.841 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T20:41:59.852Z,1621024919.852 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T20:42:00.268Z,1621024920.268 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T20:42:00.268Z,1621024920.268 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 17
2021-05-14T20:42:05.140Z,1621024925.140 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210514T195034/Courier0016.lzma
2021-05-14T20:42:06.143Z,1621024926.143 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Courier0016.lzma.bak
2021-05-14T20:42:06.143Z,1621024926.143 [DataOverHttps](INFO): SBD MOMSN=15646929
2021-05-14T20:42:23.018Z,1621024943.018 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20210514T195034/Express0017.lzma
2021-05-14T20:42:24.019Z,1621024944.019 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Express0017.lzma.bak
2021-05-14T20:42:24.019Z,1621024944.019 [DataOverHttps](INFO): SBD MOMSN=15646931
2021-05-14T20:42:26.524Z,1621024946.524 [Default:CheckIn:Read_Iridium] Stopped
2021-05-14T20:42:26.524Z,1621024946.524 [Default:CheckIn:C.Wait] Running Loop=1
2021-05-14T20:42:26.524Z,1621024946.524 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-05-14T20:44:19.614Z,1621025059.614 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-05-14T20:44:19.614Z,1621025059.614 [NAL9602] Data Fault, FailCount= 5
2021-05-14T20:44:19.615Z,1621025059.615 [NAL9602](ERROR): Data Fault
2021-05-14T20:44:19.657Z,1621025059.657 [CBIT](ERROR): Data Fault in component: NAL9602
2021-05-14T20:44:19.658Z,1621025059.658 [CBIT](CRITICAL): Data Fault in component: NAL9602
2021-05-14T20:44:20.014Z,1621025060.014 [NAL9602](INFO): Powering down
2021-05-14T20:44:20.039Z,1621025060.039 [CBIT](INFO): Critical error at 20210514T204419
2021-05-14T20:45:00.829Z,1621025100.829 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 18
2021-05-14T20:45:00.830Z,1621025100.830 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T20:45:00.840Z,1621025100.840 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T20:45:01.244Z,1621025101.244 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T20:45:01.244Z,1621025101.244 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 18
2021-05-14T20:46:19.646Z,1621025179.646 [CBIT](INFO): Clearing failed state for component NAL9602
2021-05-14T20:46:19.646Z,1621025179.646 [NAL9602] No Fault, FailCount= 5
2021-05-14T20:46:20.002Z,1621025180.002 [NAL9602](INFO): Powering up NAL9602
2021-05-14T20:46:30.914Z,1621025190.914 [NAL9602](INFO): NAL9602 initialized
2021-05-14T20:47:27.095Z,1621025247.095 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-05-14T20:47:27.095Z,1621025247.095 [Default:CheckIn:C.Wait] Stopped
2021-05-14T20:47:27.096Z,1621025247.096 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-05-14T20:47:27.096Z,1621025247.096 [Default:CheckIn:D] Running Loop=1
2021-05-14T20:47:27.486Z,1621025247.486 [Default:CheckIn:D] Stopped
2021-05-14T20:47:27.486Z,1621025247.486 [Default:CheckIn:E] Running Loop=1
2021-05-14T20:47:27.901Z,1621025247.901 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 52.845512 min 
2021-05-14T20:47:27.901Z,1621025247.901 [Default:CheckIn:E] Stopped
2021-05-14T20:47:27.902Z,1621025247.902 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-05-14T20:47:27.902Z,1621025247.902 [Default:CheckIn] Stopped
2021-05-14T20:47:27.902Z,1621025247.902 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-05-14T20:47:27.902Z,1621025247.902 [Default:CheckIn](INFO): Running loop #6
2021-05-14T20:47:27.902Z,1621025247.902 [Default:CheckIn] Running Loop=6
2021-05-14T20:47:27.902Z,1621025247.902 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-05-14T20:47:27.902Z,1621025247.902 [Default:CheckIn:Read_GPS] Running Loop=1
2021-05-14T20:48:01.822Z,1621025281.822 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 19
2021-05-14T20:48:01.822Z,1621025281.822 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T20:48:01.849Z,1621025281.849 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T20:48:02.235Z,1621025282.235 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T20:48:02.236Z,1621025282.236 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 19
2021-05-14T20:51:02.870Z,1621025462.870 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 20
2021-05-14T20:51:02.870Z,1621025462.870 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T20:51:02.881Z,1621025462.881 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T20:51:02.881Z,1621025462.881 [CBIT](FAULT): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T20:52:28.083Z,1621025548.083 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-05-14T20:47:27.9Z
2021-05-14T20:52:28.083Z,1621025548.083 [Default:CheckIn:Read_GPS] Stopped
2021-05-14T20:52:28.083Z,1621025548.083 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-05-14T20:52:35.425Z,1621025555.425 [DataOverHttps](INFO): Sending 81 bytes from file Logs/20210514T195034/Courier0019.lzma
2021-05-14T20:52:36.423Z,1621025556.423 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Courier0019.lzma.bak
2021-05-14T20:52:36.423Z,1621025556.423 [DataOverHttps](INFO): SBD MOMSN=15646966
2021-05-14T20:52:53.553Z,1621025573.553 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20210514T195034/Express0020.lzma
2021-05-14T20:52:54.555Z,1621025574.555 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Express0020.lzma.bak
2021-05-14T20:52:54.555Z,1621025574.555 [DataOverHttps](INFO): SBD MOMSN=15646969
2021-05-14T20:52:57.178Z,1621025577.178 [Default:CheckIn:Read_Iridium] Stopped
2021-05-14T20:52:57.179Z,1621025577.179 [Default:CheckIn:C.Wait] Running Loop=1
2021-05-14T20:52:57.179Z,1621025577.179 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-05-14T20:56:33.307Z,1621025793.307 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-05-14T20:56:33.307Z,1621025793.307 [NAL9602] Data Fault, FailCount= 1
2021-05-14T20:56:33.307Z,1621025793.307 [NAL9602](ERROR): Data Fault
2021-05-14T20:56:33.351Z,1621025793.351 [CBIT](ERROR): Data Fault in component: NAL9602
2021-05-14T20:56:33.706Z,1621025793.706 [NAL9602](INFO): Powering down
2021-05-14T20:56:34.538Z,1621025794.538 [CBIT](INFO): Clearing failed state for component NAL9602
2021-05-14T20:56:34.539Z,1621025794.539 [NAL9602] No Fault, FailCount= 1
2021-05-14T20:57:04.010Z,1621025824.010 [NAL9602](INFO): Powering up NAL9602
2021-05-14T20:57:14.918Z,1621025834.918 [NAL9602](INFO): NAL9602 initialized
2021-05-14T20:57:57.747Z,1621025877.747 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-05-14T20:57:57.747Z,1621025877.747 [Default:CheckIn:C.Wait] Stopped
2021-05-14T20:57:57.747Z,1621025877.747 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-05-14T20:57:57.747Z,1621025877.747 [Default:CheckIn:D] Running Loop=1
2021-05-14T20:57:58.154Z,1621025878.154 [Default:CheckIn:D] Stopped
2021-05-14T20:57:58.155Z,1621025878.155 [Default:CheckIn:E] Running Loop=1
2021-05-14T20:57:58.571Z,1621025878.571 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 63.356649 min 
2021-05-14T20:57:58.571Z,1621025878.571 [Default:CheckIn:E] Stopped
2021-05-14T20:57:58.571Z,1621025878.571 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-05-14T20:57:58.571Z,1621025878.571 [Default:CheckIn] Stopped
2021-05-14T20:57:58.571Z,1621025878.571 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-05-14T20:57:58.571Z,1621025878.571 [Default:CheckIn](INFO): Running loop #7
2021-05-14T20:57:58.571Z,1621025878.571 [Default:CheckIn] Running Loop=7
2021-05-14T20:57:58.572Z,1621025878.572 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-05-14T20:57:58.572Z,1621025878.572 [Default:CheckIn:Read_GPS] Running Loop=1
2021-05-14T21:02:58.755Z,1621026178.755 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-05-14T20:57:58.6Z
2021-05-14T21:02:58.755Z,1621026178.755 [Default:CheckIn:Read_GPS] Stopped
2021-05-14T21:02:58.755Z,1621026178.755 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-05-14T21:03:06.176Z,1621026186.176 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210514T195034/Courier0022.lzma
2021-05-14T21:03:07.179Z,1621026187.179 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Courier0022.lzma.bak
2021-05-14T21:03:07.179Z,1621026187.179 [DataOverHttps](INFO): SBD MOMSN=15646998
2021-05-14T21:03:24.712Z,1621026204.712 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20210514T195034/Express0023.lzma
2021-05-14T21:03:25.715Z,1621026205.715 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Express0023.lzma.bak
2021-05-14T21:03:25.715Z,1621026205.715 [DataOverHttps](INFO): SBD MOMSN=15647000
2021-05-14T21:03:28.264Z,1621026208.264 [Default:CheckIn:Read_Iridium] Stopped
2021-05-14T21:03:28.264Z,1621026208.264 [Default:CheckIn:C.Wait] Running Loop=1
2021-05-14T21:03:28.264Z,1621026208.264 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-05-14T21:05:34.959Z,1621026334.959 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2021-05-14T21:05:34.962Z,1621026334.962 [BPC1](INFO): Received data from all battery sticks.
2021-05-14T21:06:02.883Z,1621026362.883 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T21:06:02.883Z,1621026362.883 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 20
2021-05-14T21:07:15.954Z,1621026435.954 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-05-14T21:07:15.954Z,1621026435.954 [NAL9602] Data Fault, FailCount= 2
2021-05-14T21:07:15.954Z,1621026435.954 [NAL9602](ERROR): Data Fault
2021-05-14T21:07:15.976Z,1621026435.976 [CBIT](ERROR): Data Fault in component: NAL9602
2021-05-14T21:07:16.362Z,1621026436.362 [NAL9602](INFO): Powering down
2021-05-14T21:07:17.201Z,1621026437.201 [CBIT](INFO): Clearing failed state for component NAL9602
2021-05-14T21:07:17.201Z,1621026437.201 [NAL9602] No Fault, FailCount= 2
2021-05-14T21:07:46.662Z,1621026466.662 [NAL9602](INFO): Powering up NAL9602
2021-05-14T21:07:57.573Z,1621026477.573 [NAL9602](INFO): NAL9602 initialized
2021-05-14T21:08:29.115Z,1621026509.115 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-05-14T21:08:29.115Z,1621026509.115 [Default:CheckIn:C.Wait] Stopped
2021-05-14T21:08:29.115Z,1621026509.115 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-05-14T21:08:29.115Z,1621026509.115 [Default:CheckIn:D] Running Loop=1
2021-05-14T21:08:29.531Z,1621026509.531 [Default:CheckIn:D] Stopped
2021-05-14T21:08:29.531Z,1621026509.531 [Default:CheckIn:E] Running Loop=1
2021-05-14T21:08:29.908Z,1621026509.908 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 73.879582 min 
2021-05-14T21:08:29.908Z,1621026509.908 [Default:CheckIn:E] Stopped
2021-05-14T21:08:29.908Z,1621026509.908 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-05-14T21:08:29.908Z,1621026509.908 [Default:CheckIn] Stopped
2021-05-14T21:08:29.908Z,1621026509.908 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-05-14T21:08:29.908Z,1621026509.908 [Default:CheckIn](INFO): Running loop #8
2021-05-14T21:08:29.908Z,1621026509.908 [Default:CheckIn] Running Loop=8
2021-05-14T21:08:29.909Z,1621026509.909 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-05-14T21:08:29.909Z,1621026509.909 [Default:CheckIn:Read_GPS] Running Loop=1
2021-05-14T21:09:03.454Z,1621026543.454 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2021-05-14T21:09:03.454Z,1621026543.454 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T21:09:03.465Z,1621026543.465 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T21:09:03.857Z,1621026543.857 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T21:09:03.857Z,1621026543.857 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2021-05-14T21:12:04.428Z,1621026724.428 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2021-05-14T21:12:04.428Z,1621026724.428 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T21:12:04.438Z,1621026724.438 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T21:12:04.853Z,1621026724.853 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T21:12:04.853Z,1621026724.853 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2021-05-14T21:13:30.107Z,1621026810.107 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-05-14T21:08:29.9Z
2021-05-14T21:13:30.107Z,1621026810.107 [Default:CheckIn:Read_GPS] Stopped
2021-05-14T21:13:30.107Z,1621026810.107 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-05-14T21:13:37.428Z,1621026817.428 [DataOverHttps](INFO): Sending 51 bytes from file Logs/20210514T195034/Courier0025.lzma
2021-05-14T21:13:38.431Z,1621026818.431 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Courier0025.lzma.bak
2021-05-14T21:13:38.431Z,1621026818.431 [DataOverHttps](INFO): SBD MOMSN=15647015
2021-05-14T21:13:55.196Z,1621026835.196 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20210514T195034/Express0026.lzma
2021-05-14T21:13:56.199Z,1621026836.199 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Express0026.lzma.bak
2021-05-14T21:13:56.199Z,1621026836.199 [DataOverHttps](INFO): SBD MOMSN=15647017
2021-05-14T21:13:58.800Z,1621026838.800 [Default:CheckIn:Read_Iridium] Stopped
2021-05-14T21:13:58.800Z,1621026838.800 [Default:CheckIn:C.Wait] Running Loop=1
2021-05-14T21:13:58.801Z,1621026838.801 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-05-14T21:15:05.431Z,1621026905.431 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2021-05-14T21:15:05.431Z,1621026905.431 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T21:15:05.442Z,1621026905.442 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T21:15:05.827Z,1621026905.827 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T21:15:05.827Z,1621026905.827 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2021-05-14T21:17:59.935Z,1621027079.935 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-05-14T21:17:59.935Z,1621027079.935 [NAL9602] Data Fault, FailCount= 3
2021-05-14T21:17:59.935Z,1621027079.935 [NAL9602](ERROR): Data Fault
2021-05-14T21:17:59.981Z,1621027079.981 [CBIT](ERROR): Data Fault in component: NAL9602
2021-05-14T21:18:00.338Z,1621027080.338 [NAL9602](INFO): Powering down
2021-05-14T21:18:00.742Z,1621027080.742 [NAL9602](FAULT): LCB fault:  Software Overcurrent.
2021-05-14T21:18:00.742Z,1621027080.742 [NAL9602] Hardware Fault, FailCount= 3
2021-05-14T21:18:00.742Z,1621027080.742 [NAL9602](ERROR): Hardware Fault
2021-05-14T21:18:01.171Z,1621027081.171 [CBIT](INFO): Clearing failed state for component NAL9602
2021-05-14T21:18:01.171Z,1621027081.171 [NAL9602] No Fault, FailCount= 3
2021-05-14T21:18:06.418Z,1621027086.418 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2021-05-14T21:18:06.418Z,1621027086.418 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T21:18:06.428Z,1621027086.428 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T21:18:06.836Z,1621027086.836 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T21:18:06.836Z,1621027086.836 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2021-05-14T21:18:30.649Z,1621027110.649 [NAL9602](INFO): Powering up NAL9602
2021-05-14T21:18:41.554Z,1621027121.554 [NAL9602](INFO): NAL9602 initialized
2021-05-14T21:18:59.339Z,1621027139.339 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-05-14T21:18:59.339Z,1621027139.339 [Default:CheckIn:C.Wait] Stopped
2021-05-14T21:18:59.339Z,1621027139.339 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-05-14T21:18:59.339Z,1621027139.339 [Default:CheckIn:D] Running Loop=1
2021-05-14T21:18:59.747Z,1621027139.747 [Default:CheckIn:D] Stopped
2021-05-14T21:18:59.747Z,1621027139.747 [Default:CheckIn:E] Running Loop=1
2021-05-14T21:19:00.164Z,1621027140.164 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 84.383195 min 
2021-05-14T21:19:00.164Z,1621027140.164 [Default:CheckIn:E] Stopped
2021-05-14T21:19:00.164Z,1621027140.164 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-05-14T21:19:00.164Z,1621027140.164 [Default:CheckIn] Stopped
2021-05-14T21:19:00.164Z,1621027140.164 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-05-14T21:19:00.164Z,1621027140.164 [Default:CheckIn](INFO): Running loop #9
2021-05-14T21:19:00.164Z,1621027140.164 [Default:CheckIn] Running Loop=9
2021-05-14T21:19:00.164Z,1621027140.164 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-05-14T21:19:00.165Z,1621027140.165 [Default:CheckIn:Read_GPS] Running Loop=1
2021-05-14T21:21:07.421Z,1621027267.421 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2021-05-14T21:21:07.421Z,1621027267.421 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T21:21:07.431Z,1621027267.431 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T21:21:07.816Z,1621027267.816 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T21:21:07.816Z,1621027267.816 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2021-05-14T21:24:00.330Z,1621027440.330 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-05-14T21:19:00.2Z
2021-05-14T21:24:00.330Z,1621027440.330 [Default:CheckIn:Read_GPS] Stopped
2021-05-14T21:24:00.330Z,1621027440.330 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-05-14T21:24:07.244Z,1621027447.244 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210514T195034/Courier0028.lzma
2021-05-14T21:24:08.247Z,1621027448.247 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Courier0028.lzma.bak
2021-05-14T21:24:08.247Z,1621027448.247 [DataOverHttps](INFO): SBD MOMSN=15647082
2021-05-14T21:24:08.403Z,1621027448.403 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2021-05-14T21:24:08.403Z,1621027448.403 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T21:24:08.442Z,1621027448.442 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T21:24:08.814Z,1621027448.814 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T21:24:08.814Z,1621027448.814 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2021-05-14T21:24:24.985Z,1621027464.985 [DataOverHttps](INFO): Sending 182 bytes from file Logs/20210514T195034/Express0029.lzma
2021-05-14T21:24:25.987Z,1621027465.987 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Express0029.lzma.bak
2021-05-14T21:24:25.987Z,1621027465.987 [DataOverHttps](INFO): SBD MOMSN=15647084
2021-05-14T21:24:28.611Z,1621027468.611 [Default:CheckIn:Read_Iridium] Stopped
2021-05-14T21:24:28.612Z,1621027468.612 [Default:CheckIn:C.Wait] Running Loop=1
2021-05-14T21:24:28.612Z,1621027468.612 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-05-14T21:27:09.383Z,1621027629.383 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2021-05-14T21:27:09.383Z,1621027629.383 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T21:27:09.406Z,1621027629.406 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T21:27:09.799Z,1621027629.799 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T21:27:09.800Z,1621027629.800 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2021-05-14T21:28:43.916Z,1621027723.916 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-05-14T21:28:43.916Z,1621027723.916 [NAL9602] Data Fault, FailCount= 4
2021-05-14T21:28:43.916Z,1621027723.916 [NAL9602](ERROR): Data Fault
2021-05-14T21:28:43.953Z,1621027723.953 [CBIT](ERROR): Data Fault in component: NAL9602
2021-05-14T21:28:44.314Z,1621027724.314 [NAL9602](INFO): Powering down
2021-05-14T21:28:44.718Z,1621027724.718 [NAL9602](FAULT): LCB fault:  Software Overcurrent.
2021-05-14T21:28:44.718Z,1621027724.718 [NAL9602] Hardware Fault, FailCount= 4
2021-05-14T21:28:44.718Z,1621027724.718 [NAL9602](ERROR): Hardware Fault
2021-05-14T21:28:45.148Z,1621027725.148 [CBIT](INFO): Clearing failed state for component NAL9602
2021-05-14T21:28:45.148Z,1621027725.148 [NAL9602] No Fault, FailCount= 4
2021-05-14T21:29:14.614Z,1621027754.614 [NAL9602](INFO): Powering up NAL9602
2021-05-14T21:29:25.528Z,1621027765.528 [NAL9602](INFO): NAL9602 initialized
2021-05-14T21:29:29.191Z,1621027769.191 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-05-14T21:29:29.191Z,1621027769.191 [Default:CheckIn:C.Wait] Stopped
2021-05-14T21:29:29.191Z,1621027769.191 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-05-14T21:29:29.192Z,1621027769.192 [Default:CheckIn:D] Running Loop=1
2021-05-14T21:29:29.602Z,1621027769.602 [Default:CheckIn:D] Stopped
2021-05-14T21:29:29.602Z,1621027769.602 [Default:CheckIn:E] Running Loop=1
2021-05-14T21:29:29.992Z,1621027769.992 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 94.880770 min 
2021-05-14T21:29:29.992Z,1621027769.992 [Default:CheckIn:E] Stopped
2021-05-14T21:29:29.992Z,1621027769.992 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-05-14T21:29:29.992Z,1621027769.992 [Default:CheckIn] Stopped
2021-05-14T21:29:29.992Z,1621027769.992 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-05-14T21:29:29.992Z,1621027769.992 [Default:CheckIn](INFO): Running loop #10
2021-05-14T21:29:29.992Z,1621027769.992 [Default:CheckIn] Running Loop=10
2021-05-14T21:29:29.993Z,1621027769.993 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-05-14T21:29:29.993Z,1621027769.993 [Default:CheckIn:Read_GPS] Running Loop=1
2021-05-14T21:30:10.395Z,1621027810.395 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2021-05-14T21:30:10.395Z,1621027810.395 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T21:30:10.406Z,1621027810.406 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T21:30:10.820Z,1621027810.820 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T21:30:10.820Z,1621027810.820 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2021-05-14T21:33:11.418Z,1621027991.418 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2021-05-14T21:33:11.418Z,1621027991.418 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T21:33:11.454Z,1621027991.454 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T21:33:11.836Z,1621027991.836 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T21:33:11.836Z,1621027991.836 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2021-05-14T21:34:30.189Z,1621028070.189 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-05-14T21:29:29.0Z
2021-05-14T21:34:30.189Z,1621028070.189 [Default:CheckIn:Read_GPS] Stopped
2021-05-14T21:34:30.189Z,1621028070.189 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-05-14T21:34:37.220Z,1621028077.220 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210514T195034/Courier0031.lzma
2021-05-14T21:34:38.223Z,1621028078.223 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Courier0031.lzma.bak
2021-05-14T21:34:38.223Z,1621028078.223 [DataOverHttps](INFO): SBD MOMSN=15647099
2021-05-14T21:34:55.725Z,1621028095.725 [DataOverHttps](INFO): Sending 184 bytes from file Logs/20210514T195034/Express0032.lzma
2021-05-14T21:34:56.727Z,1621028096.727 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Express0032.lzma.bak
2021-05-14T21:34:56.727Z,1621028096.727 [DataOverHttps](INFO): SBD MOMSN=15647101
2021-05-14T21:34:59.284Z,1621028099.284 [Default:CheckIn:Read_Iridium] Stopped
2021-05-14T21:34:59.284Z,1621028099.284 [Default:CheckIn:C.Wait] Running Loop=1
2021-05-14T21:34:59.284Z,1621028099.284 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-05-14T21:36:12.425Z,1621028172.425 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2021-05-14T21:36:12.425Z,1621028172.425 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T21:36:12.464Z,1621028172.464 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T21:36:12.877Z,1621028172.877 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T21:36:12.877Z,1621028172.877 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2021-05-14T21:39:13.421Z,1621028353.421 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2021-05-14T21:39:13.421Z,1621028353.421 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T21:39:13.440Z,1621028353.440 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T21:39:13.840Z,1621028353.840 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T21:39:13.840Z,1621028353.840 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2021-05-14T21:39:29.150Z,1621028369.150 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-05-14T21:39:29.151Z,1621028369.151 [NAL9602] Data Fault, FailCount= 5
2021-05-14T21:39:29.151Z,1621028369.151 [NAL9602](ERROR): Data Fault
2021-05-14T21:39:29.176Z,1621028369.176 [CBIT](ERROR): Data Fault in component: NAL9602
2021-05-14T21:39:29.177Z,1621028369.177 [CBIT](CRITICAL): Data Fault in component: NAL9602
2021-05-14T21:39:29.562Z,1621028369.562 [NAL9602](INFO): Powering down
2021-05-14T21:39:29.599Z,1621028369.599 [CBIT](INFO): Critical error at 20210514T213929
2021-05-14T21:39:29.958Z,1621028369.958 [NAL9602](FAULT): LCB fault:  Software Overcurrent.
2021-05-14T21:39:29.958Z,1621028369.958 [NAL9602] Hardware Fault, FailCount= 5
2021-05-14T21:39:29.958Z,1621028369.958 [NAL9602](ERROR): Hardware Fault
2021-05-14T21:39:59.871Z,1621028399.871 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-05-14T21:39:59.871Z,1621028399.871 [Default:CheckIn:C.Wait] Stopped
2021-05-14T21:39:59.871Z,1621028399.871 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-05-14T21:39:59.872Z,1621028399.872 [Default:CheckIn:D] Running Loop=1
2021-05-14T21:40:00.271Z,1621028400.271 [Default:CheckIn:D] Stopped
2021-05-14T21:40:00.271Z,1621028400.271 [Default:CheckIn:E] Running Loop=1
2021-05-14T21:40:00.676Z,1621028400.676 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 105.391935 min 
2021-05-14T21:40:00.676Z,1621028400.676 [Default:CheckIn:E] Stopped
2021-05-14T21:40:00.676Z,1621028400.676 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-05-14T21:40:00.676Z,1621028400.676 [Default:CheckIn] Stopped
2021-05-14T21:40:00.676Z,1621028400.676 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-05-14T21:40:00.676Z,1621028400.676 [Default:CheckIn](INFO): Running loop #11
2021-05-14T21:40:00.676Z,1621028400.676 [Default:CheckIn] Running Loop=11
2021-05-14T21:40:00.676Z,1621028400.676 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-05-14T21:40:00.677Z,1621028400.677 [Default:CheckIn:Read_GPS] Running Loop=1
2021-05-14T21:41:29.199Z,1621028489.199 [CBIT](INFO): Clearing failed state for component NAL9602
2021-05-14T21:41:29.200Z,1621028489.200 [NAL9602] No Fault, FailCount= 5
2021-05-14T21:41:29.570Z,1621028489.570 [NAL9602](INFO): Powering up NAL9602
2021-05-14T21:41:40.487Z,1621028500.487 [NAL9602](INFO): NAL9602 initialized
2021-05-14T21:42:14.446Z,1621028534.446 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12
2021-05-14T21:42:14.446Z,1621028534.446 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T21:42:14.491Z,1621028534.491 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T21:42:14.867Z,1621028534.867 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T21:42:14.867Z,1621028534.867 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12
2021-05-14T21:45:00.894Z,1621028700.894 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-05-14T21:40:00.7Z
2021-05-14T21:45:00.894Z,1621028700.894 [Default:CheckIn:Read_GPS] Stopped
2021-05-14T21:45:00.894Z,1621028700.894 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-05-14T21:45:08.148Z,1621028708.148 [DataOverHttps](INFO): Sending 81 bytes from file Logs/20210514T195034/Courier0034.lzma
2021-05-14T21:45:09.151Z,1621028709.151 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Courier0034.lzma.bak
2021-05-14T21:45:09.151Z,1621028709.151 [DataOverHttps](INFO): SBD MOMSN=15647142
2021-05-14T21:45:15.445Z,1621028715.445 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13
2021-05-14T21:45:15.445Z,1621028715.445 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T21:45:15.476Z,1621028715.476 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T21:45:15.852Z,1621028715.852 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T21:45:15.852Z,1621028715.852 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13
2021-05-14T21:45:25.964Z,1621028725.964 [DataOverHttps](INFO): Sending 184 bytes from file Logs/20210514T195034/Express0035.lzma
2021-05-14T21:45:26.967Z,1621028726.967 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Express0035.lzma.bak
2021-05-14T21:45:26.967Z,1621028726.967 [DataOverHttps](INFO): SBD MOMSN=15647145
2021-05-14T21:45:29.574Z,1621028729.574 [Default:CheckIn:Read_Iridium] Stopped
2021-05-14T21:45:29.574Z,1621028729.574 [Default:CheckIn:C.Wait] Running Loop=1
2021-05-14T21:45:29.574Z,1621028729.574 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-05-14T21:48:16.434Z,1621028896.434 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 14
2021-05-14T21:48:16.434Z,1621028896.434 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T21:48:16.445Z,1621028896.445 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T21:48:16.860Z,1621028896.860 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T21:48:16.860Z,1621028896.860 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 14
2021-05-14T21:50:30.179Z,1621029030.179 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-05-14T21:50:30.180Z,1621029030.180 [Default:CheckIn:C.Wait] Stopped
2021-05-14T21:50:30.180Z,1621029030.180 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-05-14T21:50:30.180Z,1621029030.180 [Default:CheckIn:D] Running Loop=1
2021-05-14T21:50:30.543Z,1621029030.543 [Default:CheckIn:D] Stopped
2021-05-14T21:50:30.544Z,1621029030.544 [Default:CheckIn:E] Running Loop=1
2021-05-14T21:50:30.956Z,1621029030.956 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 115.896468 min 
2021-05-14T21:50:30.956Z,1621029030.956 [Default:CheckIn:E] Stopped
2021-05-14T21:50:30.957Z,1621029030.957 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-05-14T21:50:30.958Z,1621029030.958 [Default:CheckIn] Stopped
2021-05-14T21:50:30.958Z,1621029030.958 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-05-14T21:50:30.959Z,1621029030.959 [Default:CheckIn](INFO): Running loop #12
2021-05-14T21:50:30.959Z,1621029030.959 [Default:CheckIn] Running Loop=12
2021-05-14T21:50:30.959Z,1621029030.959 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-05-14T21:50:30.960Z,1621029030.960 [Default:CheckIn:Read_GPS] Running Loop=1
2021-05-14T21:51:17.430Z,1621029077.430 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 15
2021-05-14T21:51:17.430Z,1621029077.430 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T21:51:17.441Z,1621029077.441 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T21:51:17.844Z,1621029077.844 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T21:51:17.844Z,1621029077.844 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 15
2021-05-14T21:51:41.631Z,1621029101.631 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-05-14T21:51:41.631Z,1621029101.631 [NAL9602] Data Fault, FailCount= 1
2021-05-14T21:51:41.631Z,1621029101.631 [NAL9602](ERROR): Data Fault
2021-05-14T21:51:41.679Z,1621029101.679 [CBIT](ERROR): Data Fault in component: NAL9602
2021-05-14T21:51:42.034Z,1621029102.034 [NAL9602](INFO): Powering down
2021-05-14T21:51:42.868Z,1621029102.868 [CBIT](INFO): Clearing failed state for component NAL9602
2021-05-14T21:51:42.869Z,1621029102.869 [NAL9602] No Fault, FailCount= 1
2021-05-14T21:52:12.340Z,1621029132.340 [NAL9602](INFO): Powering up NAL9602
2021-05-14T21:52:23.248Z,1621029143.248 [NAL9602](INFO): NAL9602 initialized
2021-05-14T21:54:18.405Z,1621029258.405 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 16
2021-05-14T21:54:18.405Z,1621029258.405 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T21:54:18.444Z,1621029258.444 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T21:54:18.816Z,1621029258.816 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T21:54:18.816Z,1621029258.816 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 16
2021-05-14T21:55:31.139Z,1621029331.139 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-05-14T21:50:30.0Z
2021-05-14T21:55:31.140Z,1621029331.140 [Default:CheckIn:Read_GPS] Stopped
2021-05-14T21:55:31.140Z,1621029331.140 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-05-14T21:55:38.832Z,1621029338.832 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210514T195034/Courier0037.lzma
2021-05-14T21:55:39.835Z,1621029339.835 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Courier0037.lzma.bak
2021-05-14T21:55:39.835Z,1621029339.835 [DataOverHttps](INFO): SBD MOMSN=15647182
2021-05-14T21:55:56.633Z,1621029356.633 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20210514T195034/Express0038.lzma
2021-05-14T21:55:57.635Z,1621029357.635 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Express0038.lzma.bak
2021-05-14T21:55:57.635Z,1621029357.635 [DataOverHttps](INFO): SBD MOMSN=15647184
2021-05-14T21:56:00.211Z,1621029360.211 [Default:CheckIn:Read_Iridium] Stopped
2021-05-14T21:56:00.212Z,1621029360.212 [Default:CheckIn:C.Wait] Running Loop=1
2021-05-14T21:56:00.212Z,1621029360.212 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-05-14T21:57:19.382Z,1621029439.382 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 17
2021-05-14T21:57:19.382Z,1621029439.382 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T21:57:19.393Z,1621029439.393 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T21:57:19.804Z,1621029439.804 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T21:57:19.804Z,1621029439.804 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 17
2021-05-14T22:00:20.414Z,1621029620.414 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 18
2021-05-14T22:00:20.414Z,1621029620.414 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T22:00:20.425Z,1621029620.425 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T22:00:20.833Z,1621029620.833 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T22:00:20.833Z,1621029620.833 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 18
2021-05-14T22:01:00.800Z,1621029660.800 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-05-14T22:01:00.801Z,1621029660.801 [Default:CheckIn:C.Wait] Stopped
2021-05-14T22:01:00.801Z,1621029660.801 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-05-14T22:01:00.809Z,1621029660.809 [Default:CheckIn:D] Running Loop=1
2021-05-14T22:01:01.207Z,1621029661.207 [Default:CheckIn:D] Stopped
2021-05-14T22:01:01.207Z,1621029661.207 [Default:CheckIn:E] Running Loop=1
2021-05-14T22:01:01.628Z,1621029661.628 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 126.407536 min 
2021-05-14T22:01:01.628Z,1621029661.628 [Default:CheckIn:E] Stopped
2021-05-14T22:01:01.628Z,1621029661.628 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-05-14T22:01:01.628Z,1621029661.628 [Default:CheckIn] Stopped
2021-05-14T22:01:01.628Z,1621029661.628 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-05-14T22:01:01.628Z,1621029661.628 [Default:CheckIn](INFO): Running loop #13
2021-05-14T22:01:01.628Z,1621029661.628 [Default:CheckIn] Running Loop=13
2021-05-14T22:01:01.628Z,1621029661.628 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-05-14T22:01:01.629Z,1621029661.629 [Default:CheckIn:Read_GPS] Running Loop=1
2021-05-14T22:02:25.635Z,1621029745.635 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-05-14T22:02:25.635Z,1621029745.635 [NAL9602] Data Fault, FailCount= 2
2021-05-14T22:02:25.635Z,1621029745.635 [NAL9602](ERROR): Data Fault
2021-05-14T22:02:25.682Z,1621029745.682 [CBIT](ERROR): Data Fault in component: NAL9602
2021-05-14T22:02:26.034Z,1621029746.034 [NAL9602](INFO): Powering down
2021-05-14T22:02:26.876Z,1621029746.876 [CBIT](INFO): Clearing failed state for component NAL9602
2021-05-14T22:02:26.876Z,1621029746.876 [NAL9602] No Fault, FailCount= 2
2021-05-14T22:02:56.334Z,1621029776.334 [NAL9602](INFO): Powering up NAL9602
2021-05-14T22:03:07.246Z,1621029787.246 [NAL9602](INFO): NAL9602 initialized
2021-05-14T22:03:21.404Z,1621029801.404 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 19
2021-05-14T22:03:21.404Z,1621029801.404 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T22:03:21.414Z,1621029801.414 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T22:03:21.818Z,1621029801.818 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T22:03:21.818Z,1621029801.818 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 19
2021-05-14T22:06:01.796Z,1621029961.796 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-05-14T22:01:01.6Z
2021-05-14T22:06:01.796Z,1621029961.796 [Default:CheckIn:Read_GPS] Stopped
2021-05-14T22:06:01.796Z,1621029961.796 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-05-14T22:06:08.772Z,1621029968.772 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210514T195034/Courier0040.lzma
2021-05-14T22:06:09.775Z,1621029969.775 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Courier0040.lzma.bak
2021-05-14T22:06:09.775Z,1621029969.775 [DataOverHttps](INFO): SBD MOMSN=15647207
2021-05-14T22:06:22.398Z,1621029982.398 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 20
2021-05-14T22:06:22.398Z,1621029982.398 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T22:06:22.421Z,1621029982.421 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T22:06:22.422Z,1621029982.422 [CBIT](FAULT): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T22:06:26.500Z,1621029986.500 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20210514T195034/Express0041.lzma
2021-05-14T22:06:27.503Z,1621029987.503 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Express0041.lzma.bak
2021-05-14T22:06:27.503Z,1621029987.503 [DataOverHttps](INFO): SBD MOMSN=15647209
2021-05-14T22:06:30.094Z,1621029990.094 [Default:CheckIn:Read_Iridium] Stopped
2021-05-14T22:06:30.094Z,1621029990.094 [Default:CheckIn:C.Wait] Running Loop=1
2021-05-14T22:06:30.094Z,1621029990.094 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-05-14T22:11:30.650Z,1621030290.650 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-05-14T22:11:30.651Z,1621030290.651 [Default:CheckIn:C.Wait] Stopped
2021-05-14T22:11:30.651Z,1621030290.651 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-05-14T22:11:30.651Z,1621030290.651 [Default:CheckIn:D] Running Loop=1
2021-05-14T22:11:31.063Z,1621030291.063 [Default:CheckIn:D] Stopped
2021-05-14T22:11:31.063Z,1621030291.063 [Default:CheckIn:E] Running Loop=1
2021-05-14T22:11:31.461Z,1621030291.461 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 136.905111 min 
2021-05-14T22:11:31.461Z,1621030291.461 [Default:CheckIn:E] Stopped
2021-05-14T22:11:31.461Z,1621030291.461 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-05-14T22:11:31.461Z,1621030291.461 [Default:CheckIn] Stopped
2021-05-14T22:11:31.461Z,1621030291.461 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-05-14T22:11:31.461Z,1621030291.461 [Default:CheckIn](INFO): Running loop #14
2021-05-14T22:11:31.462Z,1621030291.462 [Default:CheckIn] Running Loop=14
2021-05-14T22:11:31.462Z,1621030291.462 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-05-14T22:11:31.462Z,1621030291.462 [Default:CheckIn:Read_GPS] Running Loop=1
2021-05-14T22:12:47.486Z,1621030367.486 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-05-14T22:13:01.531Z,1621030381.531 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2021-05-14T22:13:01.534Z,1621030381.534 [BPC1](INFO): Received data from all battery sticks.
2021-05-14T22:13:09.607Z,1621030389.607 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-05-14T22:13:09.607Z,1621030389.607 [NAL9602] Data Fault, FailCount= 3
2021-05-14T22:13:09.607Z,1621030389.607 [NAL9602](ERROR): Data Fault
2021-05-14T22:13:09.663Z,1621030389.663 [CBIT](ERROR): Data Fault in component: NAL9602
2021-05-14T22:13:10.010Z,1621030390.010 [NAL9602](INFO): Powering down
2021-05-14T22:13:10.414Z,1621030390.414 [NAL9602](FAULT): LCB fault:  Software Overcurrent.
2021-05-14T22:13:10.414Z,1621030390.414 [NAL9602] Hardware Fault, FailCount= 3
2021-05-14T22:13:10.414Z,1621030390.414 [NAL9602](ERROR): Hardware Fault
2021-05-14T22:13:10.868Z,1621030390.868 [CBIT](INFO): Clearing failed state for component NAL9602
2021-05-14T22:13:10.868Z,1621030390.868 [NAL9602] No Fault, FailCount= 3
2021-05-14T22:13:40.315Z,1621030420.315 [NAL9602](INFO): Powering up NAL9602
2021-05-14T22:13:51.222Z,1621030431.222 [NAL9602](INFO): NAL9602 initialized
2021-05-14T22:16:31.641Z,1621030591.641 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-05-14T22:11:31.5Z
2021-05-14T22:16:31.641Z,1621030591.641 [Default:CheckIn:Read_GPS] Stopped
2021-05-14T22:16:31.641Z,1621030591.641 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-05-14T22:16:38.244Z,1621030598.244 [DataOverHttps](INFO): Sending 50 bytes from file Logs/20210514T195034/Courier0043.lzma
2021-05-14T22:16:39.247Z,1621030599.247 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Courier0043.lzma.bak
2021-05-14T22:16:39.247Z,1621030599.247 [DataOverHttps](INFO): SBD MOMSN=15647226
2021-05-14T22:16:55.977Z,1621030615.977 [DataOverHttps](INFO): Sending 240 bytes from file Logs/20210514T195034/Express0044.lzma
2021-05-14T22:16:56.979Z,1621030616.979 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Express0044.lzma.bak
2021-05-14T22:16:56.979Z,1621030616.979 [DataOverHttps](INFO): SBD MOMSN=15647228
2021-05-14T22:16:59.562Z,1621030619.562 [Default:CheckIn:Read_Iridium] Stopped
2021-05-14T22:16:59.562Z,1621030619.562 [Default:CheckIn:C.Wait] Running Loop=1
2021-05-14T22:16:59.562Z,1621030619.562 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-05-14T22:21:22.552Z,1621030882.552 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T22:21:22.552Z,1621030882.552 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 20
2021-05-14T22:22:00.116Z,1621030920.116 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-05-14T22:22:00.116Z,1621030920.116 [Default:CheckIn:C.Wait] Stopped
2021-05-14T22:22:00.116Z,1621030920.116 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-05-14T22:22:00.116Z,1621030920.116 [Default:CheckIn:D] Running Loop=1
2021-05-14T22:22:00.519Z,1621030920.519 [Default:CheckIn:D] Stopped
2021-05-14T22:22:00.519Z,1621030920.519 [Default:CheckIn:E] Running Loop=1
2021-05-14T22:22:00.944Z,1621030920.944 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 147.396061 min 
2021-05-14T22:22:00.944Z,1621030920.944 [Default:CheckIn:E] Stopped
2021-05-14T22:22:00.944Z,1621030920.944 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-05-14T22:22:00.944Z,1621030920.944 [Default:CheckIn] Stopped
2021-05-14T22:22:00.944Z,1621030920.944 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-05-14T22:22:00.944Z,1621030920.944 [Default:CheckIn](INFO): Running loop #15
2021-05-14T22:22:00.944Z,1621030920.944 [Default:CheckIn] Running Loop=15
2021-05-14T22:22:00.945Z,1621030920.945 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-05-14T22:22:00.945Z,1621030920.945 [Default:CheckIn:Read_GPS] Running Loop=1
2021-05-14T22:23:53.626Z,1621031033.626 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-05-14T22:23:53.626Z,1621031033.626 [NAL9602] Data Fault, FailCount= 4
2021-05-14T22:23:53.627Z,1621031033.627 [NAL9602](ERROR): Data Fault
2021-05-14T22:23:53.646Z,1621031033.646 [CBIT](ERROR): Data Fault in component: NAL9602
2021-05-14T22:23:54.030Z,1621031034.030 [NAL9602](INFO): Powering down
2021-05-14T22:23:54.860Z,1621031034.860 [CBIT](INFO): Clearing failed state for component NAL9602
2021-05-14T22:23:54.860Z,1621031034.860 [NAL9602] No Fault, FailCount= 4
2021-05-14T22:24:23.126Z,1621031063.126 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2021-05-14T22:24:23.126Z,1621031063.126 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T22:24:23.136Z,1621031063.136 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T22:24:23.551Z,1621031063.551 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T22:24:23.551Z,1621031063.551 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2021-05-14T22:24:24.334Z,1621031064.334 [NAL9602](INFO): Powering up NAL9602
2021-05-14T22:24:35.242Z,1621031075.242 [NAL9602](INFO): NAL9602 initialized
2021-05-14T22:27:01.095Z,1621031221.095 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-05-14T22:22:00.9Z
2021-05-14T22:27:01.095Z,1621031221.095 [Default:CheckIn:Read_GPS] Stopped
2021-05-14T22:27:01.096Z,1621031221.096 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-05-14T22:27:08.104Z,1621031228.104 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210514T195034/Courier0046.lzma
2021-05-14T22:27:09.107Z,1621031229.107 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Courier0046.lzma.bak
2021-05-14T22:27:09.107Z,1621031229.107 [DataOverHttps](INFO): SBD MOMSN=15647267
2021-05-14T22:27:24.153Z,1621031244.153 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2021-05-14T22:27:24.153Z,1621031244.153 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T22:27:24.172Z,1621031244.172 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T22:27:24.575Z,1621031244.575 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T22:27:24.575Z,1621031244.575 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2021-05-14T22:27:26.654Z,1621031246.654 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20210514T195034/Express0047.lzma
2021-05-14T22:27:27.655Z,1621031247.655 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Express0047.lzma.bak
2021-05-14T22:27:27.655Z,1621031247.655 [DataOverHttps](INFO): SBD MOMSN=15647269
2021-05-14T22:27:30.222Z,1621031250.222 [Default:CheckIn:Read_Iridium] Stopped
2021-05-14T22:27:30.223Z,1621031250.223 [Default:CheckIn:C.Wait] Running Loop=1
2021-05-14T22:27:30.223Z,1621031250.223 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-05-14T22:30:25.134Z,1621031425.134 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2021-05-14T22:30:25.134Z,1621031425.134 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T22:30:25.145Z,1621031425.145 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T22:30:25.551Z,1621031425.551 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T22:30:25.551Z,1621031425.551 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2021-05-14T22:32:30.774Z,1621031550.774 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-05-14T22:32:30.774Z,1621031550.774 [Default:CheckIn:C.Wait] Stopped
2021-05-14T22:32:30.774Z,1621031550.774 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-05-14T22:32:30.774Z,1621031550.774 [Default:CheckIn:D] Running Loop=1
2021-05-14T22:32:31.175Z,1621031551.175 [Default:CheckIn:D] Stopped
2021-05-14T22:32:31.175Z,1621031551.175 [Default:CheckIn:E] Running Loop=1
2021-05-14T22:32:31.564Z,1621031551.564 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 157.906999 min 
2021-05-14T22:32:31.564Z,1621031551.564 [Default:CheckIn:E] Stopped
2021-05-14T22:32:31.564Z,1621031551.564 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-05-14T22:32:31.564Z,1621031551.564 [Default:CheckIn] Stopped
2021-05-14T22:32:31.564Z,1621031551.564 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-05-14T22:32:31.564Z,1621031551.564 [Default:CheckIn](INFO): Running loop #16
2021-05-14T22:32:31.564Z,1621031551.564 [Default:CheckIn] Running Loop=16
2021-05-14T22:32:31.564Z,1621031551.564 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-05-14T22:32:31.565Z,1621031551.565 [Default:CheckIn:Read_GPS] Running Loop=1
2021-05-14T22:33:26.106Z,1621031606.106 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2021-05-14T22:33:26.106Z,1621031606.106 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T22:33:26.117Z,1621031606.117 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T22:33:26.527Z,1621031606.527 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T22:33:26.527Z,1621031606.527 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2021-05-14T22:34:36.391Z,1621031676.391 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-05-14T22:34:36.391Z,1621031676.391 [NAL9602] Data Fault, FailCount= 5
2021-05-14T22:34:36.391Z,1621031676.391 [NAL9602](ERROR): Data Fault
2021-05-14T22:34:36.437Z,1621031676.437 [CBIT](ERROR): Data Fault in component: NAL9602
2021-05-14T22:34:36.438Z,1621031676.438 [CBIT](CRITICAL): Data Fault in component: NAL9602
2021-05-14T22:34:36.794Z,1621031676.794 [NAL9602](INFO): Powering down
2021-05-14T22:34:36.835Z,1621031676.835 [CBIT](INFO): Critical error at 20210514T223436
2021-05-14T22:36:27.111Z,1621031787.111 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2021-05-14T22:36:27.111Z,1621031787.111 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T22:36:27.122Z,1621031787.122 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T22:36:27.512Z,1621031787.512 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T22:36:27.512Z,1621031787.512 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2021-05-14T22:36:36.409Z,1621031796.409 [CBIT](INFO): Clearing failed state for component NAL9602
2021-05-14T22:36:36.409Z,1621031796.409 [NAL9602] No Fault, FailCount= 5
2021-05-14T22:36:36.782Z,1621031796.782 [NAL9602](INFO): Powering up NAL9602
2021-05-14T22:36:47.696Z,1621031807.696 [NAL9602](INFO): NAL9602 initialized
2021-05-14T22:37:31.760Z,1621031851.760 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-05-14T22:32:31.6Z
2021-05-14T22:37:31.760Z,1621031851.760 [Default:CheckIn:Read_GPS] Stopped
2021-05-14T22:37:31.760Z,1621031851.760 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-05-14T22:37:39.032Z,1621031859.032 [DataOverHttps](INFO): Sending 81 bytes from file Logs/20210514T195034/Courier0049.lzma
2021-05-14T22:37:40.035Z,1621031860.035 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Courier0049.lzma.bak
2021-05-14T22:37:40.035Z,1621031860.035 [DataOverHttps](INFO): SBD MOMSN=15647301
2021-05-14T22:37:57.320Z,1621031877.320 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20210514T195034/Express0050.lzma
2021-05-14T22:37:58.323Z,1621031878.323 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Express0050.lzma.bak
2021-05-14T22:37:58.323Z,1621031878.323 [DataOverHttps](INFO): SBD MOMSN=15647304
2021-05-14T22:38:00.838Z,1621031880.838 [Default:CheckIn:Read_Iridium] Stopped
2021-05-14T22:38:00.838Z,1621031880.838 [Default:CheckIn:C.Wait] Running Loop=1
2021-05-14T22:38:00.838Z,1621031880.838 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-05-14T22:39:28.114Z,1621031968.114 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2021-05-14T22:39:28.114Z,1621031968.114 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T22:39:28.125Z,1621031968.125 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T22:39:28.530Z,1621031968.530 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T22:39:28.531Z,1621031968.531 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2021-05-14T22:42:29.130Z,1621032149.130 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2021-05-14T22:42:29.130Z,1621032149.130 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T22:42:29.141Z,1621032149.141 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T22:42:29.571Z,1621032149.571 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T22:42:29.571Z,1621032149.571 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2021-05-14T22:43:01.443Z,1621032181.443 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-05-14T22:43:01.443Z,1621032181.443 [Default:CheckIn:C.Wait] Stopped
2021-05-14T22:43:01.443Z,1621032181.443 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-05-14T22:43:01.443Z,1621032181.443 [Default:CheckIn:D] Running Loop=1
2021-05-14T22:43:01.859Z,1621032181.859 [Default:CheckIn:D] Stopped
2021-05-14T22:43:01.859Z,1621032181.859 [Default:CheckIn:E] Running Loop=1
2021-05-14T22:43:02.252Z,1621032182.252 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 168.418392 min 
2021-05-14T22:43:02.252Z,1621032182.252 [Default:CheckIn:E] Stopped
2021-05-14T22:43:02.252Z,1621032182.252 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-05-14T22:43:02.252Z,1621032182.252 [Default:CheckIn] Stopped
2021-05-14T22:43:02.252Z,1621032182.252 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-05-14T22:43:02.252Z,1621032182.252 [Default:CheckIn](INFO): Running loop #17
2021-05-14T22:43:02.252Z,1621032182.252 [Default:CheckIn] Running Loop=17
2021-05-14T22:43:02.253Z,1621032182.253 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-05-14T22:43:02.269Z,1621032182.269 [Default:CheckIn:Read_GPS] Running Loop=1
2021-05-14T22:45:30.124Z,1621032330.124 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2021-05-14T22:45:30.124Z,1621032330.124 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T22:45:30.134Z,1621032330.134 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T22:45:30.539Z,1621032330.539 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T22:45:30.540Z,1621032330.540 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2021-05-14T22:46:50.094Z,1621032410.094 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-05-14T22:46:50.094Z,1621032410.094 [NAL9602] Data Fault, FailCount= 1
2021-05-14T22:46:50.094Z,1621032410.094 [NAL9602](ERROR): Data Fault
2021-05-14T22:46:50.140Z,1621032410.140 [CBIT](ERROR): Data Fault in component: NAL9602
2021-05-14T22:46:50.498Z,1621032410.498 [NAL9602](INFO): Powering down
2021-05-14T22:46:51.344Z,1621032411.344 [CBIT](INFO): Clearing failed state for component NAL9602
2021-05-14T22:46:51.344Z,1621032411.344 [NAL9602] No Fault, FailCount= 1
2021-05-14T22:47:20.802Z,1621032440.802 [NAL9602](INFO): Powering up NAL9602
2021-05-14T22:47:31.710Z,1621032451.710 [NAL9602](INFO): NAL9602 initialized
2021-05-14T22:48:02.432Z,1621032482.432 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-05-14T22:43:02.3Z
2021-05-14T22:48:02.432Z,1621032482.432 [Default:CheckIn:Read_GPS] Stopped
2021-05-14T22:48:02.432Z,1621032482.432 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-05-14T22:48:09.672Z,1621032489.672 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210514T195034/Courier0052.lzma
2021-05-14T22:48:10.675Z,1621032490.675 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Courier0052.lzma.bak
2021-05-14T22:48:10.675Z,1621032490.675 [DataOverHttps](INFO): SBD MOMSN=15647332
2021-05-14T22:48:27.513Z,1621032507.513 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20210514T195034/Express0053.lzma
2021-05-14T22:48:28.515Z,1621032508.515 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Express0053.lzma.bak
2021-05-14T22:48:28.515Z,1621032508.515 [DataOverHttps](INFO): SBD MOMSN=15647334
2021-05-14T22:48:31.138Z,1621032511.138 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2021-05-14T22:48:31.138Z,1621032511.138 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T22:48:31.139Z,1621032511.139 [Default:CheckIn:Read_Iridium] Stopped
2021-05-14T22:48:31.139Z,1621032511.139 [Default:CheckIn:C.Wait] Running Loop=1
2021-05-14T22:48:31.139Z,1621032511.139 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-05-14T22:48:31.153Z,1621032511.153 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T22:48:31.557Z,1621032511.557 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T22:48:31.557Z,1621032511.557 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2021-05-14T22:51:32.118Z,1621032692.118 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2021-05-14T22:51:32.119Z,1621032692.119 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T22:51:32.129Z,1621032692.129 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T22:51:32.512Z,1621032692.512 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T22:51:32.512Z,1621032692.512 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2021-05-14T22:53:31.698Z,1621032811.698 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-05-14T22:53:31.698Z,1621032811.698 [Default:CheckIn:C.Wait] Stopped
2021-05-14T22:53:31.698Z,1621032811.698 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-05-14T22:53:31.698Z,1621032811.698 [Default:CheckIn:D] Running Loop=1
2021-05-14T22:53:32.084Z,1621032812.084 [Default:CheckIn:D] Stopped
2021-05-14T22:53:32.085Z,1621032812.085 [Default:CheckIn:E] Running Loop=1
2021-05-14T22:53:32.488Z,1621032812.488 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 178.922152 min 
2021-05-14T22:53:32.488Z,1621032812.488 [Default:CheckIn:E] Stopped
2021-05-14T22:53:32.488Z,1621032812.488 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-05-14T22:53:32.488Z,1621032812.488 [Default:CheckIn] Stopped
2021-05-14T22:53:32.488Z,1621032812.488 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-05-14T22:53:32.488Z,1621032812.488 [Default:CheckIn](INFO): Running loop #18
2021-05-14T22:53:32.489Z,1621032812.489 [Default:CheckIn] Running Loop=18
2021-05-14T22:53:32.489Z,1621032812.489 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-05-14T22:53:32.489Z,1621032812.489 [Default:CheckIn:Read_GPS] Running Loop=1
2021-05-14T22:54:33.107Z,1621032873.107 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2021-05-14T22:54:33.107Z,1621032873.107 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T22:54:33.137Z,1621032873.137 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T22:54:33.526Z,1621032873.526 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T22:54:33.527Z,1621032873.527 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2021-05-14T22:57:32.862Z,1621033052.862 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-05-14T22:57:32.862Z,1621033052.862 [NAL9602] Data Fault, FailCount= 2
2021-05-14T22:57:32.863Z,1621033052.863 [NAL9602](ERROR): Data Fault
2021-05-14T22:57:32.913Z,1621033052.913 [CBIT](ERROR): Data Fault in component: NAL9602
2021-05-14T22:57:33.262Z,1621033053.262 [NAL9602](INFO): Powering down
2021-05-14T22:57:33.666Z,1621033053.666 [NAL9602](FAULT): LCB fault:  Software Overcurrent.
2021-05-14T22:57:33.666Z,1621033053.666 [NAL9602] Hardware Fault, FailCount= 2
2021-05-14T22:57:33.666Z,1621033053.666 [NAL9602](ERROR): Hardware Fault
2021-05-14T22:57:34.094Z,1621033054.094 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12
2021-05-14T22:57:34.094Z,1621033054.094 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T22:57:34.105Z,1621033054.105 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T22:57:34.105Z,1621033054.105 [CBIT](INFO): Clearing failed state for component NAL9602
2021-05-14T22:57:34.105Z,1621033054.105 [NAL9602] No Fault, FailCount= 2
2021-05-14T22:57:34.514Z,1621033054.514 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T22:57:34.514Z,1621033054.514 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12
2021-05-14T22:58:03.562Z,1621033083.562 [NAL9602](INFO): Powering up NAL9602
2021-05-14T22:58:14.474Z,1621033094.474 [NAL9602](INFO): NAL9602 initialized
2021-05-14T22:58:32.690Z,1621033112.690 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-05-14T22:53:32.5Z
2021-05-14T22:58:32.690Z,1621033112.690 [Default:CheckIn:Read_GPS] Stopped
2021-05-14T22:58:32.690Z,1621033112.690 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-05-14T22:58:40.080Z,1621033120.080 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210514T195034/Courier0055.lzma
2021-05-14T22:58:41.083Z,1621033121.083 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Courier0055.lzma.bak
2021-05-14T22:58:41.083Z,1621033121.083 [DataOverHttps](INFO): SBD MOMSN=15647386
2021-05-14T22:58:57.848Z,1621033137.848 [DataOverHttps](INFO): Sending 183 bytes from file Logs/20210514T195034/Express0056.lzma
2021-05-14T22:58:58.851Z,1621033138.851 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Express0056.lzma.bak
2021-05-14T22:58:58.851Z,1621033138.851 [DataOverHttps](INFO): SBD MOMSN=15647389
2021-05-14T22:59:01.392Z,1621033141.392 [Default:CheckIn:Read_Iridium] Stopped
2021-05-14T22:59:01.392Z,1621033141.392 [Default:CheckIn:C.Wait] Running Loop=1
2021-05-14T22:59:01.392Z,1621033141.392 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-05-14T23:00:35.099Z,1621033235.099 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13
2021-05-14T23:00:35.099Z,1621033235.099 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T23:00:35.109Z,1621033235.109 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T23:00:35.517Z,1621033235.517 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T23:00:35.517Z,1621033235.517 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13
2021-05-14T23:03:36.087Z,1621033416.087 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 14
2021-05-14T23:03:36.087Z,1621033416.087 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T23:03:36.117Z,1621033416.117 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T23:03:36.524Z,1621033416.524 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T23:03:36.524Z,1621033416.524 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 14
2021-05-14T23:04:01.971Z,1621033441.971 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-05-14T23:04:01.971Z,1621033441.971 [Default:CheckIn:C.Wait] Stopped
2021-05-14T23:04:01.972Z,1621033441.972 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-05-14T23:04:01.972Z,1621033441.972 [Default:CheckIn:D] Running Loop=1
2021-05-14T23:04:02.379Z,1621033442.379 [Default:CheckIn:D] Stopped
2021-05-14T23:04:02.379Z,1621033442.379 [Default:CheckIn:E] Running Loop=1
2021-05-14T23:04:02.768Z,1621033442.768 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 189.427051 min 
2021-05-14T23:04:02.768Z,1621033442.768 [Default:CheckIn:E] Stopped
2021-05-14T23:04:02.768Z,1621033442.768 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-05-14T23:04:02.768Z,1621033442.768 [Default:CheckIn] Stopped
2021-05-14T23:04:02.768Z,1621033442.768 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-05-14T23:04:02.768Z,1621033442.768 [Default:CheckIn](INFO): Running loop #19
2021-05-14T23:04:02.768Z,1621033442.768 [Default:CheckIn] Running Loop=19
2021-05-14T23:04:02.769Z,1621033442.769 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-05-14T23:04:02.797Z,1621033442.797 [Default:CheckIn:Read_GPS] Running Loop=1
2021-05-14T23:06:37.087Z,1621033597.087 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 15
2021-05-14T23:06:37.087Z,1621033597.087 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T23:06:37.118Z,1621033597.118 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T23:06:37.496Z,1621033597.496 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T23:06:37.496Z,1621033597.496 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 15
2021-05-14T23:08:16.054Z,1621033696.054 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-05-14T23:08:16.055Z,1621033696.055 [NAL9602] Data Fault, FailCount= 3
2021-05-14T23:08:16.055Z,1621033696.055 [NAL9602](ERROR): Data Fault
2021-05-14T23:08:16.097Z,1621033696.097 [CBIT](ERROR): Data Fault in component: NAL9602
2021-05-14T23:08:16.454Z,1621033696.454 [NAL9602](INFO): Powering down
2021-05-14T23:08:17.292Z,1621033697.292 [CBIT](INFO): Clearing failed state for component NAL9602
2021-05-14T23:08:17.292Z,1621033697.292 [NAL9602] No Fault, FailCount= 3
2021-05-14T23:08:46.758Z,1621033726.758 [NAL9602](INFO): Powering up NAL9602
2021-05-14T23:08:57.669Z,1621033737.669 [NAL9602](INFO): NAL9602 initialized
2021-05-14T23:09:02.924Z,1621033742.924 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-05-14T23:04:02.8Z
2021-05-14T23:09:02.924Z,1621033742.924 [Default:CheckIn:Read_GPS] Stopped
2021-05-14T23:09:02.924Z,1621033742.924 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-05-14T23:09:10.440Z,1621033750.440 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210514T195034/Courier0058.lzma
2021-05-14T23:09:11.443Z,1621033751.443 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Courier0058.lzma.bak
2021-05-14T23:09:11.443Z,1621033751.443 [DataOverHttps](INFO): SBD MOMSN=15647416
2021-05-14T23:09:28.129Z,1621033768.129 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20210514T195034/Express0059.lzma
2021-05-14T23:09:29.131Z,1621033769.131 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Express0059.lzma.bak
2021-05-14T23:09:29.131Z,1621033769.131 [DataOverHttps](INFO): SBD MOMSN=15647418
2021-05-14T23:09:31.637Z,1621033771.637 [Default:CheckIn:Read_Iridium] Stopped
2021-05-14T23:09:31.637Z,1621033771.637 [Default:CheckIn:C.Wait] Running Loop=1
2021-05-14T23:09:31.637Z,1621033771.637 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-05-14T23:09:38.097Z,1621033778.097 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 16
2021-05-14T23:09:38.098Z,1621033778.098 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T23:09:38.108Z,1621033778.108 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T23:09:38.510Z,1621033778.510 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T23:09:38.511Z,1621033778.511 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 16
2021-05-14T23:12:39.099Z,1621033959.099 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 17
2021-05-14T23:12:39.099Z,1621033959.099 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T23:12:39.109Z,1621033959.109 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T23:12:39.520Z,1621033959.520 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T23:12:39.520Z,1621033959.520 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 17
2021-05-14T23:14:32.220Z,1621034072.220 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-05-14T23:14:32.221Z,1621034072.221 [Default:CheckIn:C.Wait] Stopped
2021-05-14T23:14:32.223Z,1621034072.223 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-05-14T23:14:32.223Z,1621034072.223 [Default:CheckIn:D] Running Loop=1
2021-05-14T23:14:32.628Z,1621034072.628 [Default:CheckIn:D] Stopped
2021-05-14T23:14:32.628Z,1621034072.628 [Default:CheckIn:E] Running Loop=1
2021-05-14T23:14:33.048Z,1621034073.048 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 199.931217 min 
2021-05-14T23:14:33.048Z,1621034073.048 [Default:CheckIn:E] Stopped
2021-05-14T23:14:33.048Z,1621034073.048 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-05-14T23:14:33.048Z,1621034073.048 [Default:CheckIn] Stopped
2021-05-14T23:14:33.048Z,1621034073.048 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-05-14T23:14:33.048Z,1621034073.048 [Default:CheckIn](INFO): Running loop #20
2021-05-14T23:14:33.048Z,1621034073.048 [Default:CheckIn] Running Loop=20
2021-05-14T23:14:33.048Z,1621034073.048 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-05-14T23:14:33.049Z,1621034073.049 [Default:CheckIn:Read_GPS] Running Loop=1
2021-05-14T23:15:40.091Z,1621034140.091 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 18
2021-05-14T23:15:40.091Z,1621034140.091 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T23:15:40.117Z,1621034140.117 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T23:15:40.500Z,1621034140.500 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T23:15:40.500Z,1621034140.500 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 18
2021-05-14T23:18:41.075Z,1621034321.075 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 19
2021-05-14T23:18:41.075Z,1621034321.075 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T23:18:41.102Z,1621034321.102 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T23:18:41.492Z,1621034321.492 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-05-14T23:18:41.492Z,1621034321.492 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 19
2021-05-14T23:19:00.066Z,1621034340.066 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-05-14T23:19:00.066Z,1621034340.066 [NAL9602] Data Fault, FailCount= 4
2021-05-14T23:19:00.066Z,1621034340.066 [NAL9602](ERROR): Data Fault
2021-05-14T23:19:00.084Z,1621034340.084 [CBIT](ERROR): Data Fault in component: NAL9602
2021-05-14T23:19:00.458Z,1621034340.458 [NAL9602](INFO): Powering down
2021-05-14T23:19:01.291Z,1621034341.291 [CBIT](INFO): Clearing failed state for component NAL9602
2021-05-14T23:19:01.291Z,1621034341.291 [NAL9602] No Fault, FailCount= 4
2021-05-14T23:19:30.758Z,1621034370.758 [NAL9602](INFO): Powering up NAL9602
2021-05-14T23:19:33.204Z,1621034373.204 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-05-14T23:14:33.0Z
2021-05-14T23:19:33.204Z,1621034373.204 [Default:CheckIn:Read_GPS] Stopped
2021-05-14T23:19:33.204Z,1621034373.204 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-05-14T23:19:40.160Z,1621034380.160 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210514T195034/Courier0061.lzma
2021-05-14T23:19:41.163Z,1621034381.163 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Courier0061.lzma.bak
2021-05-14T23:19:41.163Z,1621034381.163 [DataOverHttps](INFO): SBD MOMSN=15647443
2021-05-14T23:19:41.666Z,1621034381.666 [NAL9602](INFO): NAL9602 initialized
2021-05-14T23:19:58.224Z,1621034398.224 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20210514T195034/Express0062.lzma
2021-05-14T23:19:59.227Z,1621034399.227 [DataOverHttps](INFO): Moved sent file to Logs/20210514T195034/Express0062.lzma.bak
2021-05-14T23:19:59.227Z,1621034399.227 [DataOverHttps](INFO): SBD MOMSN=15647445
2021-05-14T23:20:01.903Z,1621034401.903 [Default:CheckIn:Read_Iridium] Stopped
2021-05-14T23:20:01.903Z,1621034401.903 [Default:CheckIn:C.Wait] Running Loop=1
2021-05-14T23:20:01.903Z,1621034401.903 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-05-14T23:20:28.000Z,1621034429.000 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2021-05-14T23:20:29.002Z,1621034429.002 [BPC1](INFO): Received data from all battery sticks.
2021-05-14T23:21:42.162Z,1621034502.162 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 20
2021-05-14T23:21:42.162Z,1621034502.162 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-05-14T23:21:42.173Z,1621034502.173 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T23:21:42.173Z,1621034502.173 [CBIT](FAULT): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-05-14T23:25:02.518Z,1621034702.518 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-05-14T23:25:02.518Z,1621034702.518 [Default:CheckIn:C.Wait] Stopped
2021-05-14T23:25:02.518Z,1621034702.518 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-05-14T23:25:02.518Z,1621034702.518 [Default:CheckIn:D] Running Loop=1
2021-05-14T23:25:02.942Z,1621034702.942 [Default:CheckIn:D] Stopped
2021-05-14T23:25:02.943Z,1621034702.943 [Default:CheckIn:E] Running Loop=1
2021-05-14T23:25:03.338Z,1621034703.338 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 210.436458 min 
2021-05-14T23:25:03.338Z,1621034703.338 [Default:CheckIn:E] Stopped
2021-05-14T23:25:03.338Z,1621034703.338 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-05-14T23:25:03.338Z,1621034703.338 [Default:CheckIn] Stopped
2021-05-14T23:25:03.338Z,1621034703.338 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-05-14T23:25:03.339Z,1621034703.339 [Default:CheckIn](INFO): Running loop #21
2021-05-14T23:25:03.339Z,1621034703.339 [Default:CheckIn] Running Loop=21
2021-05-14T23:25:03.339Z,1621034703.339 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-05-14T23:25:03.339Z,1621034703.339 [Default:CheckIn:Read_GPS] Running Loop=1
2021-05-14T23:28:04.687Z,1621034884.687 [CommandLine](IMPORTANT): got command failComponent
2021-05-14T23:28:04.687Z,1621034884.687 [CommandLine](IMPORTANT): Failed components:
2021-05-14T23:28:04.687Z,1621034884.687 [CommandLine](IMPORTANT): DeadReckonUsingMultipleVelocitySources: Software Fault
2021-05-14T23:28:16.447Z,1621034896.447 [CommandLine](IMPORTANT): got command configSet list
2021-05-14T23:28:16.447Z,1621034896.447 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2021-05-14T23:28:16.449Z,1621034896.449 [CommandLine](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2021-05-14T23:28:16.449Z,1621034896.449 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=282 cubic_centimeter;

2021-05-14T23:28:16.450Z,1621034896.450 [CommandLine](IMPORTANT): VerticalControl.massDefault=9.25 millimeter;

2021-05-14T23:28:29.858Z,1621034909.858 [CommandLine](IMPORTANT): got command run ./Missions/lab_range_test.xml
2021-05-14T23:28:29.858Z,1621034909.858 [MissionManager](INFO): Loading Mission: ./Missions/lab_range_test.xml
2021-05-14T23:28:29.885Z,1621034909.885 [MissionManager](INFO): DefineArg lab_range_test.MissionTimeout = 2.000000 min
2021-05-14T23:28:29.888Z,1621034909.888 [MissionManager](INFO): DefineArg lab_range_test.ContactLabel = 50.000000 count
2021-05-14T23:28:29.891Z,1621034909.891 [MissionManager](INFO): DefineArg lab_range_test.TrackingUpdatePeriod = 15.000000 s
2021-05-14T23:28:29.895Z,1621034909.895 [MissionManager](INFO): DefineArg lab_range_test.NumberOfPings = 5.000000 count
2021-05-14T23:28:29.914Z,1621034909.914 [MissionManager](INFO): DefineArg lab_range_test.ContactDepth = nan m
2021-05-14T23:28:30.002Z,1621034910.002 [lab_range_test:B.Wait](DEBUG): Construct Wait.
2021-05-14T23:28:30.017Z,1621034910.017 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Derivation="Tethys/Derivation"
       xmlns:Estimation="Tethys/Estimation"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Sensor="Tethys/Sensor"
       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/Derivation http://okeanids.mbari.org/tethys/Xml/Derivation.xsd
                           Tethys/Estimation http://okeanids.mbari.org/tethys/Xml/Estimation.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Sensor http://okeanids.mbari.org/tethys/Xml/Sensor.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="lab_range_test">

    <Description>
        LAB TEST MISSION — ping remote xponder
    </Description>

    <DefineArg Name="MissionTimeout"><Description>
        Maximum duration of mission
    </Description><Units:minute/><Value>2</Value></DefineArg>

    <DefineArg Name="ContactLabel"><Description>
        The acoustic address of the asset to be tracked
    </Description><Units:count/><Value>50</Value></DefineArg>

    <DefineArg Name="TrackingUpdatePeriod"><Description>
        How long to wait between acoustic queries
    </Description><Units:second/><Value>15</Value></DefineArg>

    <DefineArg Name="NumberOfPings"><Description>
        Number of return pings to request with each acoustic query (more than 1
        will activate oneway mode)
    </Description><Units:count/><Value>5</Value></DefineArg>

    <DefineArg Name="ContactDepth"><Description>
        The acoustic address of the asset to be tracked
    </Description><Units:meter/><Value>NaN</Value></DefineArg>
    

<!-- Missions should always start with a timeout. -->

    <Timeout Duration="MissionTimeout"/>

    <Estimation:Tracking>
        <Parallel/>
        <Setting><Estimation:Tracking.contactDepthSetting/><Arg Name="ContactDepth"/></Setting>
        <Setting><Estimation:Tracking.contactLabelSetting/><Arg Name="ContactLabel"/></Setting>
        <Setting><Estimation:Tracking.numberOfSamplesSetting/><Arg Name="NumberOfPings"/></Setting>
        <Setting><Estimation:Tracking.updatePeriodSetting/><Arg Name="TrackingUpdatePeriod"/></Setting>
    </Estimation:Tracking>

    <Guidance:Wait>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Arg Name="MissionTimeout"/></Setting>
    </Guidance:Wait>

</Mission>


2021-05-14T23:28:30.020Z,1621034910.020 [CommandLine](IMPORTANT): Running ./Missions/lab_range_test.xml
2021-05-14T23:28:30.187Z,1621034910.187 [Default] Stopped
2021-05-14T23:28:30.187Z,1621034910.187 [Default](DEBUG): Aggregate::uninitialize Default
2021-05-14T23:28:30.187Z,1621034910.187 [Default:B.GoToSurface] Stopped
2021-05-14T23:28:30.187Z,1621034910.187 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-05-14T23:28:30.187Z,1621034910.187 [Default:CheckIn] Stopped
2021-05-14T23:28:30.187Z,1621034910.187 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-05-14T23:28:30.187Z,1621034910.187 [Default:CheckIn:Read_GPS] Stopped
2021-05-14T23:28:30.187Z,1621034910.187 [MissionManager](IMPORTANT): Started mission lab_range_test
2021-05-14T23:28:30.188Z,1621034910.188 [lab_range_test] Running Loop=1
2021-05-14T23:28:30.188Z,1621034910.188 [lab_range_test](DEBUG): Aggregate::initialize lab_range_test
2021-05-14T23:28:30.188Z,1621034910.188 [lab_range_test:A.] Running Loop=1
2021-05-14T23:28:30.188Z,1621034910.188 [lab_range_test:A.](INFO): Initializing Tracking.
2021-05-14T23:28:30.189Z,1621034910.189 [lab_range_test:B.Wait] Running Loop=1
2021-05-14T23:28:30.189Z,1621034910.189 [lab_range_test:B.Wait](DEBUG): Initialize Wait Component.
2021-05-14T23:28:30.189Z,1621034910.189 [lab_range_test:A.] Running Loop=1
2021-05-14T23:28:30.189Z,1621034910.189 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:30.590Z,1621034910.590 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:30.999Z,1621034910.999 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:31.387Z,1621034911.387 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:31.790Z,1621034911.790 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:32.219Z,1621034912.219 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:32.623Z,1621034912.623 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:33.013Z,1621034913.013 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:33.406Z,1621034913.406 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:33.815Z,1621034913.815 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:34.211Z,1621034914.211 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:34.648Z,1621034914.648 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:35.060Z,1621034915.060 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:35.448Z,1621034915.448 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:35.844Z,1621034915.844 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:36.259Z,1621034916.259 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:36.638Z,1621034916.638 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:37.046Z,1621034917.046 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:37.460Z,1621034917.460 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:37.851Z,1621034917.851 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:38.271Z,1621034918.271 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:38.686Z,1621034918.686 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:39.077Z,1621034919.077 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:39.466Z,1621034919.466 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:39.870Z,1621034919.870 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:40.282Z,1621034920.282 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:40.691Z,1621034920.691 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:41.113Z,1621034921.113 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:41.500Z,1621034921.500 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:41.911Z,1621034921.911 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:42.306Z,1621034922.306 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:42.698Z,1621034922.698 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:43.268Z,1621034923.268 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:43.515Z,1621034923.515 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:43.924Z,1621034923.924 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:44.327Z,1621034924.327 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:44.735Z,1621034924.735 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:45.143Z,1621034925.143 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:45.539Z,1621034925.539 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:45.540Z,1621034925.540 [lab_range_test:A.](INFO): update period (15.000000 s) has elapsed, querying...
2021-05-14T23:28:45.540Z,1621034925.540 [lab_range_test:A.](INFO): *** querying DAT ***
2021-05-14T23:28:45.923Z,1621034925.923 [DAT](INFO): entering command mode
2021-05-14T23:28:45.935Z,1621034925.935 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:46.326Z,1621034926.326 [DAT](INFO): commRate: 800
2021-05-14T23:28:46.333Z,1621034926.333 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:46.742Z,1621034926.742 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:47.163Z,1621034927.163 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:47.570Z,1621034927.570 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:47.967Z,1621034927.967 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:48.350Z,1621034928.350 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:28:48.356Z,1621034928.356 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:48.748Z,1621034928.748 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:28:48.771Z,1621034928.771 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:49.156Z,1621034929.156 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:28:49.162Z,1621034929.162 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:49.557Z,1621034929.557 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:28:49.570Z,1621034929.570 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:49.960Z,1621034929.960 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:28:49.980Z,1621034929.980 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:50.374Z,1621034930.374 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:28:50.396Z,1621034930.396 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:50.783Z,1621034930.783 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:28:50.794Z,1621034930.794 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:51.183Z,1621034931.183 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:28:51.205Z,1621034931.205 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:51.575Z,1621034931.575 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:28:51.598Z,1621034931.598 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:51.981Z,1621034931.981 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:28:52.014Z,1621034932.014 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:52.385Z,1621034932.385 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:28:52.399Z,1621034932.399 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:52.791Z,1621034932.791 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:28:52.809Z,1621034932.809 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:53.215Z,1621034933.215 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:28:53.226Z,1621034933.226 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:53.618Z,1621034933.618 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:28:53.624Z,1621034933.624 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:54.015Z,1621034934.015 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:28:54.040Z,1621034934.040 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:54.408Z,1621034934.408 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:28:54.415Z,1621034934.415 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:54.813Z,1621034934.813 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:28:54.823Z,1621034934.823 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:55.217Z,1621034935.217 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:28:55.235Z,1621034935.235 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:55.616Z,1621034935.616 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:28:55.623Z,1621034935.623 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:56.031Z,1621034936.031 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:28:56.043Z,1621034936.043 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:56.442Z,1621034936.442 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:28:56.458Z,1621034936.458 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:56.846Z,1621034936.846 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:28:56.859Z,1621034936.859 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:57.233Z,1621034937.233 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:28:57.247Z,1621034937.247 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:57.640Z,1621034937.640 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:28:57.646Z,1621034937.646 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:58.059Z,1621034938.059 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:28:58.071Z,1621034938.071 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:58.462Z,1621034938.462 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:28:58.474Z,1621034938.474 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:58.862Z,1621034938.862 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:28:58.883Z,1621034938.883 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:59.258Z,1621034939.258 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:28:59.264Z,1621034939.264 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:28:59.668Z,1621034939.668 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:28:59.675Z,1621034939.675 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:00.071Z,1621034940.071 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:29:00.094Z,1621034940.094 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:00.483Z,1621034940.483 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:29:00.504Z,1621034940.504 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:00.883Z,1621034940.883 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:29:00.890Z,1621034940.890 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:00.890Z,1621034940.890 [lab_range_test:A.](INFO): update period (15.000000 s) has elapsed, querying...
2021-05-14T23:29:00.891Z,1621034940.891 [lab_range_test:A.](INFO): *** querying DAT ***
2021-05-14T23:29:01.276Z,1621034941.276 [DAT](DEBUG): checking for command mode acknowledgment
2021-05-14T23:29:01.276Z,1621034941.276 [DAT](FAULT): failed to enter command mode
2021-05-14T23:29:01.304Z,1621034941.304 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:01.681Z,1621034941.681 [DAT](INFO): entering command mode
2021-05-14T23:29:01.705Z,1621034941.705 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:02.086Z,1621034942.086 [DAT](INFO): setting remote address to 0
2021-05-14T23:29:02.127Z,1621034942.127 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:02.489Z,1621034942.489 [DAT](INFO): set remote address to 0
2021-05-14T23:29:02.492Z,1621034942.492 [DAT](INFO): ****** ping requested ******
2021-05-14T23:29:02.503Z,1621034942.503 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:02.895Z,1621034942.895 [DAT](INFO): Ping request sent.
2021-05-14T23:29:02.903Z,1621034942.903 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:03.323Z,1621034943.323 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:03.738Z,1621034943.738 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:04.127Z,1621034944.127 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:04.527Z,1621034944.527 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:04.935Z,1621034944.935 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:05.327Z,1621034945.327 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:05.730Z,1621034945.730 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:06.159Z,1621034946.159 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:06.549Z,1621034946.549 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:06.961Z,1621034946.961 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:07.343Z,1621034947.343 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:07.755Z,1621034947.755 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:08.166Z,1621034948.166 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:08.555Z,1621034948.555 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:08.963Z,1621034948.963 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:09.379Z,1621034949.379 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:09.786Z,1621034949.786 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:10.195Z,1621034950.195 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:10.571Z,1621034950.571 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:10.986Z,1621034950.986 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:11.384Z,1621034951.384 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:11.786Z,1621034951.786 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:12.207Z,1621034952.207 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:12.618Z,1621034952.618 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:13.011Z,1621034953.011 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:13.403Z,1621034953.403 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:13.806Z,1621034953.806 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:14.218Z,1621034954.218 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:14.627Z,1621034954.627 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:15.019Z,1621034955.019 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:15.438Z,1621034955.438 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:15.850Z,1621034955.850 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:16.251Z,1621034956.251 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:16.251Z,1621034956.251 [lab_range_test:A.](INFO): update period (15.000000 s) has elapsed, querying...
2021-05-14T23:29:16.251Z,1621034956.251 [lab_range_test:A.](INFO): *** querying DAT ***
2021-05-14T23:29:16.634Z,1621034956.634 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:17.038Z,1621034957.038 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:17.444Z,1621034957.444 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:17.836Z,1621034957.836 [DAT](ERROR): No response from remote modem.
2021-05-14T23:29:17.863Z,1621034957.863 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:18.278Z,1621034958.278 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:18.688Z,1621034958.688 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:19.070Z,1621034959.070 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:19.468Z,1621034959.468 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:19.866Z,1621034959.866 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:20.267Z,1621034960.267 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:20.727Z,1621034960.727 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:21.098Z,1621034961.098 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:21.510Z,1621034961.510 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:21.922Z,1621034961.922 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:22.293Z,1621034962.293 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:22.703Z,1621034962.703 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:23.110Z,1621034963.110 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:23.507Z,1621034963.507 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:23.914Z,1621034963.914 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:24.320Z,1621034964.320 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:24.734Z,1621034964.734 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:25.141Z,1621034965.141 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:25.522Z,1621034965.522 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:25.931Z,1621034965.931 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:26.337Z,1621034966.337 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:26.734Z,1621034966.734 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:27.151Z,1621034967.151 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:27.558Z,1621034967.558 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:27.967Z,1621034967.967 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:28.350Z,1621034968.350 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:28.754Z,1621034968.754 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:29.159Z,1621034969.159 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:29.571Z,1621034969.571 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:29.978Z,1621034969.978 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:30.395Z,1621034970.395 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:30.795Z,1621034970.795 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:31.197Z,1621034971.197 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:31.596Z,1621034971.596 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:31.596Z,1621034971.596 [lab_range_test:A.](INFO): update period (15.000000 s) has elapsed, querying...
2021-05-14T23:29:31.596Z,1621034971.596 [lab_range_test:A.](INFO): *** querying DAT ***
2021-05-14T23:29:31.983Z,1621034971.983 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:32.390Z,1621034972.390 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:32.799Z,1621034972.799 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:33.204Z,1621034973.204 [DAT](INFO): ****** ping requested ******
2021-05-14T23:29:33.234Z,1621034973.234 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:33.607Z,1621034973.607 [DAT](INFO): Ping request sent.
2021-05-14T23:29:33.639Z,1621034973.639 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:34.019Z,1621034974.019 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:34.418Z,1621034974.418 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:34.826Z,1621034974.826 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:35.219Z,1621034975.219 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:35.623Z,1621034975.623 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:36.047Z,1621034976.047 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:36.450Z,1621034976.450 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:36.859Z,1621034976.859 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:37.239Z,1621034977.239 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:37.647Z,1621034977.647 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:38.071Z,1621034978.071 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:38.473Z,1621034978.473 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:38.867Z,1621034978.867 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:39.262Z,1621034979.262 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:39.708Z,1621034979.708 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:40.075Z,1621034980.075 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:40.483Z,1621034980.483 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:40.889Z,1621034980.889 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:41.275Z,1621034981.275 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:41.679Z,1621034981.679 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:42.083Z,1621034982.083 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:42.510Z,1621034982.510 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:42.926Z,1621034982.926 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:43.298Z,1621034983.298 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-05-14T23:29:43.298Z,1621034983.298 [NAL9602] Data Fault, FailCount= 5
2021-05-14T23:29:43.298Z,1621034983.298 [NAL9602](ERROR): Data Fault
2021-05-14T23:29:43.342Z,1621034983.342 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:43.355Z,1621034983.355 [CBIT](ERROR): Data Fault in component: NAL9602
2021-05-14T23:29:43.355Z,1621034983.355 [CBIT](CRITICAL): Data Fault in component: NAL9602
2021-05-14T23:29:43.702Z,1621034983.702 [NAL9602](INFO): Powering down
2021-05-14T23:29:43.718Z,1621034983.718 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:43.755Z,1621034983.755 [CBIT](INFO): Critical error at 20210514T232943
2021-05-14T23:29:43.756Z,1621034983.756 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2021-05-14T23:29:44.106Z,1621034984.106 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:29:44.107Z,1621034984.107 [MissionManager](INFO): MissionManager is completed.
2021-05-14T23:29:44.107Z,1621034984.107 [MissionManager](INFO): Uninitializing Mission lab_range_test
2021-05-14T23:29:44.107Z,1621034984.107 [lab_range_test] Stopped
2021-05-14T23:29:44.107Z,1621034984.107 [lab_range_test](DEBUG): Aggregate::uninitialize lab_range_test
2021-05-14T23:29:44.107Z,1621034984.107 [lab_range_test:A.] Stopped
2021-05-14T23:29:44.107Z,1621034984.107 [lab_range_test:A.](DEBUG): Uninitializing Tracking.
2021-05-14T23:29:44.107Z,1621034984.107 [lab_range_test:B.Wait] Stopped
2021-05-14T23:29:44.108Z,1621034984.108 [lab_range_test:B.Wait](DEBUG): Uninitialize Wait Component.
2021-05-14T23:29:44.517Z,1621034984.517 [MissionManager](IMPORTANT): Started mission Default
2021-05-14T23:29:44.517Z,1621034984.517 [Default] Running Loop=1
2021-05-14T23:29:44.517Z,1621034984.517 [Default](DEBUG): Aggregate::initialize Default
2021-05-14T23:29:44.517Z,1621034984.517 [Default:B.GoToSurface] Running Loop=1
2021-05-14T23:29:44.517Z,1621034984.517 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-05-14T23:29:44.518Z,1621034984.518 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-05-14T23:29:44.518Z,1621034984.518 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-05-14T23:29:44.518Z,1621034984.518 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-05-14T23:29:44.519Z,1621034984.519 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-05-14T23:29:44.519Z,1621034984.519 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-05-14T23:29:44.520Z,1621034984.520 [Default:A.Wait] Running Loop=1
2021-05-14T23:29:44.520Z,1621034984.520 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-05-14T23:29:48.540Z,1621034988.540 [DAT](ERROR): No response from remote modem.
2021-05-14T23:29:57.854Z,1621034997.854 [Default:A.Wait](INFO): Done Waiting.
2021-05-14T23:29:57.854Z,1621034997.854 [Default:A.Wait] Stopped
2021-05-14T23:29:57.854Z,1621034997.854 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-05-14T23:29:58.247Z,1621034998.247 [Default:CheckIn] Running Loop=1
2021-05-14T23:29:58.247Z,1621034998.247 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-05-14T23:29:58.247Z,1621034998.247 [Default:CheckIn:Read_GPS] Running Loop=1
2021-05-14T23:30:38.417Z,1621035038.417 [CommandLine](IMPORTANT): got command run ./Missions/lab_range_test.xml
2021-05-14T23:30:38.417Z,1621035038.417 [MissionManager](INFO): Loading Mission: ./Missions/lab_range_test.xml
2021-05-14T23:30:38.443Z,1621035038.443 [MissionManager](INFO): DefineArg lab_range_test.MissionTimeout = 2.000000 min
2021-05-14T23:30:38.445Z,1621035038.445 [MissionManager](INFO): DefineArg lab_range_test.ContactLabel = 50.000000 count
2021-05-14T23:30:38.448Z,1621035038.448 [MissionManager](INFO): DefineArg lab_range_test.TrackingUpdatePeriod = 15.000000 s
2021-05-14T23:30:38.547Z,1621035038.547 [MissionManager](INFO): DefineArg lab_range_test.NumberOfPings = 5.000000 count
2021-05-14T23:30:38.551Z,1621035038.551 [MissionManager](INFO): DefineArg lab_range_test.ContactDepth = nan m
2021-05-14T23:30:38.600Z,1621035038.600 [lab_range_test:B.Wait](DEBUG): Construct Wait.
2021-05-14T23:30:38.616Z,1621035038.616 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Derivation="Tethys/Derivation"
       xmlns:Estimation="Tethys/Estimation"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Sensor="Tethys/Sensor"
       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/Derivation http://okeanids.mbari.org/tethys/Xml/Derivation.xsd
                           Tethys/Estimation http://okeanids.mbari.org/tethys/Xml/Estimation.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Sensor http://okeanids.mbari.org/tethys/Xml/Sensor.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="lab_range_test">

    <Description>
        LAB TEST MISSION — ping remote xponder
    </Description>

    <DefineArg Name="MissionTimeout"><Description>
        Maximum duration of mission
    </Description><Units:minute/><Value>2</Value></DefineArg>

    <DefineArg Name="ContactLabel"><Description>
        The acoustic address of the asset to be tracked
    </Description><Units:count/><Value>50</Value></DefineArg>

    <DefineArg Name="TrackingUpdatePeriod"><Description>
        How long to wait between acoustic queries
    </Description><Units:second/><Value>15</Value></DefineArg>

    <DefineArg Name="NumberOfPings"><Description>
        Number of return pings to request with each acoustic query (more than 1
        will activate oneway mode)
    </Description><Units:count/><Value>5</Value></DefineArg>

    <DefineArg Name="ContactDepth"><Description>
        The acoustic address of the asset to be tracked
    </Description><Units:meter/><Value>NaN</Value></DefineArg>
    

<!-- Missions should always start with a timeout. -->

    <Timeout Duration="MissionTimeout"/>

    <Estimation:Tracking>
        <Parallel/>
        <Setting><Estimation:Tracking.contactDepthSetting/><Arg Name="ContactDepth"/></Setting>
        <Setting><Estimation:Tracking.contactLabelSetting/><Arg Name="ContactLabel"/></Setting>
        <Setting><Estimation:Tracking.numberOfSamplesSetting/><Arg Name="NumberOfPings"/></Setting>
        <Setting><Estimation:Tracking.updatePeriodSetting/><Arg Name="TrackingUpdatePeriod"/></Setting>
    </Estimation:Tracking>

    <Guidance:Wait>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Arg Name="MissionTimeout"/></Setting>
    </Guidance:Wait>

</Mission>


2021-05-14T23:30:38.618Z,1621035038.618 [CommandLine](IMPORTANT): Running ./Missions/lab_range_test.xml
2021-05-14T23:30:38.659Z,1621035038.659 [Default] Stopped
2021-05-14T23:30:38.659Z,1621035038.659 [Default](DEBUG): Aggregate::uninitialize Default
2021-05-14T23:30:38.660Z,1621035038.660 [Default:B.GoToSurface] Stopped
2021-05-14T23:30:38.660Z,1621035038.660 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-05-14T23:30:38.660Z,1621035038.660 [Default:CheckIn] Stopped
2021-05-14T23:30:38.660Z,1621035038.660 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-05-14T23:30:38.660Z,1621035038.660 [Default:CheckIn:Read_GPS] Stopped
2021-05-14T23:30:38.667Z,1621035038.667 [MissionManager](IMPORTANT): Started mission lab_range_test
2021-05-14T23:30:38.667Z,1621035038.667 [lab_range_test] Running Loop=1
2021-05-14T23:30:38.667Z,1621035038.667 [lab_range_test](DEBUG): Aggregate::initialize lab_range_test
2021-05-14T23:30:38.667Z,1621035038.667 [lab_range_test:A.] Running Loop=1
2021-05-14T23:30:38.668Z,1621035038.668 [lab_range_test:A.](INFO): Initializing Tracking.
2021-05-14T23:30:38.668Z,1621035038.668 [lab_range_test:B.Wait] Running Loop=1
2021-05-14T23:30:38.668Z,1621035038.668 [lab_range_test:B.Wait](DEBUG): Initialize Wait Component.
2021-05-14T23:30:38.668Z,1621035038.668 [lab_range_test:A.] Running Loop=1
2021-05-14T23:30:38.668Z,1621035038.668 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:39.054Z,1621035039.054 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:39.454Z,1621035039.454 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:39.858Z,1621035039.858 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:40.266Z,1621035040.266 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:40.670Z,1621035040.670 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:41.071Z,1621035041.071 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:41.473Z,1621035041.473 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:41.878Z,1621035041.878 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:42.291Z,1621035042.291 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:42.697Z,1621035042.697 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:43.094Z,1621035043.094 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:43.490Z,1621035043.490 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:43.900Z,1621035043.900 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:44.314Z,1621035044.314 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:44.716Z,1621035044.716 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:45.110Z,1621035045.110 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:45.518Z,1621035045.518 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:45.931Z,1621035045.931 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:46.321Z,1621035046.321 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:46.729Z,1621035046.729 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:47.133Z,1621035047.133 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:47.545Z,1621035047.545 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:47.946Z,1621035047.946 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:48.342Z,1621035048.342 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:48.751Z,1621035048.751 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:49.163Z,1621035049.163 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:49.554Z,1621035049.554 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:49.955Z,1621035049.955 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:50.370Z,1621035050.370 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:50.778Z,1621035050.778 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:51.170Z,1621035051.170 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:51.574Z,1621035051.574 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:51.990Z,1621035051.990 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:52.398Z,1621035052.398 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:52.789Z,1621035052.789 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:53.202Z,1621035053.202 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:53.616Z,1621035053.616 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:54.018Z,1621035054.018 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:54.018Z,1621035054.018 [lab_range_test:A.](INFO): update period (15.000000 s) has elapsed, querying...
2021-05-14T23:30:54.018Z,1621035054.018 [lab_range_test:A.](INFO): *** querying DAT ***
2021-05-14T23:30:54.392Z,1621035054.392 [DAT](INFO): ****** ping requested ******
2021-05-14T23:30:54.439Z,1621035054.439 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:54.796Z,1621035054.796 [DAT](INFO): Ping request sent.
2021-05-14T23:30:54.822Z,1621035054.822 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:55.219Z,1621035055.219 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:55.628Z,1621035055.628 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:56.021Z,1621035056.021 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:56.422Z,1621035056.422 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:56.839Z,1621035056.839 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:57.242Z,1621035057.242 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:57.637Z,1621035057.637 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:58.042Z,1621035058.042 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:58.451Z,1621035058.451 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:58.845Z,1621035058.845 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:59.250Z,1621035059.250 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:30:59.651Z,1621035059.651 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:00.067Z,1621035060.067 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:00.474Z,1621035060.474 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:00.865Z,1621035060.865 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:01.271Z,1621035061.271 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:01.683Z,1621035061.683 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:02.090Z,1621035062.090 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:02.481Z,1621035062.481 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:02.886Z,1621035062.886 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:03.293Z,1621035063.293 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:03.693Z,1621035063.693 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:04.098Z,1621035064.098 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:04.502Z,1621035064.502 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:04.915Z,1621035064.915 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:05.323Z,1621035065.323 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:05.713Z,1621035065.713 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:06.118Z,1621035066.118 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:06.530Z,1621035066.530 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:06.938Z,1621035066.938 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:07.329Z,1621035067.329 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:07.734Z,1621035067.734 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:08.147Z,1621035068.147 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:08.554Z,1621035068.554 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:08.943Z,1621035068.943 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:09.352Z,1621035069.352 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:09.352Z,1621035069.352 [lab_range_test:A.](INFO): update period (15.000000 s) has elapsed, querying...
2021-05-14T23:31:09.352Z,1621035069.352 [lab_range_test:A.](INFO): *** querying DAT ***
2021-05-14T23:31:09.770Z,1621035069.770 [DAT](ERROR): No response from remote modem.
2021-05-14T23:31:09.776Z,1621035069.776 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:10.155Z,1621035070.155 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:10.562Z,1621035070.562 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:10.966Z,1621035070.966 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:11.375Z,1621035071.375 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:11.786Z,1621035071.786 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:12.178Z,1621035072.178 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:12.582Z,1621035072.582 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:12.766Z,1621035072.766 [CommandLine](IMPORTANT): got command exit
2021-05-14T23:31:12.987Z,1621035072.987 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:13.398Z,1621035073.398 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:13.794Z,1621035073.794 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:13.933Z,1621035073.933 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2021-05-14T23:31:13.933Z,1621035073.933 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2021-05-14T23:31:13.934Z,1621035073.934 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-05-14T23:31:13.934Z,1621035073.934 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2021-05-14T23:31:13.934Z,1621035073.934 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-05-14T23:31:13.935Z,1621035073.935 [CommandLine](INFO): Join timeout helper Thread ID is 7465
2021-05-14T23:31:13.935Z,1621035073.935 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2021-05-14T23:31:13.935Z,1621035073.935 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-05-14T23:31:13.936Z,1621035073.936 [NavChartDb](INFO): Join timeout helper Thread ID is 7466
2021-05-14T23:31:14.114Z,1621035074.114 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2021-05-14T23:31:14.114Z,1621035074.114 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-05-14T23:31:14.133Z,1621035074.133 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2021-05-14T23:31:14.133Z,1621035074.133 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-05-14T23:31:14.133Z,1621035074.133 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 7467
2021-05-14T23:31:14.198Z,1621035074.198 [lab_range_test:A.](DEBUG): Tracking...
2021-05-14T23:31:14.198Z,1621035074.198 [MissionManager](INFO): MissionManager is completed.
2021-05-14T23:31:14.198Z,1621035074.198 [MissionManager](INFO): Uninitializing Mission lab_range_test
2021-05-14T23:31:14.198Z,1621035074.198 [lab_range_test] Stopped
2021-05-14T23:31:14.199Z,1621035074.199 [lab_range_test](DEBUG): Aggregate::uninitialize lab_range_test
2021-05-14T23:31:14.199Z,1621035074.199 [lab_range_test:A.] Stopped
2021-05-14T23:31:14.199Z,1621035074.199 [lab_range_test:A.](DEBUG): Uninitializing Tracking.
2021-05-14T23:31:14.199Z,1621035074.199 [lab_range_test:B.Wait] Stopped
2021-05-14T23:31:14.199Z,1621035074.199 [lab_range_test:B.Wait](DEBUG): Uninitialize Wait Component.
2021-05-14T23:31:14.478Z,1621035074.478 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2021-05-14T23:31:14.478Z,1621035074.478 [WetLabsBB2FL](INFO): Powering down
2021-05-14T23:31:14.478Z,1621035074.478 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-05-14T23:31:14.493Z,1621035074.493 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2021-05-14T23:31:14.493Z,1621035074.493 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-05-14T23:31:14.493Z,1621035074.493 [CTD_Seabird](INFO): Join timeout helper Thread ID is 7468
2021-05-14T23:31:14.609Z,1621035074.609 [MissionManager](IMPORTANT): Started mission Default
2021-05-14T23:31:14.610Z,1621035074.610 [Default] Running Loop=1
2021-05-14T23:31:14.610Z,1621035074.610 [Default](DEBUG): Aggregate::initialize Default
2021-05-14T23:31:14.610Z,1621035074.610 [Default:B.GoToSurface] Running Loop=1
2021-05-14T23:31:14.610Z,1621035074.610 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-05-14T23:31:14.610Z,1621035074.610 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-05-14T23:31:14.611Z,1621035074.611 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-05-14T23:31:14.611Z,1621035074.611 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-05-14T23:31:14.611Z,1621035074.611 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-05-14T23:31:14.612Z,1621035074.612 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-05-14T23:31:14.612Z,1621035074.612 [Default:A.Wait] Running Loop=1
2021-05-14T23:31:14.612Z,1621035074.612 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-05-14T23:31:15.485Z,1621035075.485 [CTD_Seabird](INFO): Powering down
2021-05-14T23:31:15.497Z,1621035075.497 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2021-05-14T23:31:15.497Z,1621035075.497 [CTD_Seabird](INFO): Powering down
2021-05-14T23:31:15.509Z,1621035075.509 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-05-14T23:31:15.525Z,1621035075.525 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2021-05-14T23:31:15.525Z,1621035075.525 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-05-14T23:31:15.526Z,1621035075.526 [Radio_Surface](INFO): Join timeout helper Thread ID is 7469
2021-05-14T23:31:15.597Z,1621035075.597 [Radio_Surface](INFO): Powering down
2021-05-14T23:31:15.598Z,1621035075.598 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2021-05-14T23:31:15.598Z,1621035075.598 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-05-14T23:31:15.610Z,1621035075.610 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2021-05-14T23:31:15.610Z,1621035075.610 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-05-14T23:31:15.610Z,1621035075.610 [Onboard](INFO): Join timeout helper Thread ID is 7470
2021-05-14T23:31:15.973Z,1621035075.973 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2021-05-14T23:31:19.733Z,1621035079.733 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2021-05-14T23:31:19.734Z,1621035079.734 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-05-14T23:31:19.750Z,1621035079.750 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2021-05-14T23:31:19.750Z,1621035079.750 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-05-14T23:31:19.750Z,1621035079.750 [DataOverHttps](INFO): Join timeout helper Thread ID is 7472
2021-05-14T23:31:20.005Z,1621035080.005 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2021-05-14T23:31:20.005Z,1621035080.005 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-05-14T23:31:20.010Z,1621035080.010 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2021-05-14T23:31:20.010Z,1621035080.010 [logger ThreadHandler](INFO): Thread cancelled.
2021-05-14T23:31:20.010Z,1621035080.010 [logger](INFO): Join timeout helper Thread ID is 7473
2021-05-14T23:31:20.049Z,1621035080.049 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2021-05-14T23:31:20.049Z,1621035080.049 [logger ThreadHandler](INFO): Thread cancelled.
2021-05-14T23:31:20.070Z,1621035080.070 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2021-05-14T23:31:20.070Z,1621035080.070 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-05-14T23:31:20.070Z,1621035080.070 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2021-05-14T23:31:20.070Z,1621035080.070 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-05-14T23:31:20.070Z,1621035080.070 [controlThread](INFO): Join timeout helper Thread ID is 7474
2021-05-14T23:31:20.237Z,1621035080.237 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2021-05-14T23:31:20.237Z,1621035080.237 [controlThread](DEBUG): Uninitializing ControlThread
2021-05-14T23:31:20.238Z,1621035080.238 [AHRS_M2](INFO): Powering down
2021-05-14T23:31:20.310Z,1621035080.310 [NAL9602](INFO): Powering down
2021-05-14T23:31:20.477Z,1621035080.477 [AMEcho](INFO): Powering down.
2021-05-14T23:31:20.478Z,1621035080.478 [DAT](INFO): Powering down
2021-05-14T23:31:20.598Z,1621035080.598 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2021-05-14T23:31:20.599Z,1621035080.599 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2021-05-14T23:31:20.599Z,1621035080.599 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2021-05-14T23:31:20.600Z,1621035080.600 [MissionManager](INFO): Uninitializing Mission Default
2021-05-14T23:31:20.600Z,1621035080.600 [Default] Stopped
2021-05-14T23:31:20.600Z,1621035080.600 [Default](DEBUG): Aggregate::uninitialize Default
2021-05-14T23:31:20.600Z,1621035080.600 [Default:A.Wait] Stopped
2021-05-14T23:31:20.600Z,1621035080.600 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-05-14T23:31:20.600Z,1621035080.600 [Default:B.GoToSurface] Stopped
2021-05-14T23:31:20.600Z,1621035080.600 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-05-14T23:31:20.603Z,1621035080.603 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2021-05-14T23:31:20.603Z,1621035080.603 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2021-05-14T23:31:20.603Z,1621035080.603 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2021-05-14T23:31:20.604Z,1621035080.604 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2021-05-14T23:31:20.604Z,1621035080.604 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2021-05-14T23:31:20.604Z,1621035080.604 [BuoyancyServo](INFO): Powering down
2021-05-14T23:31:20.617Z,1621035080.617 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2021-05-14T23:31:20.617Z,1621035080.617 [ElevatorServo](INFO): Powering down
2021-05-14T23:31:20.618Z,1621035080.618 [MassServo](DEBUG): Uninitialize Mass Servo.
2021-05-14T23:31:20.618Z,1621035080.618 [MassServo](INFO): Powering down
2021-05-14T23:31:20.619Z,1621035080.619 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-05-14T23:31:20.619Z,1621035080.619 [RudderServo](INFO): Powering down
2021-05-14T23:31:20.620Z,1621035080.620 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2021-05-14T23:31:20.620Z,1621035080.620 [ThrusterServo](INFO): Powering down
2021-05-14T23:31:20.621Z,1621035080.621 [SBIT](DEBUG): Uninitialize SBIT Component.
2021-05-14T23:31:20.621Z,1621035080.621 [IBIT](DEBUG): Uninitialize IBIT Component.
2021-05-14T23:31:20.621Z,1621035080.621 [CBIT](DEBUG): Uninitialize CBIT Component.
2021-05-14T23:31:20.621Z,1621035080.621 [CBIT](DEBUG): Powering off loads.
2021-05-14T23:31:20.633Z,1621035080.633 [CBIT](DEBUG): Disabling WDT.
2021-05-14T23:31:20.645Z,1621035080.645 [CBIT](DEBUG): Opening all GF detection circuits.
2021-05-14T23:31:20.646Z,1621035080.646 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-05-14T23:31:20.687Z,1621035080.687 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-05-14T23:31:20.690Z,1621035080.690 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-05-14T23:31:20.695Z,1621035080.695 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-05-14T23:31:20.763Z,1621035080.763 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-05-14T23:31:20.766Z,1621035080.766 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-05-14T23:31:20.803Z,1621035080.803 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-05-14T23:31:20.862Z,1621035080.862 [logger ThreadHandler](INFO): Thread cancelled.