2023-04-17T16:28:56.557Z,1681748936.557 [Supervisor](DEBUG): Initializing supervisor.
2023-04-17T16:28:56.562Z,1681748936.562 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-04-17T16:28:56.562Z,1681748936.562 [SyncHandler](INFO): Protected caller Thread ID is 1026
2023-04-17T16:28:56.563Z,1681748936.563 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-04-17T16:28:56.564Z,1681748936.564 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-04-17T16:28:56.564Z,1681748936.564 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1027
2023-04-17T16:28:56.569Z,1681748936.569 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-04-17T16:28:56.586Z,1681748936.586 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-04-17T16:28:56.587Z,1681748936.587 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-04-17T16:28:56.587Z,1681748936.587 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 1028
2023-04-17T16:28:56.591Z,1681748936.591 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-04-17T16:28:56.593Z,1681748936.593 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-04-17T16:28:56.593Z,1681748936.593 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1029
2023-04-17T16:28:56.595Z,1681748936.595 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-04-17T16:28:56.596Z,1681748936.596 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-04-17T16:28:56.596Z,1681748936.596 [logger ThreadHandler](INFO): Protected caller Thread ID is 1030
2023-04-17T16:28:56.600Z,1681748936.600 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-04-17T16:28:56.600Z,1681748936.600 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-04-17T16:28:56.602Z,1681748936.602 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-04-17T16:28:56.861Z,1681748936.861 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-04-17T16:28:56.862Z,1681748936.862 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-04-17T16:28:56.941Z,1681748936.941 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-04-17T16:28:57.394Z,1681748937.394 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-04-17T16:28:57.394Z,1681748937.394 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-04-17T16:28:57.702Z,1681748937.702 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-04-17T16:28:57.702Z,1681748937.702 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-04-17T16:28:57.798Z,1681748937.798 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-04-17T16:28:57.798Z,1681748937.798 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-04-17T16:28:58.172Z,1681748938.172 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-04-17T16:28:58.173Z,1681748938.173 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-04-17T16:28:58.373Z,1681748938.373 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-04-17T16:28:58.374Z,1681748938.374 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-04-17T16:28:58.860Z,1681748938.860 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-04-17T16:28:58.861Z,1681748938.861 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-04-17T16:28:58.994Z,1681748938.994 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-04-17T16:28:58.995Z,1681748938.995 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-04-17T16:28:59.073Z,1681748939.073 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-04-17T16:28:59.897Z,1681748939.897 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-04-17T16:28:59.897Z,1681748939.897 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-04-17T16:29:00.500Z,1681748940.500 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-04-17T16:29:00.501Z,1681748940.501 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-04-17T16:29:00.679Z,1681748940.679 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-04-17T16:29:00.679Z,1681748940.679 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-04-17T16:29:00.788Z,1681748940.788 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-04-17T16:29:00.789Z,1681748940.789 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-04-17T16:29:01.003Z,1681748941.003 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-04-17T16:29:01.004Z,1681748941.004 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-04-17T16:29:01.233Z,1681748941.233 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-04-17T16:29:01.235Z,1681748941.235 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2023-04-17T16:29:01.236Z,1681748941.236 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2023-04-17T16:29:01.325Z,1681748941.325 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2023-04-17T16:29:01.409Z,1681748941.409 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2023-04-17T16:29:01.506Z,1681748941.506 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2023-04-17T16:29:01.588Z,1681748941.588 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2023-04-17T16:29:01.685Z,1681748941.685 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2023-04-17T16:29:01.783Z,1681748941.783 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2023-04-17T16:29:01.955Z,1681748941.955 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2023-04-17T16:29:02.031Z,1681748942.031 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2023-04-17T16:29:02.171Z,1681748942.171 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2023-04-17T16:29:02.302Z,1681748942.302 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2023-04-17T16:29:02.407Z,1681748942.407 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2023-04-17T16:29:02.668Z,1681748942.668 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-04-17T16:29:02.670Z,1681748942.670 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2023-04-17T16:29:02.670Z,1681748942.670 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-04-17T16:29:02.689Z,1681748942.689 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-04-17T16:29:02.739Z,1681748942.739 [VerticalControl](DEBUG): Construct VerticalControl.
2023-04-17T16:29:02.799Z,1681748942.799 [VerticalControl] Loaded
2023-04-17T16:29:02.799Z,1681748942.799 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-04-17T16:29:02.802Z,1681748942.802 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-04-17T16:29:02.843Z,1681748942.843 [HorizontalControl] Loaded
2023-04-17T16:29:02.843Z,1681748942.843 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-04-17T16:29:02.846Z,1681748942.846 [SpeedControl](DEBUG): Construct SpeedControl.
2023-04-17T16:29:02.849Z,1681748942.849 [SpeedControl] Loaded
2023-04-17T16:29:02.849Z,1681748942.849 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-04-17T16:29:02.851Z,1681748942.851 [LoopControl](DEBUG): Construct LoopControl.
2023-04-17T16:29:02.852Z,1681748942.852 [LoopControl] Loaded
2023-04-17T16:29:02.852Z,1681748942.852 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-04-17T16:29:02.853Z,1681748942.853 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-04-17T16:29:02.853Z,1681748942.853 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-04-17T16:29:02.863Z,1681748942.863 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-04-17T16:29:02.864Z,1681748942.864 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-04-17T16:29:03.010Z,1681748943.010 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-04-17T16:29:03.010Z,1681748943.010 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-04-17T16:29:03.164Z,1681748943.164 [BuoyancyServo] Loaded
2023-04-17T16:29:03.164Z,1681748943.164 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-04-17T16:29:03.184Z,1681748943.184 [ElevatorServo] Loaded
2023-04-17T16:29:03.184Z,1681748943.184 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-04-17T16:29:03.203Z,1681748943.203 [MassServo] Loaded
2023-04-17T16:29:03.203Z,1681748943.203 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-04-17T16:29:03.221Z,1681748943.221 [RudderServo] Loaded
2023-04-17T16:29:03.221Z,1681748943.221 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-04-17T16:29:03.238Z,1681748943.238 [ThrusterServo] Loaded
2023-04-17T16:29:03.239Z,1681748943.239 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2023-04-17T16:29:03.239Z,1681748943.239 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-04-17T16:29:03.240Z,1681748943.240 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-04-17T16:29:03.350Z,1681748943.350 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-04-17T16:29:03.350Z,1681748943.350 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-04-17T16:29:03.364Z,1681748943.364 [NavChart] Loaded
2023-04-17T16:29:03.364Z,1681748943.364 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-04-17T16:29:03.370Z,1681748943.370 [UniversalFixResidualReporter] Loaded
2023-04-17T16:29:03.370Z,1681748943.370 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-04-17T16:29:03.371Z,1681748943.371 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-04-17T16:29:03.371Z,1681748943.371 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-04-17T16:29:03.427Z,1681748943.427 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-04-17T16:29:03.428Z,1681748943.428 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-04-17T16:29:03.836Z,1681748943.836 [AHRS_M2] Loaded
2023-04-17T16:29:03.837Z,1681748943.837 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-04-17T16:29:04.642Z,1681748944.642 [BPC1] Loaded
2023-04-17T16:29:04.642Z,1681748944.642 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-04-17T16:29:04.715Z,1681748944.715 [DataOverHttps] Loaded
2023-04-17T16:29:04.715Z,1681748944.715 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-04-17T16:29:04.716Z,1681748944.716 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408FD4E0
2023-04-17T16:29:04.716Z,1681748944.716 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1115
2023-04-17T16:29:04.738Z,1681748944.738 [Depth_Keller] Loaded
2023-04-17T16:29:04.738Z,1681748944.738 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-04-17T16:29:04.743Z,1681748944.743 [DropWeight] Loaded
2023-04-17T16:29:04.743Z,1681748944.743 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2023-04-17T16:29:04.804Z,1681748944.804 [NAL9602] Loaded
2023-04-17T16:29:04.804Z,1681748944.804 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-04-17T16:29:04.834Z,1681748944.834 [Onboard] Loaded
2023-04-17T16:29:04.834Z,1681748944.834 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-04-17T16:29:04.835Z,1681748944.835 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4092D4E0
2023-04-17T16:29:04.835Z,1681748944.835 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1116
2023-04-17T16:29:04.848Z,1681748944.848 [Power24vConverter] Loaded
2023-04-17T16:29:04.849Z,1681748944.849 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-04-17T16:29:04.862Z,1681748944.862 [Radio_Surface] Loaded
2023-04-17T16:29:04.862Z,1681748944.862 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-04-17T16:29:04.863Z,1681748944.863 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4095D4E0
2023-04-17T16:29:04.863Z,1681748944.863 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1117
2023-04-17T16:29:04.864Z,1681748944.864 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-04-17T16:29:04.865Z,1681748944.865 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-04-17T16:29:05.109Z,1681748945.109 [DepthRateCalculator] Loaded
2023-04-17T16:29:05.109Z,1681748945.109 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-04-17T16:29:05.114Z,1681748945.114 [PitchRateCalculator] Loaded
2023-04-17T16:29:05.115Z,1681748945.115 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-04-17T16:29:05.146Z,1681748945.146 [SpeedCalculator] Loaded
2023-04-17T16:29:05.146Z,1681748945.146 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-04-17T16:29:05.170Z,1681748945.170 [VerticalHomogeneityIndexCalculator] Loaded
2023-04-17T16:29:05.170Z,1681748945.170 [ComponentRegistry](DEBUG): SyncComponent "VerticalHomogeneityIndexCalculator" handled in the control thread.
2023-04-17T16:29:05.175Z,1681748945.175 [YawRateCalculator] Loaded
2023-04-17T16:29:05.175Z,1681748945.175 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-04-17T16:29:05.258Z,1681748945.258 [ElevatorOffsetCalculator] Loaded
2023-04-17T16:29:05.258Z,1681748945.258 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-04-17T16:29:05.258Z,1681748945.258 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-04-17T16:29:05.259Z,1681748945.259 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-04-17T16:29:05.461Z,1681748945.461 [CANONSampler] Loaded
2023-04-17T16:29:05.461Z,1681748945.461 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2023-04-17T16:29:05.531Z,1681748945.531 [CTD_Seabird] Loaded
2023-04-17T16:29:05.531Z,1681748945.531 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-04-17T16:29:05.532Z,1681748945.532 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A164E0
2023-04-17T16:29:05.533Z,1681748945.533 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1118
2023-04-17T16:29:05.553Z,1681748945.553 [PAR_Licor] Loaded
2023-04-17T16:29:05.553Z,1681748945.553 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-04-17T16:29:05.583Z,1681748945.583 [WetLabsBB2FL] Loaded
2023-04-17T16:29:05.584Z,1681748945.584 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-04-17T16:29:05.617Z,1681748945.617 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A464E0
2023-04-17T16:29:05.617Z,1681748945.617 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1119
2023-04-17T16:29:05.618Z,1681748945.618 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-04-17T16:29:05.618Z,1681748945.618 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-04-17T16:29:05.688Z,1681748945.688 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-04-17T16:29:05.689Z,1681748945.689 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-04-17T16:29:06.052Z,1681748946.052 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-04-17T16:29:06.053Z,1681748946.053 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-04-17T16:29:06.188Z,1681748946.188 [SBIT](DEBUG): Construct Startup Built In Test.
2023-04-17T16:29:06.197Z,1681748946.197 [SBIT] Loaded
2023-04-17T16:29:06.197Z,1681748946.197 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-04-17T16:29:06.200Z,1681748946.200 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-04-17T16:29:06.213Z,1681748946.213 [IBIT] Loaded
2023-04-17T16:29:06.213Z,1681748946.213 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-04-17T16:29:06.219Z,1681748946.219 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-04-17T16:29:06.324Z,1681748946.324 [CBIT] Loaded
2023-04-17T16:29:06.325Z,1681748946.325 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-04-17T16:29:06.325Z,1681748946.325 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-04-17T16:29:06.326Z,1681748946.326 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-04-17T16:29:06.422Z,1681748946.422 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-04-17T16:29:06.429Z,1681748946.429 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-04-17T16:29:06.431Z,1681748946.431 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-04-17T16:29:06.442Z,1681748946.442 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-04-17T16:29:06.443Z,1681748946.443 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B7E4E0
2023-04-17T16:29:06.444Z,1681748946.444 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1120
2023-04-17T16:29:06.448Z,1681748946.448 [Supervisor](INFO): Main Thread ID is 835
2023-04-17T16:29:06.448Z,1681748946.448 [Supervisor](DEBUG): Running supervisor.
2023-04-17T16:29:06.449Z,1681748946.449 [CommandExec ThreadHandler](INFO): Handler Thread ID is 1121
2023-04-17T16:29:06.450Z,1681748946.450 [CommandExec](INFO): Initializing the command executive.
2023-04-17T16:29:06.451Z,1681748946.451 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1122
2023-04-17T16:29:06.453Z,1681748946.453 [controlThread ThreadHandler](INFO): Handler Thread ID is 1123
2023-04-17T16:29:06.454Z,1681748946.454 [controlThread](DEBUG): Initializing ControlThread
2023-04-17T16:29:06.455Z,1681748946.455 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-04-17T16:29:06.456Z,1681748946.456 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-04-17T16:29:06.457Z,1681748946.457 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-04-17T16:29:06.458Z,1681748946.458 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-04-17T16:29:06.459Z,1681748946.459 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-04-17T16:29:06.460Z,1681748946.460 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-04-17T16:29:06.466Z,1681748946.466 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-04-17T16:29:06.466Z,1681748946.466 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-04-17T16:29:06.466Z,1681748946.466 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-04-17T16:29:06.467Z,1681748946.467 [VerticalHomogeneityIndexCalculator](DEBUG): (re)initializing
2023-04-17T16:29:06.467Z,1681748946.467 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-04-17T16:29:06.468Z,1681748946.468 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-04-17T16:29:06.472Z,1681748946.472 [SBIT](INFO): Initialize SBIT Component.
2023-04-17T16:29:06.473Z,1681748946.473 [SBIT](IMPORTANT): git: 2023-04-14_A
2023-04-17T16:29:06.473Z,1681748946.473 [SBIT](INFO): git hash: a5e7240676c499658609ad29f2edbd696bbbdf6d
2023-04-17T16:29:06.473Z,1681748946.473 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-04-17T16:29:06.474Z,1681748946.474 [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
2023-04-17T16:29:06.476Z,1681748946.476 [SBIT](INFO): Beginning SBIT in 70.000000 seconds.
2023-04-17T16:29:06.476Z,1681748946.476 [IBIT](INFO): Initialize IBIT Component.
2023-04-17T16:29:06.477Z,1681748946.477 [CBIT](DEBUG): Initialize CBIT Component.
2023-04-17T16:29:06.478Z,1681748946.478 [logger ThreadHandler](INFO): Handler Thread ID is 1124
2023-04-17T16:29:06.488Z,1681748946.488 [CBIT](DEBUG): Initialized mux pins.
2023-04-17T16:29:06.488Z,1681748946.488 [CBIT](DEBUG): Initializing the watchdog timer.
2023-04-17T16:29:06.496Z,1681748946.496 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1125
2023-04-17T16:29:06.497Z,1681748946.497 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-04-17T16:29:06.508Z,1681748946.508 [Onboard ThreadHandler](INFO): Handler Thread ID is 1126
2023-04-17T16:29:06.513Z,1681748946.513 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-04-17T16:29:06.513Z,1681748946.513 [CBIT](DEBUG): Initializing heartbeat.
2023-04-17T16:29:06.529Z,1681748946.529 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1127
2023-04-17T16:29:06.544Z,1681748946.544 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1128
2023-04-17T16:29:06.545Z,1681748946.545 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-04-17T16:29:06.550Z,1681748946.550 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1130
2023-04-17T16:29:06.553Z,1681748946.553 [WetLabsBB2FL](INFO): Powering up
2023-04-17T16:29:06.554Z,1681748946.554 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1132
2023-04-17T16:29:06.557Z,1681748946.557 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-04-17T16:29:06.557Z,1681748946.557 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-04-17T16:29:06.557Z,1681748946.557 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-04-17T16:29:06.557Z,1681748946.557 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-04-17T16:29:06.558Z,1681748946.558 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-04-17T16:29:06.558Z,1681748946.558 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-04-17T16:29:06.558Z,1681748946.558 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-04-17T16:29:06.558Z,1681748946.558 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-04-17T16:29:06.584Z,1681748946.584 [CBIT](DEBUG): Deactivating GF circuits.
2023-04-17T16:29:06.584Z,1681748946.584 [CBIT](DEBUG): Deactivating emergency mode.
2023-04-17T16:29:06.624Z,1681748946.624 [CBIT](DEBUG): Backplane powered.
2023-04-17T16:29:06.625Z,1681748946.625 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-04-17T16:29:06.638Z,1681748946.638 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-04-17T16:29:06.665Z,1681748946.665 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2023-04-17T16:29:06.666Z,1681748946.666 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-04-17T16:29:06.747Z,1681748946.747 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-04-17T16:29:06.748Z,1681748946.748 [Default:A.Wait](DEBUG): Construct Wait.
2023-04-17T16:29:06.750Z,1681748946.750 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-04-17T16:29:06.809Z,1681748946.809 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-04-17T16:29:06.811Z,1681748946.811 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-04-17T16:29:06.833Z,1681748946.833 [Default:E.Execute](DEBUG): Construct Execute.
2023-04-17T16:29:06.837Z,1681748946.837 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2023-04-17T16:29:06.850Z,1681748946.850 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,VerticalHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2023-04-17T16:29:06.876Z,1681748946.876 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-04-17T16:29:06.932Z,1681748946.932 [Radio_Surface](INFO): Powering up
2023-04-17T16:29:06.950Z,1681748946.950 [Power24vConverter](INFO): Powering up.
2023-04-17T16:29:06.951Z,1681748946.951 [CANONSampler](INFO): Powering down
2023-04-17T16:29:06.983Z,1681748946.983 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-04-17T16:29:06.988Z,1681748946.988 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-04-17T16:29:06.989Z,1681748946.989 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-04-17T16:29:06.996Z,1681748946.996 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-04-17T16:29:06.997Z,1681748946.997 [MassServo](DEBUG): Initializing EZServoServo.
2023-04-17T16:29:07.008Z,1681748947.008 [MassServo](DEBUG): Initializing MassServo.
2023-04-17T16:29:07.009Z,1681748947.009 [RudderServo](DEBUG): Initializing EZServoServo.
2023-04-17T16:29:07.016Z,1681748947.016 [RudderServo](DEBUG): Initializing RudderServo.
2023-04-17T16:29:07.017Z,1681748947.017 [ThrusterServo](DEBUG): Initializing EZServoServo.
2023-04-17T16:29:07.024Z,1681748947.024 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2023-04-17T16:29:09.164Z,1681748949.164 [WetLabsBB2FL](INFO): Powering down
2023-04-17T16:29:35.142Z,1681748975.142 [NAL9602](INFO): Powering up NAL9602
2023-04-17T16:29:46.054Z,1681748986.054 [NAL9602](INFO): NAL9602 initialized
2023-04-17T16:30:14.328Z,1681749014.328 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:30:17.181Z,1681749017.181 [SBIT](IMPORTANT): Beginning Startup BIT
2023-04-17T16:30:17.185Z,1681749017.185 [CBIT](IMPORTANT): Beginning ground fault scan
2023-04-17T16:30:21.255Z,1681749021.255 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-04-17T16:30:28.087Z,1681749028.087 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2023-04-17T16:30:28.565Z,1681749028.565 [CBIT](IMPORTANT): Beginning ground fault scan
2023-04-17T16:30:31.702Z,1681749031.702 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:30:39.482Z,1681749039.482 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2023-04-17T16:30:39.885Z,1681749039.885 [CBIT](IMPORTANT): Beginning ground fault scan
2023-04-17T16:30:48.261Z,1681749048.261 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:30:50.765Z,1681749050.765 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2023-04-17T16:30:50.765Z,1681749050.765 [CBIT](IMPORTANT): Ground fault scan returned out of bounds value in succession 3 times. Will re-run scan on normal schedule.
2023-04-17T16:31:05.633Z,1681749065.633 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:31:05.634Z,1681749065.634 [BPC1](ERROR): BPC1A: No match for serial number 0000 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file).
2023-04-17T16:31:11.324Z,1681749071.324 [SBIT](IMPORTANT): SBIT PASSED
2023-04-17T16:31:11.325Z,1681749071.325 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-04-17T16:31:11.325Z,1681749071.325 [SBIT](IMPORTANT): AMEcho.loadAtStartup=0 bool;

