2022-12-12T13:34:02.137Z,1670852042.137 [Supervisor](DEBUG): Initializing supervisor.
2022-12-12T13:34:02.142Z,1670852042.142 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2022-12-12T13:34:02.142Z,1670852042.142 [SyncHandler](INFO): Protected caller Thread ID is 844
2022-12-12T13:34:02.143Z,1670852042.143 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2022-12-12T13:34:02.143Z,1670852042.143 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2022-12-12T13:34:02.144Z,1670852042.144 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 845
2022-12-12T13:34:02.148Z,1670852042.148 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2022-12-12T13:34:02.165Z,1670852042.165 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2022-12-12T13:34:02.166Z,1670852042.166 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2022-12-12T13:34:02.166Z,1670852042.166 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 846
2022-12-12T13:34:02.170Z,1670852042.170 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2022-12-12T13:34:02.171Z,1670852042.171 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2022-12-12T13:34:02.172Z,1670852042.172 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 847
2022-12-12T13:34:02.174Z,1670852042.174 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2022-12-12T13:34:02.175Z,1670852042.175 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2022-12-12T13:34:02.175Z,1670852042.175 [logger ThreadHandler](INFO): Protected caller Thread ID is 848
2022-12-12T13:34:02.179Z,1670852042.179 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2022-12-12T13:34:02.179Z,1670852042.179 [Supervisor](INFO): Looking for Config files in directory: Config/
2022-12-12T13:34:02.183Z,1670852042.183 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2022-12-12T13:34:02.392Z,1670852042.392 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2022-12-12T13:34:02.394Z,1670852042.394 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2022-12-12T13:34:02.497Z,1670852042.497 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2022-12-12T13:34:02.498Z,1670852042.498 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2022-12-12T13:34:02.591Z,1670852042.591 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2022-12-12T13:34:02.592Z,1670852042.592 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2022-12-12T13:34:03.024Z,1670852043.024 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2022-12-12T13:34:03.025Z,1670852043.025 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2022-12-12T13:34:03.355Z,1670852043.355 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2022-12-12T13:34:03.357Z,1670852043.357 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2022-12-12T13:34:03.669Z,1670852043.669 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2022-12-12T13:34:03.670Z,1670852043.670 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2022-12-12T13:34:03.857Z,1670852043.857 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2022-12-12T13:34:03.858Z,1670852043.858 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2022-12-12T13:34:03.937Z,1670852043.937 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2022-12-12T13:34:04.018Z,1670852044.018 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2022-12-12T13:34:04.399Z,1670852044.399 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2022-12-12T13:34:04.399Z,1670852044.399 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2022-12-12T13:34:04.666Z,1670852044.666 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2022-12-12T13:34:04.666Z,1670852044.666 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2022-12-12T13:34:05.269Z,1670852045.269 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2022-12-12T13:34:05.269Z,1670852045.269 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2022-12-12T13:34:05.764Z,1670852045.764 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2022-12-12T13:34:05.764Z,1670852045.764 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2022-12-12T13:34:05.995Z,1670852045.995 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2022-12-12T13:34:05.995Z,1670852045.995 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2022-12-12T13:34:06.130Z,1670852046.130 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2022-12-12T13:34:06.131Z,1670852046.131 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2022-12-12T13:34:06.866Z,1670852046.866 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2022-12-12T13:34:06.868Z,1670852046.868 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/
2022-12-12T13:34:06.871Z,1670852046.871 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/secure.cfg
2022-12-12T13:34:06.954Z,1670852046.954 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/vehicle.cfg
2022-12-12T13:34:07.172Z,1670852047.172 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Battery.cfg
2022-12-12T13:34:07.431Z,1670852047.431 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2022-12-12T13:34:07.431Z,1670852047.431 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Science.cfg
2022-12-12T13:34:07.550Z,1670852047.550 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Control.cfg
2022-12-12T13:34:07.647Z,1670852047.647 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/logger.cfg
2022-12-12T13:34:07.739Z,1670852047.739 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Servo.cfg
2022-12-12T13:34:07.847Z,1670852047.847 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Navigation.cfg
2022-12-12T13:34:07.939Z,1670852047.939 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Simulator.cfg
2022-12-12T13:34:08.023Z,1670852048.023 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/BIT.cfg
2022-12-12T13:34:08.120Z,1670852048.120 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Sensor.cfg
2022-12-12T13:34:08.271Z,1670852048.271 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2022-12-12T13:34:08.287Z,1670852048.287 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2022-12-12T13:34:08.356Z,1670852048.356 [DepthRateCalculator] Loaded
2022-12-12T13:34:08.356Z,1670852048.356 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2022-12-12T13:34:08.362Z,1670852048.362 [PitchRateCalculator] Loaded
2022-12-12T13:34:08.362Z,1670852048.362 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2022-12-12T13:34:08.372Z,1670852048.372 [SpeedCalculator] Loaded
2022-12-12T13:34:08.373Z,1670852048.373 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2022-12-12T13:34:08.378Z,1670852048.378 [YawRateCalculator] Loaded
2022-12-12T13:34:08.378Z,1670852048.378 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2022-12-12T13:34:08.399Z,1670852048.399 [ElevatorOffsetCalculator] Loaded
2022-12-12T13:34:08.399Z,1670852048.399 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2022-12-12T13:34:08.400Z,1670852048.400 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2022-12-12T13:34:08.402Z,1670852048.402 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2022-12-12T13:34:08.444Z,1670852048.444 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2022-12-12T13:34:08.444Z,1670852048.444 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2022-12-12T13:34:08.460Z,1670852048.460 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2022-12-12T13:34:08.460Z,1670852048.460 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2022-12-12T13:34:09.179Z,1670852049.179 [AHRS_M2] Loaded
2022-12-12T13:34:09.179Z,1670852049.179 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2022-12-12T13:34:09.428Z,1670852049.428 [BackseatComponent] Loaded
2022-12-12T13:34:09.428Z,1670852049.428 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2022-12-12T13:34:09.429Z,1670852049.429 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408384E0
2022-12-12T13:34:09.430Z,1670852049.430 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 931
2022-12-12T13:34:09.432Z,1670852049.432 [LcmUniversalReporter] Loaded
2022-12-12T13:34:09.433Z,1670852049.433 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2022-12-12T13:34:10.221Z,1670852050.221 [BPC1] Loaded
2022-12-12T13:34:10.221Z,1670852050.221 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2022-12-12T13:34:10.361Z,1670852050.361 [DataOverHttps] Loaded
2022-12-12T13:34:10.361Z,1670852050.361 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2022-12-12T13:34:10.362Z,1670852050.362 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408684E0
2022-12-12T13:34:10.363Z,1670852050.363 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 932
2022-12-12T13:34:10.402Z,1670852050.402 [Depth_Keller] Loaded
2022-12-12T13:34:10.402Z,1670852050.402 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2022-12-12T13:34:10.573Z,1670852050.573 [NAL9602] Loaded
2022-12-12T13:34:10.574Z,1670852050.574 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2022-12-12T13:34:10.603Z,1670852050.603 [Onboard] Loaded
2022-12-12T13:34:10.603Z,1670852050.603 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2022-12-12T13:34:10.604Z,1670852050.604 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408984E0
2022-12-12T13:34:10.606Z,1670852050.606 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 933
2022-12-12T13:34:10.612Z,1670852050.612 [PowerOnly](INFO): Adding load control power supply at /dev/loadC3
2022-12-12T13:34:10.622Z,1670852050.622 [PowerOnly] Loaded
2022-12-12T13:34:10.622Z,1670852050.622 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2022-12-12T13:34:10.634Z,1670852050.634 [Power24vConverter] Loaded
2022-12-12T13:34:10.634Z,1670852050.634 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2022-12-12T13:34:10.648Z,1670852050.648 [Radio_Surface] Loaded
2022-12-12T13:34:10.648Z,1670852050.648 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2022-12-12T13:34:10.649Z,1670852050.649 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408C84E0
2022-12-12T13:34:10.649Z,1670852050.649 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 934
2022-12-12T13:34:10.650Z,1670852050.650 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2022-12-12T13:34:10.651Z,1670852050.651 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2022-12-12T13:34:11.395Z,1670852051.395 [DeadReckonUsingMultipleVelocitySources] Loaded
2022-12-12T13:34:11.396Z,1670852051.396 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2022-12-12T13:34:11.436Z,1670852051.436 [DeadReckonUsingSpeedCalculator] Loaded
2022-12-12T13:34:11.436Z,1670852051.436 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2022-12-12T13:34:11.450Z,1670852051.450 [NavChart] Loaded
2022-12-12T13:34:11.450Z,1670852051.450 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2022-12-12T13:34:11.456Z,1670852051.456 [UniversalFixResidualReporter] Loaded
2022-12-12T13:34:11.456Z,1670852051.456 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2022-12-12T13:34:11.456Z,1670852051.456 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2022-12-12T13:34:11.457Z,1670852051.457 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2022-12-12T13:34:11.621Z,1670852051.621 [SBIT](DEBUG): Construct Startup Built In Test.
2022-12-12T13:34:11.635Z,1670852051.635 [SBIT] Loaded
2022-12-12T13:34:11.636Z,1670852051.636 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2022-12-12T13:34:11.638Z,1670852051.638 [IBIT](DEBUG): Construct Initiated Built In Test.
2022-12-12T13:34:11.651Z,1670852051.651 [IBIT] Loaded
2022-12-12T13:34:11.651Z,1670852051.651 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2022-12-12T13:34:11.657Z,1670852051.657 [CBIT](DEBUG): Construct Continuous Built In Test.
2022-12-12T13:34:11.758Z,1670852051.758 [CBIT] Loaded
2022-12-12T13:34:11.759Z,1670852051.759 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2022-12-12T13:34:11.759Z,1670852051.759 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2022-12-12T13:34:11.760Z,1670852051.760 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2022-12-12T13:34:11.971Z,1670852051.971 [CTD_Seabird] Loaded
2022-12-12T13:34:11.972Z,1670852051.972 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2022-12-12T13:34:11.973Z,1670852051.973 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409CC4E0
2022-12-12T13:34:11.973Z,1670852051.973 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 935
2022-12-12T13:34:11.993Z,1670852051.993 [PAR_Licor] Loaded
2022-12-12T13:34:11.993Z,1670852051.993 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2022-12-12T13:34:12.024Z,1670852052.024 [WetLabsBB2FL] Loaded
2022-12-12T13:34:12.024Z,1670852052.024 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2022-12-12T13:34:12.025Z,1670852052.025 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409FC4E0
2022-12-12T13:34:12.025Z,1670852052.025 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 936
2022-12-12T13:34:12.026Z,1670852052.026 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2022-12-12T13:34:12.027Z,1670852052.027 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2022-12-12T13:34:12.186Z,1670852052.186 [BuoyancyServo] Loaded
2022-12-12T13:34:12.186Z,1670852052.186 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2022-12-12T13:34:12.207Z,1670852052.207 [ElevatorServo] Loaded
2022-12-12T13:34:12.207Z,1670852052.207 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2022-12-12T13:34:12.228Z,1670852052.228 [MassServo] Loaded
2022-12-12T13:34:12.228Z,1670852052.228 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2022-12-12T13:34:12.248Z,1670852052.248 [RudderServo] Loaded
2022-12-12T13:34:12.248Z,1670852052.248 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2022-12-12T13:34:12.264Z,1670852052.264 [ThrusterHE] Loaded
2022-12-12T13:34:12.264Z,1670852052.264 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2022-12-12T13:34:12.265Z,1670852052.265 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2022-12-12T13:34:12.267Z,1670852052.267 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2022-12-12T13:34:12.333Z,1670852052.333 [VerticalControl](DEBUG): Construct VerticalControl.
2022-12-12T13:34:12.385Z,1670852052.385 [VerticalControl] Loaded
2022-12-12T13:34:12.385Z,1670852052.385 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2022-12-12T13:34:12.388Z,1670852052.388 [HorizontalControl](DEBUG): Construct HorizontalControl.
2022-12-12T13:34:12.425Z,1670852052.425 [HorizontalControl] Loaded
2022-12-12T13:34:12.426Z,1670852052.426 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2022-12-12T13:34:12.428Z,1670852052.428 [SpeedControl](DEBUG): Construct SpeedControl.
2022-12-12T13:34:12.430Z,1670852052.430 [SpeedControl] Loaded
2022-12-12T13:34:12.430Z,1670852052.430 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2022-12-12T13:34:12.433Z,1670852052.433 [LoopControl](DEBUG): Construct LoopControl.
2022-12-12T13:34:12.433Z,1670852052.433 [LoopControl] Loaded
2022-12-12T13:34:12.434Z,1670852052.434 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2022-12-12T13:34:12.434Z,1670852052.434 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2022-12-12T13:34:12.435Z,1670852052.435 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2022-12-12T13:34:12.557Z,1670852052.557 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2022-12-12T13:34:12.558Z,1670852052.558 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2022-12-12T13:34:12.736Z,1670852052.736 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2022-12-12T13:34:12.737Z,1670852052.737 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2022-12-12T13:34:13.090Z,1670852053.090 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2022-12-12T13:34:13.091Z,1670852053.091 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2022-12-12T13:34:13.171Z,1670852053.171 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2022-12-12T13:34:13.177Z,1670852053.177 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2022-12-12T13:34:13.180Z,1670852053.180 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2022-12-12T13:34:13.191Z,1670852053.191 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2022-12-12T13:34:13.192Z,1670852053.192 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B9F4E0
2022-12-12T13:34:13.192Z,1670852053.192 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 937
2022-12-12T13:34:13.197Z,1670852053.197 [Supervisor](INFO): Main Thread ID is 830
2022-12-12T13:34:13.197Z,1670852053.197 [Supervisor](DEBUG): Running supervisor.
2022-12-12T13:34:13.198Z,1670852053.198 [CommandExec ThreadHandler](INFO): Handler Thread ID is 938
2022-12-12T13:34:13.198Z,1670852053.198 [CommandExec](INFO): Initializing the command executive.
2022-12-12T13:34:13.200Z,1670852053.200 [CommandLine ThreadHandler](INFO): Handler Thread ID is 939
2022-12-12T13:34:13.202Z,1670852053.202 [controlThread ThreadHandler](INFO): Handler Thread ID is 940
2022-12-12T13:34:13.202Z,1670852053.202 [controlThread](DEBUG): Initializing ControlThread
2022-12-12T13:34:13.203Z,1670852053.203 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2022-12-12T13:34:13.203Z,1670852053.203 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2022-12-12T13:34:13.204Z,1670852053.204 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2022-12-12T13:34:13.204Z,1670852053.204 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2022-12-12T13:34:13.204Z,1670852053.204 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2022-12-12T13:34:13.211Z,1670852053.211 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2022-12-12T13:34:13.211Z,1670852053.211 [NavChart](DEBUG): Initialize NavChart Navigation.
2022-12-12T13:34:13.211Z,1670852053.211 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2022-12-12T13:34:13.212Z,1670852053.212 [SBIT](INFO): Initialize SBIT Component.
2022-12-12T13:34:13.212Z,1670852053.212 [SBIT](IMPORTANT): git: 2022-11-18
2022-12-12T13:34:13.212Z,1670852053.212 [SBIT](INFO): git hash: 1213f736678a71319c30bd1b0c503177f42d9940
2022-12-12T13:34:13.213Z,1670852053.213 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2022-12-12T13:34:13.214Z,1670852053.214 [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
2022-12-12T13:34:13.215Z,1670852053.215 [SBIT](INFO): Beginning SBIT in 100.000000 seconds.
2022-12-12T13:34:13.216Z,1670852053.216 [IBIT](INFO): Initialize IBIT Component.
2022-12-12T13:34:13.217Z,1670852053.217 [CBIT](DEBUG): Initialize CBIT Component.
2022-12-12T13:34:13.218Z,1670852053.218 [logger ThreadHandler](INFO): Handler Thread ID is 941
2022-12-12T13:34:13.229Z,1670852053.229 [CBIT](DEBUG): Initialized mux pins.
2022-12-12T13:34:13.229Z,1670852053.229 [CBIT](DEBUG): Initializing the watchdog timer.
2022-12-12T13:34:13.237Z,1670852053.237 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 942
2022-12-12T13:34:13.249Z,1670852053.249 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 943
2022-12-12T13:34:13.250Z,1670852053.250 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2022-12-12T13:34:13.253Z,1670852053.253 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2022-12-12T13:34:13.254Z,1670852053.254 [CBIT](DEBUG): Initializing heartbeat.
2022-12-12T13:34:13.261Z,1670852053.261 [Onboard ThreadHandler](INFO): Handler Thread ID is 944
2022-12-12T13:34:13.279Z,1670852053.279 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 945
2022-12-12T13:34:13.302Z,1670852053.302 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 946
2022-12-12T13:34:13.303Z,1670852053.303 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2022-12-12T13:34:13.306Z,1670852053.306 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 948
2022-12-12T13:34:13.309Z,1670852053.309 [WetLabsBB2FL](INFO): Powering up
2022-12-12T13:34:13.311Z,1670852053.311 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 950
2022-12-12T13:34:13.318Z,1670852053.318 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2022-12-12T13:34:13.318Z,1670852053.318 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2022-12-12T13:34:13.318Z,1670852053.318 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2022-12-12T13:34:13.318Z,1670852053.318 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2022-12-12T13:34:13.319Z,1670852053.319 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2022-12-12T13:34:13.319Z,1670852053.319 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2022-12-12T13:34:13.319Z,1670852053.319 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2022-12-12T13:34:13.319Z,1670852053.319 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2022-12-12T13:34:13.325Z,1670852053.325 [CBIT](DEBUG): Deactivating GF circuits.
2022-12-12T13:34:13.325Z,1670852053.325 [CBIT](DEBUG): Deactivating emergency mode.
2022-12-12T13:34:13.361Z,1670852053.361 [CBIT](DEBUG): Backplane powered.
2022-12-12T13:34:13.366Z,1670852053.366 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2022-12-12T13:34:13.368Z,1670852053.368 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2022-12-12T13:34:13.369Z,1670852053.369 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2022-12-12T13:34:13.370Z,1670852053.370 [LoopControl](DEBUG): Initialize LoopControlComponent.
2022-12-12T13:34:13.370Z,1670852053.370 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2022-12-12T13:34:13.398Z,1670852053.398 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2022-12-12T13:34:13.442Z,1670852053.442 [MissionManager](DEBUG):
2022-12-12T13:34:13.442Z,1670852053.442 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2022-12-12T13:34:13.489Z,1670852053.489 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2022-12-12T13:34:13.490Z,1670852053.490 [Default:A.Wait](DEBUG): Construct Wait.
2022-12-12T13:34:13.492Z,1670852053.492 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2022-12-12T13:34:13.531Z,1670852053.531 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2022-12-12T13:34:13.534Z,1670852053.534 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2022-12-12T13:34:13.572Z,1670852053.572 [Default:E.Execute](DEBUG): Construct Execute.
2022-12-12T13:34:13.575Z,1670852053.575 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2022-12-12T13:34:13.579Z,1670852053.579 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,NAL9602,PowerOnly,Power24vConverter,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2022-12-12T13:34:13.597Z,1670852053.597 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2022-12-12T13:34:13.689Z,1670852053.689 [Radio_Surface](INFO): Powering up
2022-12-12T13:34:13.748Z,1670852053.748 [Power24vConverter](INFO): Powering up.
2022-12-12T13:34:13.802Z,1670852053.802 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2022-12-12T13:34:13.806Z,1670852053.806 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2022-12-12T13:34:13.807Z,1670852053.807 [ElevatorServo](DEBUG): Initializing EZServoServo.
2022-12-12T13:34:13.810Z,1670852053.810 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2022-12-12T13:34:13.811Z,1670852053.811 [MassServo](DEBUG): Initializing EZServoServo.
2022-12-12T13:34:13.814Z,1670852053.814 [MassServo](DEBUG): Initializing MassServo.
2022-12-12T13:34:13.815Z,1670852053.815 [RudderServo](DEBUG): Initializing EZServoServo.
2022-12-12T13:34:13.845Z,1670852053.845 [RudderServo](DEBUG): Initializing RudderServo.
2022-12-12T13:34:13.846Z,1670852053.846 [ThrusterHE](DEBUG): Initializing EZServoServo.
2022-12-12T13:34:13.853Z,1670852053.853 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2022-12-12T13:34:14.737Z,1670852054.737 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2022-12-12T13:34:14.737Z,1670852054.737 [RudderServo](FAULT): Rudder failed to initialize
2022-12-12T13:34:14.737Z,1670852054.737 [RudderServo] Communications Fault, FailCount= 1
2022-12-12T13:34:14.737Z,1670852054.737 [RudderServo](ERROR): Communications Fault
2022-12-12T13:34:14.741Z,1670852054.741 [CBIT](ERROR): Communications Fault in component: RudderServo
2022-12-12T13:34:14.962Z,1670852054.962 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-12-12T13:34:14.962Z,1670852054.962 [RudderServo](INFO): Powering down
2022-12-12T13:34:15.638Z,1670852055.638 [RudderServo](DEBUG): Initializing EZServoServo.
2022-12-12T13:34:15.758Z,1670852055.758 [RudderServo](DEBUG): Initializing RudderServo.
2022-12-12T13:34:15.762Z,1670852055.762 [CBIT](INFO): Clearing failed state for component RudderServo
2022-12-12T13:34:15.762Z,1670852055.762 [RudderServo] No Fault, FailCount= 1
2022-12-12T13:34:15.921Z,1670852055.921 [WetLabsBB2FL](INFO): Powering down
2022-12-12T13:34:19.538Z,1670852059.538 [ThrusterHE](ERROR): Zero Speed Commanded.
2022-12-12T13:34:40.658Z,1670852080.658 [NAL9602](INFO): Powering up NAL9602
2022-12-12T13:34:42.797Z,1670852082.797 [MassServo](ERROR): getPosition uart error serial timeout
2022-12-12T13:34:42.797Z,1670852082.797 [MassServo](FAULT): Invalid EZ Servo response:"\r"
2022-12-12T13:34:42.797Z,1670852082.797 [MassServo] Communications Fault, FailCount= 1
2022-12-12T13:34:42.798Z,1670852082.798 [MassServo](ERROR): Communications Fault
2022-12-12T13:34:42.802Z,1670852082.802 [CBIT](ERROR): Communications Fault in component: MassServo
2022-12-12T13:34:43.100Z,1670852083.100 [MassServo](DEBUG): Uninitialize Mass Servo.
2022-12-12T13:34:43.100Z,1670852083.100 [MassServo](INFO): Powering down
2022-12-12T13:34:43.922Z,1670852083.922 [MassServo](DEBUG): Initializing EZServoServo.
2022-12-12T13:34:44.038Z,1670852084.038 [MassServo](DEBUG): Initializing MassServo.
2022-12-12T13:34:44.042Z,1670852084.042 [CBIT](INFO): Clearing failed state for component MassServo
2022-12-12T13:34:44.042Z,1670852084.042 [MassServo] No Fault, FailCount= 1
2022-12-12T13:34:51.570Z,1670852091.570 [NAL9602](INFO): NAL9602 initialized
2022-12-12T13:35:53.800Z,1670852153.800 [SBIT](IMPORTANT): Beginning Startup BIT
2022-12-12T13:35:53.804Z,1670852153.804 [CBIT](IMPORTANT): Beginning ground fault scan
2022-12-12T13:36:04.753Z,1670852164.753 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.003131
CHAN A1 (24V): 0.000820
CHAN A2 (12V): -0.005688
CHAN A3 (5V): -0.002916
CHAN B0 (3.3V): -0.001523
CHAN B1 (3.15aV): -0.001529
CHAN B2 (3.15bV): -0.001562
CHAN B3 (GND): -0.001066
OPEN: 0.005089
Full Scale: +/- 1 mA
2022-12-12T13:36:47.936Z,1670852207.936 [SBIT](IMPORTANT): SBIT PASSED
2022-12-12T13:36:47.936Z,1670852207.936 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2022-12-12T13:36:47.937Z,1670852207.937 [SBIT](IMPORTANT): CBIT.gfScanTimeout=2 hour;
2022-12-12T13:36:47.937Z,1670852207.937 [SBIT](IMPORTANT): CTD_Seabird.loadAtStartup=1 bool;
2022-12-12T13:36:47.938Z,1670852207.938 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;
2022-12-12T13:36:47.938Z,1670852207.938 [SBIT](IMPORTANT): DropWeight.loadAtStartup=0 bool;
2022-12-12T13:36:47.938Z,1670852207.938 [SBIT](IMPORTANT): Express none _.ayeris_disk_space;
2022-12-12T13:36:47.938Z,1670852207.938 [SBIT](IMPORTANT): Express linearApproximation _.ayeris_particle_counts 300.000000 count_per_second;
2022-12-12T13:36:47.938Z,1670852207.938 [SBIT](IMPORTANT): Express linearApproximation _.ayeris_particle_shape 1.000000 count_per_second;
2022-12-12T13:36:47.938Z,1670852207.938 [SBIT](IMPORTANT): Express linearApproximation _.ayeris_particle_slope 0.200000 count_per_millimeter;
2022-12-12T13:36:47.938Z,1670852207.938 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=214.405822 cubic_centimeter;
2022-12-12T13:36:47.938Z,1670852207.938 [SBIT](IMPORTANT): VerticalControl.massDefault=20.210472 millimeter;
2022-12-12T13:36:47.939Z,1670852207.939 [SBIT](IMPORTANT): WetLabsBB2FL.loadAtStartup=1 bool;
2022-12-12T13:36:48.347Z,1670852208.347 [MissionManager](IMPORTANT): Started mission Startup
2022-12-12T13:36:48.347Z,1670852208.347 [Startup] Running Loop=1
2022-12-12T13:36:48.348Z,1670852208.348 [Startup](DEBUG): Aggregate::initialize Startup
2022-12-12T13:36:48.348Z,1670852208.348 [Startup:A.GoToSurface] Running Loop=1
2022-12-12T13:36:48.348Z,1670852208.348 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-12-12T13:36:48.348Z,1670852208.348 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-12-12T13:36:48.349Z,1670852208.349 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-12-12T13:36:48.349Z,1670852208.349 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-12-12T13:36:48.350Z,1670852208.350 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-12-12T13:36:48.350Z,1670852208.350 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-12-12T13:36:48.352Z,1670852208.352 [Startup:StartupSatComms] Running Loop=1
2022-12-12T13:36:48.352Z,1670852208.352 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2022-12-12T13:36:48.352Z,1670852208.352 [Startup:StartupSatComms:A] Running Loop=1
2022-12-12T13:36:48.763Z,1670852208.763 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2022-12-12T13:37:01.143Z,1670852221.143 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.008741
2022-12-12T13:37:13.597Z,1670852233.597 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2022-12-12T13:37:13.597Z,1670852233.597 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-12-12T13:37:13.599Z,1670852233.599 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2022-12-12T13:37:13.599Z,1670852233.599 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2022-12-12T13:37:13.609Z,1670852233.609 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-12-12T13:37:13.610Z,1670852233.610 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2022-12-12T13:37:14.031Z,1670852234.031 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-12-12T13:37:14.031Z,1670852234.031 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2022-12-12T13:37:14.032Z,1670852234.032 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2022-12-12T13:37:14.032Z,1670852234.032 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2022-12-12T13:37:14.401Z,1670852234.401 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2022-12-12T13:37:38.323Z,1670852258.323 [CommandExec](IMPORTANT): got command burn on
2022-12-12T13:37:38.323Z,1670852258.323 [CommandExec](IMPORTANT): Activating dropweight wire
2022-12-12T13:37:48.424Z,1670852268.424 [Startup:StartupSatComms:A](INFO): Timed out from 2022-12-12T13:36:48.4Z
2022-12-12T13:37:48.424Z,1670852268.424 [Startup:StartupSatComms:A] Stopped
2022-12-12T13:37:48.424Z,1670852268.424 [Startup:StartupSatComms:B] Running Loop=1
2022-12-12T13:37:48.858Z,1670852268.858 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-12-12T13:37:55.264Z,1670852275.264 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20221212T133402/Courier0000.lzma
2022-12-12T13:37:56.264Z,1670852276.264 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Courier0000.lzma.bak
2022-12-12T13:37:56.264Z,1670852276.264 [DataOverHttps](INFO): SBD MOMSN=17392697
2022-12-12T13:38:11.895Z,1670852291.895 [DataOverHttps](INFO): Sending 979 bytes from file Logs/20221212T133402/Express0001.lzma
2022-12-12T13:38:12.896Z,1670852292.896 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Express0001.lzma.bak
2022-12-12T13:38:12.896Z,1670852292.896 [DataOverHttps](INFO): SBD MOMSN=17392700
2022-12-12T13:38:14.217Z,1670852294.217 [Startup:StartupSatComms:B] Stopped
2022-12-12T13:38:14.217Z,1670852294.217 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2022-12-12T13:38:14.217Z,1670852294.217 [Startup:StartupSatComms] Stopped
2022-12-12T13:38:14.217Z,1670852294.217 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2022-12-12T13:38:14.218Z,1670852294.218 [Startup](INFO): Completed Startup
2022-12-12T13:38:14.218Z,1670852294.218 [MissionManager](INFO): Startup is completed.
2022-12-12T13:38:14.218Z,1670852294.218 [MissionManager](INFO): Uninitializing Mission Startup
2022-12-12T13:38:14.218Z,1670852294.218 [Startup] Stopped
2022-12-12T13:38:14.218Z,1670852294.218 [Startup](DEBUG): Aggregate::uninitialize Startup
2022-12-12T13:38:14.218Z,1670852294.218 [Startup:A.GoToSurface] Stopped
2022-12-12T13:38:14.218Z,1670852294.218 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-12-12T13:38:14.617Z,1670852294.617 [MissionManager](IMPORTANT): Started mission Default
2022-12-12T13:38:14.617Z,1670852294.617 [Default] Running Loop=1
2022-12-12T13:38:14.617Z,1670852294.617 [Default](DEBUG): Aggregate::initialize Default
2022-12-12T13:38:14.617Z,1670852294.617 [Default:B.GoToSurface] Running Loop=1
2022-12-12T13:38:14.617Z,1670852294.617 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-12-12T13:38:14.649Z,1670852294.649 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-12-12T13:38:14.650Z,1670852294.650 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-12-12T13:38:14.650Z,1670852294.650 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-12-12T13:38:14.650Z,1670852294.650 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-12-12T13:38:14.651Z,1670852294.651 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-12-12T13:38:14.651Z,1670852294.651 [Default:A.Wait] Running Loop=1
2022-12-12T13:38:14.651Z,1670852294.651 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-12-12T13:38:27.932Z,1670852307.932 [Default:A.Wait](INFO): Done Waiting.
2022-12-12T13:38:27.932Z,1670852307.932 [Default:A.Wait] Stopped
2022-12-12T13:38:27.932Z,1670852307.932 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-12-12T13:38:28.346Z,1670852308.346 [Default:CheckIn] Running Loop=1
2022-12-12T13:38:28.346Z,1670852308.346 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-12T13:38:28.346Z,1670852308.346 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-12T13:38:28.807Z,1670852308.807 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2022-12-12T13:39:55.191Z,1670852395.191 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-12T13:40:14.659Z,1670852414.659 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2022-12-12T13:40:14.659Z,1670852414.659 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-12-12T13:40:14.660Z,1670852414.660 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2022-12-12T13:40:14.661Z,1670852414.661 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2022-12-12T13:40:14.671Z,1670852414.671 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-12-12T13:40:14.671Z,1670852414.671 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2022-12-12T13:40:15.062Z,1670852415.062 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-12-12T13:40:15.062Z,1670852415.062 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2022-12-12T13:40:15.063Z,1670852415.063 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2022-12-12T13:40:15.063Z,1670852415.063 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2022-12-12T13:40:15.411Z,1670852415.411 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2022-12-12T13:41:38.187Z,1670852498.187 [CommandExec](IMPORTANT): got command burn off
2022-12-12T13:41:38.187Z,1670852498.187 [CommandExec](IMPORTANT): Deactivating dropweight wire
2022-12-12T13:42:40.830Z,1670852560.830 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2022-12-12T13:42:40.833Z,1670852560.833 [BPC1](INFO): Received data from all battery sticks.
2022-12-12T13:43:15.583Z,1670852595.583 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2022-12-12T13:43:15.583Z,1670852595.583 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-12-12T13:43:15.584Z,1670852595.584 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3
2022-12-12T13:43:15.584Z,1670852595.584 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2022-12-12T13:43:15.595Z,1670852595.595 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-12-12T13:43:15.595Z,1670852595.595 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2022-12-12T13:43:15.995Z,1670852595.995 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-12-12T13:43:15.995Z,1670852595.995 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2022-12-12T13:43:15.995Z,1670852595.995 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2022-12-12T13:43:15.995Z,1670852595.995 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3
2022-12-12T13:43:16.400Z,1670852596.400 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2022-12-12T13:43:28.522Z,1670852608.522 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-12-12T13:38:28.3Z
2022-12-12T13:43:28.522Z,1670852608.522 [Default:CheckIn:Read_GPS] Stopped
2022-12-12T13:43:28.522Z,1670852608.522 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-12T13:43:28.941Z,1670852608.941 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-12-12T13:43:35.701Z,1670852615.701 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20221212T133402/Courier0004.lzma
2022-12-12T13:43:36.704Z,1670852616.704 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Courier0004.lzma.bak
2022-12-12T13:43:36.704Z,1670852616.704 [DataOverHttps](INFO): SBD MOMSN=17392726
2022-12-12T13:43:54.542Z,1670852634.542 [DataOverHttps](INFO): Sending 238 bytes from file Logs/20221212T133402/Express0005.lzma
2022-12-12T13:43:55.544Z,1670852635.544 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Express0005.lzma.bak
2022-12-12T13:43:55.544Z,1670852635.544 [DataOverHttps](INFO): SBD MOMSN=17392728
2022-12-12T13:43:56.833Z,1670852636.833 [Default:CheckIn:Read_Iridium] Stopped
2022-12-12T13:43:56.833Z,1670852636.833 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-12T13:43:56.833Z,1670852636.833 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-12T13:44:13.421Z,1670852653.421 [CBIT](FAULT): Could not open coulomb counter log file
2022-12-12T13:44:14.605Z,1670852654.605 [Power24vConverter](INFO): Powering down.
2022-12-12T13:44:52.575Z,1670852692.575 [NAL9602](FAULT): GPS failed to acquire within timeout.
2022-12-12T13:44:52.575Z,1670852692.575 [NAL9602] Data Fault, FailCount= 1
2022-12-12T13:44:52.575Z,1670852692.575 [NAL9602](ERROR): Data Fault
2022-12-12T13:44:52.593Z,1670852692.593 [CBIT](ERROR): Data Fault in component: NAL9602
2022-12-12T13:44:52.980Z,1670852692.980 [NAL9602](INFO): Powering down
2022-12-12T13:44:53.797Z,1670852693.797 [CBIT](INFO): Clearing failed state for component NAL9602
2022-12-12T13:44:53.797Z,1670852693.797 [NAL9602] No Fault, FailCount= 1
2022-12-12T13:45:23.275Z,1670852723.275 [NAL9602](INFO): Powering up NAL9602
2022-12-12T13:45:34.188Z,1670852734.188 [NAL9602](INFO): NAL9602 initialized
2022-12-12T13:46:16.631Z,1670852776.631 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2022-12-12T13:46:16.631Z,1670852776.631 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-12-12T13:46:16.632Z,1670852776.632 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 4
2022-12-12T13:46:16.632Z,1670852776.632 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2022-12-12T13:46:16.643Z,1670852776.643 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-12-12T13:46:16.644Z,1670852776.644 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2022-12-12T13:46:17.055Z,1670852777.055 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-12-12T13:46:17.055Z,1670852777.055 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2022-12-12T13:46:17.055Z,1670852777.055 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2022-12-12T13:46:17.055Z,1670852777.055 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 4
2022-12-12T13:46:17.439Z,1670852777.439 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2022-12-12T13:47:01.785Z,1670852821.785 [CommandExec](IMPORTANT): got command ibit
2022-12-12T13:47:01.891Z,1670852821.891 [IBIT](IMPORTANT): Beginning Initiated BIT
2022-12-12T13:47:01.891Z,1670852821.891 [IBIT](IMPORTANT): Beginning control surface checks.
2022-12-12T13:47:01.895Z,1670852821.895 [CBIT](IMPORTANT): Beginning ground fault scan
2022-12-12T13:47:04.755Z,1670852824.755 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2022-12-12T13:47:12.809Z,1670852832.809 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.006667
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): -0.005429
CHAN A3 (5V): -0.003069
CHAN B0 (3.3V): -0.001043
CHAN B1 (3.15aV): -0.002370
CHAN B2 (3.15bV): -0.001285
CHAN B3 (GND): -0.000883
OPEN: 0.003729
Full Scale: +/- 1 mA
2022-12-12T13:48:52.967Z,1670852932.967 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2022-12-12T13:48:53.373Z,1670852933.373 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.532000
2022-12-12T13:48:53.373Z,1670852933.373 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2022-12-12T13:48:53.374Z,1670852933.374 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2022-12-12T13:48:53.798Z,1670852933.798 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2022-12-12T13:48:53.798Z,1670852933.798 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2022-12-12T13:48:53.799Z,1670852933.799 [IBIT](IMPORTANT): Pressure:9.134102 PSI
2022-12-12T13:48:53.799Z,1670852933.799 [IBIT](IMPORTANT): Humidity:13.057013 %
2022-12-12T13:48:54.205Z,1670852934.205 [IBIT](IMPORTANT): Vehicle Pitch:-0.806046 degrees
2022-12-12T13:48:54.205Z,1670852934.205 [IBIT](IMPORTANT): Vehicle Roll:-5.972231 degrees
2022-12-12T13:48:54.206Z,1670852934.206 [IBIT](IMPORTANT): Vehicle Heading:268.571259 degrees
2022-12-12T13:48:54.615Z,1670852934.615 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2022-12-12T13:48:54.616Z,1670852934.616 [IBIT](IMPORTANT): buoyancyNeutral: 214.405823 cc
2022-12-12T13:48:54.616Z,1670852934.616 [IBIT](IMPORTANT): massDefault: 2.021047 cm
2022-12-12T13:48:54.616Z,1670852934.616 [IBIT](IMPORTANT): stopDepth: 290.000000 m
2022-12-12T13:48:54.617Z,1670852934.617 [IBIT](IMPORTANT): abortDepth: 300.000000 m
2022-12-12T13:48:54.617Z,1670852934.617 [IBIT](IMPORTANT): IBIT FAILED
2022-12-12T13:48:57.421Z,1670852937.421 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-12T13:48:57.421Z,1670852937.421 [Default:CheckIn:C.Wait] Stopped
2022-12-12T13:48:57.421Z,1670852937.421 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-12T13:48:57.421Z,1670852937.421 [Default:CheckIn:D] Running Loop=1
2022-12-12T13:48:57.811Z,1670852937.811 [Default:CheckIn:D] Stopped
2022-12-12T13:48:57.811Z,1670852937.811 [Default:CheckIn:E] Running Loop=1
2022-12-12T13:48:58.221Z,1670852938.221 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.719905 min
2022-12-12T13:48:58.221Z,1670852938.221 [Default:CheckIn:E] Stopped
2022-12-12T13:48:58.221Z,1670852938.221 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-12T13:48:58.221Z,1670852938.221 [Default:CheckIn] Stopped
2022-12-12T13:48:58.221Z,1670852938.221 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-12T13:48:58.222Z,1670852938.222 [Default:CheckIn](INFO): Running loop #2
2022-12-12T13:48:58.222Z,1670852938.222 [Default:CheckIn] Running Loop=2
2022-12-12T13:48:58.222Z,1670852938.222 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-12T13:48:58.222Z,1670852938.222 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-12T13:49:17.658Z,1670852957.658 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2022-12-12T13:49:17.658Z,1670852957.658 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-12-12T13:49:17.660Z,1670852957.660 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 5
2022-12-12T13:49:17.660Z,1670852957.660 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2022-12-12T13:49:17.670Z,1670852957.670 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-12-12T13:49:17.671Z,1670852957.671 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2022-12-12T13:49:18.066Z,1670852958.066 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-12-12T13:49:18.066Z,1670852958.066 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2022-12-12T13:49:18.066Z,1670852958.066 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2022-12-12T13:49:18.066Z,1670852958.066 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 5
2022-12-12T13:49:18.433Z,1670852958.433 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2022-12-12T13:51:55.566Z,1670853115.566 [CommandExec](IMPORTANT): got command failComponent
2022-12-12T13:51:55.567Z,1670853115.567 [CommandExec](IMPORTANT): Failed components:
2022-12-12T13:51:55.567Z,1670853115.567 [CommandExec](IMPORTANT): No failed Components.
2022-12-12T13:52:18.648Z,1670853138.648 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2022-12-12T13:52:18.648Z,1670853138.648 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-12-12T13:52:18.649Z,1670853138.649 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 6
2022-12-12T13:52:18.649Z,1670853138.649 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2022-12-12T13:52:18.689Z,1670853138.689 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-12-12T13:52:18.689Z,1670853138.689 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2022-12-12T13:52:19.051Z,1670853139.051 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-12-12T13:52:19.051Z,1670853139.051 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2022-12-12T13:52:19.052Z,1670853139.052 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2022-12-12T13:52:19.052Z,1670853139.052 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 6
2022-12-12T13:52:19.450Z,1670853139.450 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2022-12-12T13:53:58.429Z,1670853238.429 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-12-12T13:48:58.2Z
2022-12-12T13:53:58.429Z,1670853238.429 [Default:CheckIn:Read_GPS] Stopped
2022-12-12T13:53:58.429Z,1670853238.429 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-12T13:54:03.509Z,1670853243.509 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20221212T133402/Courier0007.lzma
2022-12-12T13:54:04.512Z,1670853244.512 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Courier0007.lzma.bak
2022-12-12T13:54:04.512Z,1670853244.512 [DataOverHttps](INFO): SBD MOMSN=17392734
2022-12-12T13:54:13.775Z,1670853253.775 [CBIT](FAULT): Could not open coulomb counter log file
2022-12-12T13:54:19.895Z,1670853259.895 [DataOverHttps](INFO): Sending 856 bytes from file Logs/20221212T133402/Express0008.lzma
2022-12-12T13:54:20.895Z,1670853260.895 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Express0008.lzma.bak
2022-12-12T13:54:20.896Z,1670853260.896 [DataOverHttps](INFO): SBD MOMSN=17392736
2022-12-12T13:54:22.284Z,1670853262.284 [Default:CheckIn:Read_Iridium] Stopped
2022-12-12T13:54:22.284Z,1670853262.284 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-12T13:54:22.284Z,1670853262.284 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-12T13:55:19.645Z,1670853319.645 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2022-12-12T13:55:19.645Z,1670853319.645 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-12-12T13:55:19.647Z,1670853319.647 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 7
2022-12-12T13:55:19.647Z,1670853319.647 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2022-12-12T13:55:19.657Z,1670853319.657 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-12-12T13:55:19.657Z,1670853319.657 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2022-12-12T13:55:20.063Z,1670853320.063 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-12-12T13:55:20.063Z,1670853320.063 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2022-12-12T13:55:20.064Z,1670853320.064 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2022-12-12T13:55:20.064Z,1670853320.064 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 7
2022-12-12T13:55:20.447Z,1670853320.447 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2022-12-12T13:55:35.371Z,1670853335.371 [NAL9602](FAULT): GPS failed to acquire within timeout.
2022-12-12T13:55:35.371Z,1670853335.371 [NAL9602] Data Fault, FailCount= 2
2022-12-12T13:55:35.371Z,1670853335.371 [NAL9602](ERROR): Data Fault
2022-12-12T13:55:35.438Z,1670853335.438 [CBIT](ERROR): Data Fault in component: NAL9602
2022-12-12T13:55:35.775Z,1670853335.775 [NAL9602](INFO): Powering down
2022-12-12T13:55:36.633Z,1670853336.633 [CBIT](INFO): Clearing failed state for component NAL9602
2022-12-12T13:55:36.634Z,1670853336.634 [NAL9602] No Fault, FailCount= 2
2022-12-12T13:56:06.073Z,1670853366.073 [NAL9602](INFO): Powering up NAL9602
2022-12-12T13:56:16.989Z,1670853376.989 [NAL9602](INFO): NAL9602 initialized
2022-12-12T13:58:20.649Z,1670853500.649 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2022-12-12T13:58:20.649Z,1670853500.649 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-12-12T13:58:20.651Z,1670853500.651 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 8
2022-12-12T13:58:20.651Z,1670853500.651 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2022-12-12T13:58:20.661Z,1670853500.661 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-12-12T13:58:20.661Z,1670853500.661 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2022-12-12T13:58:21.064Z,1670853501.064 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-12-12T13:58:21.064Z,1670853501.064 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2022-12-12T13:58:21.064Z,1670853501.064 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2022-12-12T13:58:21.065Z,1670853501.065 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 8
2022-12-12T13:58:21.455Z,1670853501.455 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2022-12-12T13:59:22.861Z,1670853562.861 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-12T13:59:22.861Z,1670853562.861 [Default:CheckIn:C.Wait] Stopped
2022-12-12T13:59:22.861Z,1670853562.861 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-12T13:59:22.861Z,1670853562.861 [Default:CheckIn:D] Running Loop=1
2022-12-12T13:59:23.273Z,1670853563.273 [Default:CheckIn:D] Stopped
2022-12-12T13:59:23.273Z,1670853563.273 [Default:CheckIn:E] Running Loop=1
2022-12-12T13:59:23.674Z,1670853563.674 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.144259 min
2022-12-12T13:59:23.674Z,1670853563.674 [Default:CheckIn:E] Stopped
2022-12-12T13:59:23.674Z,1670853563.674 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-12T13:59:23.674Z,1670853563.674 [Default:CheckIn] Stopped
2022-12-12T13:59:23.674Z,1670853563.674 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-12T13:59:23.675Z,1670853563.675 [Default:CheckIn](INFO): Running loop #3
2022-12-12T13:59:23.675Z,1670853563.675 [Default:CheckIn] Running Loop=3
2022-12-12T13:59:23.675Z,1670853563.675 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-12T13:59:23.675Z,1670853563.675 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-12T14:01:21.669Z,1670853681.669 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2022-12-12T14:01:21.669Z,1670853681.669 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-12-12T14:01:21.671Z,1670853681.671 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 9
2022-12-12T14:01:21.671Z,1670853681.671 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2022-12-12T14:01:21.681Z,1670853681.681 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-12-12T14:01:21.682Z,1670853681.682 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2022-12-12T14:01:22.076Z,1670853682.076 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-12-12T14:01:22.077Z,1670853682.077 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2022-12-12T14:01:22.077Z,1670853682.077 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2022-12-12T14:01:22.077Z,1670853682.077 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 9
2022-12-12T14:01:22.463Z,1670853682.463 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2022-12-12T14:04:13.792Z,1670853853.792 [CBIT](FAULT): Could not open coulomb counter log file
2022-12-12T14:04:22.683Z,1670853862.683 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2022-12-12T14:04:22.683Z,1670853862.683 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-12-12T14:04:22.684Z,1670853862.684 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 10
2022-12-12T14:04:22.684Z,1670853862.684 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2022-12-12T14:04:22.694Z,1670853862.694 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-12-12T14:04:22.695Z,1670853862.695 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2022-12-12T14:04:23.108Z,1670853863.108 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-12-12T14:04:23.108Z,1670853863.108 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2022-12-12T14:04:23.108Z,1670853863.108 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2022-12-12T14:04:23.108Z,1670853863.108 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 10
2022-12-12T14:04:23.515Z,1670853863.515 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2022-12-12T14:04:23.913Z,1670853863.913 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-12-12T13:59:23.7Z
2022-12-12T14:04:23.913Z,1670853863.913 [Default:CheckIn:Read_GPS] Stopped
2022-12-12T14:04:23.913Z,1670853863.913 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-12T14:04:28.709Z,1670853868.709 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20221212T133402/Courier0010.lzma
2022-12-12T14:04:29.711Z,1670853869.711 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Courier0010.lzma.bak
2022-12-12T14:04:29.712Z,1670853869.712 [DataOverHttps](INFO): SBD MOMSN=17392766
2022-12-12T14:04:45.021Z,1670853885.021 [DataOverHttps](INFO): Sending 196 bytes from file Logs/20221212T133402/Express0011.lzma
2022-12-12T14:04:46.023Z,1670853886.023 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Express0011.lzma.bak
2022-12-12T14:04:46.024Z,1670853886.024 [DataOverHttps](INFO): SBD MOMSN=17392768
2022-12-12T14:04:47.344Z,1670853887.344 [Default:CheckIn:Read_Iridium] Stopped
2022-12-12T14:04:47.344Z,1670853887.344 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-12T14:04:47.344Z,1670853887.344 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-12T14:06:19.435Z,1670853979.435 [NAL9602](FAULT): GPS failed to acquire within timeout.
2022-12-12T14:06:19.435Z,1670853979.435 [NAL9602] Data Fault, FailCount= 3
2022-12-12T14:06:19.435Z,1670853979.435 [NAL9602](ERROR): Data Fault
2022-12-12T14:06:19.457Z,1670853979.457 [CBIT](ERROR): Data Fault in component: NAL9602
2022-12-12T14:06:19.831Z,1670853979.831 [NAL9602](INFO): Powering down
2022-12-12T14:06:20.660Z,1670853980.660 [CBIT](INFO): Clearing failed state for component NAL9602
2022-12-12T14:06:20.660Z,1670853980.660 [NAL9602] No Fault, FailCount= 3
2022-12-12T14:06:50.133Z,1670854010.133 [NAL9602](INFO): Powering up NAL9602
2022-12-12T14:07:01.043Z,1670854021.043 [NAL9602](INFO): NAL9602 initialized
2022-12-12T14:07:23.673Z,1670854043.673 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2022-12-12T14:07:23.673Z,1670854043.673 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-12-12T14:07:23.675Z,1670854043.675 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 11
2022-12-12T14:07:23.675Z,1670854043.675 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2022-12-12T14:07:23.712Z,1670854043.712 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-12-12T14:07:23.712Z,1670854043.712 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2022-12-12T14:07:24.083Z,1670854044.083 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-12-12T14:07:24.084Z,1670854044.084 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2022-12-12T14:07:24.084Z,1670854044.084 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2022-12-12T14:07:24.084Z,1670854044.084 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 11
2022-12-12T14:07:24.489Z,1670854044.489 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2022-12-12T14:09:47.912Z,1670854187.912 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-12T14:09:47.913Z,1670854187.913 [Default:CheckIn:C.Wait] Stopped
2022-12-12T14:09:47.913Z,1670854187.913 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-12T14:09:47.913Z,1670854187.913 [Default:CheckIn:D] Running Loop=1
2022-12-12T14:09:48.329Z,1670854188.329 [Default:CheckIn:D] Stopped
2022-12-12T14:09:48.329Z,1670854188.329 [Default:CheckIn:E] Running Loop=1
2022-12-12T14:09:48.737Z,1670854188.737 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.561861 min
2022-12-12T14:09:48.737Z,1670854188.737 [Default:CheckIn:E] Stopped
2022-12-12T14:09:48.737Z,1670854188.737 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-12T14:09:48.737Z,1670854188.737 [Default:CheckIn] Stopped
2022-12-12T14:09:48.737Z,1670854188.737 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-12T14:09:48.738Z,1670854188.738 [Default:CheckIn](INFO): Running loop #4
2022-12-12T14:09:48.738Z,1670854188.738 [Default:CheckIn] Running Loop=4
2022-12-12T14:09:48.738Z,1670854188.738 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-12T14:09:48.738Z,1670854188.738 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-12T14:10:24.678Z,1670854224.678 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12
2022-12-12T14:10:24.678Z,1670854224.678 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-12-12T14:10:24.679Z,1670854224.679 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 12
2022-12-12T14:10:24.679Z,1670854224.679 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2022-12-12T14:10:24.690Z,1670854224.690 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-12-12T14:10:24.690Z,1670854224.690 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2022-12-12T14:10:25.091Z,1670854225.091 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-12-12T14:10:25.091Z,1670854225.091 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12
2022-12-12T14:10:25.091Z,1670854225.091 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2022-12-12T14:10:25.091Z,1670854225.091 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 12
2022-12-12T14:10:25.495Z,1670854225.495 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2022-12-12T14:11:02.245Z,1670854262.245 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,141100.00,A,3648.14902,N,12147.25056,W,2.585,217.54,121222,,,A*74
2022-12-12T14:11:02.248Z,1670854262.248 [NAL9602](INFO): GPS fix at 20221212T141100: (36.802484, -121.787509)
2022-12-12T14:11:02.263Z,1670854262.263 [Default:CheckIn:Read_GPS] Stopped
2022-12-12T14:11:02.263Z,1670854262.263 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-12T14:11:09.609Z,1670854269.609 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20221212T133402/Courier0013.lzma
2022-12-12T14:11:10.611Z,1670854270.611 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Courier0013.lzma.bak
2022-12-12T14:11:10.612Z,1670854270.612 [DataOverHttps](INFO): SBD MOMSN=17392774
2022-12-12T14:11:26.250Z,1670854286.250 [DataOverHttps](INFO): Sending 283 bytes from file Logs/20221212T133402/Express0014.lzma
2022-12-12T14:11:27.252Z,1670854287.252 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Express0014.lzma.bak
2022-12-12T14:11:27.252Z,1670854287.252 [DataOverHttps](INFO): SBD MOMSN=17392777
2022-12-12T14:11:28.517Z,1670854288.517 [Default:CheckIn:Read_Iridium] Stopped
2022-12-12T14:11:28.517Z,1670854288.517 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-12T14:11:28.517Z,1670854288.517 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-12T14:11:34.566Z,1670854294.566 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-12T14:14:13.800Z,1670854453.800 [CBIT](FAULT): Could not open coulomb counter log file
2022-12-12T14:16:17.363Z,1670854577.363 [CommandExec](IMPORTANT): got command ibit
2022-12-12T14:16:17.477Z,1670854577.477 [IBIT](IMPORTANT): Beginning Initiated BIT
2022-12-12T14:16:17.477Z,1670854577.477 [IBIT](IMPORTANT): Beginning control surface checks.
2022-12-12T14:16:17.488Z,1670854577.488 [CBIT](IMPORTANT): Beginning ground fault scan
2022-12-12T14:16:19.030Z,1670854579.030 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,141618.00,A,3648.14188,N,12147.22860,W,0.019,150.30,121222,,,D*7F
2022-12-12T14:16:19.032Z,1670854579.032 [NAL9602](INFO): GPS fix at 20221212T141618: (36.802365, -121.787143)
2022-12-12T14:16:20.311Z,1670854580.311 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2022-12-12T14:16:23.873Z,1670854583.873 [NAL9602](INFO): SBD MO Status=0, MOMSN=10634, MT Status=0, MTMSN=0
2022-12-12T14:16:23.873Z,1670854583.873 [NAL9602](INFO): No messages in MT queue
2022-12-12T14:16:25.089Z,1670854585.089 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,141624.00,A,3648.14182,N,12147.22854,W,0.019,150.30,121222,,,D*7D
2022-12-12T14:16:25.091Z,1670854585.091 [NAL9602](INFO): GPS fix at 20221212T141624: (36.802364, -121.787142)
2022-12-12T14:16:27.916Z,1670854587.916 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,141627.00,A,3648.14176,N,12147.22851,W,0.078,150.30,121222,,,D*77
2022-12-12T14:16:27.919Z,1670854587.919 [NAL9602](INFO): GPS fix at 20221212T141627: (36.802363, -121.787142)
2022-12-12T14:16:28.388Z,1670854588.388 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.007599
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): -0.005414
CHAN A3 (5V): -0.002331
CHAN B0 (3.3V): -0.000864
CHAN B1 (3.15aV): -0.001126
CHAN B2 (3.15bV): -0.001628
CHAN B3 (GND): -0.000551
OPEN: 0.003395
Full Scale: +/- 1 mA
2022-12-12T14:16:31.145Z,1670854591.145 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,141630.00,A,3648.14179,N,12147.22864,W,0.058,150.30,121222,,,D*7A
2022-12-12T14:16:31.147Z,1670854591.147 [NAL9602](INFO): GPS fix at 20221212T141630: (36.802363, -121.787144)
2022-12-12T14:16:33.981Z,1670854593.981 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,141633.00,A,3648.14186,N,12147.22877,W,0.039,150.30,121222,,,D*7C
2022-12-12T14:16:33.983Z,1670854593.983 [NAL9602](INFO): GPS fix at 20221212T141633: (36.802364, -121.787146)
2022-12-12T14:16:37.204Z,1670854597.204 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,141636.00,A,3648.14189,N,12147.22884,W,0.019,150.30,121222,,,D*78
2022-12-12T14:16:37.207Z,1670854597.207 [NAL9602](INFO): GPS fix at 20221212T141636: (36.802365, -121.787147)
2022-12-12T14:16:40.036Z,1670854600.036 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,141639.00,A,3648.14191,N,12147.22899,W,0.039,150.30,121222,,,D*70
2022-12-12T14:16:40.039Z,1670854600.039 [NAL9602](INFO): GPS fix at 20221212T141639: (36.802365, -121.787150)
2022-12-12T14:16:42.860Z,1670854602.860 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,141642.00,A,3648.14191,N,12147.22914,W,0.078,150.30,121222,,,D*7D
2022-12-12T14:16:42.862Z,1670854602.862 [NAL9602](INFO): GPS fix at 20221212T141642: (36.802365, -121.787152)
2022-12-12T14:16:46.093Z,1670854606.093 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,141645.00,A,3648.14192,N,12147.22930,W,0.039,150.30,121222,,,D*7A
2022-12-12T14:16:46.095Z,1670854606.095 [NAL9602](INFO): GPS fix at 20221212T141645: (36.802365, -121.787155)
2022-12-12T14:16:48.926Z,1670854608.926 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,141648.00,A,3648.14198,N,12147.22935,W,0.058,150.30,121222,,,D*7F
2022-12-12T14:16:48.928Z,1670854608.928 [NAL9602](INFO): GPS fix at 20221212T141648: (36.802366, -121.787156)
2022-12-12T14:16:52.161Z,1670854612.161 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,141651.00,A,3648.14210,N,12147.22953,W,0.058,150.30,121222,,,D*74
2022-12-12T14:16:52.167Z,1670854612.167 [NAL9602](INFO): GPS fix at 20221212T141651: (36.802368, -121.787159)
2022-12-12T14:16:54.985Z,1670854614.985 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,141654.00,A,3648.14215,N,12147.22974,W,0.039,150.30,121222,,,D*76
2022-12-12T14:16:54.987Z,1670854614.987 [NAL9602](INFO): GPS fix at 20221212T141654: (36.802369, -121.787162)
2022-12-12T14:16:57.812Z,1670854617.812 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,141657.00,A,3648.14215,N,12147.22970,W,0.019,150.30,121222,,,D*73
2022-12-12T14:16:57.815Z,1670854617.815 [NAL9602](INFO): GPS fix at 20221212T141657: (36.802369, -121.787162)
2022-12-12T14:17:01.039Z,1670854621.039 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,141700.00,A,3648.14218,N,12147.22952,W,0.039,150.30,121222,,,D*7F
2022-12-12T14:17:01.041Z,1670854621.041 [NAL9602](INFO): GPS fix at 20221212T141700: (36.802370, -121.787159)
2022-12-12T14:17:03.872Z,1670854623.872 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,141703.00,A,3648.14221,N,12147.22929,W,0.058,150.30,121222,,,D*7D
2022-12-12T14:17:03.875Z,1670854623.875 [NAL9602](INFO): GPS fix at 20221212T141703: (36.802370, -121.787155)
2022-12-12T14:17:03.917Z,1670854623.917 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 5
Latitude: 36.802372 Longitude: -121.787155
2022-12-12T14:17:04.331Z,1670854624.331 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.532000
2022-12-12T14:17:04.331Z,1670854624.331 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2022-12-12T14:17:04.331Z,1670854624.331 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2022-12-12T14:17:04.697Z,1670854624.697 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2022-12-12T14:17:04.697Z,1670854624.697 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2022-12-12T14:17:04.698Z,1670854624.698 [IBIT](IMPORTANT): Pressure:9.150103 PSI
2022-12-12T14:17:04.698Z,1670854624.698 [IBIT](IMPORTANT): Humidity:13.392748 %
2022-12-12T14:17:05.116Z,1670854625.116 [IBIT](IMPORTANT): Vehicle Pitch:-0.465338 degrees
2022-12-12T14:17:05.116Z,1670854625.116 [IBIT](IMPORTANT): Vehicle Roll:-5.941511 degrees
2022-12-12T14:17:05.116Z,1670854625.116 [IBIT](IMPORTANT): Vehicle Heading:20.652170 degrees
2022-12-12T14:17:05.508Z,1670854625.508 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2022-12-12T14:17:05.508Z,1670854625.508 [IBIT](IMPORTANT): buoyancyNeutral: 214.405823 cc
2022-12-12T14:17:05.509Z,1670854625.509 [IBIT](IMPORTANT): massDefault: 2.021047 cm
2022-12-12T14:17:05.509Z,1670854625.509 [IBIT](IMPORTANT): stopDepth: 290.000000 m
2022-12-12T14:17:05.509Z,1670854625.509 [IBIT](IMPORTANT): abortDepth: 300.000000 m
2022-12-12T14:17:05.509Z,1670854625.509 [IBIT](IMPORTANT): IBIT PASSED
2022-12-12T14:17:05.913Z,1670854625.913 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-12T14:17:05.913Z,1670854625.913 [Default:CheckIn:C.Wait] Stopped
2022-12-12T14:17:05.913Z,1670854625.913 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-12T14:17:05.913Z,1670854625.913 [Default:CheckIn:D] Running Loop=1
2022-12-12T14:17:06.308Z,1670854626.308 [Default:CheckIn:D] Stopped
2022-12-12T14:17:06.308Z,1670854626.308 [Default:CheckIn:E] Running Loop=1
2022-12-12T14:17:06.712Z,1670854626.712 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 38.861515 min
2022-12-12T14:17:06.712Z,1670854626.712 [Default:CheckIn:E] Stopped
2022-12-12T14:17:06.713Z,1670854626.713 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-12T14:17:06.713Z,1670854626.713 [Default:CheckIn] Stopped
2022-12-12T14:17:06.713Z,1670854626.713 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-12T14:17:06.713Z,1670854626.713 [Default:CheckIn](INFO): Running loop #5
2022-12-12T14:17:06.713Z,1670854626.713 [Default:CheckIn] Running Loop=5
2022-12-12T14:17:06.713Z,1670854626.713 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-12T14:17:06.713Z,1670854626.713 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-12T14:17:08.721Z,1670854628.721 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,141708.00,A,3648.14220,N,12147.22920,W,0.039,150.30,121222,,,D*79
2022-12-12T14:17:08.723Z,1670854628.723 [NAL9602](INFO): GPS fix at 20221212T141708: (36.802370, -121.787153)
2022-12-12T14:17:08.773Z,1670854628.773 [Default:CheckIn:Read_GPS] Stopped
2022-12-12T14:17:08.773Z,1670854628.773 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-12T14:17:15.673Z,1670854635.673 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221212T133402/Courier0016.lzma
2022-12-12T14:17:16.675Z,1670854636.675 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Courier0016.lzma.bak
2022-12-12T14:17:16.676Z,1670854636.676 [DataOverHttps](INFO): SBD MOMSN=17392786
2022-12-12T14:17:32.306Z,1670854652.306 [DataOverHttps](INFO): Sending 791 bytes from file Logs/20221212T133402/Express0017.lzma
2022-12-12T14:17:33.308Z,1670854653.308 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Express0017.lzma.bak
2022-12-12T14:17:33.308Z,1670854653.308 [DataOverHttps](INFO): SBD MOMSN=17392816
2022-12-12T14:17:34.585Z,1670854654.585 [Default:CheckIn:Read_Iridium] Stopped
2022-12-12T14:17:34.585Z,1670854654.585 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-12T14:17:34.585Z,1670854654.585 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-12T14:17:41.442Z,1670854661.442 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-12T14:22:35.177Z,1670854955.177 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-12T14:22:35.177Z,1670854955.177 [Default:CheckIn:C.Wait] Stopped
2022-12-12T14:22:35.177Z,1670854955.177 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-12T14:22:35.177Z,1670854955.177 [Default:CheckIn:D] Running Loop=1
2022-12-12T14:22:35.560Z,1670854955.560 [Default:CheckIn:D] Stopped
2022-12-12T14:22:35.561Z,1670854955.561 [Default:CheckIn:E] Running Loop=1
2022-12-12T14:22:35.972Z,1670854955.972 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 44.349056 min
2022-12-12T14:22:35.972Z,1670854955.972 [Default:CheckIn:E] Stopped
2022-12-12T14:22:35.972Z,1670854955.972 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-12T14:22:35.972Z,1670854955.972 [Default:CheckIn] Stopped
2022-12-12T14:22:35.972Z,1670854955.972 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-12T14:22:35.972Z,1670854955.972 [Default:CheckIn](INFO): Running loop #6
2022-12-12T14:22:35.972Z,1670854955.972 [Default:CheckIn] Running Loop=6
2022-12-12T14:22:35.973Z,1670854955.973 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-12T14:22:35.973Z,1670854955.973 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-12T14:22:37.975Z,1670854957.975 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,142237.00,A,3648.14324,N,12147.22693,W,0.117,150.30,121222,,,D*7C
2022-12-12T14:22:37.977Z,1670854957.977 [NAL9602](INFO): GPS fix at 20221212T142237: (36.802387, -121.787115)
2022-12-12T14:22:38.017Z,1670854958.017 [Default:CheckIn:Read_GPS] Stopped
2022-12-12T14:22:38.017Z,1670854958.017 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-12T14:22:45.125Z,1670854965.125 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221212T133402/Courier0019.lzma
2022-12-12T14:22:46.128Z,1670854966.128 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Courier0019.lzma.bak
2022-12-12T14:22:46.128Z,1670854966.128 [DataOverHttps](INFO): SBD MOMSN=17392843
2022-12-12T14:23:01.793Z,1670854981.793 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20221212T133402/Express0020.lzma
2022-12-12T14:23:02.796Z,1670854982.796 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Express0020.lzma.bak
2022-12-12T14:23:02.796Z,1670854982.796 [DataOverHttps](INFO): SBD MOMSN=17392846
2022-12-12T14:23:03.848Z,1670854983.848 [Default:CheckIn:Read_Iridium] Stopped
2022-12-12T14:23:03.848Z,1670854983.848 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-12T14:23:03.848Z,1670854983.848 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-12T14:23:17.973Z,1670854997.973 [NAL9602](INFO): SBD MO Status=2, MOMSN=10635, MT Status=2, MTMSN=0
2022-12-12T14:23:17.973Z,1670854997.973 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-12-12T14:23:34.133Z,1670855014.133 [NAL9602](INFO): SBD MO Status=2, MOMSN=10635, MT Status=2, MTMSN=0
2022-12-12T14:23:34.133Z,1670855014.133 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-12-12T14:23:57.967Z,1670855037.967 [NAL9602](INFO): SBD MO Status=2, MOMSN=10635, MT Status=2, MTMSN=0
2022-12-12T14:23:57.967Z,1670855037.967 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-12-12T14:24:06.861Z,1670855046.861 [NAL9602](INFO): SBD MO Status=0, MOMSN=10635, MT Status=0, MTMSN=0
2022-12-12T14:24:06.861Z,1670855046.861 [NAL9602](INFO): No messages in MT queue
2022-12-12T14:24:14.223Z,1670855054.223 [CBIT](FAULT): Could not open coulomb counter log file
2022-12-12T14:24:37.560Z,1670855077.560 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-12T14:28:04.457Z,1670855284.457 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-12T14:28:04.457Z,1670855284.457 [Default:CheckIn:C.Wait] Stopped
2022-12-12T14:28:04.457Z,1670855284.457 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-12T14:28:04.457Z,1670855284.457 [Default:CheckIn:D] Running Loop=1
2022-12-12T14:28:04.857Z,1670855284.857 [Default:CheckIn:D] Stopped
2022-12-12T14:28:04.857Z,1670855284.857 [Default:CheckIn:E] Running Loop=1
2022-12-12T14:28:05.263Z,1670855285.263 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 49.837333 min
2022-12-12T14:28:05.263Z,1670855285.263 [Default:CheckIn:E] Stopped
2022-12-12T14:28:05.263Z,1670855285.263 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-12T14:28:05.263Z,1670855285.263 [Default:CheckIn] Stopped
2022-12-12T14:28:05.263Z,1670855285.263 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-12T14:28:05.263Z,1670855285.263 [Default:CheckIn](INFO): Running loop #7
2022-12-12T14:28:05.263Z,1670855285.263 [Default:CheckIn] Running Loop=7
2022-12-12T14:28:05.263Z,1670855285.263 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-12T14:28:05.263Z,1670855285.263 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-12T14:28:07.273Z,1670855287.273 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,142806.00,A,3648.14326,N,12147.22679,W,0.039,150.30,121222,,,D*7F
2022-12-12T14:28:07.275Z,1670855287.275 [NAL9602](INFO): GPS fix at 20221212T142806: (36.802388, -121.787113)
2022-12-12T14:28:07.324Z,1670855287.324 [Default:CheckIn:Read_GPS] Stopped
2022-12-12T14:28:07.324Z,1670855287.324 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-12T14:28:14.645Z,1670855294.645 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221212T133402/Courier0022.lzma
2022-12-12T14:28:15.648Z,1670855295.648 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Courier0022.lzma.bak
2022-12-12T14:28:15.648Z,1670855295.648 [DataOverHttps](INFO): SBD MOMSN=17392863
2022-12-12T14:28:19.392Z,1670855299.392 [NAL9602](INFO): SBD MO Status=0, MOMSN=10636, MT Status=0, MTMSN=0
2022-12-12T14:28:19.393Z,1670855299.393 [NAL9602](INFO): No messages in MT queue
2022-12-12T14:28:31.329Z,1670855311.329 [DataOverHttps](INFO): Sending 170 bytes from file Logs/20221212T133402/Express0023.lzma
2022-12-12T14:28:32.332Z,1670855312.332 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Express0023.lzma.bak
2022-12-12T14:28:32.332Z,1670855312.332 [DataOverHttps](INFO): SBD MOMSN=17392866
2022-12-12T14:28:33.550Z,1670855313.550 [Default:CheckIn:Read_Iridium] Stopped
2022-12-12T14:28:33.550Z,1670855313.550 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-12T14:28:33.550Z,1670855313.550 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-12T14:28:50.094Z,1670855330.094 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-12T14:33:34.173Z,1670855614.173 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-12T14:33:34.174Z,1670855614.174 [Default:CheckIn:C.Wait] Stopped
2022-12-12T14:33:34.174Z,1670855614.174 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-12T14:33:34.174Z,1670855614.174 [Default:CheckIn:D] Running Loop=1
2022-12-12T14:33:34.576Z,1670855614.576 [Default:CheckIn:D] Stopped
2022-12-12T14:33:34.576Z,1670855614.576 [Default:CheckIn:E] Running Loop=1
2022-12-12T14:33:34.982Z,1670855614.982 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 55.332650 min
2022-12-12T14:33:34.982Z,1670855614.982 [Default:CheckIn:E] Stopped
2022-12-12T14:33:34.983Z,1670855614.983 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-12T14:33:34.983Z,1670855614.983 [Default:CheckIn] Stopped
2022-12-12T14:33:34.983Z,1670855614.983 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-12T14:33:34.983Z,1670855614.983 [Default:CheckIn](INFO): Running loop #8
2022-12-12T14:33:34.983Z,1670855614.983 [Default:CheckIn] Running Loop=8
2022-12-12T14:33:34.983Z,1670855614.983 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-12T14:33:34.983Z,1670855614.983 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-12T14:33:36.992Z,1670855616.992 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,143336.00,A,3648.14096,N,12147.22710,W,0.058,150.30,121222,,,D*77
2022-12-12T14:33:36.995Z,1670855616.995 [NAL9602](INFO): GPS fix at 20221212T143336: (36.802349, -121.787118)
2022-12-12T14:33:37.038Z,1670855617.038 [Default:CheckIn:Read_GPS] Stopped
2022-12-12T14:33:37.038Z,1670855617.038 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-12T14:33:46.833Z,1670855626.833 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20221212T133402/Courier0025.lzma
2022-12-12T14:33:47.836Z,1670855627.836 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Courier0025.lzma.bak
2022-12-12T14:33:47.836Z,1670855627.836 [DataOverHttps](INFO): SBD MOMSN=17392871
2022-12-12T14:33:50.356Z,1670855630.356 [NAL9602](INFO): SBD MO Status=0, MOMSN=10637, MT Status=0, MTMSN=0
2022-12-12T14:33:50.356Z,1670855630.356 [NAL9602](INFO): No messages in MT queue
2022-12-12T14:34:04.029Z,1670855644.029 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20221212T133402/Express0026.lzma
2022-12-12T14:34:05.032Z,1670855645.032 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Express0026.lzma.bak
2022-12-12T14:34:05.032Z,1670855645.032 [DataOverHttps](INFO): SBD MOMSN=17392876
2022-12-12T14:34:06.143Z,1670855646.143 [Default:CheckIn:Read_Iridium] Stopped
2022-12-12T14:34:06.143Z,1670855646.143 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-12T14:34:06.144Z,1670855646.144 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-12T14:34:14.225Z,1670855654.225 [CBIT](FAULT): Could not open coulomb counter log file
2022-12-12T14:34:21.062Z,1670855661.062 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-12T14:39:06.703Z,1670855946.703 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-12T14:39:06.704Z,1670855946.704 [Default:CheckIn:C.Wait] Stopped
2022-12-12T14:39:06.704Z,1670855946.704 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-12T14:39:06.704Z,1670855946.704 [Default:CheckIn:D] Running Loop=1
2022-12-12T14:39:07.119Z,1670855947.119 [Default:CheckIn:D] Stopped
2022-12-12T14:39:07.119Z,1670855947.119 [Default:CheckIn:E] Running Loop=1
2022-12-12T14:39:07.533Z,1670855947.533 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 60.875024 min
2022-12-12T14:39:07.533Z,1670855947.533 [Default:CheckIn:E] Stopped
2022-12-12T14:39:07.533Z,1670855947.533 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-12T14:39:07.533Z,1670855947.533 [Default:CheckIn] Stopped
2022-12-12T14:39:07.534Z,1670855947.534 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-12T14:39:07.534Z,1670855947.534 [Default:CheckIn](INFO): Running loop #9
2022-12-12T14:39:07.534Z,1670855947.534 [Default:CheckIn] Running Loop=9
2022-12-12T14:39:07.534Z,1670855947.534 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-12T14:39:07.534Z,1670855947.534 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-12T14:39:09.528Z,1670855949.528 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,143908.00,A,3648.14175,N,12147.22812,W,0.039,150.30,121222,,,D*76
2022-12-12T14:39:09.531Z,1670855949.531 [NAL9602](INFO): GPS fix at 20221212T143908: (36.802363, -121.787135)
2022-12-12T14:39:09.571Z,1670855949.571 [Default:CheckIn:Read_GPS] Stopped
2022-12-12T14:39:09.571Z,1670855949.571 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-12T14:39:15.988Z,1670855955.988 [NAL9602](INFO): SBD MO Status=0, MOMSN=10638, MT Status=0, MTMSN=0
2022-12-12T14:39:15.988Z,1670855955.988 [NAL9602](INFO): No messages in MT queue
2022-12-12T14:39:17.321Z,1670855957.321 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221212T133402/Courier0028.lzma
2022-12-12T14:39:18.324Z,1670855958.324 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Courier0028.lzma.bak
2022-12-12T14:39:18.324Z,1670855958.324 [DataOverHttps](INFO): SBD MOMSN=17392884
2022-12-12T14:39:34.025Z,1670855974.025 [DataOverHttps](INFO): Sending 171 bytes from file Logs/20221212T133402/Express0029.lzma
2022-12-12T14:39:35.028Z,1670855975.028 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Express0029.lzma.bak
2022-12-12T14:39:35.028Z,1670855975.028 [DataOverHttps](INFO): SBD MOMSN=17392890
2022-12-12T14:39:36.196Z,1670855976.196 [Default:CheckIn:Read_Iridium] Stopped
2022-12-12T14:39:36.196Z,1670855976.196 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-12T14:39:36.196Z,1670855976.196 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-12T14:39:46.689Z,1670855986.689 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-12T14:44:14.241Z,1670856254.241 [CBIT](FAULT): Could not open coulomb counter log file
2022-12-12T14:44:36.841Z,1670856276.841 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-12T14:44:36.841Z,1670856276.841 [Default:CheckIn:C.Wait] Stopped
2022-12-12T14:44:36.841Z,1670856276.841 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-12T14:44:36.841Z,1670856276.841 [Default:CheckIn:D] Running Loop=1
2022-12-12T14:44:37.254Z,1670856277.254 [Default:CheckIn:D] Stopped
2022-12-12T14:44:37.254Z,1670856277.254 [Default:CheckIn:E] Running Loop=1
2022-12-12T14:44:37.660Z,1670856277.660 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 66.377275 min
2022-12-12T14:44:37.660Z,1670856277.660 [Default:CheckIn:E] Stopped
2022-12-12T14:44:37.660Z,1670856277.660 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-12T14:44:37.660Z,1670856277.660 [Default:CheckIn] Stopped
2022-12-12T14:44:37.660Z,1670856277.660 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-12T14:44:37.660Z,1670856277.660 [Default:CheckIn](INFO): Running loop #10
2022-12-12T14:44:37.660Z,1670856277.660 [Default:CheckIn] Running Loop=10
2022-12-12T14:44:37.661Z,1670856277.661 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-12T14:44:37.661Z,1670856277.661 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-12T14:44:39.665Z,1670856279.665 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,144438.00,A,3648.14188,N,12147.22926,W,0.039,150.30,121222,,,D*7B
2022-12-12T14:44:39.667Z,1670856279.667 [NAL9602](INFO): GPS fix at 20221212T144438: (36.802365, -121.787154)
2022-12-12T14:44:39.679Z,1670856279.679 [Default:CheckIn:Read_GPS] Stopped
2022-12-12T14:44:39.679Z,1670856279.679 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-12T14:44:47.037Z,1670856287.037 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221212T133402/Courier0031.lzma
2022-12-12T14:44:48.040Z,1670856288.040 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Courier0031.lzma.bak
2022-12-12T14:44:48.040Z,1670856288.040 [DataOverHttps](INFO): SBD MOMSN=17392902
2022-12-12T14:45:03.829Z,1670856303.829 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20221212T133402/Express0032.lzma
2022-12-12T14:45:04.832Z,1670856304.832 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Express0032.lzma.bak
2022-12-12T14:45:04.832Z,1670856304.832 [DataOverHttps](INFO): SBD MOMSN=17392908
2022-12-12T14:45:05.934Z,1670856305.934 [Default:CheckIn:Read_Iridium] Stopped
2022-12-12T14:45:05.934Z,1670856305.934 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-12T14:45:05.934Z,1670856305.934 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-12T14:45:08.370Z,1670856308.370 [NAL9602](INFO): SBD MO Status=0, MOMSN=10639, MT Status=0, MTMSN=0
2022-12-12T14:45:08.370Z,1670856308.370 [NAL9602](INFO): No messages in MT queue
2022-12-12T14:45:39.047Z,1670856339.047 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-12T14:50:06.591Z,1670856606.591 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-12T14:50:06.591Z,1670856606.591 [Default:CheckIn:C.Wait] Stopped
2022-12-12T14:50:06.591Z,1670856606.591 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-12T14:50:06.591Z,1670856606.591 [Default:CheckIn:D] Running Loop=1
2022-12-12T14:50:06.998Z,1670856606.998 [Default:CheckIn:D] Stopped
2022-12-12T14:50:06.998Z,1670856606.998 [Default:CheckIn:E] Running Loop=1
2022-12-12T14:50:07.390Z,1670856607.390 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 71.873014 min
2022-12-12T14:50:07.390Z,1670856607.390 [Default:CheckIn:E] Stopped
2022-12-12T14:50:07.390Z,1670856607.390 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-12T14:50:07.390Z,1670856607.390 [Default:CheckIn] Stopped
2022-12-12T14:50:07.390Z,1670856607.390 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-12T14:50:07.390Z,1670856607.390 [Default:CheckIn](INFO): Running loop #11
2022-12-12T14:50:07.391Z,1670856607.391 [Default:CheckIn] Running Loop=11
2022-12-12T14:50:07.391Z,1670856607.391 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-12T14:50:07.391Z,1670856607.391 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-12T14:50:09.414Z,1670856609.414 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,145008.00,A,3648.14214,N,12147.22818,W,0.039,0.00,121222,,,D*70
2022-12-12T14:50:09.416Z,1670856609.416 [NAL9602](INFO): GPS fix at 20221212T145008: (36.802369, -121.787136)
2022-12-12T14:50:09.455Z,1670856609.455 [Default:CheckIn:Read_GPS] Stopped
2022-12-12T14:50:09.455Z,1670856609.455 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-12T14:50:09.809Z,1670856609.809 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2022-12-12T14:50:09.812Z,1670856609.812 [BPC1](INFO): Received data from all battery sticks.
2022-12-12T14:50:16.413Z,1670856616.413 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221212T133402/Courier0034.lzma
2022-12-12T14:50:17.416Z,1670856617.416 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Courier0034.lzma.bak
2022-12-12T14:50:17.416Z,1670856617.416 [DataOverHttps](INFO): SBD MOMSN=17392941
2022-12-12T14:50:33.009Z,1670856633.009 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20221212T133402/Express0035.lzma
2022-12-12T14:50:34.012Z,1670856634.012 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Express0035.lzma.bak
2022-12-12T14:50:34.012Z,1670856634.012 [DataOverHttps](INFO): SBD MOMSN=17392947
2022-12-12T14:50:34.044Z,1670856634.044 [NAL9602](INFO): SBD MO Status=2, MOMSN=10640, MT Status=2, MTMSN=0
2022-12-12T14:50:34.044Z,1670856634.044 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-12-12T14:50:35.283Z,1670856635.283 [Default:CheckIn:Read_Iridium] Stopped
2022-12-12T14:50:35.284Z,1670856635.284 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-12T14:50:35.284Z,1670856635.284 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-12T14:50:53.840Z,1670856653.840 [NAL9602](INFO): SBD MO Status=0, MOMSN=10640, MT Status=0, MTMSN=0
2022-12-12T14:50:53.840Z,1670856653.840 [NAL9602](INFO): No messages in MT queue
2022-12-12T14:51:24.543Z,1670856684.543 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-12T14:54:14.327Z,1670856854.327 [CBIT](FAULT): Could not open coulomb counter log file
2022-12-12T14:55:35.923Z,1670856935.923 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-12T14:55:35.923Z,1670856935.923 [Default:CheckIn:C.Wait] Stopped
2022-12-12T14:55:35.923Z,1670856935.923 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-12T14:55:35.923Z,1670856935.923 [Default:CheckIn:D] Running Loop=1
2022-12-12T14:55:36.307Z,1670856936.307 [Default:CheckIn:D] Stopped
2022-12-12T14:55:36.307Z,1670856936.307 [Default:CheckIn:E] Running Loop=1
2022-12-12T14:55:36.717Z,1670856936.717 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 77.361499 min
2022-12-12T14:55:36.717Z,1670856936.717 [Default:CheckIn:E] Stopped
2022-12-12T14:55:36.717Z,1670856936.717 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-12T14:55:36.718Z,1670856936.718 [Default:CheckIn] Stopped
2022-12-12T14:55:36.718Z,1670856936.718 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-12T14:55:36.718Z,1670856936.718 [Default:CheckIn](INFO): Running loop #12
2022-12-12T14:55:36.718Z,1670856936.718 [Default:CheckIn] Running Loop=12
2022-12-12T14:55:36.718Z,1670856936.718 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-12T14:55:36.718Z,1670856936.718 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-12T14:55:38.720Z,1670856938.720 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,145538.00,A,3648.14245,N,12147.22512,W,0.058,0.00,121222,,,D*72
2022-12-12T14:55:38.732Z,1670856938.732 [NAL9602](INFO): GPS fix at 20221212T145538: (36.802374, -121.787085)
2022-12-12T14:55:38.744Z,1670856938.744 [Default:CheckIn:Read_GPS] Stopped
2022-12-12T14:55:38.744Z,1670856938.744 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-12T14:55:46.833Z,1670856946.833 [DataOverHttps](INFO): Sending 84 bytes from file Logs/20221212T133402/Courier0037.lzma
2022-12-12T14:55:47.836Z,1670856947.836 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Courier0037.lzma.bak
2022-12-12T14:55:47.836Z,1670856947.836 [DataOverHttps](INFO): SBD MOMSN=17392955
2022-12-12T14:56:05.501Z,1670856965.501 [DataOverHttps](INFO): Sending 171 bytes from file Logs/20221212T133402/Express0038.lzma
2022-12-12T14:56:06.504Z,1670856966.504 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Express0038.lzma.bak
2022-12-12T14:56:06.504Z,1670856966.504 [DataOverHttps](INFO): SBD MOMSN=17392961
2022-12-12T14:56:07.850Z,1670856967.850 [Default:CheckIn:Read_Iridium] Stopped
2022-12-12T14:56:07.850Z,1670856967.850 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-12T14:56:07.850Z,1670856967.850 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-12T14:56:08.647Z,1670856968.647 [NAL9602](INFO): SBD MO Status=0, MOMSN=10641, MT Status=0, MTMSN=0
2022-12-12T14:56:08.647Z,1670856968.647 [NAL9602](INFO): No messages in MT queue
2022-12-12T14:56:39.355Z,1670856999.355 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-12T15:01:08.442Z,1670857268.442 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-12T15:01:08.442Z,1670857268.442 [Default:CheckIn:C.Wait] Stopped
2022-12-12T15:01:08.442Z,1670857268.442 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-12T15:01:08.442Z,1670857268.442 [Default:CheckIn:D] Running Loop=1
2022-12-12T15:01:08.860Z,1670857268.860 [Default:CheckIn:D] Stopped
2022-12-12T15:01:08.860Z,1670857268.860 [Default:CheckIn:E] Running Loop=1
2022-12-12T15:01:09.254Z,1670857269.254 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 82.904045 min
2022-12-12T15:01:09.254Z,1670857269.254 [Default:CheckIn:E] Stopped
2022-12-12T15:01:09.254Z,1670857269.254 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-12T15:01:09.254Z,1670857269.254 [Default:CheckIn] Stopped
2022-12-12T15:01:09.255Z,1670857269.255 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-12T15:01:09.255Z,1670857269.255 [Default:CheckIn](INFO): Running loop #13
2022-12-12T15:01:09.255Z,1670857269.255 [Default:CheckIn] Running Loop=13
2022-12-12T15:01:09.255Z,1670857269.255 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-12T15:01:09.255Z,1670857269.255 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-12T15:01:11.260Z,1670857271.260 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150110.00,A,3648.14213,N,12147.22496,W,0.039,0.00,121222,,,D*71
2022-12-12T15:01:11.262Z,1670857271.262 [NAL9602](INFO): GPS fix at 20221212T150110: (36.802369, -121.787083)
2022-12-12T15:01:11.273Z,1670857271.273 [Default:CheckIn:Read_GPS] Stopped
2022-12-12T15:01:11.273Z,1670857271.273 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-12T15:01:18.909Z,1670857278.909 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221212T133402/Courier0040.lzma
2022-12-12T15:01:19.912Z,1670857279.912 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Courier0040.lzma.bak
2022-12-12T15:01:19.912Z,1670857279.912 [DataOverHttps](INFO): SBD MOMSN=17392970
2022-12-12T15:01:21.768Z,1670857281.768 [NAL9602](INFO): SBD MO Status=0, MOMSN=10642, MT Status=0, MTMSN=0
2022-12-12T15:01:21.768Z,1670857281.768 [NAL9602](INFO): No messages in MT queue
2022-12-12T15:01:35.593Z,1670857295.593 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20221212T133402/Express0041.lzma
2022-12-12T15:01:36.596Z,1670857296.596 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Express0041.lzma.bak
2022-12-12T15:01:36.596Z,1670857296.596 [DataOverHttps](INFO): SBD MOMSN=17392976
2022-12-12T15:01:37.938Z,1670857297.938 [Default:CheckIn:Read_Iridium] Stopped
2022-12-12T15:01:37.938Z,1670857297.938 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-12T15:01:37.938Z,1670857297.938 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-12T15:01:52.472Z,1670857312.472 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-12T15:04:14.694Z,1670857454.694 [CBIT](FAULT): Could not open coulomb counter log file
2022-12-12T15:06:38.592Z,1670857598.592 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-12T15:06:38.592Z,1670857598.592 [Default:CheckIn:C.Wait] Stopped
2022-12-12T15:06:38.592Z,1670857598.592 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-12T15:06:38.593Z,1670857598.593 [Default:CheckIn:D] Running Loop=1
2022-12-12T15:06:38.961Z,1670857598.961 [Default:CheckIn:D] Stopped
2022-12-12T15:06:38.961Z,1670857598.961 [Default:CheckIn:E] Running Loop=1
2022-12-12T15:06:39.371Z,1670857599.371 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 88.405729 min
2022-12-12T15:06:39.371Z,1670857599.371 [Default:CheckIn:E] Stopped
2022-12-12T15:06:39.371Z,1670857599.371 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-12T15:06:39.371Z,1670857599.371 [Default:CheckIn] Stopped
2022-12-12T15:06:39.371Z,1670857599.371 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-12T15:06:39.371Z,1670857599.371 [Default:CheckIn](INFO): Running loop #14
2022-12-12T15:06:39.371Z,1670857599.371 [Default:CheckIn] Running Loop=14
2022-12-12T15:06:39.371Z,1670857599.371 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-12T15:06:39.372Z,1670857599.372 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-12T15:06:41.384Z,1670857601.384 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150640.00,A,3648.16519,N,12147.21737,W,0.039,49.96,121222,,,D*45
2022-12-12T15:06:41.387Z,1670857601.387 [NAL9602](INFO): GPS fix at 20221212T150640: (36.802753, -121.786956)
2022-12-12T15:06:41.398Z,1670857601.398 [Default:CheckIn:Read_GPS] Stopped
2022-12-12T15:06:41.398Z,1670857601.398 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-12T15:06:48.329Z,1670857608.329 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221212T133402/Courier0043.lzma
2022-12-12T15:06:49.332Z,1670857609.332 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Courier0043.lzma.bak
2022-12-12T15:06:49.332Z,1670857609.332 [DataOverHttps](INFO): SBD MOMSN=17392984
2022-12-12T15:06:51.076Z,1670857611.076 [NAL9602](INFO): SBD MO Status=0, MOMSN=10643, MT Status=0, MTMSN=0
2022-12-12T15:06:51.076Z,1670857611.076 [NAL9602](INFO): No messages in MT queue
2022-12-12T15:07:05.029Z,1670857625.029 [DataOverHttps](INFO): Sending 170 bytes from file Logs/20221212T133402/Express0044.lzma
2022-12-12T15:07:06.032Z,1670857626.032 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Express0044.lzma.bak
2022-12-12T15:07:06.032Z,1670857626.032 [DataOverHttps](INFO): SBD MOMSN=17392990
2022-12-12T15:07:07.256Z,1670857627.256 [Default:CheckIn:Read_Iridium] Stopped
2022-12-12T15:07:07.257Z,1670857627.257 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-12T15:07:07.257Z,1670857627.257 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-12T15:07:21.773Z,1670857641.773 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-12T15:12:07.871Z,1670857927.871 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-12T15:12:07.871Z,1670857927.871 [Default:CheckIn:C.Wait] Stopped
2022-12-12T15:12:07.871Z,1670857927.871 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-12T15:12:07.871Z,1670857927.871 [Default:CheckIn:D] Running Loop=1
2022-12-12T15:12:08.286Z,1670857928.286 [Default:CheckIn:D] Stopped
2022-12-12T15:12:08.286Z,1670857928.286 [Default:CheckIn:E] Running Loop=1
2022-12-12T15:12:08.678Z,1670857928.678 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 93.894482 min
2022-12-12T15:12:08.678Z,1670857928.678 [Default:CheckIn:E] Stopped
2022-12-12T15:12:08.678Z,1670857928.678 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-12T15:12:08.678Z,1670857928.678 [Default:CheckIn] Stopped
2022-12-12T15:12:08.679Z,1670857928.679 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-12T15:12:08.679Z,1670857928.679 [Default:CheckIn](INFO): Running loop #15
2022-12-12T15:12:08.679Z,1670857928.679 [Default:CheckIn] Running Loop=15
2022-12-12T15:12:08.679Z,1670857928.679 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-12T15:12:08.679Z,1670857928.679 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-12T15:12:10.690Z,1670857930.690 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151209.00,A,3648.16552,N,12147.21771,W,0.078,22.59,121222,,,D*4B
2022-12-12T15:12:10.692Z,1670857930.692 [NAL9602](INFO): GPS fix at 20221212T151209: (36.802759, -121.786962)
2022-12-12T15:12:10.704Z,1670857930.704 [Default:CheckIn:Read_GPS] Stopped
2022-12-12T15:12:10.704Z,1670857930.704 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-12T15:12:18.005Z,1670857938.005 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221212T133402/Courier0046.lzma
2022-12-12T15:12:19.008Z,1670857939.008 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Courier0046.lzma.bak
2022-12-12T15:12:19.008Z,1670857939.008 [DataOverHttps](INFO): SBD MOMSN=17392999
2022-12-12T15:12:31.296Z,1670857951.296 [NAL9602](INFO): SBD MO Status=0, MOMSN=10644, MT Status=0, MTMSN=0
2022-12-12T15:12:31.296Z,1670857951.296 [NAL9602](INFO): No messages in MT queue
2022-12-12T15:12:34.781Z,1670857954.781 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20221212T133402/Express0047.lzma
2022-12-12T15:12:35.784Z,1670857955.784 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Express0047.lzma.bak
2022-12-12T15:12:35.784Z,1670857955.784 [DataOverHttps](INFO): SBD MOMSN=17393005
2022-12-12T15:12:36.957Z,1670857956.957 [Default:CheckIn:Read_Iridium] Stopped
2022-12-12T15:12:36.957Z,1670857956.957 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-12T15:12:36.957Z,1670857956.957 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-12T15:13:01.994Z,1670857981.994 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-12T15:14:14.785Z,1670858054.785 [CBIT](FAULT): Could not open coulomb counter log file
2022-12-12T15:17:37.572Z,1670858257.572 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-12T15:17:37.573Z,1670858257.573 [Default:CheckIn:C.Wait] Stopped
2022-12-12T15:17:37.573Z,1670858257.573 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-12T15:17:37.573Z,1670858257.573 [Default:CheckIn:D] Running Loop=1
2022-12-12T15:17:37.982Z,1670858257.982 [Default:CheckIn:D] Stopped
2022-12-12T15:17:37.982Z,1670858257.982 [Default:CheckIn:E] Running Loop=1
2022-12-12T15:17:38.394Z,1670858258.394 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 99.389412 min
2022-12-12T15:17:38.395Z,1670858258.395 [Default:CheckIn:E] Stopped
2022-12-12T15:17:38.395Z,1670858258.395 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-12T15:17:38.395Z,1670858258.395 [Default:CheckIn] Stopped
2022-12-12T15:17:38.395Z,1670858258.395 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-12T15:17:38.395Z,1670858258.395 [Default:CheckIn](INFO): Running loop #16
2022-12-12T15:17:38.395Z,1670858258.395 [Default:CheckIn] Running Loop=16
2022-12-12T15:17:38.395Z,1670858258.395 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-12T15:17:38.395Z,1670858258.395 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-12T15:17:40.396Z,1670858260.396 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151739.00,A,3648.16731,N,12147.21672,W,0.078,22.59,121222,,,A*4D
2022-12-12T15:17:40.399Z,1670858260.399 [NAL9602](INFO): GPS fix at 20221212T151739: (36.802788, -121.786945)
2022-12-12T15:17:40.439Z,1670858260.439 [Default:CheckIn:Read_GPS] Stopped
2022-12-12T15:17:40.439Z,1670858260.439 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-12T15:17:50.249Z,1670858270.249 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221212T133402/Courier0049.lzma
2022-12-12T15:17:51.252Z,1670858271.252 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Courier0049.lzma.bak
2022-12-12T15:17:51.252Z,1670858271.252 [DataOverHttps](INFO): SBD MOMSN=17393013
2022-12-12T15:18:06.929Z,1670858286.929 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20221212T133402/Express0050.lzma
2022-12-12T15:18:07.932Z,1670858287.932 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Express0050.lzma.bak
2022-12-12T15:18:07.932Z,1670858287.932 [DataOverHttps](INFO): SBD MOMSN=17393019
2022-12-12T15:18:08.320Z,1670858288.320 [NAL9602](INFO): SBD MO Status=0, MOMSN=10645, MT Status=0, MTMSN=0
2022-12-12T15:18:08.320Z,1670858288.320 [NAL9602](INFO): No messages in MT queue
2022-12-12T15:18:09.141Z,1670858289.141 [Default:CheckIn:Read_Iridium] Stopped
2022-12-12T15:18:09.141Z,1670858289.141 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-12T15:18:09.141Z,1670858289.141 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-12T15:18:39.017Z,1670858319.017 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-12T15:23:09.766Z,1670858589.766 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-12T15:23:09.766Z,1670858589.766 [Default:CheckIn:C.Wait] Stopped
2022-12-12T15:23:09.766Z,1670858589.766 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-12T15:23:09.766Z,1670858589.766 [Default:CheckIn:D] Running Loop=1
2022-12-12T15:23:10.170Z,1670858590.170 [Default:CheckIn:D] Stopped
2022-12-12T15:23:10.170Z,1670858590.170 [Default:CheckIn:E] Running Loop=1
2022-12-12T15:23:10.572Z,1670858590.572 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 104.925879 min
2022-12-12T15:23:10.572Z,1670858590.572 [Default:CheckIn:E] Stopped
2022-12-12T15:23:10.572Z,1670858590.572 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-12T15:23:10.572Z,1670858590.572 [Default:CheckIn] Stopped
2022-12-12T15:23:10.572Z,1670858590.572 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-12T15:23:10.572Z,1670858590.572 [Default:CheckIn](INFO): Running loop #17
2022-12-12T15:23:10.572Z,1670858590.572 [Default:CheckIn] Running Loop=17
2022-12-12T15:23:10.572Z,1670858590.572 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-12T15:23:10.573Z,1670858590.573 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-12T15:23:12.584Z,1670858592.584 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,152311.00,A,3648.49175,N,12147.24233,W,9.778,237.46,121222,,,D*7B
2022-12-12T15:23:12.597Z,1670858592.597 [NAL9602](INFO): GPS fix at 20221212T152311: (36.808196, -121.787372)
2022-12-12T15:23:12.609Z,1670858592.609 [Default:CheckIn:Read_GPS] Stopped
2022-12-12T15:23:12.609Z,1670858592.609 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-12T15:23:19.901Z,1670858599.901 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221212T133402/Courier0052.lzma
2022-12-12T15:23:20.904Z,1670858600.904 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Courier0052.lzma.bak
2022-12-12T15:23:20.904Z,1670858600.904 [DataOverHttps](INFO): SBD MOMSN=17393031
2022-12-12T15:23:26.316Z,1670858606.316 [NAL9602](INFO): SBD MO Status=0, MOMSN=10646, MT Status=0, MTMSN=0
2022-12-12T15:23:26.316Z,1670858606.316 [NAL9602](INFO): No messages in MT queue
2022-12-12T15:23:36.593Z,1670858616.593 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20221212T133402/Express0053.lzma
2022-12-12T15:23:37.596Z,1670858617.596 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Express0053.lzma.bak
2022-12-12T15:23:37.596Z,1670858617.596 [DataOverHttps](INFO): SBD MOMSN=17393037
2022-12-12T15:23:38.861Z,1670858618.861 [Default:CheckIn:Read_Iridium] Stopped
2022-12-12T15:23:38.861Z,1670858618.861 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-12T15:23:38.861Z,1670858618.861 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-12T15:23:57.081Z,1670858637.081 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-12T15:24:14.903Z,1670858654.903 [CBIT](FAULT): Could not open coulomb counter log file
2022-12-12T15:28:39.523Z,1670858919.523 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-12T15:28:39.523Z,1670858919.523 [Default:CheckIn:C.Wait] Stopped
2022-12-12T15:28:39.523Z,1670858919.523 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-12T15:28:39.524Z,1670858919.524 [Default:CheckIn:D] Running Loop=1
2022-12-12T15:28:39.931Z,1670858919.931 [Default:CheckIn:D] Stopped
2022-12-12T15:28:39.931Z,1670858919.931 [Default:CheckIn:E] Running Loop=1
2022-12-12T15:28:40.341Z,1670858920.341 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 110.421891 min
2022-12-12T15:28:40.341Z,1670858920.341 [Default:CheckIn:E] Stopped
2022-12-12T15:28:40.341Z,1670858920.341 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-12T15:28:40.341Z,1670858920.341 [Default:CheckIn] Stopped
2022-12-12T15:28:40.341Z,1670858920.341 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-12T15:28:40.341Z,1670858920.341 [Default:CheckIn](INFO): Running loop #18
2022-12-12T15:28:40.341Z,1670858920.341 [Default:CheckIn] Running Loop=18
2022-12-12T15:28:40.342Z,1670858920.342 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-12T15:28:40.342Z,1670858920.342 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-12T15:28:42.345Z,1670858922.345 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,152841.00,A,3648.19976,N,12148.77153,W,13.374,259.22,121222,,,D*4E
2022-12-12T15:28:42.356Z,1670858922.356 [NAL9602](INFO): GPS fix at 20221212T152841: (36.803329, -121.812859)
2022-12-12T15:28:42.368Z,1670858922.368 [Default:CheckIn:Read_GPS] Stopped
2022-12-12T15:28:42.368Z,1670858922.368 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-12T15:28:49.933Z,1670858929.933 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221212T133402/Courier0055.lzma
2022-12-12T15:28:50.936Z,1670858930.936 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Courier0055.lzma.bak
2022-12-12T15:28:50.936Z,1670858930.936 [DataOverHttps](INFO): SBD MOMSN=17393046
2022-12-12T15:29:06.677Z,1670858946.677 [DataOverHttps](INFO): Sending 184 bytes from file Logs/20221212T133402/Express0056.lzma
2022-12-12T15:29:12.700Z,1670858952.700 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Express0056.lzma.bak
2022-12-12T15:29:12.700Z,1670858952.700 [DataOverHttps](INFO): SBD MOMSN=17393049
2022-12-12T15:29:13.856Z,1670858953.856 [NAL9602](INFO): SBD MO Status=0, MOMSN=10647, MT Status=0, MTMSN=0
2022-12-12T15:29:13.856Z,1670858953.856 [NAL9602](INFO): No messages in MT queue
2022-12-12T15:29:13.868Z,1670858953.868 [Default:CheckIn:Read_Iridium] Stopped
2022-12-12T15:29:13.868Z,1670858953.868 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-12T15:29:13.868Z,1670858953.868 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-12T15:29:44.560Z,1670858984.560 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-12T15:34:14.496Z,1670859254.496 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-12T15:34:14.497Z,1670859254.497 [Default:CheckIn:C.Wait] Stopped
2022-12-12T15:34:14.497Z,1670859254.497 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-12T15:34:14.497Z,1670859254.497 [Default:CheckIn:D] Running Loop=1
2022-12-12T15:34:14.890Z,1670859254.890 [Default:CheckIn:D] Stopped
2022-12-12T15:34:14.890Z,1670859254.890 [Default:CheckIn:E] Running Loop=1
2022-12-12T15:34:14.929Z,1670859254.929 [CBIT](FAULT): Could not open coulomb counter log file
2022-12-12T15:34:15.289Z,1670859255.289 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 116.004541 min
2022-12-12T15:34:15.289Z,1670859255.289 [Default:CheckIn:E] Stopped
2022-12-12T15:34:15.289Z,1670859255.289 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-12T15:34:15.289Z,1670859255.289 [Default:CheckIn] Stopped
2022-12-12T15:34:15.290Z,1670859255.290 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-12T15:34:15.290Z,1670859255.290 [Default:CheckIn](INFO): Running loop #19
2022-12-12T15:34:15.290Z,1670859255.290 [Default:CheckIn] Running Loop=19
2022-12-12T15:34:15.290Z,1670859255.290 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-12T15:34:15.290Z,1670859255.290 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-12T15:34:17.301Z,1670859257.301 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153416.00,A,3647.90975,N,12150.51392,W,13.471,270.37,121222,,,A*46
2022-12-12T15:34:17.304Z,1670859257.304 [NAL9602](INFO): GPS fix at 20221212T153416: (36.798496, -121.841899)
2022-12-12T15:34:17.316Z,1670859257.316 [Default:CheckIn:Read_GPS] Stopped
2022-12-12T15:34:17.316Z,1670859257.316 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-12T15:34:24.437Z,1670859264.437 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221212T133402/Courier0058.lzma
2022-12-12T15:34:25.440Z,1670859265.440 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Courier0058.lzma.bak
2022-12-12T15:34:25.440Z,1670859265.440 [DataOverHttps](INFO): SBD MOMSN=17393063
2022-12-12T15:34:39.116Z,1670859279.116 [NAL9602](INFO): SBD MO Status=2, MOMSN=10648, MT Status=2, MTMSN=0
2022-12-12T15:34:39.116Z,1670859279.116 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-12-12T15:34:42.241Z,1670859282.241 [DataOverHttps](INFO): Sending 181 bytes from file Logs/20221212T133402/Express0059.lzma
2022-12-12T15:34:43.244Z,1670859283.244 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Express0059.lzma.bak
2022-12-12T15:34:43.244Z,1670859283.244 [DataOverHttps](INFO): SBD MOMSN=17393066
2022-12-12T15:34:44.379Z,1670859284.379 [Default:CheckIn:Read_Iridium] Stopped
2022-12-12T15:34:44.379Z,1670859284.379 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-12T15:34:44.379Z,1670859284.379 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-12T15:35:31.236Z,1670859331.236 [NAL9602](INFO): SBD MO Status=2, MOMSN=10648, MT Status=2, MTMSN=0
2022-12-12T15:35:31.236Z,1670859331.236 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-12-12T15:35:50.628Z,1670859350.628 [NAL9602](INFO): SBD MO Status=0, MOMSN=10648, MT Status=0, MTMSN=0
2022-12-12T15:35:50.628Z,1670859350.628 [NAL9602](INFO): No messages in MT queue
2022-12-12T15:36:21.327Z,1670859381.327 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-12T15:36:28.214Z,1670859388.214 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.239395
2022-12-12T15:37:00.362Z,1670859420.362 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-12-12T15:37:35.510Z,1670859455.510 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-12-12T15:38:10.694Z,1670859490.694 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-12-12T15:38:45.862Z,1670859525.862 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-12-12T15:39:21.002Z,1670859561.002 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-12-12T15:39:44.954Z,1670859584.954 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-12T15:39:44.954Z,1670859584.954 [Default:CheckIn:C.Wait] Stopped
2022-12-12T15:39:44.954Z,1670859584.954 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-12T15:39:44.954Z,1670859584.954 [Default:CheckIn:D] Running Loop=1
2022-12-12T15:39:45.362Z,1670859585.362 [Default:CheckIn:D] Stopped
2022-12-12T15:39:45.362Z,1670859585.362 [Default:CheckIn:E] Running Loop=1
2022-12-12T15:39:45.770Z,1670859585.770 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 121.512410 min
2022-12-12T15:39:45.770Z,1670859585.770 [Default:CheckIn:E] Stopped
2022-12-12T15:39:45.770Z,1670859585.770 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-12T15:39:45.770Z,1670859585.770 [Default:CheckIn] Stopped
2022-12-12T15:39:45.770Z,1670859585.770 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-12T15:39:45.770Z,1670859585.770 [Default:CheckIn](INFO): Running loop #20
2022-12-12T15:39:45.770Z,1670859585.770 [Default:CheckIn] Running Loop=20
2022-12-12T15:39:45.770Z,1670859585.770 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-12T15:39:45.770Z,1670859585.770 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-12T15:39:47.777Z,1670859587.777 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153947.00,A,3647.86830,N,12150.78189,W,0.603,61.77,121222,,,A*48
2022-12-12T15:39:47.789Z,1670859587.789 [NAL9602](INFO): GPS fix at 20221212T153947: (36.797805, -121.846365)
2022-12-12T15:39:47.801Z,1670859587.801 [Default:CheckIn:Read_GPS] Stopped
2022-12-12T15:39:47.801Z,1670859587.801 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-12T15:39:56.142Z,1670859596.142 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-12-12T15:40:09.239Z,1670859609.239 [NAL9602](INFO): SBD MO Status=2, MOMSN=10649, MT Status=2, MTMSN=0
2022-12-12T15:40:09.239Z,1670859609.239 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-12-12T15:40:31.282Z,1670859631.282 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-12-12T15:41:06.434Z,1670859666.434 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-12-12T15:41:41.574Z,1670859701.574 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-12-12T15:42:02.962Z,1670859722.962 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003007
2022-12-12T15:42:10.277Z,1670859730.277 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221212T133402/Courier0061.lzma
2022-12-12T15:42:11.280Z,1670859731.280 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Courier0061.lzma.bak
2022-12-12T15:42:11.280Z,1670859731.280 [DataOverHttps](INFO): SBD MOMSN=17393083
2022-12-12T15:42:26.937Z,1670859746.937 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20221212T133402/Express0062.lzma
2022-12-12T15:42:27.940Z,1670859747.940 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Express0062.lzma.bak
2022-12-12T15:42:27.940Z,1670859747.940 [DataOverHttps](INFO): SBD MOMSN=17393086
2022-12-12T15:42:29.038Z,1670859749.038 [Default:CheckIn:Read_Iridium] Stopped
2022-12-12T15:42:29.038Z,1670859749.038 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-12T15:42:29.038Z,1670859749.038 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-12T15:42:34.679Z,1670859754.679 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-12T15:44:15.292Z,1670859855.292 [CBIT](FAULT): Could not open coulomb counter log file
2022-12-12T15:47:29.614Z,1670860049.614 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-12T15:47:29.614Z,1670860049.614 [Default:CheckIn:C.Wait] Stopped
2022-12-12T15:47:29.614Z,1670860049.614 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-12T15:47:29.615Z,1670860049.615 [Default:CheckIn:D] Running Loop=1
2022-12-12T15:47:30.023Z,1670860050.023 [Default:CheckIn:D] Stopped
2022-12-12T15:47:30.024Z,1670860050.024 [Default:CheckIn:E] Running Loop=1
2022-12-12T15:47:30.417Z,1670860050.417 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 129.256771 min
2022-12-12T15:47:30.417Z,1670860050.417 [Default:CheckIn:E] Stopped
2022-12-12T15:47:30.417Z,1670860050.417 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-12T15:47:30.417Z,1670860050.417 [Default:CheckIn] Stopped
2022-12-12T15:47:30.417Z,1670860050.417 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-12T15:47:30.417Z,1670860050.417 [Default:CheckIn](INFO): Running loop #21
2022-12-12T15:47:30.418Z,1670860050.418 [Default:CheckIn] Running Loop=21
2022-12-12T15:47:30.418Z,1670860050.418 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-12T15:47:30.418Z,1670860050.418 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-12T15:47:32.433Z,1670860052.433 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154731.00,A,3647.90969,N,12150.76508,W,0.622,337.17,121222,,,D*79
2022-12-12T15:47:32.435Z,1670860052.435 [NAL9602](INFO): GPS fix at 20221212T154731: (36.798495, -121.846085)
2022-12-12T15:47:32.447Z,1670860052.447 [Default:CheckIn:Read_GPS] Stopped
2022-12-12T15:47:32.447Z,1670860052.447 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-12T15:47:40.089Z,1670860060.089 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221212T133402/Courier0064.lzma
2022-12-12T15:47:41.092Z,1670860061.092 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Courier0064.lzma.bak
2022-12-12T15:47:41.092Z,1670860061.092 [DataOverHttps](INFO): SBD MOMSN=17393102
2022-12-12T15:47:59.925Z,1670860079.925 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20221212T133402/Express0065.lzma
2022-12-12T15:48:00.928Z,1670860080.928 [DataOverHttps](INFO): Moved sent file to Logs/20221212T133402/Express0065.lzma.bak
2022-12-12T15:48:00.928Z,1670860080.928 [DataOverHttps](INFO): SBD MOMSN=17393107
2022-12-12T15:48:01.973Z,1670860081.973 [Default:CheckIn:Read_Iridium] Stopped
2022-12-12T15:48:01.973Z,1670860081.973 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-12T15:48:01.973Z,1670860081.973 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-12T15:49:10.244Z,1670860150.244 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=10649, MT Status=1, MTMSN=358
2022-12-12T15:49:10.244Z,1670860150.244 [NAL9602](INFO): Data available in MT queue
2022-12-12T15:49:10.747Z,1670860150.747 [NAL9602](INFO): Received command: restart logs