2021-11-17T21:56:48.314Z,1637186208.314 [Supervisor](DEBUG): Initializing supervisor.
2021-11-17T21:56:48.318Z,1637186208.318 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2021-11-17T21:56:48.319Z,1637186208.319 [SyncHandler](INFO): Protected caller Thread ID is 833
2021-11-17T21:56:48.319Z,1637186208.319 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2021-11-17T21:56:48.320Z,1637186208.320 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2021-11-17T21:56:48.320Z,1637186208.320 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 834
2021-11-17T21:56:48.324Z,1637186208.324 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2021-11-17T21:56:48.343Z,1637186208.343 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2021-11-17T21:56:48.344Z,1637186208.344 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2021-11-17T21:56:48.344Z,1637186208.344 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 835
2021-11-17T21:56:48.349Z,1637186208.349 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2021-11-17T21:56:48.350Z,1637186208.350 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2021-11-17T21:56:48.350Z,1637186208.350 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 836
2021-11-17T21:56:48.352Z,1637186208.352 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2021-11-17T21:56:48.353Z,1637186208.353 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2021-11-17T21:56:48.354Z,1637186208.354 [logger ThreadHandler](INFO): Protected caller Thread ID is 837
2021-11-17T21:56:48.357Z,1637186208.357 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2021-11-17T21:56:48.358Z,1637186208.358 [Supervisor](INFO): Looking for Config files in directory: Config/
2021-11-17T21:56:48.362Z,1637186208.362 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2021-11-17T21:56:48.586Z,1637186208.586 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2021-11-17T21:56:48.588Z,1637186208.588 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2021-11-17T21:56:48.670Z,1637186208.670 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2021-11-17T21:56:49.169Z,1637186209.169 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2021-11-17T21:56:49.171Z,1637186209.171 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2021-11-17T21:56:49.489Z,1637186209.489 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2021-11-17T21:56:49.491Z,1637186209.491 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2021-11-17T21:56:49.587Z,1637186209.587 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2021-11-17T21:56:49.588Z,1637186209.588 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2021-11-17T21:56:49.943Z,1637186209.943 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2021-11-17T21:56:49.945Z,1637186209.945 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2021-11-17T21:56:50.137Z,1637186210.137 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2021-11-17T21:56:50.139Z,1637186210.139 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2021-11-17T21:56:50.585Z,1637186210.585 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2021-11-17T21:56:50.586Z,1637186210.586 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2021-11-17T21:56:50.711Z,1637186210.711 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2021-11-17T21:56:50.712Z,1637186210.712 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2021-11-17T21:56:50.791Z,1637186210.791 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2021-11-17T21:56:51.439Z,1637186211.439 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2021-11-17T21:56:51.440Z,1637186211.440 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2021-11-17T21:56:51.805Z,1637186211.805 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2021-11-17T21:56:51.806Z,1637186211.806 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2021-11-17T21:56:52.762Z,1637186212.762 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2021-11-17T21:56:52.764Z,1637186212.764 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2021-11-17T21:56:52.873Z,1637186212.873 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2021-11-17T21:56:52.874Z,1637186212.874 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2021-11-17T21:56:53.022Z,1637186213.022 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2021-11-17T21:56:53.024Z,1637186213.024 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2021-11-17T21:56:53.245Z,1637186213.245 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2021-11-17T21:56:53.247Z,1637186213.247 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2021-11-17T21:56:53.250Z,1637186213.250 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2021-11-17T21:56:53.340Z,1637186213.340 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2021-11-17T21:56:53.425Z,1637186213.425 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2021-11-17T21:56:53.526Z,1637186213.526 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2021-11-17T21:56:53.608Z,1637186213.608 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2021-11-17T21:56:53.703Z,1637186213.703 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2021-11-17T21:56:53.802Z,1637186213.802 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2021-11-17T21:56:53.983Z,1637186213.983 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2021-11-17T21:56:54.061Z,1637186214.061 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2021-11-17T21:56:54.206Z,1637186214.206 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2021-11-17T21:56:54.341Z,1637186214.341 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2021-11-17T21:56:54.454Z,1637186214.454 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2021-11-17T21:56:54.710Z,1637186214.710 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2021-11-17T21:56:54.711Z,1637186214.711 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2021-11-17T21:56:54.716Z,1637186214.716 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2021-11-17T21:56:54.788Z,1637186214.788 [VerticalControl](DEBUG): Construct VerticalControl.
2021-11-17T21:56:54.850Z,1637186214.850 [VerticalControl] Loaded
2021-11-17T21:56:54.850Z,1637186214.850 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2021-11-17T21:56:54.853Z,1637186214.853 [HorizontalControl](DEBUG): Construct HorizontalControl.
2021-11-17T21:56:54.891Z,1637186214.891 [HorizontalControl] Loaded
2021-11-17T21:56:54.892Z,1637186214.892 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2021-11-17T21:56:54.894Z,1637186214.894 [SpeedControl](DEBUG): Construct SpeedControl.
2021-11-17T21:56:54.897Z,1637186214.897 [SpeedControl] Loaded
2021-11-17T21:56:54.897Z,1637186214.897 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2021-11-17T21:56:54.900Z,1637186214.900 [LoopControl](DEBUG): Construct LoopControl.
2021-11-17T21:56:54.900Z,1637186214.900 [LoopControl] Loaded
2021-11-17T21:56:54.901Z,1637186214.901 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2021-11-17T21:56:54.901Z,1637186214.901 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2021-11-17T21:56:54.902Z,1637186214.902 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2021-11-17T21:56:54.918Z,1637186214.918 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2021-11-17T21:56:54.919Z,1637186214.919 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2021-11-17T21:56:55.051Z,1637186215.051 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2021-11-17T21:56:55.051Z,1637186215.051 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2021-11-17T21:56:55.230Z,1637186215.230 [BuoyancyServo] Loaded
2021-11-17T21:56:55.230Z,1637186215.230 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2021-11-17T21:56:55.250Z,1637186215.250 [ElevatorServo] Loaded
2021-11-17T21:56:55.250Z,1637186215.250 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2021-11-17T21:56:55.268Z,1637186215.268 [MassServo] Loaded
2021-11-17T21:56:55.268Z,1637186215.268 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2021-11-17T21:56:55.286Z,1637186215.286 [RudderServo] Loaded
2021-11-17T21:56:55.286Z,1637186215.286 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2021-11-17T21:56:55.303Z,1637186215.303 [ThrusterServo] Loaded
2021-11-17T21:56:55.304Z,1637186215.304 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2021-11-17T21:56:55.304Z,1637186215.304 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2021-11-17T21:56:55.305Z,1637186215.305 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2021-11-17T21:56:55.404Z,1637186215.404 [DeadReckonUsingMultipleVelocitySources] Loaded
2021-11-17T21:56:55.404Z,1637186215.404 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2021-11-17T21:56:55.418Z,1637186215.418 [NavChart] Loaded
2021-11-17T21:56:55.418Z,1637186215.418 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2021-11-17T21:56:55.424Z,1637186215.424 [UniversalFixResidualReporter] Loaded
2021-11-17T21:56:55.424Z,1637186215.424 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2021-11-17T21:56:55.425Z,1637186215.425 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2021-11-17T21:56:55.425Z,1637186215.425 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2021-11-17T21:56:55.507Z,1637186215.507 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2021-11-17T21:56:55.508Z,1637186215.508 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2021-11-17T21:56:56.193Z,1637186216.193 [AHRS_M2] Loaded
2021-11-17T21:56:56.193Z,1637186216.193 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2021-11-17T21:56:56.983Z,1637186216.983 [BPC1] Loaded
2021-11-17T21:56:56.983Z,1637186216.983 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2021-11-17T21:56:57.125Z,1637186217.125 [DataOverHttps] Loaded
2021-11-17T21:56:57.125Z,1637186217.125 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2021-11-17T21:56:57.127Z,1637186217.127 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408C64E0
2021-11-17T21:56:57.127Z,1637186217.127 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 922
2021-11-17T21:56:57.147Z,1637186217.147 [Depth_Keller] Loaded
2021-11-17T21:56:57.147Z,1637186217.147 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2021-11-17T21:56:57.152Z,1637186217.152 [DropWeight] Loaded
2021-11-17T21:56:57.152Z,1637186217.152 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2021-11-17T21:56:57.211Z,1637186217.211 [NAL9602] Loaded
2021-11-17T21:56:57.211Z,1637186217.211 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2021-11-17T21:56:57.240Z,1637186217.240 [Onboard] Loaded
2021-11-17T21:56:57.240Z,1637186217.240 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2021-11-17T21:56:57.241Z,1637186217.241 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408F64E0
2021-11-17T21:56:57.242Z,1637186217.242 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 923
2021-11-17T21:56:57.254Z,1637186217.254 [Power24vConverter] Loaded
2021-11-17T21:56:57.255Z,1637186217.255 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2021-11-17T21:56:57.267Z,1637186217.267 [Radio_Surface] Loaded
2021-11-17T21:56:57.268Z,1637186217.268 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2021-11-17T21:56:57.269Z,1637186217.269 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409264E0
2021-11-17T21:56:57.269Z,1637186217.269 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 924
2021-11-17T21:56:57.289Z,1637186217.289 [AMEcho] Loaded
2021-11-17T21:56:57.290Z,1637186217.290 [ComponentRegistry](DEBUG): SyncComponent "AMEcho" handled in the control thread.
2021-11-17T21:56:57.370Z,1637186217.370 [DAT] Loaded
2021-11-17T21:56:57.371Z,1637186217.371 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2021-11-17T21:56:57.371Z,1637186217.371 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2021-11-17T21:56:57.372Z,1637186217.372 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2021-11-17T21:56:57.568Z,1637186217.568 [DepthRateCalculator] Loaded
2021-11-17T21:56:57.568Z,1637186217.568 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2021-11-17T21:56:57.573Z,1637186217.573 [PitchRateCalculator] Loaded
2021-11-17T21:56:57.573Z,1637186217.573 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2021-11-17T21:56:57.642Z,1637186217.642 [SpeedCalculator] Loaded
2021-11-17T21:56:57.642Z,1637186217.642 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2021-11-17T21:56:57.656Z,1637186217.656 [TempGradientCalculator] Loaded
2021-11-17T21:56:57.656Z,1637186217.656 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2021-11-17T21:56:57.660Z,1637186217.660 [YawRateCalculator] Loaded
2021-11-17T21:56:57.661Z,1637186217.661 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2021-11-17T21:56:57.679Z,1637186217.679 [ElevatorOffsetCalculator] Loaded
2021-11-17T21:56:57.679Z,1637186217.679 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2021-11-17T21:56:57.679Z,1637186217.679 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2021-11-17T21:56:57.680Z,1637186217.680 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2021-11-17T21:56:58.315Z,1637186218.315 [CTD_Seabird] Loaded
2021-11-17T21:56:58.315Z,1637186218.315 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2021-11-17T21:56:58.316Z,1637186218.316 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409DB4E0
2021-11-17T21:56:58.317Z,1637186218.317 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 925
2021-11-17T21:56:58.337Z,1637186218.337 [PAR_Licor] Loaded
2021-11-17T21:56:58.337Z,1637186218.337 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2021-11-17T21:56:58.369Z,1637186218.369 [WetLabsBB2FL] Loaded
2021-11-17T21:56:58.369Z,1637186218.369 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2021-11-17T21:56:58.370Z,1637186218.370 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A0B4E0
2021-11-17T21:56:58.370Z,1637186218.370 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 926
2021-11-17T21:56:58.371Z,1637186218.371 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2021-11-17T21:56:58.372Z,1637186218.372 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2021-11-17T21:56:58.414Z,1637186218.414 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2021-11-17T21:56:58.415Z,1637186218.415 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2021-11-17T21:56:58.788Z,1637186218.788 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2021-11-17T21:56:58.790Z,1637186218.790 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2021-11-17T21:56:58.962Z,1637186218.962 [SBIT](DEBUG): Construct Startup Built In Test.
2021-11-17T21:56:58.971Z,1637186218.971 [SBIT] Loaded
2021-11-17T21:56:58.971Z,1637186218.971 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2021-11-17T21:56:58.974Z,1637186218.974 [IBIT](DEBUG): Construct Initiated Built In Test.
2021-11-17T21:56:58.988Z,1637186218.988 [IBIT] Loaded
2021-11-17T21:56:58.988Z,1637186218.988 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2021-11-17T21:56:58.994Z,1637186218.994 [CBIT](DEBUG): Construct Continuous Built In Test.
2021-11-17T21:56:59.097Z,1637186219.097 [CBIT] Loaded
2021-11-17T21:56:59.097Z,1637186219.097 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2021-11-17T21:56:59.097Z,1637186219.097 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2021-11-17T21:56:59.098Z,1637186219.098 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2021-11-17T21:56:59.216Z,1637186219.216 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2021-11-17T21:56:59.222Z,1637186219.222 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2021-11-17T21:56:59.225Z,1637186219.225 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2021-11-17T21:56:59.236Z,1637186219.236 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2021-11-17T21:56:59.237Z,1637186219.237 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B404E0
2021-11-17T21:56:59.237Z,1637186219.237 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 927
2021-11-17T21:56:59.242Z,1637186219.242 [Supervisor](INFO): Main Thread ID is 829
2021-11-17T21:56:59.242Z,1637186219.242 [Supervisor](DEBUG): Running supervisor.
2021-11-17T21:56:59.243Z,1637186219.243 [CommandExec ThreadHandler](INFO): Handler Thread ID is 928
2021-11-17T21:56:59.243Z,1637186219.243 [CommandExec](INFO): Initializing the command executive.
2021-11-17T21:56:59.245Z,1637186219.245 [CommandLine ThreadHandler](INFO): Handler Thread ID is 929
2021-11-17T21:56:59.247Z,1637186219.247 [controlThread ThreadHandler](INFO): Handler Thread ID is 930
2021-11-17T21:56:59.247Z,1637186219.247 [controlThread](DEBUG): Initializing ControlThread
2021-11-17T21:56:59.248Z,1637186219.248 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2021-11-17T21:56:59.250Z,1637186219.250 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2021-11-17T21:56:59.251Z,1637186219.251 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2021-11-17T21:56:59.252Z,1637186219.252 [LoopControl](DEBUG): Initialize LoopControlComponent.
2021-11-17T21:56:59.254Z,1637186219.254 [NavChart](DEBUG): Initialize NavChart Navigation.
2021-11-17T21:56:59.254Z,1637186219.254 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2021-11-17T21:56:59.260Z,1637186219.260 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2021-11-17T21:56:59.260Z,1637186219.260 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2021-11-17T21:56:59.261Z,1637186219.261 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2021-11-17T21:56:59.261Z,1637186219.261 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2021-11-17T21:56:59.262Z,1637186219.262 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2021-11-17T21:56:59.262Z,1637186219.262 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2021-11-17T21:56:59.266Z,1637186219.266 [SBIT](INFO): Initialize SBIT Component.
2021-11-17T21:56:59.267Z,1637186219.267 [SBIT](IMPORTANT): git: 2021-10-11a
2021-11-17T21:56:59.267Z,1637186219.267 [SBIT](INFO): git hash: 36f3a97de7a122c995f034a375e3cefac6406048
2021-11-17T21:56:59.267Z,1637186219.267 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2021-11-17T21:56:59.268Z,1637186219.268 [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 Mar 17 08:23:48 PDT 2021
2021-11-17T21:56:59.270Z,1637186219.270 [SBIT](INFO): Beginning SBIT in 41.000000 seconds.
2021-11-17T21:56:59.270Z,1637186219.270 [IBIT](INFO): Initialize IBIT Component.
2021-11-17T21:56:59.271Z,1637186219.271 [CBIT](DEBUG): Initialize CBIT Component.
2021-11-17T21:56:59.272Z,1637186219.272 [logger ThreadHandler](INFO): Handler Thread ID is 931
2021-11-17T21:56:59.286Z,1637186219.286 [CBIT](DEBUG): Initialized mux pins.
2021-11-17T21:56:59.286Z,1637186219.286 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2021-11-17T21:56:59.286Z,1637186219.286 [CBIT](DEBUG): Initializing the watchdog timer.
2021-11-17T21:56:59.290Z,1637186219.290 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 932
2021-11-17T21:56:59.291Z,1637186219.291 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2021-11-17T21:56:59.299Z,1637186219.299 [Onboard ThreadHandler](INFO): Handler Thread ID is 933
2021-11-17T21:56:59.311Z,1637186219.311 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2021-11-17T21:56:59.334Z,1637186219.334 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 934
2021-11-17T21:56:59.335Z,1637186219.335 [CBIT](FAULT): Found backtrace file:
1637186087.314740 [DAT]: SIGSEGV: address not mapped to object
1637186087.314740 [DAT]: Backtrace:
./bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x1a1810]
./bin/LRAUV(_ZN7PCaller10PThreadRunEPv+0xc8) [0x1a125c]
1637186087.521101 [DAT]: SIGSEGV: address not mapped to object
1637186087.521101 [DAT]: Backtrace:
./bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x1a1810]
./bin/LRAUV(_ZN11DataElement18registerChangeDoneEv+0x1c) [0xecad4]
./bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x110) [0x1a1900]
[(nil)]
1637186088.051716 [DAT]: SIGSEGV: address not mapped to object
1637186088.051716 [DAT]: Backtrace:
./bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x1a1810]
/lib/libgcc_s.so.1 [0x402e1264]
[(nil)]
1637186088.596140 [DAT]: SIGSEGV: address not mapped to object
1637186088.596140 [DAT]: Backtrace:
2021-11-17T21:56:59.342Z,1637186219.342 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 935
2021-11-17T21:56:59.343Z,1637186219.343 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2021-11-17T21:56:59.344Z,1637186219.344 [CBIT](FAULT): Renaming backtrace file to Data/backtrace3
2021-11-17T21:56:59.345Z,1637186219.345 [CBIT](DEBUG): Initializing heartbeat.
2021-11-17T21:56:59.346Z,1637186219.346 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 937
2021-11-17T21:56:59.351Z,1637186219.351 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 939
2021-11-17T21:56:59.352Z,1637186219.352 [WetLabsBB2FL](INFO): Powering up
2021-11-17T21:56:59.362Z,1637186219.362 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2021-11-17T21:56:59.362Z,1637186219.362 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2021-11-17T21:56:59.363Z,1637186219.363 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2021-11-17T21:56:59.363Z,1637186219.363 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2021-11-17T21:56:59.363Z,1637186219.363 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2021-11-17T21:56:59.363Z,1637186219.363 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2021-11-17T21:56:59.363Z,1637186219.363 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2021-11-17T21:56:59.364Z,1637186219.364 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2021-11-17T21:56:59.364Z,1637186219.364 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2021-11-17T21:56:59.364Z,1637186219.364 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2021-11-17T21:56:59.364Z,1637186219.364 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2021-11-17T21:56:59.364Z,1637186219.364 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2021-11-17T21:56:59.365Z,1637186219.365 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2021-11-17T21:56:59.365Z,1637186219.365 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2021-11-17T21:56:59.365Z,1637186219.365 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2021-11-17T21:56:59.365Z,1637186219.365 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2021-11-17T21:56:59.414Z,1637186219.414 [CBIT](DEBUG): Deactivating GF circuits.
2021-11-17T21:56:59.414Z,1637186219.414 [CBIT](DEBUG): Deactivating emergency mode.
2021-11-17T21:56:59.450Z,1637186219.450 [CBIT](DEBUG): Backplane powered.
2021-11-17T21:56:59.451Z,1637186219.451 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2021-11-17T21:56:59.476Z,1637186219.476 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2021-11-17T21:56:59.515Z,1637186219.515 [MissionManager](DEBUG):
2021-11-17T21:56:59.516Z,1637186219.516 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2021-11-17T21:56:59.585Z,1637186219.585 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2021-11-17T21:56:59.598Z,1637186219.598 [Default:A.Wait](DEBUG): Construct Wait.
2021-11-17T21:56:59.601Z,1637186219.601 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-11-17T21:56:59.647Z,1637186219.647 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-11-17T21:56:59.650Z,1637186219.650 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-11-17T21:56:59.672Z,1637186219.672 [Default:E.Execute](DEBUG): Construct Execute.
2021-11-17T21:56:59.675Z,1637186219.675 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn on
Dropped weight due to communications timeout.
1
Default mission has been running for
Restarting logs and Default mission.
restart logs
2021-11-17T21:56:59.686Z,1637186219.686 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,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-11-17T21:56:59.696Z,1637186219.696 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2021-11-17T21:56:59.738Z,1637186219.738 [Radio_Surface](INFO): Powering up
2021-11-17T21:56:59.868Z,1637186219.868 [Power24vConverter](INFO): Powering up.
2021-11-17T21:56:59.869Z,1637186219.869 [AMEcho](INFO): Powering up.
2021-11-17T21:56:59.890Z,1637186219.890 [DAT](INFO): Powering up
2021-11-17T21:56:59.890Z,1637186219.890 [DAT](DEBUG): Initializing DAT.
2021-11-17T21:56:59.954Z,1637186219.954 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2021-11-17T21:56:59.962Z,1637186219.962 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2021-11-17T21:56:59.963Z,1637186219.963 [ElevatorServo](DEBUG): Initializing EZServoServo.
2021-11-17T21:56:59.970Z,1637186219.970 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2021-11-17T21:56:59.971Z,1637186219.971 [MassServo](DEBUG): Initializing EZServoServo.
2021-11-17T21:56:59.978Z,1637186219.978 [MassServo](DEBUG): Initializing MassServo.
2021-11-17T21:56:59.979Z,1637186219.979 [RudderServo](DEBUG): Initializing EZServoServo.
2021-11-17T21:56:59.986Z,1637186219.986 [RudderServo](DEBUG): Initializing RudderServo.
2021-11-17T21:56:59.987Z,1637186219.987 [ThrusterServo](DEBUG): Initializing EZServoServo.
2021-11-17T21:56:59.994Z,1637186219.994 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2021-11-17T21:56:59.996Z,1637186219.996 [CommandExec](FAULT): Scheduling is paused
2021-11-17T21:56:59.997Z,1637186219.997 [CBIT](INFO): Critical error at 20211117T215659
2021-11-17T21:56:59.997Z,1637186219.997 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2021-11-17T21:57:00.119Z,1637186220.119 [DropWeight](CRITICAL): DROP WEIGHT MISSING.
2021-11-17T21:57:00.119Z,1637186220.119 [DropWeight] Hardware Fault, FailCount= 1
2021-11-17T21:57:00.119Z,1637186220.119 [DropWeight](ERROR): Hardware Fault
2021-11-17T21:57:00.286Z,1637186220.286 [AMEcho](INFO): Powering down.
2021-11-17T21:57:00.324Z,1637186220.324 [CBIT](INFO): Critical error at 20211117T215700
2021-11-17T21:57:00.327Z,1637186220.327 [CBIT](ERROR): Hardware Fault in component: DropWeight
2021-11-17T21:57:00.327Z,1637186220.327 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2021-11-17T21:57:00.854Z,1637186220.854 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2021-11-17T21:57:00.854Z,1637186220.854 [RudderServo](FAULT): Rudder failed to initialize
2021-11-17T21:57:00.854Z,1637186220.854 [RudderServo] Communications Fault, FailCount= 1
2021-11-17T21:57:00.854Z,1637186220.854 [RudderServo](ERROR): Communications Fault
2021-11-17T21:57:00.955Z,1637186220.955 [CBIT](INFO): Critical error at 20211117T215700
2021-11-17T21:57:00.958Z,1637186220.958 [CBIT](ERROR): Communications Fault in component: RudderServo
2021-11-17T21:57:00.968Z,1637186220.968 [AMEcho](IMPORTANT): Setting 'depthThreshold' to 20.000000
2021-11-17T21:57:01.115Z,1637186221.115 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-11-17T21:57:01.115Z,1637186221.115 [RudderServo](INFO): Powering down
2021-11-17T21:57:01.478Z,1637186221.478 [WetLabsBB2FL](INFO): Powering down
2021-11-17T21:57:01.795Z,1637186221.795 [RudderServo](DEBUG): Initializing EZServoServo.
2021-11-17T21:57:01.915Z,1637186221.915 [RudderServo](DEBUG): Initializing RudderServo.
2021-11-17T21:57:01.919Z,1637186221.919 [CBIT](INFO): Clearing failed state for component RudderServo
2021-11-17T21:57:01.919Z,1637186221.919 [RudderServo] No Fault, FailCount= 1
2021-11-17T21:57:14.305Z,1637186234.305 [DAT](INFO): commRate: 1200
2021-11-17T21:57:16.324Z,1637186236.324 [DAT](INFO): entering command mode
2021-11-17T21:57:16.728Z,1637186236.728 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:17.132Z,1637186237.132 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:17.536Z,1637186237.536 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:17.940Z,1637186237.940 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:18.344Z,1637186238.344 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:18.748Z,1637186238.748 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:19.152Z,1637186239.152 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:19.556Z,1637186239.556 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:19.960Z,1637186239.960 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:20.364Z,1637186240.364 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:20.768Z,1637186240.768 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:21.172Z,1637186241.172 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:21.576Z,1637186241.576 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:21.984Z,1637186241.984 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:22.400Z,1637186242.400 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:22.788Z,1637186242.788 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:23.192Z,1637186243.192 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:23.604Z,1637186243.604 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:23.000Z,1637186244.000 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:24.404Z,1637186244.404 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:24.808Z,1637186244.808 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:25.216Z,1637186245.216 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:25.616Z,1637186245.616 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:26.020Z,1637186246.020 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:26.424Z,1637186246.424 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:26.828Z,1637186246.828 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:27.244Z,1637186247.244 [NAL9602](INFO): Powering up NAL9602
2021-11-17T21:57:27.246Z,1637186247.246 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:27.636Z,1637186247.636 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:28.040Z,1637186248.040 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:28.444Z,1637186248.444 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:28.856Z,1637186248.856 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:29.252Z,1637186249.252 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:29.656Z,1637186249.656 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:30.060Z,1637186250.060 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:30.468Z,1637186250.468 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:30.868Z,1637186250.868 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:31.272Z,1637186251.272 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:31.676Z,1637186251.676 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:57:31.676Z,1637186251.676 [DAT](FAULT): failed to enter command mode
2021-11-17T21:57:32.088Z,1637186252.088 [DAT](INFO): entering command mode
2021-11-17T21:57:32.492Z,1637186252.492 [DAT](INFO): setting verbose to 3
2021-11-17T21:57:32.889Z,1637186252.889 [DAT](INFO): set verbose to 3
2021-11-17T21:57:32.890Z,1637186252.890 [DAT](INFO): setting DatVerbose to 27440
2021-11-17T21:57:33.293Z,1637186253.293 [DAT](INFO): set DatVerbose to 27440
2021-11-17T21:57:33.293Z,1637186253.293 [DAT](INFO): setting transmit power to 8
2021-11-17T21:57:33.704Z,1637186253.704 [DAT](INFO): set transmit power to 8
2021-11-17T21:57:33.704Z,1637186253.704 [DAT](INFO): setting local address to 7
2021-11-17T21:57:34.101Z,1637186254.101 [DAT](INFO): set local address to 7
2021-11-17T21:57:38.139Z,1637186258.139 [NAL9602](INFO): NAL9602 initialized
2021-11-17T21:57:41.011Z,1637186261.011 [SBIT](IMPORTANT): Beginning Startup BIT
2021-11-17T21:57:41.019Z,1637186261.019 [CBIT](IMPORTANT): Beginning ground fault scan
2021-11-17T21:57:51.931Z,1637186271.931 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2021-11-17T21:57:52.354Z,1637186272.354 [CBIT](IMPORTANT): Beginning ground fault scan
2021-11-17T21:58:03.264Z,1637186283.264 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2021-11-17T21:58:03.656Z,1637186283.656 [CBIT](IMPORTANT): Beginning ground fault scan
2021-11-17T21:58:14.559Z,1637186294.559 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.002160
CHAN A1 (24V): 0.000316
CHAN A2 (12V): -0.002210
CHAN A3 (5V): -0.001225
CHAN B0 (3.3V): -0.000066
CHAN B1 (3.15aV): -0.000481
CHAN B2 (3.15bV): -0.000057
CHAN B3 (GND): -0.000212
OPEN: -0.000415
Full Scale: +/- 1 mA
2021-11-17T21:58:35.130Z,1637186315.130 [SBIT](IMPORTANT): SBIT PASSED
2021-11-17T21:58:35.131Z,1637186315.131 [SBIT](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2021-11-17T21:58:35.536Z,1637186315.536 [MissionManager](IMPORTANT): Started mission Startup
2021-11-17T21:58:35.536Z,1637186315.536 [Startup] Running Loop=1
2021-11-17T21:58:35.536Z,1637186315.536 [Startup](DEBUG): Aggregate::initialize Startup
2021-11-17T21:58:35.536Z,1637186315.536 [Startup:A.GoToSurface] Running Loop=1
2021-11-17T21:58:35.536Z,1637186315.536 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-11-17T21:58:35.537Z,1637186315.537 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-11-17T21:58:35.538Z,1637186315.538 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-11-17T21:58:35.538Z,1637186315.538 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-11-17T21:58:35.538Z,1637186315.538 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-11-17T21:58:35.539Z,1637186315.539 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-11-17T21:58:35.540Z,1637186315.540 [Startup:StartupSatComms] Running Loop=1
2021-11-17T21:58:35.540Z,1637186315.540 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2021-11-17T21:58:35.541Z,1637186315.541 [Startup:StartupSatComms:A] Running Loop=1
2021-11-17T21:58:35.928Z,1637186315.928 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2021-11-17T21:58:36.320Z,1637186316.320 [AMEcho](INFO): Powering up.
2021-11-17T21:59:32.256Z,1637186372.256 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004698
2021-11-17T21:59:35.873Z,1637186375.873 [Startup:StartupSatComms:A](INFO): Timed out from 2021-11-17T21:58:35.5Z
2021-11-17T21:59:35.873Z,1637186375.873 [Startup:StartupSatComms:A] Stopped
2021-11-17T21:59:35.873Z,1637186375.873 [Startup:StartupSatComms:B] Running Loop=1
2021-11-17T21:59:36.282Z,1637186376.282 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-11-17T21:59:43.603Z,1637186383.603 [DataOverHttps](INFO): Sending 2583 bytes from file Logs/20211117T213937/Courier9001.lzma
2021-11-17T21:59:44.600Z,1637186384.600 [DataOverHttps](INFO): Moved sent file to Logs/20211117T213937/Courier9001.lzma.bak
2021-11-17T21:59:44.600Z,1637186384.601 [DataOverHttps](INFO): SBD MOMSN=16262988
2021-11-17T21:59:59.312Z,1637186399.312 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2021-11-17T21:59:59.312Z,1637186399.312 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-11-17T21:59:59.355Z,1637186399.355 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-11-17T21:59:59.786Z,1637186399.786 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-11-17T21:59:59.786Z,1637186399.786 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2021-11-17T22:00:00.466Z,1637186400.466 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20211117T214923/Courier0000.lzma
2021-11-17T22:00:01.468Z,1637186401.468 [DataOverHttps](INFO): Moved sent file to Logs/20211117T214923/Courier0000.lzma.bak
2021-11-17T22:00:01.468Z,1637186401.468 [DataOverHttps](INFO): SBD MOMSN=16262991
2021-11-17T22:00:24.772Z,1637186424.772 [DataOverHttps](INFO): Sending 296 bytes from file Logs/20211117T215120/Courier0000.lzma
2021-11-17T22:00:25.772Z,1637186425.772 [DataOverHttps](INFO): Moved sent file to Logs/20211117T215120/Courier0000.lzma.bak
2021-11-17T22:00:25.773Z,1637186425.773 [DataOverHttps](INFO): SBD MOMSN=16262994
2021-11-17T22:00:36.149Z,1637186436.149 [Startup:StartupSatComms:B](INFO): Timed out from 2021-11-17T21:59:35.9Z
2021-11-17T22:00:36.149Z,1637186436.149 [Startup:StartupSatComms:B] Stopped
2021-11-17T22:00:36.149Z,1637186436.149 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2021-11-17T22:00:36.149Z,1637186436.149 [Startup:StartupSatComms] Stopped
2021-11-17T22:00:36.149Z,1637186436.149 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2021-11-17T22:00:36.154Z,1637186436.154 [Startup](INFO): Completed Startup
2021-11-17T22:00:36.155Z,1637186436.155 [MissionManager](INFO): Startup is completed.
2021-11-17T22:00:36.155Z,1637186436.155 [MissionManager](INFO): Uninitializing Mission Startup
2021-11-17T22:00:36.155Z,1637186436.155 [Startup] Stopped
2021-11-17T22:00:36.155Z,1637186436.155 [Startup](DEBUG): Aggregate::uninitialize Startup
2021-11-17T22:00:36.155Z,1637186436.155 [Startup:A.GoToSurface] Stopped
2021-11-17T22:00:36.155Z,1637186436.155 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-11-17T22:00:36.529Z,1637186436.529 [MissionManager](IMPORTANT): Started mission Default
2021-11-17T22:00:36.530Z,1637186436.530 [Default] Running Loop=1
2021-11-17T22:00:36.530Z,1637186436.530 [Default](DEBUG): Aggregate::initialize Default
2021-11-17T22:00:36.530Z,1637186436.530 [Default:B.GoToSurface] Running Loop=1
2021-11-17T22:00:36.530Z,1637186436.530 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-11-17T22:00:36.535Z,1637186436.535 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-11-17T22:00:36.535Z,1637186436.535 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-11-17T22:00:36.535Z,1637186436.535 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-11-17T22:00:36.536Z,1637186436.536 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-11-17T22:00:36.536Z,1637186436.536 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-11-17T22:00:36.536Z,1637186436.536 [Default:A.Wait] Running Loop=1
2021-11-17T22:00:36.536Z,1637186436.536 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-11-17T22:00:37.099Z,1637186437.099 [AMEcho](INFO): Powering down.
2021-11-17T22:00:38.147Z,1637186438.147 [AMEcho](INFO): Powering up.
2021-11-17T22:00:49.010Z,1637186449.010 [DataOverHttps](INFO): Sending 339 bytes from file Logs/20211117T215120/Courier0004.lzma
2021-11-17T22:00:49.860Z,1637186449.860 [Default:A.Wait](INFO): Done Waiting.
2021-11-17T22:00:49.860Z,1637186449.860 [Default:A.Wait] Stopped
2021-11-17T22:00:49.860Z,1637186449.860 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-11-17T22:00:50.012Z,1637186450.012 [DataOverHttps](INFO): Moved sent file to Logs/20211117T215120/Courier0004.lzma.bak
2021-11-17T22:00:50.012Z,1637186450.012 [DataOverHttps](INFO): SBD MOMSN=16262999
2021-11-17T22:00:50.259Z,1637186450.259 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2021-11-17T22:00:50.259Z,1637186450.259 [AMEcho] Communications Fault, FailCount= 1
2021-11-17T22:00:50.259Z,1637186450.259 [AMEcho](ERROR): Communications Fault
2021-11-17T22:00:50.275Z,1637186450.275 [Default:CheckIn] Running Loop=1
2021-11-17T22:00:50.275Z,1637186450.275 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-11-17T22:00:50.275Z,1637186450.275 [Default:CheckIn:Read_GPS] Running Loop=1
2021-11-17T22:00:50.284Z,1637186450.284 [CBIT](ERROR): Communications Fault in component: AMEcho
2021-11-17T22:00:50.815Z,1637186450.815 [AMEcho](INFO): Powering down.
2021-11-17T22:00:50.838Z,1637186450.838 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2021-11-17T22:00:51.483Z,1637186451.483 [CBIT](INFO): Clearing failed state for component AMEcho
2021-11-17T22:00:51.483Z,1637186451.483 [AMEcho] No Fault, FailCount= 1
2021-11-17T22:00:51.869Z,1637186451.869 [AMEcho](INFO): Powering up.
2021-11-17T22:01:03.999Z,1637186463.999 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2021-11-17T22:01:03.999Z,1637186463.999 [AMEcho] Communications Fault, FailCount= 2
2021-11-17T22:01:03.999Z,1637186463.999 [AMEcho](ERROR): Communications Fault
2021-11-17T22:01:04.043Z,1637186464.043 [CBIT](ERROR): Communications Fault in component: AMEcho
2021-11-17T22:01:04.571Z,1637186464.571 [AMEcho](INFO): Powering down.
2021-11-17T22:01:05.228Z,1637186465.228 [CBIT](INFO): Clearing failed state for component AMEcho
2021-11-17T22:01:05.228Z,1637186465.228 [AMEcho] No Fault, FailCount= 2
2021-11-17T22:01:05.604Z,1637186465.604 [AMEcho](INFO): Powering up.
2021-11-17T22:01:17.737Z,1637186477.737 [AMEcho](ERROR): No EchoSounder communication! Re-initializing
2021-11-17T22:01:17.737Z,1637186477.737 [AMEcho] Communications Fault, FailCount= 3
2021-11-17T22:01:17.737Z,1637186477.737 [AMEcho](ERROR): Communications Fault
2021-11-17T22:01:17.756Z,1637186477.756 [CBIT](ERROR): Communications Fault in component: AMEcho
2021-11-17T22:01:17.756Z,1637186477.756 [CBIT](CRITICAL): Communications Fault in component: AMEcho
2021-11-17T22:01:18.287Z,1637186478.287 [AMEcho](INFO): Powering down.
2021-11-17T22:01:18.309Z,1637186478.309 [CBIT](INFO): Critical error at 20211117T220117
2021-11-17T22:01:50.461Z,1637186510.461 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-11-17T22:00:50.3Z
2021-11-17T22:01:50.461Z,1637186510.461 [Default:CheckIn:Read_GPS] Stopped
2021-11-17T22:01:50.461Z,1637186510.461 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-11-17T22:01:50.877Z,1637186510.877 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-11-17T22:01:57.307Z,1637186517.307 [DataOverHttps](INFO): Sending 283 bytes from file Logs/20211117T215648/Courier0000.lzma
2021-11-17T22:01:58.308Z,1637186518.308 [DataOverHttps](INFO): Moved sent file to Logs/20211117T215648/Courier0000.lzma.bak
2021-11-17T22:01:58.308Z,1637186518.308 [DataOverHttps](INFO): SBD MOMSN=16263096
2021-11-17T22:02:13.978Z,1637186533.978 [DataOverHttps](INFO): Sending 87 bytes from file Logs/20211117T215648/Courier0004.lzma
2021-11-17T22:02:14.981Z,1637186534.981 [DataOverHttps](INFO): Moved sent file to Logs/20211117T215648/Courier0004.lzma.bak
2021-11-17T22:02:14.981Z,1637186534.981 [DataOverHttps](INFO): SBD MOMSN=16263105
2021-11-17T22:02:31.691Z,1637186551.691 [DataOverHttps](INFO): Sending 163 bytes from file Logs/20211117T185525/Express0068.lzma
2021-11-17T22:02:32.693Z,1637186552.693 [DataOverHttps](INFO): Moved sent file to Logs/20211117T185525/Express0068.lzma.bak
2021-11-17T22:02:32.693Z,1637186552.693 [DataOverHttps](INFO): SBD MOMSN=16263110
2021-11-17T22:02:41.444Z,1637186561.444 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-11-17T22:02:49.503Z,1637186569.503 [DataOverHttps](INFO): Sending 249 bytes from file Logs/20211117T185525/Express0071.lzma
2021-11-17T22:02:50.504Z,1637186570.504 [DataOverHttps](INFO): Moved sent file to Logs/20211117T185525/Express0071.lzma.bak
2021-11-17T22:02:50.505Z,1637186570.505 [DataOverHttps](INFO): SBD MOMSN=16263116
2021-11-17T22:03:00.423Z,1637186580.423 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2021-11-17T22:03:00.423Z,1637186580.423 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-11-17T22:03:00.435Z,1637186580.435 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-11-17T22:03:00.859Z,1637186580.859 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-11-17T22:03:00.859Z,1637186580.859 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2021-11-17T22:03:07.176Z,1637186587.176 [DataOverHttps](INFO): Sending 165 bytes from file Logs/20211117T185525/Express0074.lzma
2021-11-17T22:03:08.177Z,1637186588.177 [DataOverHttps](INFO): Moved sent file to Logs/20211117T185525/Express0074.lzma.bak
2021-11-17T22:03:08.177Z,1637186588.177 [DataOverHttps](INFO): SBD MOMSN=16263154
2021-11-17T22:03:25.039Z,1637186605.039 [DataOverHttps](INFO): Sending 163 bytes from file Logs/20211117T185525/Express0077.lzma
2021-11-17T22:03:26.041Z,1637186606.041 [DataOverHttps](INFO): Moved sent file to Logs/20211117T185525/Express0077.lzma.bak
2021-11-17T22:03:26.041Z,1637186606.041 [DataOverHttps](INFO): SBD MOMSN=16263229
2021-11-17T22:03:42.743Z,1637186622.743 [DataOverHttps](INFO): Sending 231 bytes from file Logs/20211117T185525/Express0080.lzma
2021-11-17T22:03:43.745Z,1637186623.745 [DataOverHttps](INFO): Moved sent file to Logs/20211117T185525/Express0080.lzma.bak
2021-11-17T22:03:43.745Z,1637186623.745 [DataOverHttps](INFO): SBD MOMSN=16263240
2021-11-17T22:04:00.367Z,1637186640.367 [DataOverHttps](INFO): Sending 165 bytes from file Logs/20211117T185525/Express0083.lzma
2021-11-17T22:04:01.369Z,1637186641.369 [DataOverHttps](INFO): Moved sent file to Logs/20211117T185525/Express0083.lzma.bak
2021-11-17T22:04:01.369Z,1637186641.369 [DataOverHttps](INFO): SBD MOMSN=16263247
2021-11-17T22:04:18.017Z,1637186658.017 [CBIT](INFO): Clearing failed state for component AMEcho
2021-11-17T22:04:18.017Z,1637186658.017 [AMEcho] No Fault, FailCount= 3
2021-11-17T22:04:18.399Z,1637186658.399 [AMEcho](INFO): Powering up.
2021-11-17T22:04:18.652Z,1637186658.652 [DataOverHttps](INFO): Sending 165 bytes from file Logs/20211117T185525/Express0086.lzma
2021-11-17T22:04:19.561Z,1637186659.561 [DataOverHttps](INFO): Moved sent file to Logs/20211117T185525/Express0086.lzma.bak
2021-11-17T22:04:19.561Z,1637186659.561 [DataOverHttps](INFO): SBD MOMSN=16263254
2021-11-17T22:04:30.116Z,1637186670.116 [AMEcho](INFO): Failure count cleared after critical for AMEcho
2021-11-17T22:04:36.360Z,1637186676.360 [DataOverHttps](INFO): Sending 248 bytes from file Logs/20211117T185525/Express0089.lzma
2021-11-17T22:04:37.360Z,1637186677.360 [DataOverHttps](INFO): Moved sent file to Logs/20211117T185525/Express0089.lzma.bak
2021-11-17T22:04:37.361Z,1637186677.361 [DataOverHttps](INFO): SBD MOMSN=16263258
2021-11-17T22:04:54.783Z,1637186694.783 [DataOverHttps](INFO): Sending 166 bytes from file Logs/20211117T185525/Express0092.lzma
2021-11-17T22:04:55.785Z,1637186695.785 [DataOverHttps](INFO): Moved sent file to Logs/20211117T185525/Express0092.lzma.bak
2021-11-17T22:04:55.785Z,1637186695.785 [DataOverHttps](INFO): SBD MOMSN=16263264
2021-11-17T22:05:00.817Z,1637186700.817 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2021-11-17T22:05:00.820Z,1637186700.820 [BPC1](INFO): Received data from all battery sticks.
2021-11-17T22:05:11.619Z,1637186711.619 [DataOverHttps](INFO): Sending 164 bytes from file Logs/20211117T185525/Express0095.lzma
2021-11-17T22:05:12.621Z,1637186712.621 [DataOverHttps](INFO): Moved sent file to Logs/20211117T185525/Express0095.lzma.bak
2021-11-17T22:05:12.621Z,1637186712.621 [DataOverHttps](INFO): SBD MOMSN=16263268
2021-11-17T22:05:29.903Z,1637186729.903 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20211117T185525/Express0098.lzma
2021-11-17T22:05:30.905Z,1637186730.905 [DataOverHttps](INFO): Moved sent file to Logs/20211117T185525/Express0098.lzma.bak
2021-11-17T22:05:30.905Z,1637186730.905 [DataOverHttps](INFO): SBD MOMSN=16263272
2021-11-17T22:05:47.617Z,1637186747.617 [DataOverHttps](INFO): Sending 949 bytes from file Logs/20211117T205316/Express0001.lzma
2021-11-17T22:05:48.616Z,1637186748.616 [DataOverHttps](INFO): Moved sent file to Logs/20211117T205316/Express0001.lzma.bak
2021-11-17T22:05:48.617Z,1637186748.617 [DataOverHttps](INFO): SBD MOMSN=16263276
2021-11-17T22:06:01.431Z,1637186761.431 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2021-11-17T22:06:01.431Z,1637186761.431 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-11-17T22:06:01.474Z,1637186761.474 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-11-17T22:06:01.851Z,1637186761.851 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-11-17T22:06:01.851Z,1637186761.851 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2021-11-17T22:06:05.372Z,1637186765.372 [DataOverHttps](INFO): Sending 296 bytes from file Logs/20211117T205316/Express0005.lzma
2021-11-17T22:06:06.372Z,1637186766.372 [DataOverHttps](INFO): Moved sent file to Logs/20211117T205316/Express0005.lzma.bak
2021-11-17T22:06:06.372Z,1637186766.372 [DataOverHttps](INFO): SBD MOMSN=16263309
2021-11-17T22:06:23.528Z,1637186783.528 [DataOverHttps](INFO): Sending 626 bytes from file Logs/20211117T205316/Express0008.lzma
2021-11-17T22:06:24.528Z,1637186784.528 [DataOverHttps](INFO): Moved sent file to Logs/20211117T205316/Express0008.lzma.bak
2021-11-17T22:06:24.528Z,1637186784.528 [DataOverHttps](INFO): SBD MOMSN=16263324
2021-11-17T22:06:41.333Z,1637186801.333 [DataOverHttps](INFO): Sending 950 bytes from file Logs/20211117T211816/Express0001.lzma
2021-11-17T22:06:42.333Z,1637186802.333 [DataOverHttps](INFO): Moved sent file to Logs/20211117T211816/Express0001.lzma.bak
2021-11-17T22:06:42.333Z,1637186802.333 [DataOverHttps](INFO): SBD MOMSN=16263367
2021-11-17T22:06:59.626Z,1637186819.626 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20211117T211816/Express0005.lzma
2021-11-17T22:07:00.628Z,1637186820.628 [DataOverHttps](INFO): Moved sent file to Logs/20211117T211816/Express0005.lzma.bak
2021-11-17T22:07:00.628Z,1637186820.628 [DataOverHttps](INFO): SBD MOMSN=16263398
2021-11-17T22:07:16.501Z,1637186836.501 [DataOverHttps](INFO): Sending 1005 bytes from file Logs/20211117T212446/Express0001.lzma
2021-11-17T22:07:17.501Z,1637186837.501 [DataOverHttps](INFO): Moved sent file to Logs/20211117T212446/Express0001.lzma.bak
2021-11-17T22:07:17.501Z,1637186837.501 [DataOverHttps](INFO): SBD MOMSN=16263400
2021-11-17T22:07:34.255Z,1637186854.255 [DataOverHttps](INFO): Sending 147 bytes from file Logs/20211117T212446/Express0005.lzma
2021-11-17T22:07:35.257Z,1637186855.257 [DataOverHttps](INFO): Moved sent file to Logs/20211117T212446/Express0005.lzma.bak
2021-11-17T22:07:35.257Z,1637186855.257 [DataOverHttps](INFO): SBD MOMSN=16263421
2021-11-17T22:07:40.792Z,1637186860.792 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-11-17T22:07:40.792Z,1637186860.792 [NAL9602] Data Fault, FailCount= 1
2021-11-17T22:07:40.792Z,1637186860.792 [NAL9602](ERROR): Data Fault
2021-11-17T22:07:40.859Z,1637186860.859 [CBIT](ERROR): Data Fault in component: NAL9602
2021-11-17T22:07:41.196Z,1637186861.196 [NAL9602](INFO): Powering down
2021-11-17T22:07:41.604Z,1637186861.604 [NAL9602](FAULT): LCB fault: Software Overcurrent.
2021-11-17T22:07:41.604Z,1637186861.604 [NAL9602] Hardware Fault, FailCount= 1
2021-11-17T22:07:41.604Z,1637186861.604 [NAL9602](ERROR): Hardware Fault
2021-11-17T22:07:42.108Z,1637186862.108 [CBIT](INFO): Clearing failed state for component NAL9602
2021-11-17T22:07:42.108Z,1637186862.108 [NAL9602] No Fault, FailCount= 1
2021-11-17T22:07:51.341Z,1637186871.341 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20211117T212446/Express0008.lzma
2021-11-17T22:07:52.320Z,1637186872.320 [DataOverHttps](INFO): Moved sent file to Logs/20211117T212446/Express0008.lzma.bak
2021-11-17T22:07:52.320Z,1637186872.320 [DataOverHttps](INFO): SBD MOMSN=16263426
2021-11-17T22:08:09.036Z,1637186889.036 [DataOverHttps](INFO): Sending 888 bytes from file Logs/20211117T213937/Express0001.lzma
2021-11-17T22:08:10.036Z,1637186890.036 [DataOverHttps](INFO): Moved sent file to Logs/20211117T213937/Express0001.lzma.bak
2021-11-17T22:08:10.037Z,1637186890.037 [DataOverHttps](INFO): SBD MOMSN=16263429
2021-11-17T22:08:11.500Z,1637186891.500 [NAL9602](INFO): Powering up NAL9602
2021-11-17T22:08:22.430Z,1637186902.430 [NAL9602](INFO): NAL9602 initialized
2021-11-17T22:08:26.838Z,1637186906.838 [DataOverHttps](INFO): Sending 83 bytes from file Logs/20211117T213937/Express0005.lzma
2021-11-17T22:08:27.840Z,1637186907.840 [DataOverHttps](INFO): Moved sent file to Logs/20211117T213937/Express0005.lzma.bak
2021-11-17T22:08:27.840Z,1637186907.840 [DataOverHttps](INFO): SBD MOMSN=16263459
2021-11-17T22:08:44.594Z,1637186924.594 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20211117T213937/Express0008.lzma
2021-11-17T22:08:45.596Z,1637186925.596 [DataOverHttps](INFO): Moved sent file to Logs/20211117T213937/Express0008.lzma.bak
2021-11-17T22:08:45.596Z,1637186925.596 [DataOverHttps](INFO): SBD MOMSN=16263462
2021-11-17T22:09:02.274Z,1637186942.274 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20211117T213937/Express0011.lzma
2021-11-17T22:09:02.485Z,1637186942.485 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2021-11-17T22:09:02.485Z,1637186942.485 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-11-17T22:09:02.496Z,1637186942.496 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-11-17T22:09:02.904Z,1637186942.904 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-11-17T22:09:02.905Z,1637186942.905 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2021-11-17T22:09:03.276Z,1637186943.276 [DataOverHttps](INFO): Moved sent file to Logs/20211117T213937/Express0011.lzma.bak
2021-11-17T22:09:03.276Z,1637186943.276 [DataOverHttps](INFO): SBD MOMSN=16263466
2021-11-17T22:09:20.226Z,1637186960.226 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20211117T214923/Express0001.lzma
2021-11-17T22:09:21.228Z,1637186961.228 [DataOverHttps](INFO): Moved sent file to Logs/20211117T214923/Express0001.lzma.bak
2021-11-17T22:09:21.228Z,1637186961.228 [DataOverHttps](INFO): SBD MOMSN=16263468
2021-11-17T22:09:38.016Z,1637186978.016 [DataOverHttps](INFO): Sending 1168 bytes from file Logs/20211117T215120/Express0001.lzma
2021-11-17T22:09:39.016Z,1637186979.016 [DataOverHttps](INFO): Moved sent file to Logs/20211117T215120/Express0001.lzma.bak
2021-11-17T22:09:39.016Z,1637186979.016 [DataOverHttps](INFO): SBD MOMSN=16263474
2021-11-17T22:09:55.734Z,1637186995.734 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20211117T215120/Express0005.lzma
2021-11-17T22:09:56.736Z,1637186996.736 [DataOverHttps](INFO): Moved sent file to Logs/20211117T215120/Express0005.lzma.bak
2021-11-17T22:09:56.736Z,1637186996.736 [DataOverHttps](INFO): SBD MOMSN=16263518
2021-11-17T22:10:16.144Z,1637187016.144 [DataOverHttps](INFO): Sending 1038 bytes from file Logs/20211117T215648/Express0001.lzma
2021-11-17T22:10:17.203Z,1637187017.203 [DataOverHttps](INFO): Moved sent file to Logs/20211117T215648/Express0001.lzma.bak
2021-11-17T22:10:17.203Z,1637187017.203 [DataOverHttps](INFO): SBD MOMSN=16263521
2021-11-17T22:10:36.674Z,1637187036.674 [DataOverHttps](INFO): Sending 83 bytes from file Logs/20211117T215648/Express0005.lzma
2021-11-17T22:10:37.676Z,1637187037.676 [DataOverHttps](INFO): Moved sent file to Logs/20211117T215648/Express0005.lzma.bak
2021-11-17T22:10:37.676Z,1637187037.676 [DataOverHttps](INFO): SBD MOMSN=16263541
2021-11-17T22:10:39.962Z,1637187039.962 [Default:CheckIn:Read_Iridium] Stopped
2021-11-17T22:10:39.962Z,1637187039.962 [Default:CheckIn:C.Wait] Running Loop=1
2021-11-17T22:10:39.962Z,1637187039.962 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-11-17T22:11:40.562Z,1637187100.562 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-11-17T22:11:40.562Z,1637187100.562 [Default:CheckIn:C.Wait] Stopped
2021-11-17T22:11:40.562Z,1637187100.562 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-11-17T22:11:40.562Z,1637187100.562 [Default:CheckIn:D] Running Loop=1
2021-11-17T22:11:40.976Z,1637187100.976 [Default:CheckIn:D] Stopped
2021-11-17T22:11:40.976Z,1637187100.976 [Default:CheckIn:E] Running Loop=1
2021-11-17T22:11:41.344Z,1637187101.344 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.074106 min
2021-11-17T22:11:41.344Z,1637187101.344 [Default:CheckIn:E] Stopped
2021-11-17T22:11:41.344Z,1637187101.344 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-11-17T22:11:41.344Z,1637187101.344 [Default:CheckIn] Stopped
2021-11-17T22:11:41.344Z,1637187101.344 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-11-17T22:11:41.344Z,1637187101.344 [Default:CheckIn](INFO): Running loop #2
2021-11-17T22:11:41.344Z,1637187101.344 [Default:CheckIn] Running Loop=2
2021-11-17T22:11:41.344Z,1637187101.344 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-11-17T22:11:41.345Z,1637187101.345 [Default:CheckIn:Read_GPS] Running Loop=1
2021-11-17T22:12:00.351Z,1637187120.351 [CBIT](INFO): Clearing failed state for component DropWeight
2021-11-17T22:12:00.351Z,1637187120.351 [DropWeight] No Fault, FailCount= 1
2021-11-17T22:12:03.571Z,1637187123.571 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2021-11-17T22:12:03.571Z,1637187123.571 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-11-17T22:12:03.582Z,1637187123.582 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-11-17T22:12:04.002Z,1637187124.002 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-11-17T22:12:04.002Z,1637187124.002 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2021-11-17T22:12:41.557Z,1637187161.557 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-11-17T22:11:41.3Z
2021-11-17T22:12:41.558Z,1637187161.558 [Default:CheckIn:Read_GPS] Stopped
2021-11-17T22:12:41.558Z,1637187161.558 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-11-17T22:12:49.346Z,1637187169.346 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20211117T215648/Courier0007.lzma
2021-11-17T22:12:50.348Z,1637187170.348 [DataOverHttps](INFO): Moved sent file to Logs/20211117T215648/Courier0007.lzma.bak
2021-11-17T22:12:50.348Z,1637187170.348 [DataOverHttps](INFO): SBD MOMSN=16263548
2021-11-17T22:13:07.138Z,1637187187.138 [DataOverHttps](INFO): Sending 274 bytes from file Logs/20211117T215648/Express0008.lzma
2021-11-17T22:13:08.140Z,1637187188.140 [DataOverHttps](INFO): Moved sent file to Logs/20211117T215648/Express0008.lzma.bak
2021-11-17T22:13:08.140Z,1637187188.140 [DataOverHttps](INFO): SBD MOMSN=16263550
2021-11-17T22:13:10.252Z,1637187190.252 [Default:CheckIn:Read_Iridium] Stopped
2021-11-17T22:13:10.252Z,1637187190.252 [Default:CheckIn:C.Wait] Running Loop=1
2021-11-17T22:13:10.252Z,1637187190.252 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-11-17T22:14:10.861Z,1637187250.861 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-11-17T22:14:10.861Z,1637187250.861 [Default:CheckIn:C.Wait] Stopped
2021-11-17T22:14:10.861Z,1637187250.861 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-11-17T22:14:10.861Z,1637187250.861 [Default:CheckIn:D] Running Loop=1
2021-11-17T22:14:11.231Z,1637187251.231 [Default:CheckIn:D] Stopped
2021-11-17T22:14:11.231Z,1637187251.231 [Default:CheckIn:E] Running Loop=1
2021-11-17T22:14:11.643Z,1637187251.643 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 13.578355 min
2021-11-17T22:14:11.643Z,1637187251.643 [Default:CheckIn:E] Stopped
2021-11-17T22:14:11.643Z,1637187251.643 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-11-17T22:14:11.643Z,1637187251.643 [Default:CheckIn] Stopped
2021-11-17T22:14:11.643Z,1637187251.643 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-11-17T22:14:11.643Z,1637187251.643 [Default:CheckIn](INFO): Running loop #3
2021-11-17T22:14:11.643Z,1637187251.643 [Default:CheckIn] Running Loop=3
2021-11-17T22:14:11.643Z,1637187251.643 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-11-17T22:14:11.644Z,1637187251.644 [Default:CheckIn:Read_GPS] Running Loop=1
2021-11-17T22:15:04.557Z,1637187304.557 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2021-11-17T22:15:04.557Z,1637187304.557 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-11-17T22:15:04.568Z,1637187304.568 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-11-17T22:15:04.983Z,1637187304.983 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-11-17T22:15:04.984Z,1637187304.984 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2021-11-17T22:15:11.852Z,1637187311.852 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-11-17T22:14:11.6Z
2021-11-17T22:15:11.852Z,1637187311.852 [Default:CheckIn:Read_GPS] Stopped
2021-11-17T22:15:11.852Z,1637187311.852 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-11-17T22:15:18.758Z,1637187318.758 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20211117T215648/Courier0010.lzma
2021-11-17T22:15:19.760Z,1637187319.760 [DataOverHttps](INFO): Moved sent file to Logs/20211117T215648/Courier0010.lzma.bak
2021-11-17T22:15:19.760Z,1637187319.760 [DataOverHttps](INFO): SBD MOMSN=16263556
2021-11-17T22:15:36.438Z,1637187336.438 [DataOverHttps](INFO): Sending 108 bytes from file Logs/20211117T215648/Express0011.lzma
2021-11-17T22:15:37.440Z,1637187337.440 [DataOverHttps](INFO): Moved sent file to Logs/20211117T215648/Express0011.lzma.bak
2021-11-17T22:15:37.441Z,1637187337.441 [DataOverHttps](INFO): SBD MOMSN=16263558
2021-11-17T22:15:39.737Z,1637187339.737 [Default:CheckIn:Read_Iridium] Stopped
2021-11-17T22:15:39.737Z,1637187339.737 [Default:CheckIn:C.Wait] Running Loop=1
2021-11-17T22:15:39.737Z,1637187339.737 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-11-17T22:16:40.340Z,1637187400.340 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-11-17T22:16:40.340Z,1637187400.340 [Default:CheckIn:C.Wait] Stopped
2021-11-17T22:16:40.340Z,1637187400.340 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-11-17T22:16:40.340Z,1637187400.340 [Default:CheckIn:D] Running Loop=1
2021-11-17T22:16:40.729Z,1637187400.729 [Default:CheckIn:D] Stopped
2021-11-17T22:16:40.729Z,1637187400.729 [Default:CheckIn:E] Running Loop=1
2021-11-17T22:16:41.123Z,1637187401.123 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 16.069994 min
2021-11-17T22:16:41.123Z,1637187401.123 [Default:CheckIn:E] Stopped
2021-11-17T22:16:41.123Z,1637187401.123 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-11-17T22:16:41.123Z,1637187401.123 [Default:CheckIn] Stopped
2021-11-17T22:16:41.124Z,1637187401.124 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-11-17T22:16:41.124Z,1637187401.124 [Default:CheckIn](INFO): Running loop #4
2021-11-17T22:16:41.124Z,1637187401.124 [Default:CheckIn] Running Loop=4
2021-11-17T22:16:41.124Z,1637187401.124 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-11-17T22:16:41.124Z,1637187401.124 [Default:CheckIn:Read_GPS] Running Loop=1
2021-11-17T22:17:41.348Z,1637187461.348 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-11-17T22:16:41.1Z
2021-11-17T22:17:41.348Z,1637187461.348 [Default:CheckIn:Read_GPS] Stopped
2021-11-17T22:17:41.348Z,1637187461.348 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-11-17T22:17:48.682Z,1637187468.682 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20211117T215648/Courier0013.lzma
2021-11-17T22:17:49.684Z,1637187469.684 [DataOverHttps](INFO): Moved sent file to Logs/20211117T215648/Courier0013.lzma.bak
2021-11-17T22:17:49.684Z,1637187469.684 [DataOverHttps](INFO): SBD MOMSN=16263569
2021-11-17T22:18:05.597Z,1637187485.597 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2021-11-17T22:18:05.597Z,1637187485.597 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-11-17T22:18:05.644Z,1637187485.644 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-11-17T22:18:06.007Z,1637187486.007 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-11-17T22:18:06.007Z,1637187486.007 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2021-11-17T22:18:06.690Z,1637187486.690 [DataOverHttps](INFO): Sending 108 bytes from file Logs/20211117T215648/Express0014.lzma
2021-11-17T22:18:07.697Z,1637187487.697 [DataOverHttps](INFO): Moved sent file to Logs/20211117T215648/Express0014.lzma.bak
2021-11-17T22:18:07.697Z,1637187487.697 [DataOverHttps](INFO): SBD MOMSN=16263571
2021-11-17T22:18:10.939Z,1637187490.939 [Default:CheckIn:Read_Iridium] Stopped
2021-11-17T22:18:10.939Z,1637187490.939 [Default:CheckIn:C.Wait] Running Loop=1
2021-11-17T22:18:10.939Z,1637187490.939 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-11-17T22:18:25.064Z,1637187505.064 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-11-17T22:18:25.064Z,1637187505.064 [NAL9602] Data Fault, FailCount= 2
2021-11-17T22:18:25.064Z,1637187505.064 [NAL9602](ERROR): Data Fault
2021-11-17T22:18:25.084Z,1637187505.084 [CBIT](ERROR): Data Fault in component: NAL9602
2021-11-17T22:18:25.468Z,1637187505.468 [NAL9602](INFO): Powering down
2021-11-17T22:18:26.329Z,1637187506.329 [CBIT](INFO): Clearing failed state for component NAL9602
2021-11-17T22:18:26.329Z,1637187506.329 [NAL9602] No Fault, FailCount= 2
2021-11-17T22:18:55.792Z,1637187535.792 [NAL9602](INFO): Powering up NAL9602
2021-11-17T22:19:06.732Z,1637187546.732 [NAL9602](INFO): NAL9602 initialized
2021-11-17T22:19:11.589Z,1637187551.589 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-11-17T22:19:11.589Z,1637187551.589 [Default:CheckIn:C.Wait] Stopped
2021-11-17T22:19:11.589Z,1637187551.589 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-11-17T22:19:11.589Z,1637187551.589 [Default:CheckIn:D] Running Loop=1
2021-11-17T22:19:11.995Z,1637187551.995 [Default:CheckIn:D] Stopped
2021-11-17T22:19:11.995Z,1637187551.995 [Default:CheckIn:E] Running Loop=1
2021-11-17T22:19:12.407Z,1637187552.407 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.591091 min
2021-11-17T22:19:12.407Z,1637187552.407 [Default:CheckIn:E] Stopped
2021-11-17T22:19:12.408Z,1637187552.408 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-11-17T22:19:12.408Z,1637187552.408 [Default:CheckIn] Stopped
2021-11-17T22:19:12.408Z,1637187552.408 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-11-17T22:19:12.408Z,1637187552.408 [Default:CheckIn](INFO): Running loop #5
2021-11-17T22:19:12.408Z,1637187552.408 [Default:CheckIn] Running Loop=5
2021-11-17T22:19:12.408Z,1637187552.408 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-11-17T22:19:12.408Z,1637187552.408 [Default:CheckIn:Read_GPS] Running Loop=1
2021-11-17T22:20:12.625Z,1637187612.625 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-11-17T22:19:12.4Z
2021-11-17T22:20:12.626Z,1637187612.626 [Default:CheckIn:Read_GPS] Stopped
2021-11-17T22:20:12.626Z,1637187612.626 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-11-17T22:20:20.950Z,1637187620.950 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20211117T215648/Courier0016.lzma
2021-11-17T22:20:21.952Z,1637187621.952 [DataOverHttps](INFO): Moved sent file to Logs/20211117T215648/Courier0016.lzma.bak
2021-11-17T22:20:21.953Z,1637187621.953 [DataOverHttps](INFO): SBD MOMSN=16263576
2021-11-17T22:20:38.150Z,1637187638.150 [DataOverHttps](INFO): Sending 2583 bytes from file Logs/20211117T215648/Courier9001.lzma
2021-11-17T22:20:39.156Z,1637187639.156 [DataOverHttps](INFO): Moved sent file to Logs/20211117T215648/Courier9001.lzma.bak
2021-11-17T22:20:39.156Z,1637187639.156 [DataOverHttps](INFO): SBD MOMSN=16263578
2021-11-17T22:20:56.170Z,1637187656.170 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20211117T215648/Express0017.lzma
2021-11-17T22:20:57.172Z,1637187657.172 [DataOverHttps](INFO): Moved sent file to Logs/20211117T215648/Express0017.lzma.bak
2021-11-17T22:20:57.172Z,1637187657.172 [DataOverHttps](INFO): SBD MOMSN=16263580
2021-11-17T22:20:59.300Z,1637187659.300 [Default:CheckIn:Read_Iridium] Stopped
2021-11-17T22:20:59.300Z,1637187659.300 [Default:CheckIn:C.Wait] Running Loop=1
2021-11-17T22:20:59.301Z,1637187659.301 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-11-17T22:21:06.581Z,1637187666.581 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2021-11-17T22:21:06.581Z,1637187666.581 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-11-17T22:21:06.625Z,1637187666.625 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-11-17T22:21:06.989Z,1637187666.989 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-11-17T22:21:06.989Z,1637187666.989 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2021-11-17T22:21:59.885Z,1637187719.885 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-11-17T22:21:59.885Z,1637187719.885 [Default:CheckIn:C.Wait] Stopped
2021-11-17T22:21:59.885Z,1637187719.885 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-11-17T22:21:59.885Z,1637187719.885 [Default:CheckIn:D] Running Loop=1
2021-11-17T22:22:00.285Z,1637187720.285 [Default:CheckIn:D] Stopped
2021-11-17T22:22:00.285Z,1637187720.285 [Default:CheckIn:E] Running Loop=1
2021-11-17T22:22:00.697Z,1637187720.697 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.395923 min
2021-11-17T22:22:00.698Z,1637187720.698 [Default:CheckIn:E] Stopped
2021-11-17T22:22:00.698Z,1637187720.698 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-11-17T22:22:00.698Z,1637187720.698 [Default:CheckIn] Stopped
2021-11-17T22:22:00.698Z,1637187720.698 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-11-17T22:22:00.699Z,1637187720.699 [Default:CheckIn](INFO): Running loop #6
2021-11-17T22:22:00.699Z,1637187720.699 [Default:CheckIn] Running Loop=6
2021-11-17T22:22:00.699Z,1637187720.699 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-11-17T22:22:00.699Z,1637187720.699 [Default:CheckIn:Read_GPS] Running Loop=1
2021-11-17T22:23:00.913Z,1637187780.913 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-11-17T22:22:00.7Z
2021-11-17T22:23:00.913Z,1637187780.913 [Default:CheckIn:Read_GPS] Stopped
2021-11-17T22:23:00.913Z,1637187780.913 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-11-17T22:23:07.842Z,1637187787.842 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20211117T215648/Courier0019.lzma
2021-11-17T22:23:08.844Z,1637187788.844 [DataOverHttps](INFO): Moved sent file to Logs/20211117T215648/Courier0019.lzma.bak
2021-11-17T22:23:08.844Z,1637187788.844 [DataOverHttps](INFO): SBD MOMSN=16263584
2021-11-17T22:23:25.571Z,1637187805.571 [DataOverHttps](INFO): Sending 108 bytes from file Logs/20211117T215648/Express0020.lzma
2021-11-17T22:23:26.572Z,1637187806.572 [DataOverHttps](INFO): Moved sent file to Logs/20211117T215648/Express0020.lzma.bak
2021-11-17T22:23:26.572Z,1637187806.572 [DataOverHttps](INFO): SBD MOMSN=16263586
2021-11-17T22:23:28.795Z,1637187808.795 [Default:CheckIn:Read_Iridium] Stopped
2021-11-17T22:23:28.795Z,1637187808.795 [Default:CheckIn:C.Wait] Running Loop=1
2021-11-17T22:23:28.795Z,1637187808.795 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-11-17T22:24:07.569Z,1637187847.569 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2021-11-17T22:24:07.569Z,1637187847.569 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-11-17T22:24:07.580Z,1637187847.580 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-11-17T22:24:07.982Z,1637187847.982 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-11-17T22:24:07.982Z,1637187847.982 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2021-11-17T22:24:29.387Z,1637187869.387 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-11-17T22:24:29.387Z,1637187869.387 [Default:CheckIn:C.Wait] Stopped
2021-11-17T22:24:29.387Z,1637187869.387 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-11-17T22:24:29.387Z,1637187869.387 [Default:CheckIn:D] Running Loop=1
2021-11-17T22:24:29.773Z,1637187869.773 [Default:CheckIn:D] Stopped
2021-11-17T22:24:29.773Z,1637187869.773 [Default:CheckIn:E] Running Loop=1
2021-11-17T22:24:30.190Z,1637187870.190 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.887392 min
2021-11-17T22:24:30.190Z,1637187870.190 [Default:CheckIn:E] Stopped
2021-11-17T22:24:30.190Z,1637187870.190 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-11-17T22:24:30.190Z,1637187870.190 [Default:CheckIn] Stopped
2021-11-17T22:24:30.190Z,1637187870.190 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-11-17T22:24:30.190Z,1637187870.190 [Default:CheckIn](INFO): Running loop #7
2021-11-17T22:24:30.191Z,1637187870.191 [Default:CheckIn] Running Loop=7
2021-11-17T22:24:30.191Z,1637187870.191 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-11-17T22:24:30.191Z,1637187870.191 [Default:CheckIn:Read_GPS] Running Loop=1
2021-11-17T22:25:30.373Z,1637187930.373 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-11-17T22:24:30.2Z
2021-11-17T22:25:30.374Z,1637187930.374 [Default:CheckIn:Read_GPS] Stopped
2021-11-17T22:25:30.374Z,1637187930.374 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-11-17T22:25:37.550Z,1637187937.550 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20211117T215648/Courier0022.lzma
2021-11-17T22:25:38.552Z,1637187938.552 [DataOverHttps](INFO): Moved sent file to Logs/20211117T215648/Courier0022.lzma.bak
2021-11-17T22:25:38.552Z,1637187938.552 [DataOverHttps](INFO): SBD MOMSN=16263589
2021-11-17T22:25:55.338Z,1637187955.338 [DataOverHttps](INFO): Sending 107 bytes from file Logs/20211117T215648/Express0023.lzma
2021-11-17T22:25:56.340Z,1637187956.340 [DataOverHttps](INFO): Moved sent file to Logs/20211117T215648/Express0023.lzma.bak
2021-11-17T22:25:56.340Z,1637187956.340 [DataOverHttps](INFO): SBD MOMSN=16263592
2021-11-17T22:25:58.699Z,1637187958.699 [Default:CheckIn:Read_Iridium] Stopped
2021-11-17T22:25:58.699Z,1637187958.699 [Default:CheckIn:C.Wait] Running Loop=1
2021-11-17T22:25:58.699Z,1637187958.699 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-11-17T22:26:59.276Z,1637188019.276 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-11-17T22:26:59.276Z,1637188019.276 [Default:CheckIn:C.Wait] Stopped
2021-11-17T22:26:59.277Z,1637188019.277 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-11-17T22:26:59.277Z,1637188019.277 [Default:CheckIn:D] Running Loop=1
2021-11-17T22:26:59.691Z,1637188019.691 [Default:CheckIn:D] Stopped
2021-11-17T22:26:59.691Z,1637188019.691 [Default:CheckIn:E] Running Loop=1
2021-11-17T22:27:00.078Z,1637188020.078 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 26.386025 min
2021-11-17T22:27:00.078Z,1637188020.078 [Default:CheckIn:E] Stopped
2021-11-17T22:27:00.078Z,1637188020.078 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-11-17T22:27:00.078Z,1637188020.078 [Default:CheckIn] Stopped
2021-11-17T22:27:00.078Z,1637188020.078 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-11-17T22:27:00.078Z,1637188020.078 [Default:CheckIn](INFO): Running loop #8
2021-11-17T22:27:00.079Z,1637188020.079 [Default:CheckIn] Running Loop=8
2021-11-17T22:27:00.079Z,1637188020.079 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-11-17T22:27:00.079Z,1637188020.079 [Default:CheckIn:Read_GPS] Running Loop=1
2021-11-17T22:27:08.560Z,1637188028.560 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2021-11-17T22:27:08.560Z,1637188028.560 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-11-17T22:27:08.571Z,1637188028.571 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-11-17T22:27:08.974Z,1637188028.974 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-11-17T22:27:08.974Z,1637188028.974 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2021-11-17T22:28:00.284Z,1637188080.284 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-11-17T22:27:00.1Z
2021-11-17T22:28:00.284Z,1637188080.284 [Default:CheckIn:Read_GPS] Stopped
2021-11-17T22:28:00.284Z,1637188080.284 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-11-17T22:28:08.042Z,1637188088.042 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20211117T215648/Courier0025.lzma
2021-11-17T22:28:09.044Z,1637188089.044 [DataOverHttps](INFO): Moved sent file to Logs/20211117T215648/Courier0025.lzma.bak
2021-11-17T22:28:09.044Z,1637188089.044 [DataOverHttps](INFO): SBD MOMSN=16263604
2021-11-17T22:28:25.846Z,1637188105.846 [DataOverHttps](INFO): Sending 108 bytes from file Logs/20211117T215648/Express0026.lzma
2021-11-17T22:28:26.848Z,1637188106.848 [DataOverHttps](INFO): Moved sent file to Logs/20211117T215648/Express0026.lzma.bak
2021-11-17T22:28:26.848Z,1637188106.848 [DataOverHttps](INFO): SBD MOMSN=16263606
2021-11-17T22:28:28.956Z,1637188108.956 [Default:CheckIn:Read_Iridium] Stopped
2021-11-17T22:28:28.956Z,1637188108.956 [Default:CheckIn:C.Wait] Running Loop=1
2021-11-17T22:28:28.956Z,1637188108.956 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-11-17T22:29:07.712Z,1637188147.712 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-11-17T22:29:07.712Z,1637188147.712 [NAL9602] Data Fault, FailCount= 3
2021-11-17T22:29:07.712Z,1637188147.712 [NAL9602](ERROR): Data Fault
2021-11-17T22:29:07.763Z,1637188147.763 [CBIT](ERROR): Data Fault in component: NAL9602
2021-11-17T22:29:08.116Z,1637188148.116 [NAL9602](INFO): Powering down
2021-11-17T22:29:08.949Z,1637188148.949 [CBIT](INFO): Clearing failed state for component NAL9602
2021-11-17T22:29:08.949Z,1637188148.949 [NAL9602] No Fault, FailCount= 3
2021-11-17T22:29:29.539Z,1637188169.539 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-11-17T22:29:29.539Z,1637188169.539 [Default:CheckIn:C.Wait] Stopped
2021-11-17T22:29:29.539Z,1637188169.539 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-11-17T22:29:29.539Z,1637188169.539 [Default:CheckIn:D] Running Loop=1
2021-11-17T22:29:29.953Z,1637188169.953 [Default:CheckIn:D] Stopped
2021-11-17T22:29:29.953Z,1637188169.953 [Default:CheckIn:E] Running Loop=1
2021-11-17T22:29:30.357Z,1637188170.357 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.890393 min
2021-11-17T22:29:30.357Z,1637188170.357 [Default:CheckIn:E] Stopped
2021-11-17T22:29:30.358Z,1637188170.358 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-11-17T22:29:30.358Z,1637188170.358 [Default:CheckIn] Stopped
2021-11-17T22:29:30.358Z,1637188170.358 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-11-17T22:29:30.358Z,1637188170.358 [Default:CheckIn](INFO): Running loop #9
2021-11-17T22:29:30.358Z,1637188170.358 [Default:CheckIn] Running Loop=9
2021-11-17T22:29:30.358Z,1637188170.358 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-11-17T22:29:30.359Z,1637188170.359 [Default:CheckIn:Read_GPS] Running Loop=1
2021-11-17T22:29:38.417Z,1637188178.417 [NAL9602](INFO): Powering up NAL9602
2021-11-17T22:29:49.324Z,1637188189.324 [NAL9602](INFO): NAL9602 initialized
2021-11-17T22:30:09.536Z,1637188209.536 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2021-11-17T22:30:09.536Z,1637188209.536 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-11-17T22:30:09.579Z,1637188209.579 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-11-17T22:30:09.991Z,1637188209.991 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-11-17T22:30:09.991Z,1637188209.991 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2021-11-17T22:30:30.651Z,1637188230.651 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-11-17T22:29:30.4Z
2021-11-17T22:30:30.651Z,1637188230.651 [Default:CheckIn:Read_GPS] Stopped
2021-11-17T22:30:30.651Z,1637188230.651 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-11-17T22:30:39.206Z,1637188239.206 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20211117T215648/Courier0028.lzma
2021-11-17T22:30:40.208Z,1637188240.208 [DataOverHttps](INFO): Moved sent file to Logs/20211117T215648/Courier0028.lzma.bak
2021-11-17T22:30:40.208Z,1637188240.208 [DataOverHttps](INFO): SBD MOMSN=16263610
2021-11-17T22:30:56.842Z,1637188256.842 [DataOverHttps](INFO): Sending 149 bytes from file Logs/20211117T215648/Express0029.lzma
2021-11-17T22:30:57.845Z,1637188257.845 [DataOverHttps](INFO): Moved sent file to Logs/20211117T215648/Express0029.lzma.bak
2021-11-17T22:30:57.845Z,1637188257.845 [DataOverHttps](INFO): SBD MOMSN=16263612
2021-11-17T22:31:00.137Z,1637188260.137 [Default:CheckIn:Read_Iridium] Stopped
2021-11-17T22:31:00.137Z,1637188260.137 [Default:CheckIn:C.Wait] Running Loop=1
2021-11-17T22:31:00.137Z,1637188260.137 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-11-17T22:32:00.736Z,1637188320.736 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-11-17T22:32:00.736Z,1637188320.736 [Default:CheckIn:C.Wait] Stopped
2021-11-17T22:32:00.736Z,1637188320.736 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-11-17T22:32:00.736Z,1637188320.736 [Default:CheckIn:D] Running Loop=1
2021-11-17T22:32:01.153Z,1637188321.153 [Default:CheckIn:D] Stopped
2021-11-17T22:32:01.153Z,1637188321.153 [Default:CheckIn:E] Running Loop=1
2021-11-17T22:32:01.566Z,1637188321.566 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.410392 min
2021-11-17T22:32:01.570Z,1637188321.570 [Default:CheckIn:E] Stopped
2021-11-17T22:32:01.571Z,1637188321.571 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-11-17T22:32:01.571Z,1637188321.571 [Default:CheckIn] Stopped
2021-11-17T22:32:01.571Z,1637188321.571 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-11-17T22:32:01.571Z,1637188321.571 [Default:CheckIn](INFO): Running loop #10
2021-11-17T22:32:01.571Z,1637188321.571 [Default:CheckIn] Running Loop=10
2021-11-17T22:32:01.571Z,1637188321.571 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-11-17T22:32:01.571Z,1637188321.571 [Default:CheckIn:Read_GPS] Running Loop=1
2021-11-17T22:33:01.725Z,1637188381.725 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-11-17T22:32:01.6Z
2021-11-17T22:33:01.726Z,1637188381.726 [Default:CheckIn:Read_GPS] Stopped
2021-11-17T22:33:01.726Z,1637188381.726 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-11-17T22:33:08.926Z,1637188388.926 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20211117T215648/Courier0031.lzma
2021-11-17T22:33:09.928Z,1637188389.928 [DataOverHttps](INFO): Moved sent file to Logs/20211117T215648/Courier0031.lzma.bak
2021-11-17T22:33:09.928Z,1637188389.928 [DataOverHttps](INFO): SBD MOMSN=16263616
2021-11-17T22:33:10.632Z,1637188390.632 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12
2021-11-17T22:33:10.632Z,1637188390.632 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-11-17T22:33:10.675Z,1637188390.675 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-11-17T22:33:11.046Z,1637188391.046 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-11-17T22:33:11.046Z,1637188391.046 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12
2021-11-17T22:33:26.870Z,1637188406.870 [DataOverHttps](INFO): Sending 108 bytes from file Logs/20211117T215648/Express0032.lzma
2021-11-17T22:33:27.872Z,1637188407.872 [DataOverHttps](INFO): Moved sent file to Logs/20211117T215648/Express0032.lzma.bak
2021-11-17T22:33:27.872Z,1637188407.872 [DataOverHttps](INFO): SBD MOMSN=16263618
2021-11-17T22:33:30.039Z,1637188410.039 [Default:CheckIn:Read_Iridium] Stopped
2021-11-17T22:33:30.040Z,1637188410.040 [Default:CheckIn:C.Wait] Running Loop=1
2021-11-17T22:33:30.040Z,1637188410.040 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-11-17T22:34:30.665Z,1637188470.665 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-11-17T22:34:30.665Z,1637188470.665 [Default:CheckIn:C.Wait] Stopped
2021-11-17T22:34:30.665Z,1637188470.665 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-11-17T22:34:30.665Z,1637188470.665 [Default:CheckIn:D] Running Loop=1
2021-11-17T22:34:31.089Z,1637188471.089 [Default:CheckIn:D] Stopped
2021-11-17T22:34:31.089Z,1637188471.089 [Default:CheckIn:E] Running Loop=1
2021-11-17T22:34:31.493Z,1637188471.493 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 33.909320 min
2021-11-17T22:34:31.493Z,1637188471.493 [Default:CheckIn:E] Stopped
2021-11-17T22:34:31.493Z,1637188471.493 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-11-17T22:34:31.494Z,1637188471.494 [Default:CheckIn] Stopped
2021-11-17T22:34:31.494Z,1637188471.494 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-11-17T22:34:31.494Z,1637188471.494 [Default:CheckIn](INFO): Running loop #11
2021-11-17T22:34:31.494Z,1637188471.494 [Default:CheckIn] Running Loop=11
2021-11-17T22:34:31.494Z,1637188471.494 [Default:CheckIn](DEBUG): Aggregate::initialize Default:Che