2023-04-17T16:31:11.326Z,1681749071.326 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=10 count;

2023-04-17T16:31:11.326Z,1681749071.326 [SBIT](IMPORTANT): CANONSampler.loadAtStartup=1 bool;

2023-04-17T16:31:11.326Z,1681749071.326 [SBIT](IMPORTANT): CBIT.runElevOffsetCalc=1 bool;

2023-04-17T16:31:11.326Z,1681749071.326 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;

2023-04-17T16:31:11.326Z,1681749071.326 [SBIT](IMPORTANT): Express linearApproximation VerticalHomogeneityIndexCalculator.vertical_salinity_homogeneity_index 0.050000 practical_salinity_unit;

2023-04-17T16:31:11.326Z,1681749071.326 [SBIT](IMPORTANT): Express linearApproximation VerticalHomogeneityIndexCalculator.vertical_temperature_homogeneity_index 0.050000 celsius;

2023-04-17T16:31:11.326Z,1681749071.326 [SBIT](IMPORTANT): RudderServo.offsetAngle=0 degree;

2023-04-17T16:31:11.326Z,1681749071.326 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.latVertex1=36.81 degree;

2023-04-17T16:31:11.327Z,1681749071.327 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.latVertex2=36.81 degree;

2023-04-17T16:31:11.327Z,1681749071.327 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.latVertex3=36.78 degree;

2023-04-17T16:31:11.327Z,1681749071.327 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.latVertex4=36.78 degree;

2023-04-17T16:31:11.327Z,1681749071.327 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.loadAtStartup=0 bool;

2023-04-17T16:31:11.327Z,1681749071.327 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.lonVertex1=-121.87 degree;

2023-04-17T16:31:11.327Z,1681749071.327 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.lonVertex2=-121.83 degree;

2023-04-17T16:31:11.327Z,1681749071.327 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.lonVertex3=-121.83 degree;

2023-04-17T16:31:11.327Z,1681749071.327 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.lonVertex4=-121.87 degree;

2023-04-17T16:31:11.327Z,1681749071.327 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=264.326605 cubic_centimeter;

2023-04-17T16:31:11.328Z,1681749071.328 [SBIT](IMPORTANT): VerticalControl.massDefault=-12.747315 millimeter;

2023-04-17T16:31:11.328Z,1681749071.328 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth3=20 meter;

2023-04-17T16:31:11.328Z,1681749071.328 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth4=30 meter;

2023-04-17T16:31:11.328Z,1681749071.328 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.loadAtStartup=1 bool;

2023-04-17T16:31:11.719Z,1681749071.719 [MissionManager](IMPORTANT): Started mission Startup
2023-04-17T16:31:11.720Z,1681749071.720 [Startup] Running Loop=1
2023-04-17T16:31:11.720Z,1681749071.720 [Startup](DEBUG): Aggregate::initialize Startup
2023-04-17T16:31:11.720Z,1681749071.720 [Startup:A.GoToSurface] Running Loop=1
2023-04-17T16:31:11.720Z,1681749071.720 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-04-17T16:31:11.721Z,1681749071.721 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-04-17T16:31:11.721Z,1681749071.721 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-04-17T16:31:11.721Z,1681749071.721 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-04-17T16:31:11.722Z,1681749071.722 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-04-17T16:31:11.722Z,1681749071.722 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-04-17T16:31:11.724Z,1681749071.724 [Startup:StartupSatComms] Running Loop=1
2023-04-17T16:31:11.724Z,1681749071.724 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-04-17T16:31:11.724Z,1681749071.724 [Startup:StartupSatComms:A] Running Loop=1
2023-04-17T16:31:12.112Z,1681749072.112 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-04-17T16:31:23.004Z,1681749083.004 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:31:40.038Z,1681749100.038 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:31:49.359Z,1681749109.359 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004903
2023-04-17T16:31:49.726Z,1681749109.726 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-04-17T16:31:57.344Z,1681749117.344 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:32:06.664Z,1681749126.664 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2023-04-17T16:32:06.665Z,1681749126.665 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-17T16:32:06.688Z,1681749126.688 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-17T16:32:07.079Z,1681749127.079 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-17T16:32:07.079Z,1681749127.079 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2023-04-17T16:32:11.908Z,1681749131.908 [Startup:StartupSatComms:A](INFO): Timed out from 2023-04-17T16:31:11.7Z
2023-04-17T16:32:11.908Z,1681749131.908 [Startup:StartupSatComms:A] Stopped
2023-04-17T16:32:11.908Z,1681749131.908 [Startup:StartupSatComms:B] Running Loop=1
2023-04-17T16:32:12.331Z,1681749132.331 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-04-17T16:32:18.956Z,1681749138.956 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20230417T162856/Courier0000.lzma
2023-04-17T16:32:19.958Z,1681749139.958 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Courier0000.lzma.bak
2023-04-17T16:32:19.958Z,1681749139.958 [DataOverHttps](INFO): SBD MOMSN=18231833
2023-04-17T16:32:35.333Z,1681749155.333 [DataOverHttps](INFO): Sending 934 bytes from file Logs/20230417T162856/Express0001.lzma
2023-04-17T16:32:36.334Z,1681749156.334 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Express0001.lzma.bak
2023-04-17T16:32:36.334Z,1681749156.334 [DataOverHttps](INFO): SBD MOMSN=18231836
2023-04-17T16:32:37.365Z,1681749157.365 [Startup:StartupSatComms:B] Stopped
2023-04-17T16:32:37.365Z,1681749157.365 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-04-17T16:32:37.365Z,1681749157.365 [Startup:StartupSatComms] Stopped
2023-04-17T16:32:37.365Z,1681749157.365 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-04-17T16:32:37.366Z,1681749157.366 [Startup](INFO): Completed Startup
2023-04-17T16:32:37.366Z,1681749157.366 [MissionManager](INFO): Startup is completed.
2023-04-17T16:32:37.366Z,1681749157.366 [MissionManager](INFO): Uninitializing Mission Startup
2023-04-17T16:32:37.366Z,1681749157.366 [Startup] Stopped
2023-04-17T16:32:37.367Z,1681749157.367 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-04-17T16:32:37.367Z,1681749157.367 [Startup:A.GoToSurface] Stopped
2023-04-17T16:32:37.367Z,1681749157.367 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-04-17T16:32:37.769Z,1681749157.769 [MissionManager](IMPORTANT): Started mission Default
2023-04-17T16:32:37.769Z,1681749157.769 [Default] Running Loop=1
2023-04-17T16:32:37.769Z,1681749157.769 [Default](DEBUG): Aggregate::initialize Default
2023-04-17T16:32:37.769Z,1681749157.769 [Default:B.GoToSurface] Running Loop=1
2023-04-17T16:32:37.769Z,1681749157.769 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-04-17T16:32:37.770Z,1681749157.770 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-04-17T16:32:37.770Z,1681749157.770 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-04-17T16:32:37.770Z,1681749157.770 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-04-17T16:32:37.771Z,1681749157.771 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-04-17T16:32:37.771Z,1681749157.771 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-04-17T16:32:37.771Z,1681749157.771 [Default:A.Wait] Running Loop=1
2023-04-17T16:32:37.771Z,1681749157.771 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-04-17T16:32:51.108Z,1681749171.108 [Default:A.Wait](INFO): Done Waiting.
2023-04-17T16:32:51.108Z,1681749171.108 [Default:A.Wait] Stopped
2023-04-17T16:32:51.108Z,1681749171.108 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-04-17T16:32:51.522Z,1681749171.522 [Default:CheckIn] Running Loop=1
2023-04-17T16:32:51.522Z,1681749171.522 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-17T16:32:51.522Z,1681749171.522 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-17T16:32:51.915Z,1681749171.915 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-04-17T16:34:49.458Z,1681749289.458 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-04-17T16:35:07.644Z,1681749307.644 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2023-04-17T16:35:07.644Z,1681749307.644 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-17T16:35:07.654Z,1681749307.654 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-17T16:35:08.060Z,1681749308.060 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-17T16:35:08.060Z,1681749308.060 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2023-04-17T16:37:51.702Z,1681749471.702 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-04-17T16:32:51.5Z
2023-04-17T16:37:51.702Z,1681749471.702 [Default:CheckIn:Read_GPS] Stopped
2023-04-17T16:37:51.702Z,1681749471.702 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-17T16:37:52.107Z,1681749472.107 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-04-17T16:37:59.040Z,1681749479.040 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230417T162856/Courier0004.lzma
2023-04-17T16:38:00.042Z,1681749480.042 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Courier0004.lzma.bak
2023-04-17T16:38:00.042Z,1681749480.042 [DataOverHttps](INFO): SBD MOMSN=18231872
2023-04-17T16:38:08.636Z,1681749488.636 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2023-04-17T16:38:08.637Z,1681749488.637 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-17T16:38:08.647Z,1681749488.647 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-17T16:38:09.052Z,1681749489.052 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-17T16:38:09.052Z,1681749489.052 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2023-04-17T16:38:15.395Z,1681749495.395 [DataOverHttps](INFO): Sending 188 bytes from file Logs/20230417T162856/Express0005.lzma
2023-04-17T16:38:16.398Z,1681749496.398 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Express0005.lzma.bak
2023-04-17T16:38:16.398Z,1681749496.398 [DataOverHttps](INFO): SBD MOMSN=18231876
2023-04-17T16:38:17.542Z,1681749497.542 [Default:CheckIn:Read_Iridium] Stopped
2023-04-17T16:38:17.542Z,1681749497.542 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-17T16:38:17.542Z,1681749497.542 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-17T16:39:08.036Z,1681749548.036 [Power24vConverter](INFO): Powering down.
2023-04-17T16:39:11.247Z,1681749551.247 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:39:18.114Z,1681749558.114 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:39:33.057Z,1681749573.057 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:39:48.057Z,1681749588.057 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-04-17T16:39:48.057Z,1681749588.057 [NAL9602] Data Fault, FailCount= 1
2023-04-17T16:39:48.057Z,1681749588.057 [NAL9602](ERROR): Data Fault
2023-04-17T16:39:48.074Z,1681749588.074 [CBIT](ERROR): Data Fault in component: NAL9602
2023-04-17T16:39:48.408Z,1681749588.408 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:39:48.438Z,1681749588.438 [NAL9602](INFO): Powering down
2023-04-17T16:39:49.267Z,1681749589.267 [CBIT](INFO): Clearing failed state for component NAL9602
2023-04-17T16:39:49.267Z,1681749589.267 [NAL9602] No Fault, FailCount= 1
2023-04-17T16:40:03.760Z,1681749603.760 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:40:18.708Z,1681749618.708 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:40:18.744Z,1681749618.744 [NAL9602](INFO): Powering up NAL9602
2023-04-17T16:40:29.622Z,1681749629.622 [NAL9602](INFO): NAL9602 initialized
2023-04-17T16:40:34.885Z,1681749634.885 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:40:49.833Z,1681749649.833 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:41:04.377Z,1681749664.377 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:41:09.645Z,1681749669.645 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2023-04-17T16:41:09.645Z,1681749669.645 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-17T16:41:09.655Z,1681749669.655 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-17T16:41:10.064Z,1681749670.064 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-17T16:41:10.064Z,1681749670.064 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2023-04-17T16:41:19.729Z,1681749679.729 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:43:18.134Z,1681749798.134 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-17T16:43:18.134Z,1681749798.134 [Default:CheckIn:C.Wait] Stopped
2023-04-17T16:43:18.134Z,1681749798.134 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-17T16:43:18.134Z,1681749798.134 [Default:CheckIn:D] Running Loop=1
2023-04-17T16:43:18.518Z,1681749798.518 [Default:CheckIn:D] Stopped
2023-04-17T16:43:18.518Z,1681749798.518 [Default:CheckIn:E] Running Loop=1
2023-04-17T16:43:18.926Z,1681749798.926 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.679150 min 
2023-04-17T16:43:18.926Z,1681749798.926 [Default:CheckIn:E] Stopped
2023-04-17T16:43:18.926Z,1681749798.926 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-17T16:43:18.926Z,1681749798.926 [Default:CheckIn] Stopped
2023-04-17T16:43:18.926Z,1681749798.926 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-17T16:43:18.926Z,1681749798.926 [Default:CheckIn](INFO): Running loop #2
2023-04-17T16:43:18.926Z,1681749798.926 [Default:CheckIn] Running Loop=2
2023-04-17T16:43:18.926Z,1681749798.926 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-17T16:43:18.926Z,1681749798.926 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-17T16:44:10.636Z,1681749850.636 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2023-04-17T16:44:10.636Z,1681749850.636 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-17T16:44:10.673Z,1681749850.673 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-17T16:44:11.049Z,1681749851.049 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-17T16:44:11.050Z,1681749851.050 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2023-04-17T16:45:50.408Z,1681749950.408 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2023-04-17T16:47:11.637Z,1681750031.637 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2023-04-17T16:47:11.637Z,1681750031.637 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-17T16:47:11.647Z,1681750031.647 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-17T16:47:12.061Z,1681750032.061 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-17T16:47:12.061Z,1681750032.061 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2023-04-17T16:48:19.112Z,1681750099.112 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-04-17T16:43:18.9Z
2023-04-17T16:48:19.112Z,1681750099.112 [Default:CheckIn:Read_GPS] Stopped
2023-04-17T16:48:19.112Z,1681750099.112 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-17T16:48:26.063Z,1681750106.063 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230417T162856/Courier0007.lzma
2023-04-17T16:48:27.066Z,1681750107.066 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Courier0007.lzma.bak
2023-04-17T16:48:27.066Z,1681750107.066 [DataOverHttps](INFO): SBD MOMSN=18231885
2023-04-17T16:48:38.882Z,1681750118.882 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:48:42.592Z,1681750122.592 [DataOverHttps](INFO): Sending 181 bytes from file Logs/20230417T162856/Express0008.lzma
2023-04-17T16:48:43.594Z,1681750123.594 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Express0008.lzma.bak
2023-04-17T16:48:43.594Z,1681750123.594 [DataOverHttps](INFO): SBD MOMSN=18231887
2023-04-17T16:48:44.986Z,1681750124.986 [Default:CheckIn:Read_Iridium] Stopped
2023-04-17T16:48:44.986Z,1681750124.986 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-17T16:48:44.986Z,1681750124.986 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-17T16:48:45.341Z,1681750125.341 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:49:00.289Z,1681750140.289 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:49:15.640Z,1681750155.640 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:49:30.588Z,1681750170.588 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:49:45.537Z,1681750185.537 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:50:00.889Z,1681750200.889 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:50:12.668Z,1681750212.668 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2023-04-17T16:50:12.668Z,1681750212.668 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-17T16:50:12.679Z,1681750212.679 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-17T16:50:13.055Z,1681750213.055 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-17T16:50:13.055Z,1681750213.055 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2023-04-17T16:50:15.837Z,1681750215.837 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:50:31.188Z,1681750231.188 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:50:31.610Z,1681750231.610 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-04-17T16:50:31.610Z,1681750231.610 [NAL9602] Data Fault, FailCount= 2
2023-04-17T16:50:31.610Z,1681750231.610 [NAL9602](ERROR): Data Fault
2023-04-17T16:50:31.628Z,1681750231.628 [CBIT](ERROR): Data Fault in component: NAL9602
2023-04-17T16:50:32.017Z,1681750232.017 [NAL9602](INFO): Powering down
2023-04-17T16:50:32.853Z,1681750232.853 [CBIT](INFO): Clearing failed state for component NAL9602
2023-04-17T16:50:32.854Z,1681750232.854 [NAL9602] No Fault, FailCount= 2
2023-04-17T16:50:46.142Z,1681750246.142 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:50:53.097Z,1681750253.097 [DataOverHttps](IMPORTANT): SBD MTMSN=20230417T165052
2023-04-17T16:51:00.408Z,1681750260.408 [DataOverHttps](INFO): Received command: strobe off
2023-04-17T16:51:00.413Z,1681750260.413 [CommandExec](IMPORTANT): got command strobe off
2023-04-17T16:51:00.413Z,1681750260.413 [CommandExec](IMPORTANT): Deactivating strobe
2023-04-17T16:51:02.309Z,1681750262.309 [NAL9602](INFO): Powering up NAL9602
2023-04-17T16:51:13.222Z,1681750273.222 [NAL9602](INFO): NAL9602 initialized
2023-04-17T16:51:44.849Z,1681750304.849 [CommandExec](IMPORTANT): got command strobe off
2023-04-17T16:51:44.849Z,1681750304.849 [CommandExec](IMPORTANT): Deactivating strobe
2023-04-17T16:53:13.638Z,1681750393.638 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2023-04-17T16:53:13.638Z,1681750393.638 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-17T16:53:13.674Z,1681750393.674 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-17T16:53:14.051Z,1681750394.051 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-17T16:53:14.051Z,1681750394.051 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2023-04-17T16:53:45.534Z,1681750425.534 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-17T16:53:45.534Z,1681750425.534 [Default:CheckIn:C.Wait] Stopped
2023-04-17T16:53:45.534Z,1681750425.534 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-17T16:53:45.535Z,1681750425.535 [Default:CheckIn:D] Running Loop=1
2023-04-17T16:53:45.947Z,1681750425.947 [Default:CheckIn:D] Stopped
2023-04-17T16:53:45.947Z,1681750425.947 [Default:CheckIn:E] Running Loop=1
2023-04-17T16:53:46.363Z,1681750426.363 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.136300 min 
2023-04-17T16:53:46.363Z,1681750426.363 [Default:CheckIn:E] Stopped
2023-04-17T16:53:46.363Z,1681750426.363 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-17T16:53:46.363Z,1681750426.363 [Default:CheckIn] Stopped
2023-04-17T16:53:46.363Z,1681750426.363 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-17T16:53:46.363Z,1681750426.363 [Default:CheckIn](INFO): Running loop #3
2023-04-17T16:53:46.363Z,1681750426.363 [Default:CheckIn] Running Loop=3
2023-04-17T16:53:46.363Z,1681750426.363 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-17T16:53:46.364Z,1681750426.364 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-17T16:55:18.312Z,1681750518.312 [CommandExec](IMPORTANT): got command failComponent
2023-04-17T16:55:18.313Z,1681750518.313 [CommandExec](IMPORTANT): Failed components:
2023-04-17T16:55:18.313Z,1681750518.313 [CommandExec](IMPORTANT): No failed Components.
2023-04-17T16:56:14.666Z,1681750574.666 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2023-04-17T16:56:14.666Z,1681750574.666 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-17T16:56:14.700Z,1681750574.700 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-17T16:56:15.068Z,1681750575.068 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-17T16:56:15.068Z,1681750575.068 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2023-04-17T16:57:04.997Z,1681750624.997 [DataOverHttps](IMPORTANT): SBD MTMSN=20230417T165703
2023-04-17T16:57:12.127Z,1681750632.127 [DataOverHttps](INFO): Received command: burn on
2023-04-17T16:57:12.129Z,1681750632.129 [CommandExec](IMPORTANT): got command burn on
2023-04-17T16:57:12.129Z,1681750632.129 [CommandExec](IMPORTANT): Activating dropweight wire
2023-04-17T16:57:43.393Z,1681750663.393 [DataOverHttps](IMPORTANT): SBD MTMSN=20230417T165742
2023-04-17T16:57:43.914Z,1681750663.914 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file).
2023-04-17T16:57:50.520Z,1681750670.520 [DataOverHttps](INFO): Received command: burn off
2023-04-17T16:57:50.541Z,1681750670.541 [CommandExec](IMPORTANT): got command burn off
2023-04-17T16:57:50.541Z,1681750670.541 [CommandExec](IMPORTANT): Deactivating dropweight wire
2023-04-17T16:58:12.194Z,1681750692.194 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:58:27.547Z,1681750707.547 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:58:43.701Z,1681750723.701 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:58:46.551Z,1681750726.551 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-04-17T16:53:46.4Z
2023-04-17T16:58:46.551Z,1681750726.551 [Default:CheckIn:Read_GPS] Stopped
2023-04-17T16:58:46.551Z,1681750726.551 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-17T16:58:50.562Z,1681750730.562 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230417T162856/Courier0010.lzma
2023-04-17T16:58:51.330Z,1681750731.330 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Courier0010.lzma.bak
2023-04-17T16:58:51.330Z,1681750731.330 [DataOverHttps](INFO): SBD MOMSN=18231897
2023-04-17T16:58:58.729Z,1681750738.729 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:59:05.604Z,1681750745.604 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-04-17T16:59:06.787Z,1681750746.787 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230417T162856/Courier0013.lzma
2023-04-17T16:59:07.790Z,1681750747.790 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Courier0013.lzma.bak
2023-04-17T16:59:07.790Z,1681750747.790 [DataOverHttps](INFO): SBD MOMSN=18231899
2023-04-17T16:59:14.082Z,1681750754.082 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:59:15.724Z,1681750755.724 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2023-04-17T16:59:15.724Z,1681750755.724 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-17T16:59:15.735Z,1681750755.735 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-17T16:59:16.140Z,1681750756.140 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-17T16:59:16.140Z,1681750756.140 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2023-04-17T16:59:29.842Z,1681750769.842 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:59:45.592Z,1681750785.592 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T16:59:54.636Z,1681750794.636 [DataOverHttps](INFO): Sending 382 bytes from file Logs/20230417T162856/Express0011.lzma
2023-04-17T16:59:55.638Z,1681750795.638 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Express0011.lzma.bak
2023-04-17T16:59:55.638Z,1681750795.638 [DataOverHttps](INFO): SBD MOMSN=18231901
2023-04-17T17:00:00.945Z,1681750800.945 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T17:00:07.409Z,1681750807.409 [BPC1](INFO): Calculating totals. Valid battery stick count: 45. Valid reserve battery stick count: 5.
2023-04-17T17:00:07.425Z,1681750807.425 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle.
2023-04-17T17:00:11.127Z,1681750811.127 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230417T162856/Express0014.lzma
2023-04-17T17:00:12.130Z,1681750812.130 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Express0014.lzma.bak
2023-04-17T17:00:12.130Z,1681750812.130 [DataOverHttps](INFO): SBD MOMSN=18231919
2023-04-17T17:00:13.486Z,1681750813.486 [Default:CheckIn:Read_Iridium] Stopped
2023-04-17T17:00:13.486Z,1681750813.486 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-17T17:00:13.486Z,1681750813.486 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-17T17:01:14.921Z,1681750874.921 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-04-17T17:01:14.922Z,1681750874.921 [NAL9602] Data Fault, FailCount= 3
2023-04-17T17:01:14.922Z,1681750874.922 [NAL9602](ERROR): Data Fault
2023-04-17T17:01:14.967Z,1681750874.967 [CBIT](ERROR): Data Fault in component: NAL9602
2023-04-17T17:01:15.321Z,1681750875.321 [NAL9602](INFO): Powering down
2023-04-17T17:01:16.208Z,1681750876.208 [CBIT](INFO): Clearing failed state for component NAL9602
2023-04-17T17:01:16.208Z,1681750876.208 [NAL9602] No Fault, FailCount= 3
2023-04-17T17:01:45.626Z,1681750905.626 [NAL9602](INFO): Powering up NAL9602
2023-04-17T17:01:56.535Z,1681750916.535 [NAL9602](INFO): NAL9602 initialized
2023-04-17T17:02:16.768Z,1681750936.768 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2023-04-17T17:02:16.768Z,1681750936.768 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-17T17:02:16.818Z,1681750936.818 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-17T17:02:17.210Z,1681750937.210 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-17T17:02:17.210Z,1681750937.210 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2023-04-17T17:05:14.270Z,1681751114.270 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-17T17:05:14.270Z,1681751114.270 [Default:CheckIn:C.Wait] Stopped
2023-04-17T17:05:14.270Z,1681751114.270 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-17T17:05:14.270Z,1681751114.270 [Default:CheckIn:D] Running Loop=1
2023-04-17T17:05:14.678Z,1681751114.678 [Default:CheckIn:D] Stopped
2023-04-17T17:05:14.678Z,1681751114.678 [Default:CheckIn:E] Running Loop=1
2023-04-17T17:05:15.070Z,1681751115.070 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.615139 min 
2023-04-17T17:05:15.070Z,1681751115.070 [Default:CheckIn:E] Stopped
2023-04-17T17:05:15.070Z,1681751115.070 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-17T17:05:15.070Z,1681751115.070 [Default:CheckIn] Stopped
2023-04-17T17:05:15.070Z,1681751115.070 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-17T17:05:15.071Z,1681751115.071 [Default:CheckIn](INFO): Running loop #4
2023-04-17T17:05:15.071Z,1681751115.071 [Default:CheckIn] Running Loop=4
2023-04-17T17:05:15.071Z,1681751115.071 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-17T17:05:15.071Z,1681751115.071 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-17T17:05:17.901Z,1681751117.901 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12
2023-04-17T17:05:17.901Z,1681751117.901 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-17T17:05:17.911Z,1681751117.911 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-17T17:05:18.331Z,1681751118.331 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-17T17:05:18.331Z,1681751118.331 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12
2023-04-17T17:08:18.988Z,1681751298.988 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13
2023-04-17T17:08:18.988Z,1681751298.988 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-17T17:08:19.018Z,1681751299.018 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-17T17:08:19.414Z,1681751299.414 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-17T17:08:19.414Z,1681751299.414 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13
2023-04-17T17:10:15.403Z,1681751415.403 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-04-17T17:05:15.1Z
2023-04-17T17:10:15.403Z,1681751415.403 [Default:CheckIn:Read_GPS] Stopped
2023-04-17T17:10:15.403Z,1681751415.403 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-17T17:10:24.852Z,1681751424.852 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20230417T162856/Courier0016.lzma
2023-04-17T17:10:25.854Z,1681751425.854 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Courier0016.lzma.bak
2023-04-17T17:10:25.854Z,1681751425.854 [DataOverHttps](INFO): SBD MOMSN=18231928
2023-04-17T17:10:41.111Z,1681751441.111 [DataOverHttps](INFO): Sending 149 bytes from file Logs/20230417T162856/Express0017.lzma
2023-04-17T17:10:42.114Z,1681751442.114 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Express0017.lzma.bak
2023-04-17T17:10:42.114Z,1681751442.114 [DataOverHttps](INFO): SBD MOMSN=18231930
2023-04-17T17:10:43.329Z,1681751443.329 [Default:CheckIn:Read_Iridium] Stopped
2023-04-17T17:10:43.329Z,1681751443.329 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-17T17:10:43.329Z,1681751443.329 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-17T17:11:20.115Z,1681751480.115 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 14
2023-04-17T17:11:20.115Z,1681751480.115 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-17T17:11:20.125Z,1681751480.125 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-17T17:11:20.538Z,1681751480.538 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-17T17:11:20.538Z,1681751480.538 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 14
2023-04-17T17:11:58.474Z,1681751518.474 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-04-17T17:11:58.474Z,1681751518.474 [NAL9602] Data Fault, FailCount= 4
2023-04-17T17:11:58.474Z,1681751518.474 [NAL9602](ERROR): Data Fault
2023-04-17T17:11:58.516Z,1681751518.516 [CBIT](ERROR): Data Fault in component: NAL9602
2023-04-17T17:11:58.892Z,1681751518.892 [NAL9602](INFO): Powering down
2023-04-17T17:11:59.701Z,1681751519.701 [CBIT](INFO): Clearing failed state for component NAL9602
2023-04-17T17:11:59.701Z,1681751519.701 [NAL9602] No Fault, FailCount= 4
2023-04-17T17:12:29.185Z,1681751549.185 [NAL9602](INFO): Powering up NAL9602
2023-04-17T17:12:40.088Z,1681751560.088 [NAL9602](INFO): NAL9602 initialized
2023-04-17T17:14:21.185Z,1681751661.185 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 15
2023-04-17T17:14:21.185Z,1681751661.185 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-17T17:14:21.249Z,1681751661.249 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-17T17:14:21.647Z,1681751661.647 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-17T17:14:21.647Z,1681751661.647 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 15
2023-04-17T17:15:44.074Z,1681751744.074 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-17T17:15:44.074Z,1681751744.074 [Default:CheckIn:C.Wait] Stopped
2023-04-17T17:15:44.074Z,1681751744.074 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-17T17:15:44.074Z,1681751744.074 [Default:CheckIn:D] Running Loop=1
2023-04-17T17:15:44.467Z,1681751744.467 [Default:CheckIn:D] Stopped
2023-04-17T17:15:44.467Z,1681751744.467 [Default:CheckIn:E] Running Loop=1
2023-04-17T17:15:44.867Z,1681751744.867 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.111621 min 
2023-04-17T17:15:44.867Z,1681751744.867 [Default:CheckIn:E] Stopped
2023-04-17T17:15:44.867Z,1681751744.867 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-17T17:15:44.867Z,1681751744.867 [Default:CheckIn] Stopped
2023-04-17T17:15:44.867Z,1681751744.867 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-17T17:15:44.867Z,1681751744.867 [Default:CheckIn](INFO): Running loop #5
2023-04-17T17:15:44.867Z,1681751744.867 [Default:CheckIn] Running Loop=5
2023-04-17T17:15:44.867Z,1681751744.867 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-17T17:15:44.868Z,1681751744.868 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-17T17:16:28.932Z,1681751788.932 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171627.00,A,3648.16278,N,12147.28139,W,0.428,213.75,170423,,,D*71
2023-04-17T17:16:28.969Z,1681751788.969 [NAL9602](INFO): GPS fix at 20230417T171627: (36.802713, -121.788023)
2023-04-17T17:16:29.007Z,1681751789.007 [Default:CheckIn:Read_GPS] Stopped
2023-04-17T17:16:29.007Z,1681751789.007 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-17T17:16:37.556Z,1681751797.556 [DataOverHttps](INFO): Sending 221 bytes from file Logs/20230417T162856/Courier0019.lzma
2023-04-17T17:16:38.558Z,1681751798.558 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Courier0019.lzma.bak
2023-04-17T17:16:38.558Z,1681751798.558 [DataOverHttps](INFO): SBD MOMSN=18231938
2023-04-17T17:16:57.812Z,1681751817.812 [DataOverHttps](INFO): Sending 286 bytes from file Logs/20230417T162856/Express0020.lzma
2023-04-17T17:16:58.814Z,1681751818.814 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Express0020.lzma.bak
2023-04-17T17:16:58.814Z,1681751818.814 [DataOverHttps](INFO): SBD MOMSN=18231941
2023-04-17T17:17:00.102Z,1681751820.102 [Default:CheckIn:Read_Iridium] Stopped
2023-04-17T17:17:00.102Z,1681751820.102 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-17T17:17:00.102Z,1681751820.102 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-17T17:17:01.303Z,1681751821.303 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-17T17:22:00.689Z,1681752120.689 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-17T17:22:00.690Z,1681752120.690 [Default:CheckIn:C.Wait] Stopped
2023-04-17T17:22:00.690Z,1681752120.690 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-17T17:22:00.690Z,1681752120.690 [Default:CheckIn:D] Running Loop=1
2023-04-17T17:22:01.087Z,1681752121.087 [Default:CheckIn:D] Stopped
2023-04-17T17:22:01.087Z,1681752121.087 [Default:CheckIn:E] Running Loop=1
2023-04-17T17:22:01.491Z,1681752121.491 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 49.388623 min 
2023-04-17T17:22:01.491Z,1681752121.491 [Default:CheckIn:E] Stopped
2023-04-17T17:22:01.491Z,1681752121.491 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-17T17:22:01.491Z,1681752121.491 [Default:CheckIn] Stopped
2023-04-17T17:22:01.491Z,1681752121.491 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-17T17:22:01.491Z,1681752121.491 [Default:CheckIn](INFO): Running loop #6
2023-04-17T17:22:01.492Z,1681752121.492 [Default:CheckIn] Running Loop=6
2023-04-17T17:22:01.492Z,1681752121.492 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-17T17:22:01.492Z,1681752121.492 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-17T17:22:03.503Z,1681752123.503 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172201.00,A,3648.16082,N,12147.28225,W,0.700,213.98,170423,,,D*71
2023-04-17T17:22:03.505Z,1681752123.505 [NAL9602](INFO): GPS fix at 20230417T172201: (36.802680, -121.788038)
2023-04-17T17:22:03.515Z,1681752123.515 [Default:CheckIn:Read_GPS] Stopped
2023-04-17T17:22:03.515Z,1681752123.515 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-17T17:22:10.887Z,1681752130.887 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230417T162856/Courier0022.lzma
2023-04-17T17:22:11.890Z,1681752131.890 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Courier0022.lzma.bak
2023-04-17T17:22:11.890Z,1681752131.890 [DataOverHttps](INFO): SBD MOMSN=18231945
2023-04-17T17:22:30.755Z,1681752150.755 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230417T162856/Express0023.lzma
2023-04-17T17:22:31.758Z,1681752151.758 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Express0023.lzma.bak
2023-04-17T17:22:31.758Z,1681752151.758 [DataOverHttps](INFO): SBD MOMSN=18231948
2023-04-17T17:22:33.038Z,1681752153.038 [Default:CheckIn:Read_Iridium] Stopped
2023-04-17T17:22:33.038Z,1681752153.038 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-17T17:22:33.038Z,1681752153.038 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-17T17:27:05.339Z,1681752425.339 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-04-17T17:27:33.623Z,1681752453.623 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-17T17:27:33.623Z,1681752453.623 [Default:CheckIn:C.Wait] Stopped
2023-04-17T17:27:33.623Z,1681752453.623 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-17T17:27:33.623Z,1681752453.623 [Default:CheckIn:D] Running Loop=1
2023-04-17T17:27:34.027Z,1681752454.027 [Default:CheckIn:D] Stopped
2023-04-17T17:27:34.027Z,1681752454.027 [Default:CheckIn:E] Running Loop=1
2023-04-17T17:27:34.444Z,1681752454.444 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 54.937634 min 
2023-04-17T17:27:34.444Z,1681752454.444 [Default:CheckIn:E] Stopped
2023-04-17T17:27:34.444Z,1681752454.444 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-17T17:27:34.444Z,1681752454.444 [Default:CheckIn] Stopped
2023-04-17T17:27:34.444Z,1681752454.444 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-17T17:27:34.444Z,1681752454.444 [Default:CheckIn](INFO): Running loop #7
2023-04-17T17:27:34.444Z,1681752454.444 [Default:CheckIn] Running Loop=7
2023-04-17T17:27:34.444Z,1681752454.444 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-17T17:27:34.445Z,1681752454.445 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-17T17:27:36.451Z,1681752456.451 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172735.00,A,3648.16449,N,12147.28062,W,0.272,296.26,170423,,,D*79
2023-04-17T17:27:36.453Z,1681752456.453 [NAL9602](INFO): GPS fix at 20230417T172735: (36.802742, -121.788010)
2023-04-17T17:27:36.464Z,1681752456.464 [Default:CheckIn:Read_GPS] Stopped
2023-04-17T17:27:36.464Z,1681752456.464 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-17T17:27:44.003Z,1681752464.003 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230417T162856/Courier0025.lzma
2023-04-17T17:27:45.006Z,1681752465.006 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Courier0025.lzma.bak
2023-04-17T17:27:45.006Z,1681752465.006 [DataOverHttps](INFO): SBD MOMSN=18231956
2023-04-17T17:28:00.708Z,1681752480.708 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20230417T162856/Express0026.lzma
2023-04-17T17:28:01.710Z,1681752481.710 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Express0026.lzma.bak
2023-04-17T17:28:01.710Z,1681752481.710 [DataOverHttps](INFO): SBD MOMSN=18231960
2023-04-17T17:28:02.721Z,1681752482.721 [Default:CheckIn:Read_Iridium] Stopped
2023-04-17T17:28:02.722Z,1681752482.722 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-17T17:28:02.722Z,1681752482.722 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-17T17:28:08.361Z,1681752488.361 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-17T17:30:42.202Z,1681752642.202 [DataOverHttps](IMPORTANT): SBD MTMSN=20230417T173041
2023-04-17T17:30:50.388Z,1681752650.388 [DataOverHttps](INFO): Received command: strobe on; ibit
2023-04-17T17:30:50.402Z,1681752650.402 [CommandExec](IMPORTANT): got command strobe on
2023-04-17T17:30:50.402Z,1681752650.402 [CommandExec](IMPORTANT): Activating strobe
2023-04-17T17:30:50.402Z,1681752650.402 [CommandExec](IMPORTANT): got command ibit
2023-04-17T17:30:50.483Z,1681752650.483 [IBIT](IMPORTANT): Beginning Initiated BIT
2023-04-17T17:30:50.483Z,1681752650.483 [IBIT](IMPORTANT): Beginning control surface checks.
2023-04-17T17:30:50.499Z,1681752650.499 [CBIT](IMPORTANT): Beginning ground fault scan
2023-04-17T17:30:51.998Z,1681752651.998 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173051.00,A,3648.17176,N,12147.28013,W,0.039,296.26,170423,,,A*7B
2023-04-17T17:30:52.000Z,1681752652.000 [NAL9602](INFO): GPS fix at 20230417T173051: (36.802863, -121.788002)
2023-04-17T17:30:53.320Z,1681752653.320 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2023-04-17T17:31:01.315Z,1681752661.315 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.002712
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): -0.002412
CHAN A3 (5V): -0.001501
CHAN B0 (3.3V): 0.000085
CHAN B1 (3.15aV): -0.000355
CHAN B2 (3.15bV): -0.000373
CHAN B3 (GND): -0.000126
OPEN: -0.000382
Full Scale: +/- 1 mA
2023-04-17T17:31:22.705Z,1681752682.705 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-04-17T17:31:22.788Z,1681752682.788 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-04-17T17:31:36.473Z,1681752696.473 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 4
Latitude: 36.802864 Longitude: -121.788002
2023-04-17T17:31:36.860Z,1681752696.860 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.650999
2023-04-17T17:31:36.860Z,1681752696.860 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2023-04-17T17:31:36.861Z,1681752696.861 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2023-04-17T17:31:37.267Z,1681752697.267 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2023-04-17T17:31:37.267Z,1681752697.267 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2023-04-17T17:31:37.267Z,1681752697.267 [IBIT](IMPORTANT): Pressure:9.852732 PSI
2023-04-17T17:31:37.268Z,1681752697.268 [IBIT](IMPORTANT): Humidity:1.428397 %
2023-04-17T17:31:37.682Z,1681752697.682 [IBIT](IMPORTANT): Vehicle Pitch:-1.096906 degrees
2023-04-17T17:31:37.682Z,1681752697.682 [IBIT](IMPORTANT): Vehicle  Roll:-1.981228 degrees
2023-04-17T17:31:37.682Z,1681752697.682 [IBIT](IMPORTANT): Vehicle  Heading:21.293453 degrees
2023-04-17T17:31:38.073Z,1681752698.073 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2023-04-17T17:31:38.073Z,1681752698.073 [IBIT](IMPORTANT): buoyancyNeutral: 264.326599 cc
2023-04-17T17:31:38.073Z,1681752698.073 [IBIT](IMPORTANT): massDefault: -1.274732 cm
2023-04-17T17:31:38.074Z,1681752698.074 [IBIT](IMPORTANT): stopDepth: 250.000000 m
2023-04-17T17:31:38.074Z,1681752698.074 [IBIT](IMPORTANT): abortDepth: 270.000000 m
2023-04-17T17:31:38.074Z,1681752698.074 [IBIT](IMPORTANT): IBIT PASSED
2023-04-17T17:31:50.981Z,1681752710.981 [NAL9602](INFO): SBD MO Status=0, MOMSN=40866, MT Status=0, MTMSN=0
2023-04-17T17:31:50.981Z,1681752710.981 [NAL9602](INFO): No messages in MT queue
2023-04-17T17:32:21.745Z,1681752741.745 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-17T17:33:03.414Z,1681752783.414 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-17T17:33:03.415Z,1681752783.415 [Default:CheckIn:C.Wait] Stopped
2023-04-17T17:33:03.415Z,1681752783.415 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-17T17:33:03.415Z,1681752783.415 [Default:CheckIn:D] Running Loop=1
2023-04-17T17:33:03.814Z,1681752783.814 [Default:CheckIn:D] Stopped
2023-04-17T17:33:03.814Z,1681752783.814 [Default:CheckIn:E] Running Loop=1
2023-04-17T17:33:04.221Z,1681752784.221 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 60.434086 min 
2023-04-17T17:33:04.221Z,1681752784.221 [Default:CheckIn:E] Stopped
2023-04-17T17:33:04.221Z,1681752784.221 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-17T17:33:04.221Z,1681752784.221 [Default:CheckIn] Stopped
2023-04-17T17:33:04.221Z,1681752784.221 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-17T17:33:04.222Z,1681752784.222 [Default:CheckIn](INFO): Running loop #8
2023-04-17T17:33:04.222Z,1681752784.222 [Default:CheckIn] Running Loop=8
2023-04-17T17:33:04.222Z,1681752784.222 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-17T17:33:04.222Z,1681752784.222 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-17T17:33:06.230Z,1681752786.230 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173305.00,A,3648.17755,N,12147.28391,W,0.136,296.26,170423,,,A*79
2023-04-17T17:33:06.232Z,1681752786.232 [NAL9602](INFO): GPS fix at 20230417T173305: (36.802959, -121.788065)
2023-04-17T17:33:06.263Z,1681752786.263 [Default:CheckIn:Read_GPS] Stopped
2023-04-17T17:33:06.263Z,1681752786.263 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-17T17:33:13.103Z,1681752793.103 [NAL9602](INFO): SBD MO Status=0, MOMSN=40867, MT Status=0, MTMSN=0
2023-04-17T17:33:13.103Z,1681752793.103 [NAL9602](INFO): No messages in MT queue
2023-04-17T17:33:13.807Z,1681752793.807 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230417T162856/Courier0028.lzma
2023-04-17T17:33:14.811Z,1681752794.811 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Courier0028.lzma.bak
2023-04-17T17:33:14.811Z,1681752794.811 [DataOverHttps](INFO): SBD MOMSN=18231980
2023-04-17T17:33:30.513Z,1681752810.513 [DataOverHttps](INFO): Sending 822 bytes from file Logs/20230417T162856/Express0029.lzma
2023-04-17T17:33:31.514Z,1681752811.514 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Express0029.lzma.bak
2023-04-17T17:33:31.514Z,1681752811.514 [DataOverHttps](INFO): SBD MOMSN=18231983
2023-04-17T17:33:43.809Z,1681752823.809 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-17T17:33:47.303Z,1681752827.303 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20230417T162856/Express0032.lzma
2023-04-17T17:33:48.306Z,1681752828.306 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Express0032.lzma.bak
2023-04-17T17:33:48.306Z,1681752828.306 [DataOverHttps](INFO): SBD MOMSN=18232011
2023-04-17T17:33:49.474Z,1681752829.474 [Default:CheckIn:Read_Iridium] Stopped
2023-04-17T17:33:49.474Z,1681752829.474 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-17T17:33:49.475Z,1681752829.475 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-17T17:38:50.257Z,1681753130.257 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-17T17:38:50.257Z,1681753130.257 [Default:CheckIn:C.Wait] Stopped
2023-04-17T17:38:50.257Z,1681753130.257 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-17T17:38:50.257Z,1681753130.257 [Default:CheckIn:D] Running Loop=1
2023-04-17T17:38:50.667Z,1681753130.667 [Default:CheckIn:D] Stopped
2023-04-17T17:38:50.667Z,1681753130.667 [Default:CheckIn:E] Running Loop=1
2023-04-17T17:38:51.082Z,1681753131.082 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 66.214970 min 
2023-04-17T17:38:51.083Z,1681753131.083 [Default:CheckIn:E] Stopped
2023-04-17T17:38:51.083Z,1681753131.083 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-17T17:38:51.083Z,1681753131.083 [Default:CheckIn] Stopped
2023-04-17T17:38:51.083Z,1681753131.083 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-17T17:38:51.083Z,1681753131.083 [Default:CheckIn](INFO): Running loop #9
2023-04-17T17:38:51.083Z,1681753131.083 [Default:CheckIn] Running Loop=9
2023-04-17T17:38:51.083Z,1681753131.083 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-17T17:38:51.083Z,1681753131.083 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-17T17:38:53.071Z,1681753133.071 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173852.00,A,3648.14057,N,12147.22978,W,0.058,77.59,170423,,,D*48
2023-04-17T17:38:53.073Z,1681753133.073 [NAL9602](INFO): GPS fix at 20230417T173852: (36.802343, -121.787163)
2023-04-17T17:38:53.126Z,1681753133.126 [Default:CheckIn:Read_GPS] Stopped
2023-04-17T17:38:53.126Z,1681753133.126 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-17T17:39:00.231Z,1681753140.231 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230417T162856/Courier0034.lzma
2023-04-17T17:39:01.234Z,1681753141.234 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Courier0034.lzma.bak
2023-04-17T17:39:01.234Z,1681753141.234 [DataOverHttps](INFO): SBD MOMSN=18232017
2023-04-17T17:39:08.826Z,1681753148.826 [NAL9602](INFO): SBD MO Status=0, MOMSN=40868, MT Status=0, MTMSN=0
2023-04-17T17:39:08.826Z,1681753148.826 [NAL9602](INFO): No messages in MT queue
2023-04-17T17:39:16.899Z,1681753156.899 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20230417T162856/Express0035.lzma
2023-04-17T17:39:17.902Z,1681753157.902 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Express0035.lzma.bak
2023-04-17T17:39:17.902Z,1681753157.902 [DataOverHttps](INFO): SBD MOMSN=18232020
2023-04-17T17:39:18.943Z,1681753158.943 [Default:CheckIn:Read_Iridium] Stopped
2023-04-17T17:39:18.943Z,1681753158.943 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-17T17:39:18.943Z,1681753158.943 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-17T17:39:39.533Z,1681753179.533 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-17T17:44:19.653Z,1681753459.653 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-17T17:44:19.653Z,1681753459.653 [Default:CheckIn:C.Wait] Stopped
2023-04-17T17:44:19.653Z,1681753459.653 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-17T17:44:19.653Z,1681753459.653 [Default:CheckIn:D] Running Loop=1
2023-04-17T17:44:20.075Z,1681753460.075 [Default:CheckIn:D] Stopped
2023-04-17T17:44:20.075Z,1681753460.075 [Default:CheckIn:E] Running Loop=1
2023-04-17T17:44:20.497Z,1681753460.497 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 71.705094 min 
2023-04-17T17:44:20.498Z,1681753460.498 [Default:CheckIn:E] Stopped
2023-04-17T17:44:20.498Z,1681753460.498 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-17T17:44:20.498Z,1681753460.498 [Default:CheckIn] Stopped
2023-04-17T17:44:20.498Z,1681753460.498 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-17T17:44:20.498Z,1681753460.498 [Default:CheckIn](INFO): Running loop #10
2023-04-17T17:44:20.498Z,1681753460.498 [Default:CheckIn] Running Loop=10
2023-04-17T17:44:20.498Z,1681753460.498 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-17T17:44:20.498Z,1681753460.498 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-17T17:44:22.467Z,1681753462.467 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174421.00,A,3648.14290,N,12147.22919,W,0.019,37.32,170423,,,D*45
2023-04-17T17:44:22.469Z,1681753462.469 [NAL9602](INFO): GPS fix at 20230417T174421: (36.802382, -121.787153)
2023-04-17T17:44:22.488Z,1681753462.488 [Default:CheckIn:Read_GPS] Stopped
2023-04-17T17:44:22.488Z,1681753462.488 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-17T17:44:31.647Z,1681753471.647 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230417T162856/Courier0037.lzma
2023-04-17T17:44:32.650Z,1681753472.650 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Courier0037.lzma.bak
2023-04-17T17:44:32.650Z,1681753472.650 [DataOverHttps](INFO): SBD MOMSN=18232024
2023-04-17T17:44:48.640Z,1681753488.640 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230417T162856/Express0038.lzma
2023-04-17T17:44:48.759Z,1681753488.759 [NAL9602](INFO): SBD MO Status=2, MOMSN=40869, MT Status=2, MTMSN=0
2023-04-17T17:44:48.759Z,1681753488.759 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-04-17T17:44:49.642Z,1681753489.642 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Express0038.lzma.bak
2023-04-17T17:44:49.642Z,1681753489.642 [DataOverHttps](INFO): SBD MOMSN=18232027
2023-04-17T17:44:50.795Z,1681753490.795 [Default:CheckIn:Read_Iridium] Stopped
2023-04-17T17:44:50.795Z,1681753490.795 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-17T17:44:50.795Z,1681753490.795 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-17T17:45:08.186Z,1681753508.186 [NAL9602](INFO): SBD MO Status=2, MOMSN=40869, MT Status=2, MTMSN=0
2023-04-17T17:45:08.187Z,1681753508.187 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-04-17T17:45:24.346Z,1681753524.346 [NAL9602](INFO): SBD MO Status=2, MOMSN=40869, MT Status=2, MTMSN=0
2023-04-17T17:45:24.347Z,1681753524.347 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-04-17T17:46:07.580Z,1681753567.580 [NAL9602](INFO): SBD MO Status=0, MOMSN=40869, MT Status=0, MTMSN=0
2023-04-17T17:46:07.580Z,1681753567.580 [NAL9602](INFO): No messages in MT queue
2023-04-17T17:46:38.282Z,1681753598.282 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-17T17:49:51.431Z,1681753791.431 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-17T17:49:51.431Z,1681753791.431 [Default:CheckIn:C.Wait] Stopped
2023-04-17T17:49:51.431Z,1681753791.431 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-17T17:49:51.431Z,1681753791.431 [Default:CheckIn:D] Running Loop=1
2023-04-17T17:49:51.835Z,1681753791.835 [Default:CheckIn:D] Stopped
2023-04-17T17:49:51.835Z,1681753791.835 [Default:CheckIn:E] Running Loop=1
2023-04-17T17:49:52.243Z,1681753792.243 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 77.234424 min 
2023-04-17T17:49:52.243Z,1681753792.243 [Default:CheckIn:E] Stopped
2023-04-17T17:49:52.243Z,1681753792.243 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-17T17:49:52.243Z,1681753792.243 [Default:CheckIn] Stopped
2023-04-17T17:49:52.243Z,1681753792.243 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-17T17:49:52.244Z,1681753792.244 [Default:CheckIn](INFO): Running loop #11
2023-04-17T17:49:52.244Z,1681753792.244 [Default:CheckIn] Running Loop=11
2023-04-17T17:49:52.244Z,1681753792.244 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-17T17:49:52.244Z,1681753792.244 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-17T17:49:54.251Z,1681753794.251 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174953.00,A,3648.15098,N,12147.22066,W,0.039,0.00,170423,,,A*75
2023-04-17T17:49:54.253Z,1681753794.253 [NAL9602](INFO): GPS fix at 20230417T174953: (36.802516, -121.787011)
2023-04-17T17:49:54.289Z,1681753794.289 [Default:CheckIn:Read_GPS] Stopped
2023-04-17T17:49:54.289Z,1681753794.289 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-17T17:50:01.555Z,1681753801.555 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230417T162856/Courier0040.lzma
2023-04-17T17:50:02.558Z,1681753802.558 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Courier0040.lzma.bak
2023-04-17T17:50:02.558Z,1681753802.558 [DataOverHttps](INFO): SBD MOMSN=18232041
2023-04-17T17:50:10.003Z,1681753810.003 [NAL9602](INFO): SBD MO Status=0, MOMSN=40870, MT Status=0, MTMSN=0
2023-04-17T17:50:10.003Z,1681753810.003 [NAL9602](INFO): No messages in MT queue
2023-04-17T17:50:18.399Z,1681753818.399 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230417T162856/Express0041.lzma
2023-04-17T17:50:19.402Z,1681753819.402 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Express0041.lzma.bak
2023-04-17T17:50:19.402Z,1681753819.402 [DataOverHttps](INFO): SBD MOMSN=18232044
2023-04-17T17:50:20.514Z,1681753820.514 [Default:CheckIn:Read_Iridium] Stopped
2023-04-17T17:50:20.514Z,1681753820.514 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-17T17:50:20.514Z,1681753820.514 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-17T17:50:40.751Z,1681753840.751 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-17T17:55:21.265Z,1681754121.265 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-17T17:55:21.265Z,1681754121.265 [Default:CheckIn:C.Wait] Stopped
2023-04-17T17:55:21.266Z,1681754121.266 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-17T17:55:21.266Z,1681754121.266 [Default:CheckIn:D] Running Loop=1
2023-04-17T17:55:21.659Z,1681754121.659 [Default:CheckIn:D] Stopped
2023-04-17T17:55:21.659Z,1681754121.659 [Default:CheckIn:E] Running Loop=1
2023-04-17T17:55:22.063Z,1681754122.063 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 82.731486 min 
2023-04-17T17:55:22.063Z,1681754122.063 [Default:CheckIn:E] Stopped
2023-04-17T17:55:22.063Z,1681754122.063 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-17T17:55:22.063Z,1681754122.063 [Default:CheckIn] Stopped
2023-04-17T17:55:22.063Z,1681754122.063 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-17T17:55:22.063Z,1681754122.063 [Default:CheckIn](INFO): Running loop #12
2023-04-17T17:55:22.064Z,1681754122.064 [Default:CheckIn] Running Loop=12
2023-04-17T17:55:22.064Z,1681754122.064 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-17T17:55:22.064Z,1681754122.064 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-17T17:55:24.079Z,1681754124.079 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175523.00,A,3648.15216,N,12147.22080,W,0.039,0.00,170423,,,A*73
2023-04-17T17:55:24.081Z,1681754124.081 [NAL9602](INFO): GPS fix at 20230417T175523: (36.802536, -121.787013)
2023-04-17T17:55:24.093Z,1681754124.093 [Default:CheckIn:Read_GPS] Stopped
2023-04-17T17:55:24.093Z,1681754124.093 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-17T17:55:30.511Z,1681754130.511 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230417T162856/Courier0043.lzma
2023-04-17T17:55:31.514Z,1681754131.514 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Courier0043.lzma.bak
2023-04-17T17:55:31.514Z,1681754131.514 [DataOverHttps](INFO): SBD MOMSN=18232048
2023-04-17T17:55:37.007Z,1681754137.007 [NAL9602](INFO): SBD MO Status=0, MOMSN=40871, MT Status=0, MTMSN=0
2023-04-17T17:55:37.007Z,1681754137.007 [NAL9602](INFO): No messages in MT queue
2023-04-17T17:55:47.263Z,1681754147.263 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230417T162856/Express0044.lzma
2023-04-17T17:55:48.266Z,1681754148.266 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Express0044.lzma.bak
2023-04-17T17:55:48.266Z,1681754148.266 [DataOverHttps](INFO): SBD MOMSN=18232051
2023-04-17T17:55:49.543Z,1681754149.543 [Default:CheckIn:Read_Iridium] Stopped
2023-04-17T17:55:49.543Z,1681754149.543 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-17T17:55:49.543Z,1681754149.543 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-17T17:56:07.705Z,1681754167.705 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-17T18:00:50.283Z,1681754450.283 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-17T18:00:50.283Z,1681754450.283 [Default:CheckIn:C.Wait] Stopped
2023-04-17T18:00:50.284Z,1681754450.284 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-17T18:00:50.284Z,1681754450.284 [Default:CheckIn:D] Running Loop=1
2023-04-17T18:00:50.667Z,1681754450.667 [Default:CheckIn:D] Stopped
2023-04-17T18:00:50.667Z,1681754450.667 [Default:CheckIn:E] Running Loop=1
2023-04-17T18:00:51.070Z,1681754451.070 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 88.214966 min 
2023-04-17T18:00:51.071Z,1681754451.071 [Default:CheckIn:E] Stopped
2023-04-17T18:00:51.071Z,1681754451.071 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-17T18:00:51.071Z,1681754451.071 [Default:CheckIn] Stopped
2023-04-17T18:00:51.071Z,1681754451.071 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-17T18:00:51.071Z,1681754451.071 [Default:CheckIn](INFO): Running loop #13
2023-04-17T18:00:51.071Z,1681754451.071 [Default:CheckIn] Running Loop=13
2023-04-17T18:00:51.071Z,1681754451.071 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-17T18:00:51.071Z,1681754451.071 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-17T18:00:53.082Z,1681754453.082 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180052.00,A,3648.15127,N,12147.22176,W,0.039,0.00,170423,,,A*73
2023-04-17T18:00:53.084Z,1681754453.084 [NAL9602](INFO): GPS fix at 20230417T180052: (36.802521, -121.787029)
2023-04-17T18:00:53.103Z,1681754453.103 [Default:CheckIn:Read_GPS] Stopped
2023-04-17T18:00:53.103Z,1681754453.103 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-17T18:01:00.871Z,1681754460.871 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230417T162856/Courier0046.lzma
2023-04-17T18:01:01.174Z,1681754461.174 [NAL9602](INFO): SBD MO Status=0, MOMSN=40872, MT Status=0, MTMSN=0
2023-04-17T18:01:01.175Z,1681754461.175 [NAL9602](INFO): No messages in MT queue
2023-04-17T18:01:01.874Z,1681754461.874 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Courier0046.lzma.bak
2023-04-17T18:01:01.874Z,1681754461.874 [DataOverHttps](INFO): SBD MOMSN=18232055
2023-04-17T18:01:17.807Z,1681754477.807 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230417T162856/Express0047.lzma
2023-04-17T18:01:18.810Z,1681754478.810 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Express0047.lzma.bak
2023-04-17T18:01:18.810Z,1681754478.810 [DataOverHttps](INFO): SBD MOMSN=18232058
2023-04-17T18:01:20.166Z,1681754480.166 [Default:CheckIn:Read_Iridium] Stopped
2023-04-17T18:01:20.166Z,1681754480.166 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-17T18:01:20.166Z,1681754480.166 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-17T18:01:31.873Z,1681754491.873 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-17T18:05:01.605Z,1681754701.605 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T18:05:02.794Z,1681754702.794 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-04-17T18:05:08.047Z,1681754708.047 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2023-04-17T18:05:16.531Z,1681754716.531 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T18:05:31.478Z,1681754731.478 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T18:05:46.426Z,1681754746.426 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T18:06:01.778Z,1681754761.778 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T18:06:17.537Z,1681754777.537 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T18:06:20.791Z,1681754780.791 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-17T18:06:20.791Z,1681754780.791 [Default:CheckIn:C.Wait] Stopped
2023-04-17T18:06:20.791Z,1681754780.791 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-17T18:06:20.791Z,1681754780.791 [Default:CheckIn:D] Running Loop=1
2023-04-17T18:06:21.214Z,1681754781.214 [Default:CheckIn:D] Stopped
2023-04-17T18:06:21.214Z,1681754781.214 [Default:CheckIn:E] Running Loop=1
2023-04-17T18:06:21.594Z,1681754781.594 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 93.724080 min 
2023-04-17T18:06:21.594Z,1681754781.594 [Default:CheckIn:E] Stopped
2023-04-17T18:06:21.594Z,1681754781.594 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-17T18:06:21.594Z,1681754781.594 [Default:CheckIn] Stopped
2023-04-17T18:06:21.594Z,1681754781.594 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-17T18:06:21.595Z,1681754781.595 [Default:CheckIn](INFO): Running loop #14
2023-04-17T18:06:21.595Z,1681754781.595 [Default:CheckIn] Running Loop=14
2023-04-17T18:06:21.595Z,1681754781.595 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-17T18:06:21.595Z,1681754781.595 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-17T18:06:23.607Z,1681754783.607 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180622.00,A,3648.39876,N,12147.10998,W,4.276,4.34,170423,,,D*73
2023-04-17T18:06:23.610Z,1681754783.610 [NAL9602](INFO): GPS fix at 20230417T180622: (36.806646, -121.785166)
2023-04-17T18:06:23.629Z,1681754783.629 [Default:CheckIn:Read_GPS] Stopped
2023-04-17T18:06:23.629Z,1681754783.629 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-17T18:06:31.575Z,1681754791.575 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230417T162856/Courier0049.lzma
2023-04-17T18:06:32.578Z,1681754792.578 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Courier0049.lzma.bak
2023-04-17T18:06:32.578Z,1681754792.578 [DataOverHttps](INFO): SBD MOMSN=18232062
2023-04-17T18:06:33.705Z,1681754793.705 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T18:06:48.652Z,1681754808.652 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T18:06:48.828Z,1681754808.828 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20230417T162856/Express0050.lzma
2023-04-17T18:06:54.850Z,1681754814.850 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Express0050.lzma.bak
2023-04-17T18:06:54.850Z,1681754814.850 [DataOverHttps](INFO): SBD MOMSN=18232065
2023-04-17T18:06:55.939Z,1681754815.939 [Default:CheckIn:Read_Iridium] Stopped
2023-04-17T18:06:55.939Z,1681754815.939 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-17T18:06:55.939Z,1681754815.939 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-17T18:07:04.009Z,1681754824.009 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T18:07:19.354Z,1681754839.354 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T18:07:19.363Z,1681754839.363 [NAL9602](INFO): SBD MO Status=2, MOMSN=40873, MT Status=2, MTMSN=0
2023-04-17T18:07:19.363Z,1681754839.363 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-04-17T18:07:36.753Z,1681754856.753 [NAL9602](INFO): SBD MO Status=0, MOMSN=40873, MT Status=0, MTMSN=0
2023-04-17T18:07:36.753Z,1681754856.753 [NAL9602](INFO): No messages in MT queue
2023-04-17T18:08:07.483Z,1681754887.483 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-17T18:11:56.519Z,1681755116.519 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-17T18:11:56.519Z,1681755116.519 [Default:CheckIn:C.Wait] Stopped
2023-04-17T18:11:56.520Z,1681755116.520 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-17T18:11:56.520Z,1681755116.520 [Default:CheckIn:D] Running Loop=1
2023-04-17T18:11:56.935Z,1681755116.935 [Default:CheckIn:D] Stopped
2023-04-17T18:11:56.935Z,1681755116.935 [Default:CheckIn:E] Running Loop=1
2023-04-17T18:11:57.327Z,1681755117.327 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 99.319434 min 
2023-04-17T18:11:57.327Z,1681755117.327 [Default:CheckIn:E] Stopped
2023-04-17T18:11:57.327Z,1681755117.327 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-17T18:11:57.327Z,1681755117.327 [Default:CheckIn] Stopped
2023-04-17T18:11:57.327Z,1681755117.327 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-17T18:11:57.328Z,1681755117.328 [Default:CheckIn](INFO): Running loop #15
2023-04-17T18:11:57.328Z,1681755117.328 [Default:CheckIn] Running Loop=15
2023-04-17T18:11:57.328Z,1681755117.328 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-17T18:11:57.328Z,1681755117.328 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-17T18:11:59.343Z,1681755119.343 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181158.00,A,3648.28606,N,12147.67559,W,8.767,249.09,170423,,,D*7C
2023-04-17T18:11:59.345Z,1681755119.345 [NAL9602](INFO): GPS fix at 20230417T181158: (36.804768, -121.794593)
2023-04-17T18:11:59.356Z,1681755119.356 [Default:CheckIn:Read_GPS] Stopped
2023-04-17T18:11:59.357Z,1681755119.357 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-17T18:12:06.775Z,1681755126.775 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230417T162856/Courier0052.lzma
2023-04-17T18:12:07.778Z,1681755127.778 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Courier0052.lzma.bak
2023-04-17T18:12:07.778Z,1681755127.778 [DataOverHttps](INFO): SBD MOMSN=18232069
2023-04-17T18:12:12.671Z,1681755132.671 [NAL9602](INFO): SBD MO Status=0, MOMSN=40874, MT Status=0, MTMSN=0
2023-04-17T18:12:12.671Z,1681755132.671 [NAL9602](INFO): No messages in MT queue
2023-04-17T18:12:26.636Z,1681755146.636 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20230417T162856/Express0053.lzma
2023-04-17T18:12:27.638Z,1681755147.638 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Express0053.lzma.bak
2023-04-17T18:12:27.638Z,1681755147.638 [DataOverHttps](INFO): SBD MOMSN=18232074
2023-04-17T18:12:28.953Z,1681755148.953 [Default:CheckIn:Read_Iridium] Stopped
2023-04-17T18:12:28.953Z,1681755148.953 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-17T18:12:28.953Z,1681755148.953 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-17T18:12:43.437Z,1681755163.437 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-17T18:14:36.173Z,1681755276.173 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T18:14:42.636Z,1681755282.636 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T18:14:57.582Z,1681755297.582 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T18:15:12.530Z,1681755312.530 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T18:15:27.478Z,1681755327.478 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T18:15:42.830Z,1681755342.830 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T18:15:57.780Z,1681755357.780 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T18:16:13.130Z,1681755373.130 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T18:16:28.484Z,1681755388.484 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T18:16:32.628Z,1681755392.628 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-04-17T18:16:43.834Z,1681755403.834 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-04-17T18:17:12.142Z,1681755432.142 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2023-04-17T18:17:12.147Z,1681755432.147 [BPC1](INFO): Calculating totals. Valid battery stick count: 49. Valid reserve battery stick count: 5.
2023-04-17T18:17:12.150Z,1681755432.150 [BPC1](INFO): Received data from all battery sticks.
2023-04-17T18:17:29.521Z,1681755449.521 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-17T18:17:29.521Z,1681755449.521 [Default:CheckIn:C.Wait] Stopped
2023-04-17T18:17:29.521Z,1681755449.521 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-17T18:17:29.521Z,1681755449.521 [Default:CheckIn:D] Running Loop=1
2023-04-17T18:17:29.937Z,1681755449.937 [Default:CheckIn:D] Stopped
2023-04-17T18:17:29.937Z,1681755449.937 [Default:CheckIn:E] Running Loop=1
2023-04-17T18:17:30.323Z,1681755450.323 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 104.869466 min 
2023-04-17T18:17:30.323Z,1681755450.323 [Default:CheckIn:E] Stopped
2023-04-17T18:17:30.323Z,1681755450.323 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-17T18:17:30.323Z,1681755450.323 [Default:CheckIn] Stopped
2023-04-17T18:17:30.323Z,1681755450.323 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-17T18:17:30.324Z,1681755450.324 [Default:CheckIn](INFO): Running loop #16
2023-04-17T18:17:30.324Z,1681755450.324 [Default:CheckIn] Running Loop=16
2023-04-17T18:17:30.324Z,1681755450.324 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-17T18:17:30.324Z,1681755450.324 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-17T18:17:32.331Z,1681755452.331 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181731.00,A,3648.06524,N,12149.24592,W,16.251,258.96,170423,,,D*4D
2023-04-17T18:17:32.334Z,1681755452.334 [NAL9602](INFO): GPS fix at 20230417T181731: (36.801087, -121.820765)
2023-04-17T18:17:32.344Z,1681755452.344 [Default:CheckIn:Read_GPS] Stopped
2023-04-17T18:17:32.344Z,1681755452.344 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-17T18:17:46.475Z,1681755466.475 [NAL9602](INFO): SBD MO Status=0, MOMSN=40875, MT Status=0, MTMSN=0
2023-04-17T18:17:46.475Z,1681755466.475 [NAL9602](INFO): No messages in MT queue
2023-04-17T18:18:17.195Z,1681755497.195 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-17T18:18:17.679Z,1681755497.679 [DataOverHttps](INFO): Sending 83 bytes from file Logs/20230417T162856/Courier0055.lzma
2023-04-17T18:18:18.682Z,1681755498.682 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Courier0055.lzma.bak
2023-04-17T18:18:18.682Z,1681755498.682 [DataOverHttps](INFO): SBD MOMSN=18232097
2023-04-17T18:18:45.407Z,1681755525.407 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20230417T162856/Express0056.lzma
2023-04-17T18:18:46.410Z,1681755526.410 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Express0056.lzma.bak
2023-04-17T18:18:46.410Z,1681755526.410 [DataOverHttps](INFO): SBD MOMSN=18232100
2023-04-17T18:18:47.498Z,1681755527.498 [Default:CheckIn:Read_Iridium] Stopped
2023-04-17T18:18:47.498Z,1681755527.498 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-17T18:18:47.498Z,1681755527.498 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-17T18:23:48.264Z,1681755828.264 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-17T18:23:48.264Z,1681755828.264 [Default:CheckIn:C.Wait] Stopped
2023-04-17T18:23:48.264Z,1681755828.264 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-17T18:23:48.264Z,1681755828.264 [Default:CheckIn:D] Running Loop=1
2023-04-17T18:23:48.643Z,1681755828.643 [Default:CheckIn:D] Stopped
2023-04-17T18:23:48.643Z,1681755828.643 [Default:CheckIn:E] Running Loop=1
2023-04-17T18:23:49.048Z,1681755829.048 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 111.181226 min 
2023-04-17T18:23:49.048Z,1681755829.048 [Default:CheckIn:E] Stopped
2023-04-17T18:23:49.048Z,1681755829.048 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-17T18:23:49.048Z,1681755829.048 [Default:CheckIn] Stopped
2023-04-17T18:23:49.048Z,1681755829.048 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-17T18:23:49.048Z,1681755829.048 [Default:CheckIn](INFO): Running loop #17
2023-04-17T18:23:49.049Z,1681755829.049 [Default:CheckIn] Running Loop=17
2023-04-17T18:23:49.049Z,1681755829.049 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-17T18:23:49.049Z,1681755829.049 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-17T18:23:51.063Z,1681755831.063 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182350.00,A,3647.69740,N,12150.62703,W,2.819,102.90,170423,,,D*72
2023-04-17T18:23:51.065Z,1681755831.065 [NAL9602](INFO): GPS fix at 20230417T182350: (36.794957, -121.843784)
2023-04-17T18:23:51.096Z,1681755831.096 [Default:CheckIn:Read_GPS] Stopped
2023-04-17T18:23:51.096Z,1681755831.096 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-17T18:24:08.527Z,1681755848.527 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230417T162856/Courier0058.lzma
2023-04-17T18:24:09.530Z,1681755849.530 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Courier0058.lzma.bak
2023-04-17T18:24:09.530Z,1681755849.530 [DataOverHttps](INFO): SBD MOMSN=18232109
2023-04-17T18:24:23.379Z,1681755863.379 [NAL9602](INFO): SBD MO Status=2, MOMSN=40876, MT Status=2, MTMSN=0
2023-04-17T18:24:23.379Z,1681755863.379 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-04-17T18:24:35.543Z,1681755875.543 [NAL9602](INFO): SBD MO Status=0, MOMSN=40876, MT Status=0, MTMSN=0
2023-04-17T18:24:35.543Z,1681755875.543 [NAL9602](INFO): No messages in MT queue
2023-04-17T18:24:38.292Z,1681755878.292 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20230417T162856/Express0059.lzma
2023-04-17T18:24:39.294Z,1681755879.294 [DataOverHttps](INFO): Moved sent file to Logs/20230417T162856/Express0059.lzma.bak
2023-04-17T18:24:39.294Z,1681755879.294 [DataOverHttps](INFO): SBD MOMSN=18232112
2023-04-17T18:24:40.413Z,1681755880.413 [Default:CheckIn:Read_Iridium] Stopped
2023-04-17T18:24:40.413Z,1681755880.413 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-17T18:24:40.413Z,1681755880.413 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-17T18:25:06.249Z,1681755906.249 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-17T18:29:14.945Z,1681756154.945 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-04-17T18:29:40.987Z,1681756180.987 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-17T18:29:40.987Z,1681756180.987 [Default:CheckIn:C.Wait] Stopped
2023-04-17T18:29:40.987Z,1681756180.987 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-17T18:29:40.987Z,1681756180.987 [Default:CheckIn:D] Running Loop=1
2023-04-17T18:29:41.399Z,1681756181.399 [Default:CheckIn:D] Stopped
2023-04-17T18:29:41.399Z,1681756181.399 [Default:CheckIn:E] Running Loop=1
2023-04-17T18:29:41.794Z,1681756181.794 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 117.060506 min 
2023-04-17T18:29:41.794Z,1681756181.794 [Default:CheckIn:E] Stopped
2023-04-17T18:29:41.794Z,1681756181.794 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-17T18:29:41.794Z,1681756181.794 [Default:CheckIn] Stopped
2023-04-17T18:29:41.794Z,1681756181.794 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-17T18:29:41.794Z,1681756181.794 [Default:CheckIn](INFO): Running loop #18
2023-04-17T18:29:41.794Z,1681756181.794 [Default:CheckIn] Running Loop=18
2023-04-17T18:29:41.794Z,1681756181.794 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-17T18:29:41.794Z,1681756181.794 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-17T18:29:43.811Z,1681756183.811 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182943.00,A,3648.37807,N,12150.74423,W,3.441,19.96,170423,,,D*49
2023-04-17T18:29:43.814Z,1681756183.814 [NAL9602](INFO): GPS fix at 20230417T182943: (36.806301, -121.845737)
2023-04-17T18:29:43.824Z,1681756183.824 [Default:CheckIn:Read_GPS] Stopped
2023-04-17T18:29:43.824Z,1681756183.824 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-17T18:29:46.084Z,1681756186.084 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-04-17T18:29:56.334Z,1681756196.334 [NAL9602](INFO): SBD MO Status=0, MOMSN=40877, MT Status=0, MTMSN=0
2023-04-17T18:29:56.335Z,1681756196.335 [NAL9602](INFO): No messages in MT queue
2023-04-17T18:30:17.208Z,1681756217.208 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-04-17T18:30:27.033Z,1681756227.033 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-17T18:30:48.360Z,1681756248.360 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-04-17T18:30:50.369Z,1681756250.369 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.219635
2023-04-17T18:31:11.120Z,1681756271.120 [NAL9602](INFO): SBD MO Status=2, MOMSN=40878, MT Status=2, MTMSN=0
2023-04-17T18:31:11.120Z,1681756271.120 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-04-17T18:31:21.496Z,1681756281.496 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-04-17T18:31:38.627Z,1681756298.627 [NAL9602](INFO): SBD MO Status=1, MOMSN=40878, MT Status=0, MTMSN=0
2023-04-17T18:31:38.684Z,1681756298.684 [NAL9602](INFO): Sent 72 bytes from file Logs/20230417T162856/Courier0061.lzma
2023-04-17T18:31:38.684Z,1681756298.684 [NAL9602](INFO): Packets left to send: 0
2023-04-17T18:31:48.365Z,1681756308.365 [NAL9602](INFO): SBD MO Status=1, MOMSN=40879, MT Status=0, MTMSN=0
2023-04-17T18:31:48.412Z,1681756308.412 [NAL9602](INFO): Sent 144 bytes from file Logs/20230417T162856/Express0062.lzma
2023-04-17T18:31:48.412Z,1681756308.412 [NAL9602](INFO): Packets left to send: 0
2023-04-17T18:31:52.620Z,1681756312.620 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-04-17T18:31:58.870Z,1681756318.870 [NAL9602](INFO): SBD MO Status=0, MOMSN=40880, MT Status=0, MTMSN=0
2023-04-17T18:31:58.973Z,1681756318.973 [Default:CheckIn:Read_Iridium] Stopped
2023-04-17T18:31:58.973Z,1681756318.973 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-17T18:31:58.973Z,1681756318.973 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-17T18:32:23.744Z,1681756343.744 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-04-17T18:32:29.578Z,1681756349.578 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-17T18:32:54.868Z,1681756374.868 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-04-17T18:33:25.992Z,1681756405.992 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-04-17T18:33:57.116Z,1681756437.116 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-04-17T18:34:28.268Z,1681756468.268 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-04-17T18:34:59.392Z,1681756499.392 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-04-17T18:35:30.516Z,1681756530.516 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-04-17T18:36:01.640Z,1681756561.640 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-04-17T18:36:32.788Z,1681756592.788 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-04-17T18:36:59.454Z,1681756619.454 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-17T18:36:59.454Z,1681756619.454 [Default:CheckIn:C.Wait] Stopped
2023-04-17T18:36:59.454Z,1681756619.454 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-17T18:36:59.454Z,1681756619.454 [Default:CheckIn:D] Running Loop=1
2023-04-17T18:36:59.863Z,1681756619.863 [Default:CheckIn:D] Stopped
2023-04-17T18:36:59.863Z,1681756619.863 [Default:CheckIn:E] Running Loop=1
2023-04-17T18:37:00.274Z,1681756620.274 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 124.368229 min 
2023-04-17T18:37:00.274Z,1681756620.274 [Default:CheckIn:E] Stopped
2023-04-17T18:37:00.274Z,1681756620.274 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-17T18:37:00.274Z,1681756620.274 [Default:CheckIn] Stopped
2023-04-17T18:37:00.275Z,1681756620.275 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-17T18:37:00.275Z,1681756620.275 [Default:CheckIn](INFO): Running loop #19
2023-04-17T18:37:00.275Z,1681756620.275 [Default:CheckIn] Running Loop=19
2023-04-17T18:37:00.275Z,1681756620.275 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-17T18:37:00.275Z,1681756620.275 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-17T18:37:02.275Z,1681756622.275 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183701.00,A,3648.35488,N,12150.60035,W,0.350,122.03,170423,,,D*7E
2023-04-17T18:37:02.277Z,1681756622.277 [NAL9602](INFO): GPS fix at 20230417T183701: (36.805915, -121.843339)
2023-04-17T18:37:02.326Z,1681756622.326 [Default:CheckIn:Read_GPS] Stopped
2023-04-17T18:37:02.327Z,1681756622.327 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-17T18:37:03.948Z,1681756623.948 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-04-17T18:37:17.267Z,1681756637.267 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=40881, MT Status=1, MTMSN=2913
2023-04-17T18:37:17.313Z,1681756637.313 [NAL9602](INFO): Sent 72 bytes from file Logs/20230417T162856/Courier0064.lzma
2023-04-17T18:37:17.313Z,1681756637.313 [NAL9602](INFO): Packets left to send: 0
2023-04-17T18:37:17.756Z,1681756637.756 [NAL9602](INFO): Received command: restart logs