2023-09-11T16:19:45.565Z,1694449185.565 [Supervisor](DEBUG): Initializing supervisor.
2023-09-11T16:19:45.570Z,1694449185.570 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-09-11T16:19:45.570Z,1694449185.570 [SyncHandler](INFO): Protected caller Thread ID is 8118
2023-09-11T16:19:45.571Z,1694449185.571 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-09-11T16:19:45.572Z,1694449185.572 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-09-11T16:19:45.572Z,1694449185.572 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 8119
2023-09-11T16:19:45.576Z,1694449185.576 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-09-11T16:19:45.593Z,1694449185.593 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-09-11T16:19:45.594Z,1694449185.594 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-09-11T16:19:45.594Z,1694449185.594 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 8120
2023-09-11T16:19:45.598Z,1694449185.598 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-09-11T16:19:45.599Z,1694449185.599 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-09-11T16:19:45.600Z,1694449185.600 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 8121
2023-09-11T16:19:45.601Z,1694449185.601 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-09-11T16:19:45.602Z,1694449185.602 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-09-11T16:19:45.603Z,1694449185.603 [logger ThreadHandler](INFO): Protected caller Thread ID is 8122
2023-09-11T16:19:45.606Z,1694449185.606 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-09-11T16:19:45.607Z,1694449185.607 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-09-11T16:19:45.608Z,1694449185.608 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-09-11T16:19:45.880Z,1694449185.880 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-09-11T16:19:45.881Z,1694449185.881 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-09-11T16:19:45.961Z,1694449185.961 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-09-11T16:19:46.438Z,1694449186.438 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-09-11T16:19:46.439Z,1694449186.439 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-09-11T16:19:46.765Z,1694449186.765 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-09-11T16:19:46.765Z,1694449186.765 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-09-11T16:19:46.862Z,1694449186.862 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-09-11T16:19:46.863Z,1694449186.863 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-09-11T16:19:47.257Z,1694449187.257 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-09-11T16:19:47.258Z,1694449187.258 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-09-11T16:19:47.473Z,1694449187.473 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-09-11T16:19:47.474Z,1694449187.474 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-09-11T16:19:48.000Z,1694449188.000 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-09-11T16:19:48.001Z,1694449188.001 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-09-11T16:19:48.137Z,1694449188.137 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-09-11T16:19:48.137Z,1694449188.137 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-09-11T16:19:48.217Z,1694449188.217 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-09-11T16:19:49.003Z,1694449189.003 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-09-11T16:19:49.003Z,1694449189.003 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-09-11T16:19:49.378Z,1694449189.378 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-09-11T16:19:49.379Z,1694449189.379 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-09-11T16:19:49.568Z,1694449189.568 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-09-11T16:19:49.568Z,1694449189.568 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-09-11T16:19:49.680Z,1694449189.680 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-09-11T16:19:49.680Z,1694449189.680 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-09-11T16:19:49.912Z,1694449189.912 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-09-11T16:19:49.913Z,1694449189.913 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-09-11T16:19:50.159Z,1694449190.159 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-09-11T16:19:50.161Z,1694449190.161 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2023-09-11T16:19:50.162Z,1694449190.162 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2023-09-11T16:19:50.295Z,1694449190.295 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2023-09-11T16:19:50.525Z,1694449190.525 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2023-09-11T16:19:50.725Z,1694449190.725 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2023-09-11T16:19:50.871Z,1694449190.871 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2023-09-11T16:19:51.169Z,1694449191.169 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2023-09-11T16:19:51.318Z,1694449191.318 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2023-09-11T16:19:51.440Z,1694449191.440 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2023-09-11T16:19:51.517Z,1694449191.517 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2023-09-11T16:19:51.670Z,1694449191.670 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2023-09-11T16:19:51.811Z,1694449191.811 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2023-09-11T16:19:51.923Z,1694449191.923 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2023-09-11T16:19:52.191Z,1694449192.191 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-09-11T16:19:52.192Z,1694449192.192 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-09-11T16:19:52.203Z,1694449192.203 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-09-11T16:19:52.254Z,1694449192.254 [VerticalControl](DEBUG): Construct VerticalControl.
2023-09-11T16:19:52.313Z,1694449192.313 [VerticalControl] Loaded
2023-09-11T16:19:52.314Z,1694449192.314 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-09-11T16:19:52.316Z,1694449192.316 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-09-11T16:19:52.356Z,1694449192.356 [HorizontalControl] Loaded
2023-09-11T16:19:52.356Z,1694449192.356 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-09-11T16:19:52.359Z,1694449192.359 [SpeedControl](DEBUG): Construct SpeedControl.
2023-09-11T16:19:52.362Z,1694449192.362 [SpeedControl] Loaded
2023-09-11T16:19:52.362Z,1694449192.362 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-09-11T16:19:52.365Z,1694449192.365 [LoopControl](DEBUG): Construct LoopControl.
2023-09-11T16:19:52.365Z,1694449192.365 [LoopControl] Loaded
2023-09-11T16:19:52.365Z,1694449192.365 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-09-11T16:19:52.366Z,1694449192.366 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-09-11T16:19:52.366Z,1694449192.366 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-09-11T16:19:52.376Z,1694449192.376 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-09-11T16:19:52.377Z,1694449192.377 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-09-11T16:19:52.525Z,1694449192.525 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-09-11T16:19:52.525Z,1694449192.525 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-09-11T16:19:52.656Z,1694449192.656 [BuoyancyServo] Loaded
2023-09-11T16:19:52.656Z,1694449192.656 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-09-11T16:19:52.675Z,1694449192.675 [ElevatorServo] Loaded
2023-09-11T16:19:52.676Z,1694449192.676 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-09-11T16:19:52.694Z,1694449192.694 [MassServo] Loaded
2023-09-11T16:19:52.695Z,1694449192.695 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-09-11T16:19:52.713Z,1694449192.713 [RudderServo] Loaded
2023-09-11T16:19:52.713Z,1694449192.713 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-09-11T16:19:52.728Z,1694449192.728 [ThrusterHE] Loaded
2023-09-11T16:19:52.728Z,1694449192.728 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2023-09-11T16:19:52.728Z,1694449192.728 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-09-11T16:19:52.729Z,1694449192.729 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-09-11T16:19:52.841Z,1694449192.841 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-09-11T16:19:52.841Z,1694449192.841 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-09-11T16:19:52.855Z,1694449192.855 [NavChart] Loaded
2023-09-11T16:19:52.855Z,1694449192.855 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-09-11T16:19:52.860Z,1694449192.860 [UniversalFixResidualReporter] Loaded
2023-09-11T16:19:52.861Z,1694449192.861 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-09-11T16:19:52.861Z,1694449192.861 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-09-11T16:19:52.862Z,1694449192.862 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-09-11T16:19:52.918Z,1694449192.918 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-09-11T16:19:52.919Z,1694449192.919 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-09-11T16:19:53.344Z,1694449193.344 [AHRS_M2] Loaded
2023-09-11T16:19:53.344Z,1694449193.344 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-09-11T16:19:53.379Z,1694449193.379 [BackseatComponent] Loaded
2023-09-11T16:19:53.379Z,1694449193.379 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-09-11T16:19:53.381Z,1694449193.381 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 4090C4E0
2023-09-11T16:19:53.381Z,1694449193.381 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 8207
2023-09-11T16:19:53.384Z,1694449193.384 [LcmUniversalReporter] Loaded
2023-09-11T16:19:53.384Z,1694449193.384 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-09-11T16:19:54.287Z,1694449194.287 [BPC1] Loaded
2023-09-11T16:19:54.287Z,1694449194.287 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-09-11T16:19:54.361Z,1694449194.361 [DataOverHttps] Loaded
2023-09-11T16:19:54.361Z,1694449194.361 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-09-11T16:19:54.362Z,1694449194.362 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4093C4E0
2023-09-11T16:19:54.363Z,1694449194.363 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 8209
2023-09-11T16:19:54.383Z,1694449194.383 [Depth_Keller] Loaded
2023-09-11T16:19:54.384Z,1694449194.384 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-09-11T16:19:54.389Z,1694449194.389 [DropWeight] Loaded
2023-09-11T16:19:54.389Z,1694449194.389 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2023-09-11T16:19:54.452Z,1694449194.452 [NAL9602] Loaded
2023-09-11T16:19:54.452Z,1694449194.452 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-09-11T16:19:54.482Z,1694449194.482 [Onboard] Loaded
2023-09-11T16:19:54.483Z,1694449194.483 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-09-11T16:19:54.484Z,1694449194.484 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4096C4E0
2023-09-11T16:19:54.484Z,1694449194.484 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 8210
2023-09-11T16:19:54.496Z,1694449194.496 [Power24vConverter] Loaded
2023-09-11T16:19:54.497Z,1694449194.497 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-09-11T16:19:54.510Z,1694449194.510 [Radio_Surface] Loaded
2023-09-11T16:19:54.510Z,1694449194.510 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-09-11T16:19:54.511Z,1694449194.511 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4099C4E0
2023-09-11T16:19:54.511Z,1694449194.511 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 8211
2023-09-11T16:19:54.512Z,1694449194.512 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-09-11T16:19:54.513Z,1694449194.513 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-09-11T16:19:54.562Z,1694449194.562 [DepthRateCalculator] Loaded
2023-09-11T16:19:54.562Z,1694449194.562 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-09-11T16:19:54.567Z,1694449194.567 [PitchRateCalculator] Loaded
2023-09-11T16:19:54.567Z,1694449194.567 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-09-11T16:19:54.576Z,1694449194.576 [SpeedCalculator] Loaded
2023-09-11T16:19:54.576Z,1694449194.576 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-09-11T16:19:54.581Z,1694449194.581 [YawRateCalculator] Loaded
2023-09-11T16:19:54.581Z,1694449194.581 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-09-11T16:19:54.599Z,1694449194.599 [ElevatorOffsetCalculator] Loaded
2023-09-11T16:19:54.599Z,1694449194.599 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-09-11T16:19:54.600Z,1694449194.600 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-09-11T16:19:54.600Z,1694449194.600 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-09-11T16:19:54.734Z,1694449194.734 [CANONSampler] Loaded
2023-09-11T16:19:54.734Z,1694449194.734 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2023-09-11T16:19:54.794Z,1694449194.794 [CTD_Seabird] Loaded
2023-09-11T16:19:54.794Z,1694449194.794 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-09-11T16:19:54.795Z,1694449194.795 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A574E0
2023-09-11T16:19:54.796Z,1694449194.796 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 8212
2023-09-11T16:19:54.816Z,1694449194.816 [PAR_Licor] Loaded
2023-09-11T16:19:54.816Z,1694449194.816 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-09-11T16:19:54.855Z,1694449194.855 [WetLabsBB2FL] Loaded
2023-09-11T16:19:54.856Z,1694449194.856 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-09-11T16:19:54.857Z,1694449194.857 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A874E0
2023-09-11T16:19:54.857Z,1694449194.857 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 8213
2023-09-11T16:19:54.858Z,1694449194.858 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-09-11T16:19:54.858Z,1694449194.858 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-09-11T16:19:54.884Z,1694449194.884 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-09-11T16:19:54.885Z,1694449194.885 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-09-11T16:19:55.195Z,1694449195.195 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-09-11T16:19:55.195Z,1694449195.195 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-09-11T16:19:55.337Z,1694449195.337 [SBIT](DEBUG): Construct Startup Built In Test.
2023-09-11T16:19:55.346Z,1694449195.346 [SBIT] Loaded
2023-09-11T16:19:55.347Z,1694449195.347 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-09-11T16:19:55.349Z,1694449195.349 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-09-11T16:19:55.363Z,1694449195.363 [IBIT] Loaded
2023-09-11T16:19:55.363Z,1694449195.363 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-09-11T16:19:55.369Z,1694449195.369 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-09-11T16:19:55.543Z,1694449195.543 [CBIT] Loaded
2023-09-11T16:19:55.543Z,1694449195.543 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-09-11T16:19:55.544Z,1694449195.544 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-09-11T16:19:55.544Z,1694449195.544 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-09-11T16:19:55.889Z,1694449195.889 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-09-11T16:19:56.044Z,1694449196.044 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-09-11T16:19:56.047Z,1694449196.047 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-09-11T16:19:56.058Z,1694449196.058 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-09-11T16:19:56.059Z,1694449196.059 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BC84E0
2023-09-11T16:19:56.059Z,1694449196.059 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 8214
2023-09-11T16:19:56.064Z,1694449196.064 [Supervisor](INFO): Main Thread ID is 8117
2023-09-11T16:19:56.064Z,1694449196.064 [Supervisor](DEBUG): Running supervisor.
2023-09-11T16:19:56.064Z,1694449196.064 [CommandExec ThreadHandler](INFO): Handler Thread ID is 8215
2023-09-11T16:19:56.065Z,1694449196.065 [CommandExec](INFO): Initializing the command executive.
2023-09-11T16:19:56.066Z,1694449196.066 [CommandLine ThreadHandler](INFO): Handler Thread ID is 8216
2023-09-11T16:19:56.069Z,1694449196.069 [controlThread ThreadHandler](INFO): Handler Thread ID is 8217
2023-09-11T16:19:56.069Z,1694449196.069 [controlThread](DEBUG): Initializing ControlThread
2023-09-11T16:19:56.070Z,1694449196.070 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-09-11T16:19:56.072Z,1694449196.072 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-09-11T16:19:56.073Z,1694449196.073 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-09-11T16:19:56.073Z,1694449196.073 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-09-11T16:19:56.075Z,1694449196.075 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-09-11T16:19:56.075Z,1694449196.075 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-09-11T16:19:56.080Z,1694449196.080 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-09-11T16:19:56.081Z,1694449196.081 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-09-11T16:19:56.081Z,1694449196.081 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-09-11T16:19:56.081Z,1694449196.081 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-09-11T16:19:56.081Z,1694449196.081 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-09-11T16:19:56.087Z,1694449196.087 [SBIT](INFO): Initialize SBIT Component.
2023-09-11T16:19:56.088Z,1694449196.088 [SBIT](IMPORTANT): git: 2023-07-13-16-gac1c2d9c8
2023-09-11T16:19:56.088Z,1694449196.088 [SBIT](INFO): git hash: ac1c2d9c86739cc59064b1e8d69712a613ceedbd
2023-09-11T16:19:56.088Z,1694449196.088 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-09-11T16:19:56.089Z,1694449196.089 [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-09-11T16:19:56.090Z,1694449196.090 [SBIT](INFO): Beginning SBIT in 54.000000 seconds.
2023-09-11T16:19:56.091Z,1694449196.091 [IBIT](INFO): Initialize IBIT Component.
2023-09-11T16:19:56.092Z,1694449196.092 [CBIT](DEBUG): Initialize CBIT Component.
2023-09-11T16:19:56.093Z,1694449196.093 [logger ThreadHandler](INFO): Handler Thread ID is 8218
2023-09-11T16:19:56.106Z,1694449196.106 [CBIT](DEBUG): Initialized mux pins.
2023-09-11T16:19:56.107Z,1694449196.107 [CBIT](DEBUG): Initializing the watchdog timer.
2023-09-11T16:19:56.108Z,1694449196.108 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 8219
2023-09-11T16:19:56.115Z,1694449196.115 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 8220
2023-09-11T16:19:56.116Z,1694449196.116 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-09-11T16:19:56.127Z,1694449196.127 [Onboard ThreadHandler](INFO): Handler Thread ID is 8221
2023-09-11T16:19:56.131Z,1694449196.131 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-09-11T16:19:56.131Z,1694449196.131 [CBIT](DEBUG): Initializing heartbeat.
2023-09-11T16:19:56.147Z,1694449196.147 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 8222
2023-09-11T16:19:56.163Z,1694449196.163 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 8223
2023-09-11T16:19:56.163Z,1694449196.163 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-09-11T16:19:56.169Z,1694449196.169 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 8225
2023-09-11T16:19:56.175Z,1694449196.175 [WetLabsBB2FL](INFO): Powering up
2023-09-11T16:19:56.176Z,1694449196.176 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 8227
2023-09-11T16:19:56.179Z,1694449196.179 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-09-11T16:19:56.179Z,1694449196.179 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-09-11T16:19:56.180Z,1694449196.180 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-09-11T16:19:56.180Z,1694449196.180 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-09-11T16:19:56.180Z,1694449196.180 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-09-11T16:19:56.180Z,1694449196.180 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-09-11T16:19:56.180Z,1694449196.180 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-09-11T16:19:56.180Z,1694449196.180 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-09-11T16:19:56.202Z,1694449196.202 [CBIT](DEBUG): Deactivating GF circuits.
2023-09-11T16:19:56.203Z,1694449196.203 [CBIT](DEBUG): Deactivating emergency mode.
2023-09-11T16:19:56.242Z,1694449196.242 [CBIT](DEBUG): Backplane powered.
2023-09-11T16:19:56.243Z,1694449196.243 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-09-11T16:19:56.256Z,1694449196.256 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-09-11T16:19:56.287Z,1694449196.287 [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-09-11T16:19:56.288Z,1694449196.288 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-09-11T16:19:56.357Z,1694449196.357 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-09-11T16:19:56.359Z,1694449196.359 [Default:A.Wait](DEBUG): Construct Wait.
2023-09-11T16:19:56.361Z,1694449196.361 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-09-11T16:19:56.415Z,1694449196.415 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-09-11T16:19:56.418Z,1694449196.418 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-09-11T16:19:56.448Z,1694449196.448 [Default:E.Execute](DEBUG): Construct Execute.
2023-09-11T16:19:56.451Z,1694449196.451 [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-09-11T16:19:56.462Z,1694449196.462 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2023-09-11T16:19:56.477Z,1694449196.477 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-09-11T16:19:56.551Z,1694449196.551 [Radio_Surface](INFO): Powering up
2023-09-11T16:19:56.561Z,1694449196.561 [Power24vConverter](INFO): Powering up.
2023-09-11T16:19:56.562Z,1694449196.562 [CANONSampler](INFO): Powering down
2023-09-11T16:19:56.600Z,1694449196.600 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-09-11T16:19:56.607Z,1694449196.607 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-09-11T16:19:56.608Z,1694449196.608 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-09-11T16:19:56.615Z,1694449196.615 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-09-11T16:19:56.616Z,1694449196.616 [MassServo](DEBUG): Initializing EZServoServo.
2023-09-11T16:19:56.623Z,1694449196.623 [MassServo](DEBUG): Initializing MassServo.
2023-09-11T16:19:56.624Z,1694449196.624 [RudderServo](DEBUG): Initializing EZServoServo.
2023-09-11T16:19:56.631Z,1694449196.631 [RudderServo](DEBUG): Initializing RudderServo.
2023-09-11T16:19:56.632Z,1694449196.632 [ThrusterHE](DEBUG): Initializing EZServoServo.
2023-09-11T16:19:56.639Z,1694449196.639 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2023-09-11T16:19:58.782Z,1694449198.782 [WetLabsBB2FL](INFO): Powering down
2023-09-11T16:20:02.348Z,1694449202.348 [ThrusterHE](ERROR): Zero Speed Commanded.
2023-09-11T16:20:11.606Z,1694449211.606 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005296
2023-09-11T16:20:24.512Z,1694449224.512 [NAL9602](INFO): Powering up NAL9602
2023-09-11T16:20:35.416Z,1694449235.416 [NAL9602](INFO): NAL9602 initialized
2023-09-11T16:20:42.963Z,1694449242.963 [CommandExec](IMPORTANT): got command failComponent
2023-09-11T16:20:42.963Z,1694449242.963 [CommandExec](IMPORTANT): Failed components:
2023-09-11T16:20:42.963Z,1694449242.963 [CommandExec](IMPORTANT): No failed Components.
2023-09-11T16:20:50.845Z,1694449250.845 [SBIT](IMPORTANT): Beginning Startup BIT
2023-09-11T16:20:50.849Z,1694449250.849 [CBIT](IMPORTANT): Beginning ground fault scan
2023-09-11T16:21:01.701Z,1694449261.701 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2023-09-11T16:21:02.119Z,1694449262.119 [CBIT](IMPORTANT): Beginning ground fault scan
2023-09-11T16:21:13.204Z,1694449273.204 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2023-09-11T16:21:13.495Z,1694449273.495 [CBIT](IMPORTANT): Beginning ground fault scan
2023-09-11T16:21:23.436Z,1694449283.436 [CommandExec](IMPORTANT): got command ! /etc/rc.d/init.d/settime restart
2023-09-11T16:21:24.391Z,1694449284.391 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2023-09-11T16:21:24.392Z,1694449284.392 [CBIT](IMPORTANT): Ground fault scan returned out of bounds value in succession 3 times. Will re-run scan on normal schedule.
2023-09-11T16:21:26.219Z,1694449286.219 [CommandExec](IMPORTANT): settime stop or restart
  Setting hardware clock from system clock
  Mon Sep 11 16:21:23 2023  0.000000 seconds
  settime start or restart
  Setting clock frequency and tick values from nonvolatile memory.
      mode:         16386
  -o  offset:       -221
  -f  frequency:    886544
      maxerror:     195777
      esterror:     326
      status:       1 (PLL)
  -p  timeconstant: 10
      precision:    1
      tolerance:    32768000
  -t  tick:         10000
      time.tv_sec:  1694449283
      time.tv_usec: 749908
      return value: 0 (clock synchronized)
  ping returned from NTP server: 216.239.35.4
  45178 58884.957   43040.0      0.0    -648.5     91.6    886544
  Time set from NTP server: 216.239.35.4
  Setting hardware clock from system clock
  Mon Sep 11 16:21:25 2023  0.000000 seconds
  NTPD already running.
  
2023-09-11T16:21:34.156Z,1694449294.156 [CommandExec](IMPORTANT): got command 
2023-09-11T16:21:34.157Z,1694449294.157 [CommandExec](FAULT): Incomplete syntax. Try: help
2023-09-11T16:21:44.968Z,1694449304.968 [SBIT](IMPORTANT): SBIT PASSED
2023-09-11T16:21:44.969Z,1694449304.969 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-09-11T16:21:44.969Z,1694449304.969 [SBIT](IMPORTANT): AMEcho.loadAtStartup=0 bool;

2023-09-11T16:21:44.970Z,1694449304.970 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=20 count;

2023-09-11T16:21:44.970Z,1694449304.970 [SBIT](IMPORTANT): BackseatComponent.loadAtStartup=1 bool;

2023-09-11T16:21:44.970Z,1694449304.970 [SBIT](IMPORTANT): BackseatComponent.simulateHardware=1 bool;

2023-09-11T16:21:44.970Z,1694449304.970 [SBIT](IMPORTANT): CANONSampler.loadAtStartup=1 bool;

2023-09-11T16:21:44.970Z,1694449304.970 [SBIT](IMPORTANT): CBIT.runElevOffsetCalc=1 bool;

2023-09-11T16:21:44.970Z,1694449304.970 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;

2023-09-11T16:21:44.970Z,1694449304.970 [SBIT](IMPORTANT): RudderServo.offsetAngle=0 degree;

2023-09-11T16:21:44.970Z,1694449304.970 [SBIT](IMPORTANT): Sonardyne_Nano.loadAtStartup=0 bool;

2023-09-11T16:21:44.971Z,1694449304.971 [SBIT](IMPORTANT): ThrusterServo.currLimit=50 percent;

2023-09-11T16:21:44.971Z,1694449304.971 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=301.364504 cubic_centimeter;

2023-09-11T16:21:44.971Z,1694449304.971 [SBIT](IMPORTANT): VerticalControl.massDefault=-8.504934 millimeter;

2023-09-11T16:21:45.342Z,1694449305.342 [MissionManager](IMPORTANT): Started mission Startup
2023-09-11T16:21:45.342Z,1694449305.342 [Startup] Running Loop=1
2023-09-11T16:21:45.342Z,1694449305.342 [Startup](DEBUG): Aggregate::initialize Startup
2023-09-11T16:21:45.343Z,1694449305.343 [Startup:A.GoToSurface] Running Loop=1
2023-09-11T16:21:45.343Z,1694449305.343 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-09-11T16:21:45.343Z,1694449305.343 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-09-11T16:21:45.344Z,1694449305.344 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-09-11T16:21:45.344Z,1694449305.344 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-09-11T16:21:45.345Z,1694449305.345 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-09-11T16:21:45.345Z,1694449305.345 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-09-11T16:21:45.346Z,1694449305.346 [Startup:StartupSatComms] Running Loop=1
2023-09-11T16:21:45.346Z,1694449305.346 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-09-11T16:21:45.346Z,1694449305.346 [Startup:StartupSatComms:A] Running Loop=1
2023-09-11T16:21:45.714Z,1694449305.714 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-09-11T16:22:34.973Z,1694449354.973 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T16:22:45.493Z,1694449365.493 [Startup:StartupSatComms:A](INFO): Timed out from 2023-09-11T16:21:45.3Z
2023-09-11T16:22:45.493Z,1694449365.493 [Startup:StartupSatComms:A] Stopped
2023-09-11T16:22:45.493Z,1694449365.493 [Startup:StartupSatComms:B] Running Loop=1
2023-09-11T16:22:45.898Z,1694449365.898 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-09-11T16:22:46.302Z,1694449366.302 [Startup:StartupSatComms:B] Stopped
2023-09-11T16:22:46.302Z,1694449366.302 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-09-11T16:22:46.302Z,1694449366.302 [Startup:StartupSatComms] Stopped
2023-09-11T16:22:46.302Z,1694449366.302 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-09-11T16:22:46.303Z,1694449366.303 [Startup](INFO): Completed Startup
2023-09-11T16:22:46.303Z,1694449366.303 [MissionManager](INFO): Startup is completed.
2023-09-11T16:22:46.303Z,1694449366.303 [MissionManager](INFO): Uninitializing Mission Startup
2023-09-11T16:22:46.303Z,1694449366.303 [Startup] Stopped
2023-09-11T16:22:46.303Z,1694449366.303 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-09-11T16:22:46.303Z,1694449366.303 [Startup:A.GoToSurface] Stopped
2023-09-11T16:22:46.303Z,1694449366.303 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-09-11T16:22:46.714Z,1694449366.714 [MissionManager](IMPORTANT): Started mission Default
2023-09-11T16:22:46.714Z,1694449366.714 [Default] Running Loop=1
2023-09-11T16:22:46.714Z,1694449366.714 [Default](DEBUG): Aggregate::initialize Default
2023-09-11T16:22:46.714Z,1694449366.714 [Default:B.GoToSurface] Running Loop=1
2023-09-11T16:22:46.714Z,1694449366.714 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-09-11T16:22:46.715Z,1694449366.715 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-09-11T16:22:46.715Z,1694449366.715 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-09-11T16:22:46.715Z,1694449366.715 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-09-11T16:22:46.716Z,1694449366.716 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-09-11T16:22:46.716Z,1694449366.716 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-09-11T16:22:46.716Z,1694449366.716 [Default:A.Wait] Running Loop=1
2023-09-11T16:22:46.716Z,1694449366.716 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-09-11T16:22:48.709Z,1694449368.709 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T16:22:56.405Z,1694449376.405 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2023-09-11T16:22:56.405Z,1694449376.405 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-09-11T16:22:56.415Z,1694449376.415 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-09-11T16:22:56.829Z,1694449376.829 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-09-11T16:22:56.829Z,1694449376.829 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2023-09-11T16:23:00.063Z,1694449380.063 [Default:A.Wait](INFO): Done Waiting.
2023-09-11T16:23:00.063Z,1694449380.063 [Default:A.Wait] Stopped
2023-09-11T16:23:00.063Z,1694449380.063 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T16:23:00.463Z,1694449380.463 [Default:CheckIn] Running Loop=1
2023-09-11T16:23:00.463Z,1694449380.463 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T16:23:00.463Z,1694449380.463 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T16:23:00.842Z,1694449380.842 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-09-11T16:23:02.041Z,1694449382.041 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T16:23:15.776Z,1694449395.776 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T16:23:29.917Z,1694449409.917 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T16:23:43.654Z,1694449423.654 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T16:23:57.793Z,1694449437.793 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T16:24:11.528Z,1694449451.528 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T16:24:25.265Z,1694449465.265 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T16:24:37.821Z,1694449477.821 [CommandExec](IMPORTANT): got command burn on
2023-09-11T16:24:37.821Z,1694449477.821 [CommandExec](IMPORTANT): Activating dropweight wire
2023-09-11T16:24:39.001Z,1694449479.001 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T16:24:41.985Z,1694449481.985 [CommandExec](IMPORTANT): got command burn off
2023-09-11T16:24:41.985Z,1694449481.985 [CommandExec](IMPORTANT): Deactivating dropweight wire
2023-09-11T16:24:54.353Z,1694449494.353 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T16:25:10.109Z,1694449510.109 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T16:25:25.460Z,1694449525.460 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T16:25:35.941Z,1694449535.941 [CommandExec](IMPORTANT): got command failComponent
2023-09-11T16:25:35.941Z,1694449535.941 [CommandExec](IMPORTANT): Failed components:
2023-09-11T16:25:35.941Z,1694449535.941 [CommandExec](IMPORTANT): No failed Components.
2023-09-11T16:25:38.807Z,1694449538.807 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-09-11T16:25:41.621Z,1694449541.621 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T16:25:45.614Z,1694449545.614 [CommandExec](IMPORTANT): got command get Onboard.Humidity
2023-09-11T16:25:45.615Z,1694449545.615 [CommandExec](IMPORTANT): Onboard.Humidity 12.489318 %
2023-09-11T16:25:56.345Z,1694449556.345 [CommandExec](IMPORTANT): got command get Onboard.Pressure
2023-09-11T16:25:56.346Z,1694449556.346 [CommandExec](IMPORTANT): Onboard.Pressure 67100.054688 Pa
2023-09-11T16:25:56.974Z,1694449556.974 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T16:25:57.397Z,1694449557.397 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2023-09-11T16:25:57.397Z,1694449557.397 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-09-11T16:25:57.408Z,1694449557.408 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-09-11T16:25:57.823Z,1694449557.823 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-09-11T16:25:57.823Z,1694449557.823 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2023-09-11T16:26:11.926Z,1694449571.926 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T16:26:26.869Z,1694449586.869 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T16:26:31.645Z,1694449591.645 [CommandExec](IMPORTANT): got command failComponent
2023-09-11T16:26:31.645Z,1694449591.645 [CommandExec](IMPORTANT): Failed components:
2023-09-11T16:26:31.645Z,1694449591.645 [CommandExec](IMPORTANT): No failed Components.
2023-09-11T16:26:42.221Z,1694449602.221 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T16:26:57.578Z,1694449617.578 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T16:27:12.117Z,1694449632.117 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2023-09-11T16:27:18.588Z,1694449638.588 [BPC1](INFO): Calculating totals. Valid battery stick count: 38. Valid reserve battery stick count: 5.
2023-09-11T16:27:18.591Z,1694449638.591 [BPC1](INFO): Received data from all battery sticks.
2023-09-11T16:28:00.621Z,1694449680.621 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-09-11T16:23:00.5Z
2023-09-11T16:28:00.621Z,1694449680.621 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T16:28:00.621Z,1694449680.621 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T16:28:01.038Z,1694449681.038 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-09-11T16:28:07.597Z,1694449687.597 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20230911T161945/Courier0000.lzma
2023-09-11T16:28:08.598Z,1694449688.598 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0000.lzma.bak
2023-09-11T16:28:08.598Z,1694449688.598 [DataOverHttps](INFO): SBD MOMSN=18760579
2023-09-11T16:28:58.398Z,1694449738.398 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2023-09-11T16:28:58.398Z,1694449738.398 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-09-11T16:28:58.408Z,1694449738.408 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-09-11T16:28:58.823Z,1694449738.823 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-09-11T16:28:58.823Z,1694449738.823 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2023-09-11T16:29:19.169Z,1694449759.169 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-09-11T16:29:50.320Z,1694449790.320 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-09-11T16:29:57.375Z,1694449797.375 [Power24vConverter](INFO): Powering down.
2023-09-11T16:30:21.444Z,1694449821.444 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-09-11T16:30:38.182Z,1694449838.182 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-09-11T16:30:38.182Z,1694449838.182 [NAL9602] Data Fault, FailCount= 1
2023-09-11T16:30:38.182Z,1694449838.182 [NAL9602](ERROR): Data Fault
2023-09-11T16:30:38.198Z,1694449838.198 [CBIT](ERROR): Data Fault in component: NAL9602
2023-09-11T16:30:38.574Z,1694449838.574 [NAL9602](INFO): Powering down
2023-09-11T16:30:39.405Z,1694449839.405 [CBIT](INFO): Clearing failed state for component NAL9602
2023-09-11T16:30:39.405Z,1694449839.405 [NAL9602] No Fault, FailCount= 1
2023-09-11T16:30:52.568Z,1694449852.568 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-09-11T16:31:08.882Z,1694449868.882 [NAL9602](INFO): Powering up NAL9602
2023-09-11T16:31:17.677Z,1694449877.677 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.963440
2023-09-11T16:31:19.790Z,1694449879.790 [NAL9602](INFO): NAL9602 initialized
2023-09-11T16:31:48.808Z,1694449908.808 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-09-11T16:31:59.401Z,1694449919.401 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2023-09-11T16:31:59.401Z,1694449919.401 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-09-11T16:31:59.432Z,1694449919.432 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-09-11T16:31:59.795Z,1694449919.795 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-09-11T16:31:59.795Z,1694449919.795 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2023-09-11T16:32:19.944Z,1694449939.944 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-09-11T16:32:51.068Z,1694449971.068 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-09-11T16:33:22.220Z,1694450002.220 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-09-11T16:33:53.348Z,1694450033.348 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-09-11T16:34:24.472Z,1694450064.472 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-09-11T16:34:55.605Z,1694450095.605 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-09-11T16:35:00.373Z,1694450100.373 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2023-09-11T16:35:00.373Z,1694450100.373 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-09-11T16:35:00.384Z,1694450100.384 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-09-11T16:35:00.795Z,1694450100.795 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-09-11T16:35:00.795Z,1694450100.795 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2023-09-11T16:35:26.729Z,1694450126.729 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-09-11T16:35:45.224Z,1694450145.224 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163544.00,A,3648.15926,N,12147.28716,W,2.877,150.40,110923,,,A*74
2023-09-11T16:35:45.227Z,1694450145.227 [NAL9602](INFO): GPS fix at 20230911T163544: (36.802654, -121.788119)
2023-09-11T16:35:56.676Z,1694450156.676 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003094
2023-09-11T16:36:05.012Z,1694450165.012 [DataOverHttps](INFO): Sending 167 bytes from file Logs/20230911T161945/Courier0004.lzma
2023-09-11T16:36:06.014Z,1694450166.014 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0004.lzma.bak
2023-09-11T16:36:06.014Z,1694450166.014 [DataOverHttps](INFO): SBD MOMSN=18760584
2023-09-11T16:36:24.446Z,1694450184.446 [DataOverHttps](INFO): Sending 1273 bytes from file Logs/20230911T161945/Express0001.lzma
2023-09-11T16:36:25.446Z,1694450185.446 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0001.lzma.bak
2023-09-11T16:36:25.446Z,1694450185.446 [DataOverHttps](INFO): SBD MOMSN=18760586
2023-09-11T16:36:27.697Z,1694450187.697 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T16:36:41.508Z,1694450201.508 [DataOverHttps](INFO): Sending 376 bytes from file Logs/20230911T161945/Express0005.lzma
2023-09-11T16:36:42.511Z,1694450202.511 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0005.lzma.bak
2023-09-11T16:36:42.511Z,1694450202.511 [DataOverHttps](INFO): SBD MOMSN=18760618
2023-09-11T16:36:43.882Z,1694450203.882 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T16:36:43.882Z,1694450203.882 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T16:36:43.882Z,1694450203.882 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T16:41:44.292Z,1694450504.292 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T16:41:44.292Z,1694450504.292 [Default:CheckIn:C.Wait] Stopped
2023-09-11T16:41:44.292Z,1694450504.292 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T16:41:44.292Z,1694450504.292 [Default:CheckIn:D] Running Loop=1
2023-09-11T16:41:44.687Z,1694450504.687 [Default:CheckIn:D] Stopped
2023-09-11T16:41:44.687Z,1694450504.687 [Default:CheckIn:E] Running Loop=1
2023-09-11T16:41:45.113Z,1694450505.113 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.966215 min 
2023-09-11T16:41:45.113Z,1694450505.113 [Default:CheckIn:E] Stopped
2023-09-11T16:41:45.113Z,1694450505.113 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T16:41:45.113Z,1694450505.113 [Default:CheckIn] Stopped
2023-09-11T16:41:45.114Z,1694450505.114 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T16:41:45.114Z,1694450505.114 [Default:CheckIn](INFO): Running loop #2
2023-09-11T16:41:45.114Z,1694450505.114 [Default:CheckIn] Running Loop=2
2023-09-11T16:41:45.114Z,1694450505.114 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T16:41:45.114Z,1694450505.114 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T16:41:47.098Z,1694450507.098 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164146.00,A,3648.14000,N,12147.22759,W,0.039,73.35,110923,,,A*4A
2023-09-11T16:41:47.100Z,1694450507.100 [NAL9602](INFO): GPS fix at 20230911T164146: (36.802333, -121.787126)
2023-09-11T16:41:47.111Z,1694450507.111 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T16:41:47.111Z,1694450507.111 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T16:41:54.020Z,1694450514.020 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20230911T161945/Courier0007.lzma
2023-09-11T16:41:55.059Z,1694450515.059 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0007.lzma.bak
2023-09-11T16:41:55.060Z,1694450515.060 [DataOverHttps](INFO): SBD MOMSN=18760637
2023-09-11T16:42:01.243Z,1694450521.243 [NAL9602](INFO): SBD MO Status=0, MOMSN=44597, MT Status=0, MTMSN=0
2023-09-11T16:42:01.243Z,1694450521.243 [NAL9602](INFO): No messages in MT queue
2023-09-11T16:42:10.684Z,1694450530.684 [DataOverHttps](INFO): Sending 331 bytes from file Logs/20230911T161945/Express0008.lzma
2023-09-11T16:42:11.686Z,1694450531.686 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0008.lzma.bak
2023-09-11T16:42:11.686Z,1694450531.686 [DataOverHttps](INFO): SBD MOMSN=18760640
2023-09-11T16:42:12.963Z,1694450532.963 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T16:42:12.963Z,1694450532.963 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T16:42:12.963Z,1694450532.963 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T16:42:31.947Z,1694450551.947 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T16:46:57.546Z,1694450817.546 [DataOverHttps](IMPORTANT): SBD MTMSN=20230911T164656
2023-09-11T16:47:05.013Z,1694450825.013 [DataOverHttps](INFO): Received command: ibit
2023-09-11T16:47:05.048Z,1694450825.048 [CommandExec](IMPORTANT): got command ibit
2023-09-11T16:47:05.289Z,1694450825.289 [IBIT](IMPORTANT): Beginning Initiated BIT
2023-09-11T16:47:05.290Z,1694450825.290 [IBIT](IMPORTANT): Beginning control surface checks.
2023-09-11T16:47:05.293Z,1694450825.293 [CBIT](IMPORTANT): Beginning ground fault scan
2023-09-11T16:47:06.895Z,1694450826.895 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164706.00,A,3648.14135,N,12147.22855,W,0.019,73.35,110923,,,A*4E
2023-09-11T16:47:06.897Z,1694450826.897 [NAL9602](INFO): GPS fix at 20230911T164706: (36.802356, -121.787143)
2023-09-11T16:47:08.186Z,1694450828.186 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2023-09-11T16:47:16.200Z,1694450836.200 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2023-09-11T16:47:16.608Z,1694450836.608 [CBIT](IMPORTANT): Beginning ground fault scan
2023-09-11T16:47:19.428Z,1694450839.428 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2023-09-11T16:47:27.589Z,1694450847.589 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2023-09-11T16:47:28.025Z,1694450848.025 [CBIT](IMPORTANT): Beginning ground fault scan
2023-09-11T16:47:29.511Z,1694450849.511 [NAL9602](INFO): SBD MO Status=0, MOMSN=44598, MT Status=0, MTMSN=0
2023-09-11T16:47:29.511Z,1694450849.511 [NAL9602](INFO): No messages in MT queue
2023-09-11T16:47:30.727Z,1694450850.727 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164730.00,A,3648.14165,N,12147.22865,W,0.097,73.35,110923,,,A*4B
2023-09-11T16:47:30.730Z,1694450850.730 [NAL9602](INFO): GPS fix at 20230911T164730: (36.802361, -121.787144)
2023-09-11T16:47:30.821Z,1694450850.821 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2023-09-11T16:47:33.955Z,1694450853.955 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164733.00,A,3648.14170,N,12147.22861,W,0.019,73.35,110923,,,A*4E
2023-09-11T16:47:33.958Z,1694450853.958 [NAL9602](INFO): GPS fix at 20230911T164733: (36.802362, -121.787143)
2023-09-11T16:47:36.792Z,1694450856.792 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164736.00,A,3648.14185,N,12147.22860,W,0.078,73.35,110923,,,A*47
2023-09-11T16:47:36.795Z,1694450856.795 [NAL9602](INFO): GPS fix at 20230911T164736: (36.802364, -121.787143)
2023-09-11T16:47:38.888Z,1694450858.888 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.002151
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): -0.001874
CHAN A3 (5V): -0.001312
CHAN B0 (3.3V): 0.000093
CHAN B1 (3.15aV): -0.000434
CHAN B2 (3.15bV): -0.000061
CHAN B3 (GND): 0.000170
OPEN: -0.000423
Full Scale: +/- 1 mA
2023-09-11T16:47:40.014Z,1694450860.014 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164739.00,A,3648.14195,N,12147.22863,W,0.019,73.35,110923,,,A*4D
2023-09-11T16:47:40.017Z,1694450860.017 [NAL9602](INFO): GPS fix at 20230911T164739: (36.802366, -121.787144)
2023-09-11T16:47:42.843Z,1694450862.843 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164742.00,A,3648.14201,N,12147.22865,W,0.019,73.35,110923,,,A*49
2023-09-11T16:47:42.845Z,1694450862.845 [NAL9602](INFO): GPS fix at 20230911T164742: (36.802367, -121.787144)
2023-09-11T16:47:46.079Z,1694450866.079 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164745.00,A,3648.14202,N,12147.22863,W,0.000,73.35,110923,,,A*43
2023-09-11T16:47:46.081Z,1694450866.081 [NAL9602](INFO): GPS fix at 20230911T164745: (36.802367, -121.787144)
2023-09-11T16:47:48.903Z,1694450868.903 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164748.00,A,3648.14202,N,12147.22862,W,0.000,73.35,110923,,,A*4F
2023-09-11T16:47:48.906Z,1694450868.906 [NAL9602](INFO): GPS fix at 20230911T164748: (36.802367, -121.787144)
2023-09-11T16:47:51.345Z,1694450871.345 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 2
Latitude: 36.802368 Longitude: -121.787140
2023-09-11T16:47:51.766Z,1694450871.766 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.650999
2023-09-11T16:47:51.767Z,1694450871.767 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2023-09-11T16:47:51.767Z,1694450871.767 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2023-09-11T16:47:52.139Z,1694450872.139 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164751.00,A,3648.14198,N,12147.22862,W,0.078,73.35,110923,,,A*48
2023-09-11T16:47:52.141Z,1694450872.141 [NAL9602](INFO): GPS fix at 20230911T164751: (36.802366, -121.787144)
2023-09-11T16:47:52.174Z,1694450872.174 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2023-09-11T16:47:52.174Z,1694450872.174 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2023-09-11T16:47:52.174Z,1694450872.174 [IBIT](IMPORTANT): Pressure:9.706940 PSI
2023-09-11T16:47:52.175Z,1694450872.175 [IBIT](IMPORTANT): Humidity:12.312294 %
2023-09-11T16:47:52.599Z,1694450872.599 [IBIT](IMPORTANT): Vehicle Pitch:-0.482365 degrees
2023-09-11T16:47:52.599Z,1694450872.599 [IBIT](IMPORTANT): Vehicle  Roll:2.841682 degrees
2023-09-11T16:47:52.599Z,1694450872.599 [IBIT](IMPORTANT): Vehicle  Heading:217.301071 degrees
2023-09-11T16:47:52.963Z,1694450872.963 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2023-09-11T16:47:52.963Z,1694450872.963 [IBIT](IMPORTANT): buoyancyNeutral: 301.364502 cc
2023-09-11T16:47:52.964Z,1694450872.964 [IBIT](IMPORTANT): massDefault: -0.850493 cm
2023-09-11T16:47:52.964Z,1694450872.964 [IBIT](IMPORTANT): stopDepth: 250.000000 m
2023-09-11T16:47:52.965Z,1694450872.965 [IBIT](IMPORTANT): abortDepth: 270.000000 m
2023-09-11T16:47:52.965Z,1694450872.965 [IBIT](IMPORTANT): IBIT PASSED
2023-09-11T16:47:53.381Z,1694450873.381 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T16:47:53.381Z,1694450873.381 [Default:CheckIn:C.Wait] Stopped
2023-09-11T16:47:53.381Z,1694450873.381 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T16:47:53.381Z,1694450873.381 [Default:CheckIn:D] Running Loop=1
2023-09-11T16:47:53.771Z,1694450873.771 [Default:CheckIn:D] Stopped
2023-09-11T16:47:53.771Z,1694450873.771 [Default:CheckIn:E] Running Loop=1
2023-09-11T16:47:54.165Z,1694450874.165 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 25.117621 min 
2023-09-11T16:47:54.165Z,1694450874.165 [Default:CheckIn:E] Stopped
2023-09-11T16:47:54.165Z,1694450874.165 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T16:47:54.165Z,1694450874.165 [Default:CheckIn] Stopped
2023-09-11T16:47:54.165Z,1694450874.165 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T16:47:54.165Z,1694450874.165 [Default:CheckIn](INFO): Running loop #3
2023-09-11T16:47:54.165Z,1694450874.165 [Default:CheckIn] Running Loop=3
2023-09-11T16:47:54.165Z,1694450874.165 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T16:47:54.166Z,1694450874.166 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T16:47:56.175Z,1694450876.175 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164755.00,A,3648.14196,N,12147.22860,W,0.058,73.35,110923,,,A*42
2023-09-11T16:47:56.177Z,1694450876.177 [NAL9602](INFO): GPS fix at 20230911T164755: (36.802366, -121.787143)
2023-09-11T16:47:56.209Z,1694450876.209 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T16:47:56.209Z,1694450876.209 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T16:48:03.471Z,1694450883.471 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230911T161945/Courier0010.lzma
2023-09-11T16:48:04.474Z,1694450884.474 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0010.lzma.bak
2023-09-11T16:48:04.474Z,1694450884.474 [DataOverHttps](INFO): SBD MOMSN=18760648
2023-09-11T16:48:22.169Z,1694450902.169 [DataOverHttps](INFO): Sending 824 bytes from file Logs/20230911T161945/Express0011.lzma
2023-09-11T16:48:23.170Z,1694450903.170 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0011.lzma.bak
2023-09-11T16:48:23.170Z,1694450903.170 [DataOverHttps](INFO): SBD MOMSN=18760651
2023-09-11T16:48:28.513Z,1694450908.513 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T16:48:39.947Z,1694450919.947 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20230911T161945/Express0014.lzma
2023-09-11T16:48:40.950Z,1694450920.950 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0014.lzma.bak
2023-09-11T16:48:40.950Z,1694450920.950 [DataOverHttps](INFO): SBD MOMSN=18760679
2023-09-11T16:48:42.263Z,1694450922.263 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T16:48:42.263Z,1694450922.263 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T16:48:42.263Z,1694450922.263 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T16:53:42.996Z,1694451222.996 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T16:53:42.996Z,1694451222.996 [Default:CheckIn:C.Wait] Stopped
2023-09-11T16:53:42.996Z,1694451222.996 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T16:53:42.996Z,1694451222.996 [Default:CheckIn:D] Running Loop=1
2023-09-11T16:53:43.387Z,1694451223.387 [Default:CheckIn:D] Stopped
2023-09-11T16:53:43.387Z,1694451223.387 [Default:CheckIn:E] Running Loop=1
2023-09-11T16:53:43.796Z,1694451223.796 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 30.944543 min 
2023-09-11T16:53:43.796Z,1694451223.796 [Default:CheckIn:E] Stopped
2023-09-11T16:53:43.796Z,1694451223.796 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T16:53:43.797Z,1694451223.797 [Default:CheckIn] Stopped
2023-09-11T16:53:43.797Z,1694451223.797 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T16:53:43.797Z,1694451223.797 [Default:CheckIn](INFO): Running loop #4
2023-09-11T16:53:43.797Z,1694451223.797 [Default:CheckIn] Running Loop=4
2023-09-11T16:53:43.797Z,1694451223.797 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T16:53:43.797Z,1694451223.797 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T16:53:45.807Z,1694451225.807 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165345.00,A,3648.14142,N,12147.22850,W,0.039,73.35,110923,,,A*4B
2023-09-11T16:53:45.809Z,1694451225.809 [NAL9602](INFO): GPS fix at 20230911T165345: (36.802357, -121.787142)
2023-09-11T16:53:45.819Z,1694451225.819 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T16:53:45.819Z,1694451225.819 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T16:53:52.511Z,1694451232.511 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230911T161945/Courier0016.lzma
2023-09-11T16:53:53.514Z,1694451233.514 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0016.lzma.bak
2023-09-11T16:53:53.514Z,1694451233.514 [DataOverHttps](INFO): SBD MOMSN=18760682
2023-09-11T16:54:09.224Z,1694451249.224 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230911T161945/Express0017.lzma
2023-09-11T16:54:10.226Z,1694451250.226 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0017.lzma.bak
2023-09-11T16:54:10.226Z,1694451250.226 [DataOverHttps](INFO): SBD MOMSN=18760685
2023-09-11T16:54:11.269Z,1694451251.269 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T16:54:11.269Z,1694451251.269 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T16:54:11.270Z,1694451251.270 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T16:55:26.403Z,1694451326.403 [NAL9602](INFO): SBD MO Status=2, MOMSN=44599, MT Status=2, MTMSN=0
2023-09-11T16:55:26.403Z,1694451326.403 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-11T16:55:53.875Z,1694451353.875 [NAL9602](INFO): SBD MO Status=0, MOMSN=44599, MT Status=0, MTMSN=0
2023-09-11T16:55:53.875Z,1694451353.875 [NAL9602](INFO): No messages in MT queue
2023-09-11T16:56:24.596Z,1694451384.596 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T16:59:11.980Z,1694451551.980 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T16:59:11.980Z,1694451551.980 [Default:CheckIn:C.Wait] Stopped
2023-09-11T16:59:11.980Z,1694451551.980 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T16:59:11.980Z,1694451551.980 [Default:CheckIn:D] Running Loop=1
2023-09-11T16:59:12.397Z,1694451552.397 [Default:CheckIn:D] Stopped
2023-09-11T16:59:12.397Z,1694451552.397 [Default:CheckIn:E] Running Loop=1
2023-09-11T16:59:12.793Z,1694451552.793 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 36.428052 min 
2023-09-11T16:59:12.793Z,1694451552.793 [Default:CheckIn:E] Stopped
2023-09-11T16:59:12.793Z,1694451552.793 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T16:59:12.793Z,1694451552.793 [Default:CheckIn] Stopped
2023-09-11T16:59:12.793Z,1694451552.793 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T16:59:12.794Z,1694451552.794 [Default:CheckIn](INFO): Running loop #5
2023-09-11T16:59:12.794Z,1694451552.794 [Default:CheckIn] Running Loop=5
2023-09-11T16:59:12.794Z,1694451552.794 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T16:59:12.794Z,1694451552.794 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T16:59:14.800Z,1694451554.800 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165914.00,A,3648.14183,N,12147.22811,W,0.058,73.35,110923,,,A*4A
2023-09-11T16:59:14.803Z,1694451554.803 [NAL9602](INFO): GPS fix at 20230911T165914: (36.802364, -121.787135)
2023-09-11T16:59:14.813Z,1694451554.813 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T16:59:14.813Z,1694451554.813 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T16:59:22.103Z,1694451562.103 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230911T161945/Courier0019.lzma
2023-09-11T16:59:23.107Z,1694451563.107 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0019.lzma.bak
2023-09-11T16:59:23.107Z,1694451563.107 [DataOverHttps](INFO): SBD MOMSN=18760689
2023-09-11T16:59:28.535Z,1694451568.535 [NAL9602](INFO): SBD MO Status=0, MOMSN=44600, MT Status=0, MTMSN=0
2023-09-11T16:59:28.535Z,1694451568.535 [NAL9602](INFO): No messages in MT queue
2023-09-11T16:59:38.960Z,1694451578.960 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230911T161945/Express0020.lzma
2023-09-11T16:59:39.962Z,1694451579.962 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0020.lzma.bak
2023-09-11T16:59:39.962Z,1694451579.962 [DataOverHttps](INFO): SBD MOMSN=18760692
2023-09-11T16:59:41.078Z,1694451581.078 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T16:59:41.078Z,1694451581.078 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T16:59:41.078Z,1694451581.078 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T16:59:59.241Z,1694451599.241 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T17:01:50.113Z,1694451710.113 [DataOverHttps](IMPORTANT): SBD MTMSN=20230911T170149
2023-09-11T17:01:57.432Z,1694451717.432 [DataOverHttps](INFO): Received command: ibit
2023-09-11T17:01:57.453Z,1694451717.453 [CommandExec](IMPORTANT): got command ibit
2023-09-11T17:01:57.629Z,1694451717.629 [IBIT](IMPORTANT): Beginning Initiated BIT
2023-09-11T17:01:57.629Z,1694451717.629 [IBIT](IMPORTANT): Beginning control surface checks.
2023-09-11T17:01:57.632Z,1694451717.632 [CBIT](IMPORTANT): Beginning ground fault scan
2023-09-11T17:01:59.232Z,1694451719.232 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170158.00,A,3648.14315,N,12147.22865,W,0.078,73.35,110923,,,A*42
2023-09-11T17:01:59.234Z,1694451719.234 [NAL9602](INFO): GPS fix at 20230911T170158: (36.802386, -121.787144)
2023-09-11T17:02:00.521Z,1694451720.521 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2023-09-11T17:02:08.572Z,1694451728.572 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2023-09-11T17:02:08.943Z,1694451728.943 [CBIT](IMPORTANT): Beginning ground fault scan
2023-09-11T17:02:11.790Z,1694451731.790 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2023-09-11T17:02:19.937Z,1694451739.937 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2023-09-11T17:02:20.377Z,1694451740.377 [CBIT](IMPORTANT): Beginning ground fault scan
2023-09-11T17:02:22.258Z,1694451742.258 [NAL9602](INFO): SBD MO Status=2, MOMSN=44601, MT Status=2, MTMSN=0
2023-09-11T17:02:22.258Z,1694451742.258 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-11T17:02:23.145Z,1694451743.145 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2023-09-11T17:02:31.256Z,1694451751.256 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.002257
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): -0.001953
CHAN A3 (5V): -0.001537
CHAN B0 (3.3V): 0.000243
CHAN B1 (3.15aV): -0.000382
CHAN B2 (3.15bV): 0.000223
CHAN B3 (GND): 0.000617
OPEN: -0.000267
Full Scale: +/- 1 mA
2023-09-11T17:03:13.235Z,1694451793.235 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 1
Latitude: 36.802387 Longitude: -121.787148
2023-09-11T17:03:13.655Z,1694451793.655 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.650999
2023-09-11T17:03:13.655Z,1694451793.655 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2023-09-11T17:03:13.655Z,1694451793.655 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2023-09-11T17:03:14.021Z,1694451794.021 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2023-09-11T17:03:14.022Z,1694451794.022 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2023-09-11T17:03:14.022Z,1694451794.022 [IBIT](IMPORTANT): Pressure:9.670396 PSI
2023-09-11T17:03:14.022Z,1694451794.022 [IBIT](IMPORTANT): Humidity:12.232939 %
2023-09-11T17:03:14.437Z,1694451794.437 [IBIT](IMPORTANT): Vehicle Pitch:-0.477272 degrees
2023-09-11T17:03:14.438Z,1694451794.438 [IBIT](IMPORTANT): Vehicle  Roll:2.835842 degrees
2023-09-11T17:03:14.438Z,1694451794.438 [IBIT](IMPORTANT): Vehicle  Heading:217.321899 degrees
2023-09-11T17:03:14.829Z,1694451794.829 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2023-09-11T17:03:14.829Z,1694451794.829 [IBIT](IMPORTANT): buoyancyNeutral: 301.364502 cc
2023-09-11T17:03:14.830Z,1694451794.830 [IBIT](IMPORTANT): massDefault: -0.850493 cm
2023-09-11T17:03:14.830Z,1694451794.830 [IBIT](IMPORTANT): stopDepth: 250.000000 m
2023-09-11T17:03:14.830Z,1694451794.830 [IBIT](IMPORTANT): abortDepth: 270.000000 m
2023-09-11T17:03:14.830Z,1694451794.830 [IBIT](IMPORTANT): IBIT PASSED
2023-09-11T17:03:58.053Z,1694451838.053 [NAL9602](INFO): SBD MO Status=2, MOMSN=44601, MT Status=2, MTMSN=0
2023-09-11T17:03:58.053Z,1694451838.053 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-11T17:04:15.824Z,1694451855.824 [NAL9602](INFO): SBD MO Status=0, MOMSN=44601, MT Status=0, MTMSN=0
2023-09-11T17:04:15.825Z,1694451855.825 [NAL9602](INFO): No messages in MT queue
2023-09-11T17:04:41.687Z,1694451881.687 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T17:04:41.687Z,1694451881.687 [Default:CheckIn:C.Wait] Stopped
2023-09-11T17:04:41.687Z,1694451881.687 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T17:04:41.687Z,1694451881.687 [Default:CheckIn:D] Running Loop=1
2023-09-11T17:04:42.086Z,1694451882.086 [Default:CheckIn:D] Stopped
2023-09-11T17:04:42.086Z,1694451882.086 [Default:CheckIn:E] Running Loop=1
2023-09-11T17:04:42.500Z,1694451882.500 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 41.922868 min 
2023-09-11T17:04:42.500Z,1694451882.500 [Default:CheckIn:E] Stopped
2023-09-11T17:04:42.500Z,1694451882.500 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T17:04:42.500Z,1694451882.500 [Default:CheckIn] Stopped
2023-09-11T17:04:42.501Z,1694451882.501 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T17:04:42.501Z,1694451882.501 [Default:CheckIn](INFO): Running loop #6
2023-09-11T17:04:42.501Z,1694451882.501 [Default:CheckIn] Running Loop=6
2023-09-11T17:04:42.501Z,1694451882.501 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T17:04:42.501Z,1694451882.501 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T17:04:44.507Z,1694451884.507 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170443.00,A,3648.14059,N,12147.22856,W,0.000,73.35,110923,,,A*49
2023-09-11T17:04:44.509Z,1694451884.509 [NAL9602](INFO): GPS fix at 20230911T170443: (36.802343, -121.787143)
2023-09-11T17:04:44.520Z,1694451884.520 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T17:04:44.520Z,1694451884.520 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T17:04:55.216Z,1694451895.216 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230911T161945/Courier0022.lzma
2023-09-11T17:04:56.218Z,1694451896.218 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0022.lzma.bak
2023-09-11T17:04:56.218Z,1694451896.218 [DataOverHttps](INFO): SBD MOMSN=18760698
2023-09-11T17:05:12.025Z,1694451912.025 [DataOverHttps](INFO): Sending 798 bytes from file Logs/20230911T161945/Express0023.lzma
2023-09-11T17:05:13.026Z,1694451913.026 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0023.lzma.bak
2023-09-11T17:05:13.026Z,1694451913.026 [DataOverHttps](INFO): SBD MOMSN=18760701
2023-09-11T17:05:16.493Z,1694451916.493 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T17:05:28.812Z,1694451928.812 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20230911T161945/Express0026.lzma
2023-09-11T17:05:29.814Z,1694451929.814 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0026.lzma.bak
2023-09-11T17:05:29.814Z,1694451929.814 [DataOverHttps](INFO): SBD MOMSN=18760729
2023-09-11T17:05:31.046Z,1694451931.046 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T17:05:31.046Z,1694451931.046 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T17:05:31.047Z,1694451931.047 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T17:10:31.652Z,1694452231.652 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T17:10:31.652Z,1694452231.652 [Default:CheckIn:C.Wait] Stopped
2023-09-11T17:10:31.652Z,1694452231.652 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T17:10:31.652Z,1694452231.652 [Default:CheckIn:D] Running Loop=1
2023-09-11T17:10:32.049Z,1694452232.049 [Default:CheckIn:D] Stopped
2023-09-11T17:10:32.049Z,1694452232.049 [Default:CheckIn:E] Running Loop=1
2023-09-11T17:10:32.454Z,1694452232.454 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 47.755587 min 
2023-09-11T17:10:32.454Z,1694452232.454 [Default:CheckIn:E] Stopped
2023-09-11T17:10:32.454Z,1694452232.454 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T17:10:32.454Z,1694452232.454 [Default:CheckIn] Stopped
2023-09-11T17:10:32.454Z,1694452232.454 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T17:10:32.455Z,1694452232.455 [Default:CheckIn](INFO): Running loop #7
2023-09-11T17:10:32.455Z,1694452232.455 [Default:CheckIn] Running Loop=7
2023-09-11T17:10:32.455Z,1694452232.455 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T17:10:32.455Z,1694452232.455 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T17:10:34.471Z,1694452234.471 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171033.00,A,3648.13933,N,12147.22698,W,0.019,73.35,110923,,,A*4D
2023-09-11T17:10:34.474Z,1694452234.474 [NAL9602](INFO): GPS fix at 20230911T171033: (36.802322, -121.787116)
2023-09-11T17:10:34.484Z,1694452234.484 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T17:10:34.484Z,1694452234.484 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T17:10:42.088Z,1694452242.088 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230911T161945/Courier0028.lzma
2023-09-11T17:10:43.090Z,1694452243.090 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0028.lzma.bak
2023-09-11T17:10:43.090Z,1694452243.090 [DataOverHttps](INFO): SBD MOMSN=18760732
2023-09-11T17:10:51.439Z,1694452251.439 [NAL9602](INFO): SBD MO Status=0, MOMSN=44602, MT Status=0, MTMSN=0
2023-09-11T17:10:51.439Z,1694452251.439 [NAL9602](INFO): No messages in MT queue
2023-09-11T17:10:58.792Z,1694452258.792 [DataOverHttps](INFO): Sending 127 bytes from file Logs/20230911T161945/Express0029.lzma
2023-09-11T17:10:59.794Z,1694452259.794 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0029.lzma.bak
2023-09-11T17:10:59.794Z,1694452259.794 [DataOverHttps](INFO): SBD MOMSN=18760735
2023-09-11T17:11:01.142Z,1694452261.142 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T17:11:01.142Z,1694452261.142 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T17:11:01.143Z,1694452261.143 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T17:11:22.145Z,1694452282.145 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T17:16:01.718Z,1694452561.718 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T17:16:01.719Z,1694452561.719 [Default:CheckIn:C.Wait] Stopped
2023-09-11T17:16:01.719Z,1694452561.719 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T17:16:01.719Z,1694452561.719 [Default:CheckIn:D] Running Loop=1
2023-09-11T17:16:02.120Z,1694452562.120 [Default:CheckIn:D] Stopped
2023-09-11T17:16:02.120Z,1694452562.120 [Default:CheckIn:E] Running Loop=1
2023-09-11T17:16:02.531Z,1694452562.531 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 53.256767 min 
2023-09-11T17:16:02.531Z,1694452562.531 [Default:CheckIn:E] Stopped
2023-09-11T17:16:02.531Z,1694452562.531 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T17:16:02.531Z,1694452562.531 [Default:CheckIn] Stopped
2023-09-11T17:16:02.532Z,1694452562.532 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T17:16:02.532Z,1694452562.532 [Default:CheckIn](INFO): Running loop #8
2023-09-11T17:16:02.532Z,1694452562.532 [Default:CheckIn] Running Loop=8
2023-09-11T17:16:02.532Z,1694452562.532 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T17:16:02.532Z,1694452562.532 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T17:16:04.535Z,1694452564.535 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171603.00,A,3648.14183,N,12147.23087,W,0.019,0.00,110923,,,A*77
2023-09-11T17:16:04.537Z,1694452564.537 [NAL9602](INFO): GPS fix at 20230911T171603: (36.802364, -121.787181)
2023-09-11T17:16:04.577Z,1694452564.577 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T17:16:04.578Z,1694452564.578 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T17:16:11.959Z,1694452571.959 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230911T161945/Courier0031.lzma
2023-09-11T17:16:12.962Z,1694452572.962 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0031.lzma.bak
2023-09-11T17:16:12.962Z,1694452572.962 [DataOverHttps](INFO): SBD MOMSN=18760747
2023-09-11T17:16:30.015Z,1694452590.015 [NAL9602](INFO): SBD MO Status=0, MOMSN=44603, MT Status=0, MTMSN=0
2023-09-11T17:16:30.015Z,1694452590.015 [NAL9602](INFO): No messages in MT queue
2023-09-11T17:16:31.964Z,1694452591.964 [DataOverHttps](INFO): Sending 127 bytes from file Logs/20230911T161945/Express0032.lzma
2023-09-11T17:16:32.966Z,1694452592.966 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0032.lzma.bak
2023-09-11T17:16:32.966Z,1694452592.966 [DataOverHttps](INFO): SBD MOMSN=18760750
2023-09-11T17:16:34.088Z,1694452594.088 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T17:16:34.088Z,1694452594.088 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T17:16:34.088Z,1694452594.088 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T17:17:00.717Z,1694452620.717 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T17:21:34.648Z,1694452894.648 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T17:21:34.648Z,1694452894.648 [Default:CheckIn:C.Wait] Stopped
2023-09-11T17:21:34.648Z,1694452894.648 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T17:21:34.675Z,1694452894.675 [Default:CheckIn:D] Running Loop=1
2023-09-11T17:21:35.042Z,1694452895.042 [Default:CheckIn:D] Stopped
2023-09-11T17:21:35.042Z,1694452895.042 [Default:CheckIn:E] Running Loop=1
2023-09-11T17:21:35.455Z,1694452895.455 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 58.805457 min 
2023-09-11T17:21:35.455Z,1694452895.455 [Default:CheckIn:E] Stopped
2023-09-11T17:21:35.455Z,1694452895.455 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T17:21:35.455Z,1694452895.455 [Default:CheckIn] Stopped
2023-09-11T17:21:35.456Z,1694452895.456 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T17:21:35.456Z,1694452895.456 [Default:CheckIn](INFO): Running loop #9
2023-09-11T17:21:35.456Z,1694452895.456 [Default:CheckIn] Running Loop=9
2023-09-11T17:21:35.456Z,1694452895.456 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T17:21:35.456Z,1694452895.456 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T17:21:37.469Z,1694452897.469 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172136.00,A,3648.14137,N,12147.22927,W,0.039,0.00,110923,,,A*7A
2023-09-11T17:21:37.472Z,1694452897.472 [NAL9602](INFO): GPS fix at 20230911T172136: (36.802356, -121.787154)
2023-09-11T17:21:37.482Z,1694452897.482 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T17:21:37.482Z,1694452897.482 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T17:21:45.235Z,1694452905.235 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230911T161945/Courier0034.lzma
2023-09-11T17:21:46.238Z,1694452906.238 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0034.lzma.bak
2023-09-11T17:21:46.238Z,1694452906.238 [DataOverHttps](INFO): SBD MOMSN=18760754
2023-09-11T17:21:48.779Z,1694452908.779 [NAL9602](INFO): SBD MO Status=0, MOMSN=44604, MT Status=0, MTMSN=0
2023-09-11T17:21:48.779Z,1694452908.779 [NAL9602](INFO): No messages in MT queue
2023-09-11T17:22:02.024Z,1694452922.024 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230911T161945/Express0035.lzma
2023-09-11T17:22:03.026Z,1694452923.026 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0035.lzma.bak
2023-09-11T17:22:03.026Z,1694452923.026 [DataOverHttps](INFO): SBD MOMSN=18760757
2023-09-11T17:22:04.149Z,1694452924.149 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T17:22:04.150Z,1694452924.150 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T17:22:04.150Z,1694452924.150 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T17:22:19.473Z,1694452939.473 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T17:27:04.705Z,1694453224.705 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T17:27:04.706Z,1694453224.706 [Default:CheckIn:C.Wait] Stopped
2023-09-11T17:27:04.706Z,1694453224.706 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T17:27:04.706Z,1694453224.706 [Default:CheckIn:D] Running Loop=1
2023-09-11T17:27:05.115Z,1694453225.115 [Default:CheckIn:D] Stopped
2023-09-11T17:27:05.115Z,1694453225.115 [Default:CheckIn:E] Running Loop=1
2023-09-11T17:27:05.527Z,1694453225.527 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 64.306681 min 
2023-09-11T17:27:05.527Z,1694453225.527 [Default:CheckIn:E] Stopped
2023-09-11T17:27:05.527Z,1694453225.527 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T17:27:05.527Z,1694453225.527 [Default:CheckIn] Stopped
2023-09-11T17:27:05.527Z,1694453225.527 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T17:27:05.527Z,1694453225.527 [Default:CheckIn](INFO): Running loop #10
2023-09-11T17:27:05.528Z,1694453225.528 [Default:CheckIn] Running Loop=10
2023-09-11T17:27:05.528Z,1694453225.528 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T17:27:05.528Z,1694453225.528 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T17:27:07.531Z,1694453227.531 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172706.00,A,3648.14035,N,12147.22765,W,0.039,0.00,110923,,,A*74
2023-09-11T17:27:07.534Z,1694453227.534 [NAL9602](INFO): GPS fix at 20230911T172706: (36.802339, -121.787127)
2023-09-11T17:27:07.545Z,1694453227.545 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T17:27:07.545Z,1694453227.545 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T17:27:15.171Z,1694453235.171 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230911T161945/Courier0037.lzma
2023-09-11T17:27:16.174Z,1694453236.174 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0037.lzma.bak
2023-09-11T17:27:16.174Z,1694453236.174 [DataOverHttps](INFO): SBD MOMSN=18760761
2023-09-11T17:27:27.731Z,1694453247.731 [NAL9602](INFO): SBD MO Status=2, MOMSN=44605, MT Status=2, MTMSN=0
2023-09-11T17:27:27.731Z,1694453247.731 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-11T17:27:32.144Z,1694453252.144 [DataOverHttps](INFO): Sending 127 bytes from file Logs/20230911T161945/Express0038.lzma
2023-09-11T17:27:33.146Z,1694453253.146 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0038.lzma.bak
2023-09-11T17:27:33.146Z,1694453253.146 [DataOverHttps](INFO): SBD MOMSN=18760764
2023-09-11T17:27:34.200Z,1694453254.200 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T17:27:34.200Z,1694453254.200 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T17:27:34.200Z,1694453254.200 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T17:27:34.617Z,1694453254.617 [NAL9602](INFO): SBD MO Status=0, MOMSN=44605, MT Status=0, MTMSN=0
2023-09-11T17:27:34.617Z,1694453254.617 [NAL9602](INFO): No messages in MT queue
2023-09-11T17:28:05.296Z,1694453285.296 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T17:29:57.204Z,1694453397.204 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T17:30:10.534Z,1694453410.534 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T17:30:24.275Z,1694453424.275 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T17:30:38.010Z,1694453438.010 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T17:30:52.151Z,1694453452.151 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T17:31:06.292Z,1694453466.292 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T17:31:20.026Z,1694453480.026 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T17:31:33.763Z,1694453493.763 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T17:31:48.307Z,1694453508.307 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T17:32:02.042Z,1694453522.042 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T17:32:34.791Z,1694453554.791 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T17:32:34.792Z,1694453554.792 [Default:CheckIn:C.Wait] Stopped
2023-09-11T17:32:34.792Z,1694453554.792 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T17:32:34.792Z,1694453554.792 [Default:CheckIn:D] Running Loop=1
2023-09-11T17:32:35.189Z,1694453555.189 [Default:CheckIn:D] Stopped
2023-09-11T17:32:35.189Z,1694453555.189 [Default:CheckIn:E] Running Loop=1
2023-09-11T17:32:35.591Z,1694453555.591 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 69.807910 min 
2023-09-11T17:32:35.592Z,1694453555.592 [Default:CheckIn:E] Stopped
2023-09-11T17:32:35.592Z,1694453555.592 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T17:32:35.592Z,1694453555.592 [Default:CheckIn] Stopped
2023-09-11T17:32:35.592Z,1694453555.592 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T17:32:35.592Z,1694453555.592 [Default:CheckIn](INFO): Running loop #11
2023-09-11T17:32:35.592Z,1694453555.592 [Default:CheckIn] Running Loop=11
2023-09-11T17:32:35.593Z,1694453555.593 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T17:32:35.593Z,1694453555.593 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T17:32:37.607Z,1694453557.607 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173236.00,A,3648.14930,N,12147.22257,W,0.097,29.60,110923,,,A*42
2023-09-11T17:32:37.610Z,1694453557.610 [NAL9602](INFO): GPS fix at 20230911T173236: (36.802488, -121.787043)
2023-09-11T17:32:37.620Z,1694453557.620 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T17:32:37.620Z,1694453557.620 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T17:32:44.000Z,1694453565.000 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20230911T161945/Courier0040.lzma
2023-09-11T17:32:46.002Z,1694453566.002 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0040.lzma.bak
2023-09-11T17:32:46.002Z,1694453566.002 [DataOverHttps](INFO): SBD MOMSN=18760768
2023-09-11T17:33:01.107Z,1694453581.107 [NAL9602](INFO): SBD MO Status=0, MOMSN=44606, MT Status=0, MTMSN=0
2023-09-11T17:33:01.107Z,1694453581.107 [NAL9602](INFO): No messages in MT queue
2023-09-11T17:33:04.379Z,1694453584.379 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230911T161945/Express0041.lzma
2023-09-11T17:33:05.378Z,1694453585.378 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0041.lzma.bak
2023-09-11T17:33:05.378Z,1694453585.378 [DataOverHttps](INFO): SBD MOMSN=18760771
2023-09-11T17:33:06.759Z,1694453586.759 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T17:33:06.759Z,1694453586.759 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T17:33:06.759Z,1694453586.759 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T17:33:31.801Z,1694453611.801 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T17:34:39.272Z,1694453679.272 [BPC1](INFO): Calculating totals. Valid battery stick count: 40. Valid reserve battery stick count: 5.
2023-09-11T17:34:39.275Z,1694453679.275 [BPC1](INFO): Received data from all battery sticks.
2023-09-11T17:38:07.344Z,1694453887.344 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T17:38:07.345Z,1694453887.345 [Default:CheckIn:C.Wait] Stopped
2023-09-11T17:38:07.345Z,1694453887.345 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T17:38:07.345Z,1694453887.345 [Default:CheckIn:D] Running Loop=1
2023-09-11T17:38:07.745Z,1694453887.745 [Default:CheckIn:D] Stopped
2023-09-11T17:38:07.745Z,1694453887.745 [Default:CheckIn:E] Running Loop=1
2023-09-11T17:38:08.142Z,1694453888.142 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 75.350521 min 
2023-09-11T17:38:08.142Z,1694453888.142 [Default:CheckIn:E] Stopped
2023-09-11T17:38:08.142Z,1694453888.142 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T17:38:08.142Z,1694453888.142 [Default:CheckIn] Stopped
2023-09-11T17:38:08.142Z,1694453888.142 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T17:38:08.142Z,1694453888.142 [Default:CheckIn](INFO): Running loop #12
2023-09-11T17:38:08.143Z,1694453888.143 [Default:CheckIn] Running Loop=12
2023-09-11T17:38:08.143Z,1694453888.143 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T17:38:08.143Z,1694453888.143 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T17:38:10.155Z,1694453890.155 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173809.00,A,3648.14295,N,12147.20036,W,0.000,0.79,110923,,,A*7A
2023-09-11T17:38:10.157Z,1694453890.157 [NAL9602](INFO): GPS fix at 20230911T173809: (36.802383, -121.786673)
2023-09-11T17:38:10.169Z,1694453890.169 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T17:38:10.169Z,1694453890.169 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T17:38:18.180Z,1694453898.180 [DataOverHttps](INFO): Sending 83 bytes from file Logs/20230911T161945/Courier0043.lzma
2023-09-11T17:38:19.182Z,1694453899.182 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0043.lzma.bak
2023-09-11T17:38:19.182Z,1694453899.182 [DataOverHttps](INFO): SBD MOMSN=18760776
2023-09-11T17:38:29.208Z,1694453909.208 [NAL9602](INFO): SBD MO Status=0, MOMSN=44607, MT Status=0, MTMSN=0
2023-09-11T17:38:29.208Z,1694453909.208 [NAL9602](INFO): No messages in MT queue
2023-09-11T17:38:37.692Z,1694453917.692 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20230911T161945/Express0044.lzma
2023-09-11T17:38:38.694Z,1694453918.694 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0044.lzma.bak
2023-09-11T17:38:38.694Z,1694453918.694 [DataOverHttps](INFO): SBD MOMSN=18760779
2023-09-11T17:38:39.723Z,1694453919.723 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T17:38:39.723Z,1694453919.723 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T17:38:39.723Z,1694453919.723 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T17:38:59.905Z,1694453939.905 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T17:43:40.475Z,1694454220.475 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T17:43:40.475Z,1694454220.475 [Default:CheckIn:C.Wait] Stopped
2023-09-11T17:43:40.475Z,1694454220.475 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T17:43:40.475Z,1694454220.475 [Default:CheckIn:D] Running Loop=1
2023-09-11T17:43:40.879Z,1694454220.879 [Default:CheckIn:D] Stopped
2023-09-11T17:43:40.879Z,1694454220.879 [Default:CheckIn:E] Running Loop=1
2023-09-11T17:43:41.274Z,1694454221.274 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 80.902751 min 
2023-09-11T17:43:41.274Z,1694454221.274 [Default:CheckIn:E] Stopped
2023-09-11T17:43:41.274Z,1694454221.274 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T17:43:41.274Z,1694454221.274 [Default:CheckIn] Stopped
2023-09-11T17:43:41.274Z,1694454221.274 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T17:43:41.274Z,1694454221.274 [Default:CheckIn](INFO): Running loop #13
2023-09-11T17:43:41.274Z,1694454221.274 [Default:CheckIn] Running Loop=13
2023-09-11T17:43:41.274Z,1694454221.274 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T17:43:41.275Z,1694454221.275 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T17:43:43.291Z,1694454223.291 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174342.00,A,3648.14261,N,12147.20199,W,0.019,0.79,110923,,,D*7B
2023-09-11T17:43:43.293Z,1694454223.293 [NAL9602](INFO): GPS fix at 20230911T174342: (36.802377, -121.786700)
2023-09-11T17:43:43.303Z,1694454223.303 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T17:43:43.304Z,1694454223.304 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T17:43:50.587Z,1694454230.587 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230911T161945/Courier0046.lzma
2023-09-11T17:43:51.590Z,1694454231.590 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0046.lzma.bak
2023-09-11T17:43:51.590Z,1694454231.590 [DataOverHttps](INFO): SBD MOMSN=18760784
2023-09-11T17:44:06.320Z,1694454246.320 [NAL9602](INFO): SBD MO Status=0, MOMSN=44608, MT Status=0, MTMSN=0
2023-09-11T17:44:06.320Z,1694454246.320 [NAL9602](INFO): No messages in MT queue
2023-09-11T17:44:07.516Z,1694454247.516 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230911T161945/Express0047.lzma
2023-09-11T17:44:08.518Z,1694454248.518 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0047.lzma.bak
2023-09-11T17:44:08.518Z,1694454248.518 [DataOverHttps](INFO): SBD MOMSN=18760787
2023-09-11T17:44:09.561Z,1694454249.561 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T17:44:09.561Z,1694454249.561 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T17:44:09.561Z,1694454249.561 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T17:44:37.026Z,1694454277.026 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T17:49:10.209Z,1694454550.209 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T17:49:10.209Z,1694454550.209 [Default:CheckIn:C.Wait] Stopped
2023-09-11T17:49:10.209Z,1694454550.209 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T17:49:10.209Z,1694454550.209 [Default:CheckIn:D] Running Loop=1
2023-09-11T17:49:10.595Z,1694454550.595 [Default:CheckIn:D] Stopped
2023-09-11T17:49:10.595Z,1694454550.595 [Default:CheckIn:E] Running Loop=1
2023-09-11T17:49:10.994Z,1694454550.994 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 86.398006 min 
2023-09-11T17:49:10.994Z,1694454550.994 [Default:CheckIn:E] Stopped
2023-09-11T17:49:10.995Z,1694454550.995 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T17:49:10.995Z,1694454550.995 [Default:CheckIn] Stopped
2023-09-11T17:49:10.995Z,1694454550.995 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T17:49:10.995Z,1694454550.995 [Default:CheckIn](INFO): Running loop #14
2023-09-11T17:49:10.995Z,1694454550.995 [Default:CheckIn] Running Loop=14
2023-09-11T17:49:10.995Z,1694454550.995 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T17:49:10.995Z,1694454550.995 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T17:49:13.011Z,1694454553.011 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174912.00,A,3648.14272,N,12147.20089,W,0.019,0.79,110923,,,D*76
2023-09-11T17:49:13.014Z,1694454553.014 [NAL9602](INFO): GPS fix at 20230911T174912: (36.802379, -121.786682)
2023-09-11T17:49:13.024Z,1694454553.024 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T17:49:13.024Z,1694454553.024 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T17:49:20.230Z,1694454560.230 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230911T161945/Courier0049.lzma
2023-09-11T17:49:21.230Z,1694454561.230 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0049.lzma.bak
2023-09-11T17:49:21.230Z,1694454561.230 [DataOverHttps](INFO): SBD MOMSN=18760791
2023-09-11T17:49:27.151Z,1694454567.151 [NAL9602](INFO): SBD MO Status=0, MOMSN=44609, MT Status=0, MTMSN=0
2023-09-11T17:49:27.151Z,1694454567.151 [NAL9602](INFO): No messages in MT queue
2023-09-11T17:49:37.077Z,1694454577.077 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20230911T161945/Express0050.lzma
2023-09-11T17:49:38.078Z,1694454578.078 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0050.lzma.bak
2023-09-11T17:49:38.078Z,1694454578.078 [DataOverHttps](INFO): SBD MOMSN=18760794
2023-09-11T17:49:39.276Z,1694454579.276 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T17:49:39.276Z,1694454579.276 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T17:49:39.276Z,1694454579.276 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T17:49:57.849Z,1694454597.849 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T17:54:39.913Z,1694454879.913 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T17:54:39.913Z,1694454879.913 [Default:CheckIn:C.Wait] Stopped
2023-09-11T17:54:39.913Z,1694454879.913 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T17:54:39.913Z,1694454879.913 [Default:CheckIn:D] Running Loop=1
2023-09-11T17:54:40.333Z,1694454880.333 [Default:CheckIn:D] Stopped
2023-09-11T17:54:40.333Z,1694454880.333 [Default:CheckIn:E] Running Loop=1
2023-09-11T17:54:40.721Z,1694454880.721 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 91.893644 min 
2023-09-11T17:54:40.722Z,1694454880.722 [Default:CheckIn:E] Stopped
2023-09-11T17:54:40.722Z,1694454880.722 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T17:54:40.722Z,1694454880.722 [Default:CheckIn] Stopped
2023-09-11T17:54:40.722Z,1694454880.722 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T17:54:40.722Z,1694454880.722 [Default:CheckIn](INFO): Running loop #15
2023-09-11T17:54:40.722Z,1694454880.722 [Default:CheckIn] Running Loop=15
2023-09-11T17:54:40.722Z,1694454880.722 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T17:54:40.722Z,1694454880.722 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T17:54:42.722Z,1694454882.722 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175442.00,A,3648.14399,N,12147.20166,W,0.078,0.79,110923,,,D*7C
2023-09-11T17:54:42.724Z,1694454882.724 [NAL9602](INFO): GPS fix at 20230911T175442: (36.802400, -121.786694)
2023-09-11T17:54:42.734Z,1694454882.734 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T17:54:42.734Z,1694454882.734 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T17:54:51.211Z,1694454891.211 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230911T161945/Courier0052.lzma
2023-09-11T17:54:52.214Z,1694454892.214 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0052.lzma.bak
2023-09-11T17:54:52.214Z,1694454892.214 [DataOverHttps](INFO): SBD MOMSN=18760799
2023-09-11T17:55:09.620Z,1694454909.620 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230911T161945/Express0053.lzma
2023-09-11T17:55:10.622Z,1694454910.622 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0053.lzma.bak
2023-09-11T17:55:10.622Z,1694454910.622 [DataOverHttps](INFO): SBD MOMSN=18760804
2023-09-11T17:55:11.842Z,1694454911.842 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T17:55:11.842Z,1694454911.842 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T17:55:11.842Z,1694454911.842 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T17:55:58.299Z,1694454958.299 [NAL9602](INFO): SBD MO Status=0, MOMSN=44610, MT Status=0, MTMSN=0
2023-09-11T17:55:58.299Z,1694454958.299 [NAL9602](INFO): No messages in MT queue
2023-09-11T17:56:29.033Z,1694454989.033 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T18:00:12.563Z,1694455212.563 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T18:00:12.563Z,1694455212.563 [Default:CheckIn:C.Wait] Stopped
2023-09-11T18:00:12.563Z,1694455212.563 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T18:00:12.563Z,1694455212.563 [Default:CheckIn:D] Running Loop=1
2023-09-11T18:00:12.982Z,1694455212.982 [Default:CheckIn:D] Stopped
2023-09-11T18:00:12.982Z,1694455212.982 [Default:CheckIn:E] Running Loop=1
2023-09-11T18:00:13.371Z,1694455213.371 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 97.437793 min 
2023-09-11T18:00:13.371Z,1694455213.371 [Default:CheckIn:E] Stopped
2023-09-11T18:00:13.372Z,1694455213.372 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T18:00:13.372Z,1694455213.372 [Default:CheckIn] Stopped
2023-09-11T18:00:13.372Z,1694455213.372 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T18:00:13.373Z,1694455213.373 [Default:CheckIn](INFO): Running loop #16
2023-09-11T18:00:13.373Z,1694455213.373 [Default:CheckIn] Running Loop=16
2023-09-11T18:00:13.373Z,1694455213.373 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T18:00:13.373Z,1694455213.373 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T18:00:15.383Z,1694455215.383 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180014.00,A,3648.14324,N,12147.20214,W,0.019,0.79,110923,,,D*76
2023-09-11T18:00:15.385Z,1694455215.385 [NAL9602](INFO): GPS fix at 20230911T180014: (36.802387, -121.786702)
2023-09-11T18:00:15.395Z,1694455215.395 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T18:00:15.395Z,1694455215.395 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T18:00:23.923Z,1694455223.923 [NAL9602](INFO): SBD MO Status=0, MOMSN=44611, MT Status=0, MTMSN=0
2023-09-11T18:00:23.923Z,1694455223.923 [NAL9602](INFO): No messages in MT queue
2023-09-11T18:00:25.672Z,1694455225.672 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230911T161945/Courier0055.lzma
2023-09-11T18:00:26.674Z,1694455226.674 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0055.lzma.bak
2023-09-11T18:00:26.674Z,1694455226.674 [DataOverHttps](INFO): SBD MOMSN=18760811
2023-09-11T18:00:42.624Z,1694455242.624 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20230911T161945/Express0056.lzma
2023-09-11T18:00:43.626Z,1694455243.626 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0056.lzma.bak
2023-09-11T18:00:43.626Z,1694455243.626 [DataOverHttps](INFO): SBD MOMSN=18760814
2023-09-11T18:00:44.935Z,1694455244.935 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T18:00:44.935Z,1694455244.935 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T18:00:44.935Z,1694455244.935 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T18:00:54.669Z,1694455254.669 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T18:05:45.374Z,1694455545.374 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T18:05:45.374Z,1694455545.374 [Default:CheckIn:C.Wait] Stopped
2023-09-11T18:05:45.374Z,1694455545.374 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T18:05:45.374Z,1694455545.374 [Default:CheckIn:D] Running Loop=1
2023-09-11T18:05:45.763Z,1694455545.763 [Default:CheckIn:D] Stopped
2023-09-11T18:05:45.763Z,1694455545.763 [Default:CheckIn:E] Running Loop=1
2023-09-11T18:05:46.167Z,1694455546.167 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 102.984155 min 
2023-09-11T18:05:46.167Z,1694455546.167 [Default:CheckIn:E] Stopped
2023-09-11T18:05:46.167Z,1694455546.167 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T18:05:46.168Z,1694455546.168 [Default:CheckIn] Stopped
2023-09-11T18:05:46.168Z,1694455546.168 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T18:05:46.168Z,1694455546.168 [Default:CheckIn](INFO): Running loop #17
2023-09-11T18:05:46.168Z,1694455546.168 [Default:CheckIn] Running Loop=17
2023-09-11T18:05:46.168Z,1694455546.168 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T18:05:46.168Z,1694455546.168 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T18:05:48.175Z,1694455548.175 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180547.00,A,3648.14209,N,12147.20072,W,0.097,0.79,110923,,,D*7F
2023-09-11T18:05:48.178Z,1694455548.178 [NAL9602](INFO): GPS fix at 20230911T180547: (36.802368, -121.786679)
2023-09-11T18:05:48.188Z,1694455548.188 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T18:05:48.188Z,1694455548.188 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T18:05:55.339Z,1694455555.339 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230911T161945/Courier0058.lzma
2023-09-11T18:05:56.342Z,1694455556.342 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0058.lzma.bak
2023-09-11T18:05:56.342Z,1694455556.342 [DataOverHttps](INFO): SBD MOMSN=18760837
2023-09-11T18:06:12.088Z,1694455572.088 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230911T161945/Express0059.lzma
2023-09-11T18:06:13.090Z,1694455573.090 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0059.lzma.bak
2023-09-11T18:06:13.090Z,1694455573.090 [DataOverHttps](INFO): SBD MOMSN=18760840
2023-09-11T18:06:14.442Z,1694455574.442 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T18:06:14.442Z,1694455574.442 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T18:06:14.442Z,1694455574.442 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T18:06:52.519Z,1694455612.519 [NAL9602](INFO): SBD MO Status=2, MOMSN=44612, MT Status=2, MTMSN=0
2023-09-11T18:06:52.519Z,1694455612.519 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-11T18:07:09.471Z,1694455629.471 [NAL9602](INFO): SBD MO Status=0, MOMSN=44612, MT Status=0, MTMSN=0
2023-09-11T18:07:09.471Z,1694455629.471 [NAL9602](INFO): No messages in MT queue
2023-09-11T18:07:40.178Z,1694455660.178 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T18:11:14.910Z,1694455874.910 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T18:11:14.911Z,1694455874.911 [Default:CheckIn:C.Wait] Stopped
2023-09-11T18:11:14.911Z,1694455874.911 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T18:11:14.911Z,1694455874.911 [Default:CheckIn:D] Running Loop=1
2023-09-11T18:11:15.347Z,1694455875.347 [Default:CheckIn:D] Stopped
2023-09-11T18:11:15.347Z,1694455875.347 [Default:CheckIn:E] Running Loop=1
2023-09-11T18:11:15.717Z,1694455875.717 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 108.477222 min 
2023-09-11T18:11:15.717Z,1694455875.717 [Default:CheckIn:E] Stopped
2023-09-11T18:11:15.717Z,1694455875.717 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T18:11:15.718Z,1694455875.718 [Default:CheckIn] Stopped
2023-09-11T18:11:15.718Z,1694455875.718 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T18:11:15.718Z,1694455875.718 [Default:CheckIn](INFO): Running loop #18
2023-09-11T18:11:15.718Z,1694455875.718 [Default:CheckIn] Running Loop=18
2023-09-11T18:11:15.718Z,1694455875.718 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T18:11:15.718Z,1694455875.718 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T18:11:17.727Z,1694455877.727 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181117.00,A,3648.14264,N,12147.20159,W,0.039,0.79,110923,,,D*78
2023-09-11T18:11:17.729Z,1694455877.729 [NAL9602](INFO): GPS fix at 20230911T181117: (36.802377, -121.786693)
2023-09-11T18:11:17.739Z,1694455877.739 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T18:11:17.739Z,1694455877.739 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T18:11:24.655Z,1694455884.655 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230911T161945/Courier0061.lzma
2023-09-11T18:11:25.658Z,1694455885.658 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0061.lzma.bak
2023-09-11T18:11:25.658Z,1694455885.658 [DataOverHttps](INFO): SBD MOMSN=18760848
2023-09-11T18:11:41.447Z,1694455901.447 [DataOverHttps](INFO): Sending 127 bytes from file Logs/20230911T161945/Express0062.lzma
2023-09-11T18:11:42.450Z,1694455902.450 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0062.lzma.bak
2023-09-11T18:11:42.450Z,1694455902.450 [DataOverHttps](INFO): SBD MOMSN=18760851
2023-09-11T18:11:43.591Z,1694455903.591 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T18:11:43.592Z,1694455903.592 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T18:11:43.592Z,1694455903.592 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T18:11:51.660Z,1694455911.660 [NAL9602](INFO): SBD MO Status=0, MOMSN=44613, MT Status=0, MTMSN=0
2023-09-11T18:11:51.660Z,1694455911.660 [NAL9602](INFO): No messages in MT queue
2023-09-11T18:12:22.377Z,1694455942.377 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T18:16:44.418Z,1694456204.418 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T18:16:44.418Z,1694456204.418 [Default:CheckIn:C.Wait] Stopped
2023-09-11T18:16:44.418Z,1694456204.418 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T18:16:44.418Z,1694456204.418 [Default:CheckIn:D] Running Loop=1
2023-09-11T18:16:44.813Z,1694456204.813 [Default:CheckIn:D] Stopped
2023-09-11T18:16:44.813Z,1694456204.813 [Default:CheckIn:E] Running Loop=1
2023-09-11T18:16:45.214Z,1694456205.214 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 113.968311 min 
2023-09-11T18:16:45.214Z,1694456205.214 [Default:CheckIn:E] Stopped
2023-09-11T18:16:45.214Z,1694456205.214 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T18:16:45.214Z,1694456205.214 [Default:CheckIn] Stopped
2023-09-11T18:16:45.214Z,1694456205.214 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T18:16:45.214Z,1694456205.214 [Default:CheckIn](INFO): Running loop #19
2023-09-11T18:16:45.214Z,1694456205.214 [Default:CheckIn] Running Loop=19
2023-09-11T18:16:45.214Z,1694456205.214 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T18:16:45.214Z,1694456205.214 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T18:16:47.240Z,1694456207.240 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181646.00,A,3648.14234,N,12147.20229,W,0.058,0.00,110923,,,D*73
2023-09-11T18:16:47.242Z,1694456207.242 [NAL9602](INFO): GPS fix at 20230911T181646: (36.802372, -121.786705)
2023-09-11T18:16:47.252Z,1694456207.252 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T18:16:47.252Z,1694456207.252 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T18:16:57.376Z,1694456217.376 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230911T161945/Courier0064.lzma
2023-09-11T18:16:58.378Z,1694456218.378 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0064.lzma.bak
2023-09-11T18:16:58.378Z,1694456218.378 [DataOverHttps](INFO): SBD MOMSN=18760858
2023-09-11T18:17:06.287Z,1694456226.287 [NAL9602](INFO): SBD MO Status=0, MOMSN=44614, MT Status=0, MTMSN=0
2023-09-11T18:17:06.287Z,1694456226.287 [NAL9602](INFO): No messages in MT queue
2023-09-11T18:17:14.091Z,1694456234.091 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230911T161945/Express0065.lzma
2023-09-11T18:17:15.094Z,1694456235.094 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0065.lzma.bak
2023-09-11T18:17:15.094Z,1694456235.094 [DataOverHttps](INFO): SBD MOMSN=18760861
2023-09-11T18:17:16.396Z,1694456236.396 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T18:17:16.396Z,1694456236.396 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T18:17:16.396Z,1694456236.396 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T18:17:36.989Z,1694456256.989 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T18:22:17.216Z,1694456537.216 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T18:22:17.216Z,1694456537.216 [Default:CheckIn:C.Wait] Stopped
2023-09-11T18:22:17.216Z,1694456537.216 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T18:22:17.216Z,1694456537.216 [Default:CheckIn:D] Running Loop=1
2023-09-11T18:22:17.671Z,1694456537.671 [Default:CheckIn:D] Stopped
2023-09-11T18:22:17.671Z,1694456537.671 [Default:CheckIn:E] Running Loop=1
2023-09-11T18:22:18.013Z,1694456538.013 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 119.515951 min 
2023-09-11T18:22:18.013Z,1694456538.013 [Default:CheckIn:E] Stopped
2023-09-11T18:22:18.013Z,1694456538.013 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T18:22:18.013Z,1694456538.013 [Default:CheckIn] Stopped
2023-09-11T18:22:18.013Z,1694456538.013 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T18:22:18.013Z,1694456538.013 [Default:CheckIn](INFO): Running loop #20
2023-09-11T18:22:18.013Z,1694456538.013 [Default:CheckIn] Running Loop=20
2023-09-11T18:22:18.014Z,1694456538.014 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T18:22:18.014Z,1694456538.014 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T18:22:20.011Z,1694456540.011 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182219.00,A,3648.14258,N,12147.20156,W,0.039,0.00,110923,,,D*78
2023-09-11T18:22:20.017Z,1694456540.017 [NAL9602](INFO): GPS fix at 20230911T182219: (36.802376, -121.786693)
2023-09-11T18:22:20.042Z,1694456540.042 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T18:22:20.042Z,1694456540.042 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T18:22:30.184Z,1694456550.184 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230911T161945/Courier0067.lzma
2023-09-11T18:22:31.186Z,1694456551.186 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0067.lzma.bak
2023-09-11T18:22:31.186Z,1694456551.186 [DataOverHttps](INFO): SBD MOMSN=18760869
2023-09-11T18:22:46.880Z,1694456566.880 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230911T161945/Express0068.lzma
2023-09-11T18:22:47.882Z,1694456567.882 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0068.lzma.bak
2023-09-11T18:22:47.882Z,1694456567.882 [DataOverHttps](INFO): SBD MOMSN=18760872
2023-09-11T18:22:49.179Z,1694456569.179 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T18:22:49.179Z,1694456569.179 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T18:22:49.180Z,1694456569.180 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T18:23:44.567Z,1694456624.567 [NAL9602](INFO): SBD MO Status=2, MOMSN=44615, MT Status=2, MTMSN=0
2023-09-11T18:23:44.567Z,1694456624.567 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-11T18:23:55.888Z,1694456635.888 [NAL9602](INFO): SBD MO Status=0, MOMSN=44615, MT Status=0, MTMSN=0
2023-09-11T18:23:55.888Z,1694456635.888 [NAL9602](INFO): No messages in MT queue
2023-09-11T18:24:26.629Z,1694456666.629 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T18:27:49.902Z,1694456869.902 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T18:27:49.902Z,1694456869.902 [Default:CheckIn:C.Wait] Stopped
2023-09-11T18:27:49.902Z,1694456869.902 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T18:27:49.902Z,1694456869.902 [Default:CheckIn:D] Running Loop=1
2023-09-11T18:27:50.307Z,1694456870.307 [Default:CheckIn:D] Stopped
2023-09-11T18:27:50.307Z,1694456870.307 [Default:CheckIn:E] Running Loop=1
2023-09-11T18:27:50.784Z,1694456870.784 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 125.059888 min 
2023-09-11T18:27:50.784Z,1694456870.784 [Default:CheckIn:E] Stopped
2023-09-11T18:27:50.784Z,1694456870.784 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T18:27:50.784Z,1694456870.784 [Default:CheckIn] Stopped
2023-09-11T18:27:50.784Z,1694456870.784 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T18:27:50.784Z,1694456870.784 [Default:CheckIn](INFO): Running loop #21
2023-09-11T18:27:50.784Z,1694456870.784 [Default:CheckIn] Running Loop=21
2023-09-11T18:27:50.784Z,1694456870.784 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T18:27:50.785Z,1694456870.785 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T18:27:52.727Z,1694456872.727 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182752.00,A,3648.14304,N,12147.20190,W,0.058,0.00,110923,,,D*77
2023-09-11T18:27:52.729Z,1694456872.729 [NAL9602](INFO): GPS fix at 20230911T182752: (36.802384, -121.786698)
2023-09-11T18:27:52.740Z,1694456872.740 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T18:27:52.740Z,1694456872.740 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T18:28:00.539Z,1694456880.539 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20230911T161945/Courier0070.lzma
2023-09-11T18:28:01.542Z,1694456881.542 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0070.lzma.bak
2023-09-11T18:28:01.542Z,1694456881.542 [DataOverHttps](INFO): SBD MOMSN=18760877
2023-09-11T18:28:13.731Z,1694456893.731 [NAL9602](INFO): SBD MO Status=2, MOMSN=44616, MT Status=2, MTMSN=0
2023-09-11T18:28:13.731Z,1694456893.731 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-11T18:28:17.371Z,1694456897.371 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230911T161945/Express0071.lzma
2023-09-11T18:28:18.375Z,1694456898.375 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0071.lzma.bak
2023-09-11T18:28:18.375Z,1694456898.375 [DataOverHttps](INFO): SBD MOMSN=18760880
2023-09-11T18:28:19.431Z,1694456899.431 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T18:28:19.431Z,1694456899.431 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T18:28:19.431Z,1694456899.431 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T18:28:40.067Z,1694456920.067 [NAL9602](INFO): SBD MO Status=2, MOMSN=44616, MT Status=2, MTMSN=0
2023-09-11T18:28:40.067Z,1694456920.067 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-11T18:29:14.455Z,1694456954.455 [NAL9602](INFO): SBD MO Status=2, MOMSN=44616, MT Status=2, MTMSN=0
2023-09-11T18:29:14.455Z,1694456954.455 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-11T18:29:30.207Z,1694456970.207 [NAL9602](INFO): SBD MO Status=2, MOMSN=44616, MT Status=2, MTMSN=0
2023-09-11T18:29:30.207Z,1694456970.207 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-11T18:29:50.825Z,1694456990.825 [NAL9602](INFO): SBD MO Status=0, MOMSN=44616, MT Status=0, MTMSN=0
2023-09-11T18:29:50.825Z,1694456990.825 [NAL9602](INFO): No messages in MT queue
2023-09-11T18:30:21.512Z,1694457021.512 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T18:33:20.123Z,1694457200.123 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T18:33:20.123Z,1694457200.123 [Default:CheckIn:C.Wait] Stopped
2023-09-11T18:33:20.123Z,1694457200.123 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T18:33:20.123Z,1694457200.123 [Default:CheckIn:D] Running Loop=1
2023-09-11T18:33:20.527Z,1694457200.527 [Default:CheckIn:D] Stopped
2023-09-11T18:33:20.527Z,1694457200.527 [Default:CheckIn:E] Running Loop=1
2023-09-11T18:33:20.929Z,1694457200.929 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 130.563550 min 
2023-09-11T18:33:20.929Z,1694457200.929 [Default:CheckIn:E] Stopped
2023-09-11T18:33:20.929Z,1694457200.929 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T18:33:20.929Z,1694457200.929 [Default:CheckIn] Stopped
2023-09-11T18:33:20.929Z,1694457200.929 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T18:33:20.929Z,1694457200.929 [Default:CheckIn](INFO): Running loop #22
2023-09-11T18:33:20.929Z,1694457200.929 [Default:CheckIn] Running Loop=22
2023-09-11T18:33:20.929Z,1694457200.929 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T18:33:20.930Z,1694457200.930 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T18:33:22.943Z,1694457202.943 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183322.00,A,3648.14297,N,12147.20159,W,0.000,0.00,110923,,,D*76
2023-09-11T18:33:22.955Z,1694457202.955 [NAL9602](INFO): GPS fix at 20230911T183322: (36.802383, -121.786693)
2023-09-11T18:33:22.965Z,1694457202.965 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T18:33:22.965Z,1694457202.965 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T18:33:29.875Z,1694457209.875 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230911T161945/Courier0073.lzma
2023-09-11T18:33:30.878Z,1694457210.878 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0073.lzma.bak
2023-09-11T18:33:30.878Z,1694457210.878 [DataOverHttps](INFO): SBD MOMSN=18760885
2023-09-11T18:33:37.895Z,1694457217.895 [NAL9602](INFO): SBD MO Status=0, MOMSN=44617, MT Status=0, MTMSN=0
2023-09-11T18:33:37.895Z,1694457217.895 [NAL9602](INFO): No messages in MT queue
2023-09-11T18:33:46.732Z,1694457226.732 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230911T161945/Express0074.lzma
2023-09-11T18:33:47.734Z,1694457227.734 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0074.lzma.bak
2023-09-11T18:33:47.734Z,1694457227.734 [DataOverHttps](INFO): SBD MOMSN=18760888
2023-09-11T18:33:48.801Z,1694457228.801 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T18:33:48.802Z,1694457228.802 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T18:33:48.802Z,1694457228.802 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T18:34:08.588Z,1694457248.588 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T18:37:18.623Z,1694457438.623 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T18:37:32.754Z,1694457452.754 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T18:37:46.501Z,1694457466.501 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T18:38:00.226Z,1694457480.226 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T18:38:13.558Z,1694457493.558 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T18:38:26.890Z,1694457506.890 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T18:38:41.031Z,1694457521.031 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T18:38:49.535Z,1694457529.535 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T18:38:49.535Z,1694457529.535 [Default:CheckIn:C.Wait] Stopped
2023-09-11T18:38:49.535Z,1694457529.535 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T18:38:49.535Z,1694457529.535 [Default:CheckIn:D] Running Loop=1
2023-09-11T18:38:49.949Z,1694457529.949 [Default:CheckIn:D] Stopped
2023-09-11T18:38:49.949Z,1694457529.949 [Default:CheckIn:E] Running Loop=1
2023-09-11T18:38:50.335Z,1694457530.335 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 136.053923 min 
2023-09-11T18:38:50.335Z,1694457530.335 [Default:CheckIn:E] Stopped
2023-09-11T18:38:50.335Z,1694457530.335 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T18:38:50.335Z,1694457530.335 [Default:CheckIn] Stopped
2023-09-11T18:38:50.335Z,1694457530.335 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T18:38:50.335Z,1694457530.335 [Default:CheckIn](INFO): Running loop #23
2023-09-11T18:38:50.336Z,1694457530.336 [Default:CheckIn] Running Loop=23
2023-09-11T18:38:50.336Z,1694457530.336 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T18:38:50.336Z,1694457530.336 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T18:38:52.351Z,1694457532.351 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183851.00,A,3648.14324,N,12147.20126,W,0.039,0.00,110923,,,D*72
2023-09-11T18:38:52.362Z,1694457532.362 [NAL9602](INFO): GPS fix at 20230911T183851: (36.802387, -121.786688)
2023-09-11T18:38:52.374Z,1694457532.374 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T18:38:52.374Z,1694457532.374 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T18:38:54.450Z,1694457534.450 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T18:38:59.859Z,1694457539.859 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230911T161945/Courier0076.lzma
2023-09-11T18:39:00.862Z,1694457540.862 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0076.lzma.bak
2023-09-11T18:39:00.862Z,1694457540.862 [DataOverHttps](INFO): SBD MOMSN=18760892
2023-09-11T18:39:08.187Z,1694457548.187 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T18:39:16.724Z,1694457556.724 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230911T161945/Express0077.lzma
2023-09-11T18:39:17.726Z,1694457557.726 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0077.lzma.bak
2023-09-11T18:39:17.726Z,1694457557.726 [DataOverHttps](INFO): SBD MOMSN=18760895
2023-09-11T18:39:19.107Z,1694457559.107 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T18:39:19.107Z,1694457559.107 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T18:39:19.107Z,1694457559.107 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T18:39:21.923Z,1694457561.923 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T18:39:44.963Z,1694457584.963 [NAL9602](INFO): SBD MO Status=2, MOMSN=44618, MT Status=2, MTMSN=0
2023-09-11T18:39:44.963Z,1694457584.963 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-11T18:40:49.647Z,1694457649.647 [NAL9602](INFO): SBD MO Status=2, MOMSN=44618, MT Status=2, MTMSN=0
2023-09-11T18:40:49.647Z,1694457649.647 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-11T18:41:05.038Z,1694457665.038 [NAL9602](INFO): SBD MO Status=0, MOMSN=44618, MT Status=0, MTMSN=0
2023-09-11T18:41:05.038Z,1694457665.038 [NAL9602](INFO): No messages in MT queue
2023-09-11T18:41:35.745Z,1694457695.745 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T18:41:59.179Z,1694457719.179 [BPC1](INFO): Calculating totals. Valid battery stick count: 40. Valid reserve battery stick count: 5.
2023-09-11T18:41:59.182Z,1694457719.182 [BPC1](INFO): Received data from all battery sticks.
2023-09-11T18:44:19.809Z,1694457859.809 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T18:44:19.809Z,1694457859.809 [Default:CheckIn:C.Wait] Stopped
2023-09-11T18:44:19.809Z,1694457859.809 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T18:44:19.809Z,1694457859.809 [Default:CheckIn:D] Running Loop=1
2023-09-11T18:44:20.237Z,1694457860.237 [Default:CheckIn:D] Stopped
2023-09-11T18:44:20.237Z,1694457860.237 [Default:CheckIn:E] Running Loop=1
2023-09-11T18:44:20.610Z,1694457860.610 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 141.558708 min 
2023-09-11T18:44:20.610Z,1694457860.610 [Default:CheckIn:E] Stopped
2023-09-11T18:44:20.610Z,1694457860.610 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T18:44:20.610Z,1694457860.610 [Default:CheckIn] Stopped
2023-09-11T18:44:20.610Z,1694457860.610 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T18:44:20.610Z,1694457860.610 [Default:CheckIn](INFO): Running loop #24
2023-09-11T18:44:20.610Z,1694457860.610 [Default:CheckIn] Running Loop=24
2023-09-11T18:44:20.610Z,1694457860.610 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T18:44:20.611Z,1694457860.611 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T18:44:22.623Z,1694457862.623 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184421.00,A,3648.14329,N,12147.20195,W,0.019,0.00,110923,,,D*79
2023-09-11T18:44:22.625Z,1694457862.625 [NAL9602](INFO): GPS fix at 20230911T184421: (36.802388, -121.786699)
2023-09-11T18:44:22.672Z,1694457862.672 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T18:44:22.672Z,1694457862.672 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T18:44:30.435Z,1694457870.435 [DataOverHttps](INFO): Sending 84 bytes from file Logs/20230911T161945/Courier0079.lzma
2023-09-11T18:44:31.438Z,1694457871.438 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0079.lzma.bak
2023-09-11T18:44:31.438Z,1694457871.438 [DataOverHttps](INFO): SBD MOMSN=18760899
2023-09-11T18:44:44.047Z,1694457884.047 [NAL9602](INFO): SBD MO Status=0, MOMSN=44619, MT Status=0, MTMSN=0
2023-09-11T18:44:44.047Z,1694457884.047 [NAL9602](INFO): No messages in MT queue
2023-09-11T18:44:47.289Z,1694457887.289 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20230911T161945/Express0080.lzma
2023-09-11T18:44:48.290Z,1694457888.290 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0080.lzma.bak
2023-09-11T18:44:48.290Z,1694457888.290 [DataOverHttps](INFO): SBD MOMSN=18760902
2023-09-11T18:44:49.330Z,1694457889.330 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T18:44:49.330Z,1694457889.330 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T18:44:49.330Z,1694457889.330 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T18:45:14.482Z,1694457914.482 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T18:49:50.115Z,1694458190.115 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T18:49:50.115Z,1694458190.115 [Default:CheckIn:C.Wait] Stopped
2023-09-11T18:49:50.115Z,1694458190.115 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T18:49:50.115Z,1694458190.115 [Default:CheckIn:D] Running Loop=1
2023-09-11T18:49:50.505Z,1694458190.505 [Default:CheckIn:D] Stopped
2023-09-11T18:49:50.505Z,1694458190.505 [Default:CheckIn:E] Running Loop=1
2023-09-11T18:49:50.931Z,1694458190.931 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 147.063184 min 
2023-09-11T18:49:50.931Z,1694458190.931 [Default:CheckIn:E] Stopped
2023-09-11T18:49:50.931Z,1694458190.931 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T18:49:50.931Z,1694458190.931 [Default:CheckIn] Stopped
2023-09-11T18:49:50.932Z,1694458190.932 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T18:49:50.952Z,1694458190.952 [Default:CheckIn](INFO): Running loop #25
2023-09-11T18:49:50.952Z,1694458190.952 [Default:CheckIn] Running Loop=25
2023-09-11T18:49:50.952Z,1694458190.952 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T18:49:50.952Z,1694458190.952 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T18:49:52.931Z,1694458192.931 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184952.00,A,3648.14337,N,12147.20177,W,0.019,0.00,110923,,,D*73
2023-09-11T18:49:52.933Z,1694458192.933 [NAL9602](INFO): GPS fix at 20230911T184952: (36.802389, -121.786696)
2023-09-11T18:49:52.943Z,1694458192.943 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T18:49:52.944Z,1694458192.944 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T18:49:59.155Z,1694458199.155 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20230911T161945/Courier0082.lzma
2023-09-11T18:50:00.158Z,1694458200.158 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0082.lzma.bak
2023-09-11T18:50:00.158Z,1694458200.158 [DataOverHttps](INFO): SBD MOMSN=18760906
2023-09-11T18:50:15.912Z,1694458215.912 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230911T161945/Express0083.lzma
2023-09-11T18:50:16.915Z,1694458216.915 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0083.lzma.bak
2023-09-11T18:50:16.915Z,1694458216.915 [DataOverHttps](INFO): SBD MOMSN=18760909
2023-09-11T18:50:18.004Z,1694458218.004 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T18:50:18.004Z,1694458218.004 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T18:50:18.004Z,1694458218.004 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T18:50:18.375Z,1694458218.375 [NAL9602](INFO): SBD MO Status=2, MOMSN=44620, MT Status=2, MTMSN=0
2023-09-11T18:50:18.375Z,1694458218.375 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-11T18:50:47.116Z,1694458247.116 [NAL9602](INFO): SBD MO Status=2, MOMSN=44620, MT Status=2, MTMSN=0
2023-09-11T18:50:47.116Z,1694458247.116 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-11T18:51:05.339Z,1694458265.339 [NAL9602](INFO): SBD MO Status=0, MOMSN=44620, MT Status=0, MTMSN=0
2023-09-11T18:51:05.339Z,1694458265.339 [NAL9602](INFO): No messages in MT queue
2023-09-11T18:51:36.035Z,1694458296.035 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T18:55:18.799Z,1694458518.799 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T18:55:18.799Z,1694458518.799 [Default:CheckIn:C.Wait] Stopped
2023-09-11T18:55:18.799Z,1694458518.799 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T18:55:18.799Z,1694458518.799 [Default:CheckIn:D] Running Loop=1
2023-09-11T18:55:19.221Z,1694458519.221 [Default:CheckIn:D] Stopped
2023-09-11T18:55:19.221Z,1694458519.221 [Default:CheckIn:E] Running Loop=1
2023-09-11T18:55:19.594Z,1694458519.594 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 152.541781 min 
2023-09-11T18:55:19.595Z,1694458519.595 [Default:CheckIn:E] Stopped
2023-09-11T18:55:19.595Z,1694458519.595 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T18:55:19.595Z,1694458519.595 [Default:CheckIn] Stopped
2023-09-11T18:55:19.595Z,1694458519.595 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T18:55:19.595Z,1694458519.595 [Default:CheckIn](INFO): Running loop #26
2023-09-11T18:55:19.595Z,1694458519.595 [Default:CheckIn] Running Loop=26
2023-09-11T18:55:19.595Z,1694458519.595 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T18:55:19.595Z,1694458519.595 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T18:55:21.615Z,1694458521.615 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185520.00,A,3648.14384,N,12147.20167,W,0.039,0.00,110923,,,D*70
2023-09-11T18:55:21.617Z,1694458521.617 [NAL9602](INFO): GPS fix at 20230911T185520: (36.802397, -121.786694)
2023-09-11T18:55:21.627Z,1694458521.627 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T18:55:21.628Z,1694458521.628 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T18:55:28.887Z,1694458528.887 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230911T161945/Courier0085.lzma
2023-09-11T18:55:29.890Z,1694458529.890 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0085.lzma.bak
2023-09-11T18:55:29.890Z,1694458529.890 [DataOverHttps](INFO): SBD MOMSN=18760920
2023-09-11T18:55:45.760Z,1694458545.760 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230911T161945/Express0086.lzma
2023-09-11T18:55:46.762Z,1694458546.762 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0086.lzma.bak
2023-09-11T18:55:46.762Z,1694458546.762 [DataOverHttps](INFO): SBD MOMSN=18760923
2023-09-11T18:55:47.919Z,1694458547.919 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T18:55:47.919Z,1694458547.919 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T18:55:47.919Z,1694458547.919 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T18:56:42.497Z,1694458602.497 [NAL9602](INFO): SBD MO Status=2, MOMSN=44621, MT Status=2, MTMSN=0
2023-09-11T18:56:42.498Z,1694458602.498 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-11T18:57:56.882Z,1694458676.882 [NAL9602](INFO): SBD MO Status=2, MOMSN=44621, MT Status=2, MTMSN=0
2023-09-11T18:57:56.883Z,1694458676.883 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-11T18:59:40.019Z,1694458780.019 [NAL9602](INFO): SBD MO Status=2, MOMSN=44621, MT Status=2, MTMSN=0
2023-09-11T18:59:40.019Z,1694458780.019 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-11T19:00:09.507Z,1694458809.507 [NAL9602](INFO): SBD MO Status=0, MOMSN=44621, MT Status=0, MTMSN=0
2023-09-11T19:00:09.507Z,1694458809.507 [NAL9602](INFO): No messages in MT queue
2023-09-11T19:00:40.209Z,1694458840.209 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T19:00:48.710Z,1694458848.710 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T19:00:48.710Z,1694458848.710 [Default:CheckIn:C.Wait] Stopped
2023-09-11T19:00:48.710Z,1694458848.710 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T19:00:48.710Z,1694458848.710 [Default:CheckIn:D] Running Loop=1
2023-09-11T19:00:49.150Z,1694458849.150 [Default:CheckIn:D] Stopped
2023-09-11T19:00:49.150Z,1694458849.150 [Default:CheckIn:E] Running Loop=1
2023-09-11T19:00:49.537Z,1694458849.537 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 158.040592 min 
2023-09-11T19:00:49.537Z,1694458849.537 [Default:CheckIn:E] Stopped
2023-09-11T19:00:49.537Z,1694458849.537 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T19:00:49.537Z,1694458849.537 [Default:CheckIn] Stopped
2023-09-11T19:00:49.537Z,1694458849.537 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T19:00:49.538Z,1694458849.538 [Default:CheckIn](INFO): Running loop #27
2023-09-11T19:00:49.538Z,1694458849.538 [Default:CheckIn] Running Loop=27
2023-09-11T19:00:49.538Z,1694458849.538 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T19:00:49.538Z,1694458849.538 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T19:00:51.535Z,1694458851.535 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190050.00,A,3648.14295,N,12147.20064,W,0.019,0.00,110923,,,D*77
2023-09-11T19:00:51.537Z,1694458851.537 [NAL9602](INFO): GPS fix at 20230911T190050: (36.802383, -121.786677)
2023-09-11T19:00:51.556Z,1694458851.556 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T19:00:51.556Z,1694458851.556 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T19:00:59.851Z,1694458859.851 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230911T161945/Courier0088.lzma
2023-09-11T19:01:00.854Z,1694458860.854 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0088.lzma.bak
2023-09-11T19:01:00.854Z,1694458860.854 [DataOverHttps](INFO): SBD MOMSN=18760927
2023-09-11T19:01:04.587Z,1694458864.587 [NAL9602](INFO): SBD MO Status=0, MOMSN=44622, MT Status=0, MTMSN=0
2023-09-11T19:01:04.587Z,1694458864.587 [NAL9602](INFO): No messages in MT queue
2023-09-11T19:01:16.624Z,1694458876.624 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230911T161945/Express0089.lzma
2023-09-11T19:01:17.626Z,1694458877.626 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0089.lzma.bak
2023-09-11T19:01:17.626Z,1694458877.626 [DataOverHttps](INFO): SBD MOMSN=18760930
2023-09-11T19:01:18.727Z,1694458878.727 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T19:01:18.727Z,1694458878.727 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T19:01:18.727Z,1694458878.727 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T19:01:35.277Z,1694458895.277 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T19:06:19.453Z,1694459179.453 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T19:06:19.453Z,1694459179.453 [Default:CheckIn:C.Wait] Stopped
2023-09-11T19:06:19.453Z,1694459179.453 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T19:06:19.453Z,1694459179.453 [Default:CheckIn:D] Running Loop=1
2023-09-11T19:06:19.820Z,1694459179.820 [Default:CheckIn:D] Stopped
2023-09-11T19:06:19.820Z,1694459179.820 [Default:CheckIn:E] Running Loop=1
2023-09-11T19:06:20.224Z,1694459180.224 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 163.551774 min 
2023-09-11T19:06:20.224Z,1694459180.224 [Default:CheckIn:E] Stopped
2023-09-11T19:06:20.224Z,1694459180.224 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T19:06:20.224Z,1694459180.224 [Default:CheckIn] Stopped
2023-09-11T19:06:20.224Z,1694459180.224 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T19:06:20.225Z,1694459180.225 [Default:CheckIn](INFO): Running loop #28
2023-09-11T19:06:20.225Z,1694459180.225 [Default:CheckIn] Running Loop=28
2023-09-11T19:06:20.225Z,1694459180.225 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T19:06:20.225Z,1694459180.225 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T19:06:22.235Z,1694459182.235 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190621.00,A,3648.14329,N,12147.20196,W,0.019,0.00,110923,,,D*7D
2023-09-11T19:06:22.237Z,1694459182.237 [NAL9602](INFO): GPS fix at 20230911T190621: (36.802388, -121.786699)
2023-09-11T19:06:22.255Z,1694459182.255 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T19:06:22.255Z,1694459182.255 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T19:06:29.847Z,1694459189.847 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230911T161945/Courier0091.lzma
2023-09-11T19:06:30.850Z,1694459190.850 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0091.lzma.bak
2023-09-11T19:06:30.850Z,1694459190.850 [DataOverHttps](INFO): SBD MOMSN=18760935
2023-09-11T19:06:46.604Z,1694459206.604 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230911T161945/Express0092.lzma
2023-09-11T19:06:47.606Z,1694459207.606 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0092.lzma.bak
2023-09-11T19:06:47.606Z,1694459207.606 [DataOverHttps](INFO): SBD MOMSN=18760938
2023-09-11T19:06:48.935Z,1694459208.935 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T19:06:48.935Z,1694459208.935 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T19:06:48.936Z,1694459208.936 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T19:07:49.175Z,1694459269.175 [NAL9602](INFO): SBD MO Status=0, MOMSN=44623, MT Status=0, MTMSN=0
2023-09-11T19:07:49.175Z,1694459269.175 [NAL9602](INFO): No messages in MT queue
2023-09-11T19:08:19.921Z,1694459299.921 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T19:11:49.696Z,1694459509.696 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T19:11:49.697Z,1694459509.697 [Default:CheckIn:C.Wait] Stopped
2023-09-11T19:11:49.697Z,1694459509.697 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T19:11:49.697Z,1694459509.697 [Default:CheckIn:D] Running Loop=1
2023-09-11T19:11:50.099Z,1694459510.099 [Default:CheckIn:D] Stopped
2023-09-11T19:11:50.099Z,1694459510.099 [Default:CheckIn:E] Running Loop=1
2023-09-11T19:11:50.504Z,1694459510.504 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 169.056413 min 
2023-09-11T19:11:50.504Z,1694459510.504 [Default:CheckIn:E] Stopped
2023-09-11T19:11:50.504Z,1694459510.504 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T19:11:50.504Z,1694459510.504 [Default:CheckIn] Stopped
2023-09-11T19:11:50.505Z,1694459510.505 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T19:11:50.505Z,1694459510.505 [Default:CheckIn](INFO): Running loop #29
2023-09-11T19:11:50.505Z,1694459510.505 [Default:CheckIn] Running Loop=29
2023-09-11T19:11:50.505Z,1694459510.505 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T19:11:50.505Z,1694459510.505 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T19:11:52.515Z,1694459512.515 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191151.00,A,3648.20694,N,12147.15125,W,2.838,12.55,110923,,,D*4C
2023-09-11T19:11:52.526Z,1694459512.526 [NAL9602](INFO): GPS fix at 20230911T191151: (36.803449, -121.785854)
2023-09-11T19:11:52.537Z,1694459512.537 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T19:11:52.537Z,1694459512.537 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T19:12:00.223Z,1694459520.223 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230911T161945/Courier0094.lzma
2023-09-11T19:12:01.226Z,1694459521.226 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0094.lzma.bak
2023-09-11T19:12:01.226Z,1694459521.226 [DataOverHttps](INFO): SBD MOMSN=18760943
2023-09-11T19:12:06.667Z,1694459526.667 [NAL9602](INFO): SBD MO Status=0, MOMSN=44624, MT Status=0, MTMSN=0
2023-09-11T19:12:06.667Z,1694459526.667 [NAL9602](INFO): No messages in MT queue
2023-09-11T19:12:17.076Z,1694459537.076 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20230911T161945/Express0095.lzma
2023-09-11T19:12:18.078Z,1694459538.078 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0095.lzma.bak
2023-09-11T19:12:18.078Z,1694459538.078 [DataOverHttps](INFO): SBD MOMSN=18760946
2023-09-11T19:12:19.182Z,1694459539.182 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T19:12:19.182Z,1694459539.182 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T19:12:19.182Z,1694459539.182 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T19:12:37.406Z,1694459557.406 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T19:17:19.613Z,1694459839.613 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T19:17:19.613Z,1694459839.613 [Default:CheckIn:C.Wait] Stopped
2023-09-11T19:17:19.613Z,1694459839.613 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T19:17:19.613Z,1694459839.613 [Default:CheckIn:D] Running Loop=1
2023-09-11T19:17:20.008Z,1694459840.008 [Default:CheckIn:D] Stopped
2023-09-11T19:17:20.008Z,1694459840.008 [Default:CheckIn:E] Running Loop=1
2023-09-11T19:17:20.429Z,1694459840.429 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 174.554899 min 
2023-09-11T19:17:20.429Z,1694459840.429 [Default:CheckIn:E] Stopped
2023-09-11T19:17:20.429Z,1694459840.429 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T19:17:20.429Z,1694459840.429 [Default:CheckIn] Stopped
2023-09-11T19:17:20.430Z,1694459840.430 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T19:17:20.430Z,1694459840.430 [Default:CheckIn](INFO): Running loop #30
2023-09-11T19:17:20.430Z,1694459840.430 [Default:CheckIn] Running Loop=30
2023-09-11T19:17:20.430Z,1694459840.430 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T19:17:20.430Z,1694459840.430 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T19:17:22.414Z,1694459842.414 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191721.00,A,3648.46903,N,12147.11142,W,2.877,3.63,110923,,,D*77
2023-09-11T19:17:22.417Z,1694459842.417 [NAL9602](INFO): GPS fix at 20230911T191721: (36.807817, -121.785190)
2023-09-11T19:17:22.427Z,1694459842.427 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T19:17:22.427Z,1694459842.427 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T19:17:29.427Z,1694459849.427 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230911T161945/Courier0097.lzma
2023-09-11T19:17:30.430Z,1694459850.430 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0097.lzma.bak
2023-09-11T19:17:30.431Z,1694459850.431 [DataOverHttps](INFO): SBD MOMSN=18760952
2023-09-11T19:17:43.831Z,1694459863.831 [NAL9602](INFO): SBD MO Status=0, MOMSN=44625, MT Status=0, MTMSN=0
2023-09-11T19:17:43.831Z,1694459863.831 [NAL9602](INFO): No messages in MT queue
2023-09-11T19:17:46.212Z,1694459866.212 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20230911T161945/Express0098.lzma
2023-09-11T19:17:51.230Z,1694459871.230 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0098.lzma.bak
2023-09-11T19:17:51.230Z,1694459871.230 [DataOverHttps](INFO): SBD MOMSN=18760955
2023-09-11T19:17:52.332Z,1694459872.332 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T19:17:52.332Z,1694459872.332 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T19:17:52.332Z,1694459872.332 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T19:18:14.528Z,1694459894.528 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T19:22:52.939Z,1694460172.939 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T19:22:52.939Z,1694460172.939 [Default:CheckIn:C.Wait] Stopped
2023-09-11T19:22:52.940Z,1694460172.940 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T19:22:52.940Z,1694460172.940 [Default:CheckIn:D] Running Loop=1
2023-09-11T19:22:53.334Z,1694460173.334 [Default:CheckIn:D] Stopped
2023-09-11T19:22:53.334Z,1694460173.334 [Default:CheckIn:E] Running Loop=1
2023-09-11T19:22:53.735Z,1694460173.735 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 180.110335 min 
2023-09-11T19:22:53.735Z,1694460173.735 [Default:CheckIn:E] Stopped
2023-09-11T19:22:53.735Z,1694460173.735 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T19:22:53.735Z,1694460173.735 [Default:CheckIn] Stopped
2023-09-11T19:22:53.735Z,1694460173.735 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T19:22:53.736Z,1694460173.736 [Default:CheckIn](INFO): Running loop #31
2023-09-11T19:22:53.736Z,1694460173.736 [Default:CheckIn] Running Loop=31
2023-09-11T19:22:53.736Z,1694460173.736 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T19:22:53.736Z,1694460173.736 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T19:22:55.746Z,1694460175.746 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192255.00,A,3648.34307,N,12147.53714,W,4.918,248.68,110923,,,D*72
2023-09-11T19:22:55.749Z,1694460175.749 [NAL9602](INFO): GPS fix at 20230911T192255: (36.805718, -121.792286)
2023-09-11T19:22:55.759Z,1694460175.759 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T19:22:55.759Z,1694460175.759 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T19:22:56.567Z,1694460176.567 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T19:22:56.567Z,1694460176.567 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T19:22:56.567Z,1694460176.567 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T19:23:16.351Z,1694460196.351 [NAL9602](INFO): SBD MO Status=0, MOMSN=44626, MT Status=0, MTMSN=0
2023-09-11T19:23:16.351Z,1694460196.351 [NAL9602](INFO): No messages in MT queue
2023-09-11T19:23:47.057Z,1694460227.057 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T19:27:57.151Z,1694460477.151 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T19:27:57.151Z,1694460477.151 [Default:CheckIn:C.Wait] Stopped
2023-09-11T19:27:57.151Z,1694460477.151 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T19:27:57.151Z,1694460477.151 [Default:CheckIn:D] Running Loop=1
2023-09-11T19:27:57.552Z,1694460477.552 [Default:CheckIn:D] Stopped
2023-09-11T19:27:57.552Z,1694460477.552 [Default:CheckIn:E] Running Loop=1
2023-09-11T19:27:57.967Z,1694460477.967 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 185.180632 min 
2023-09-11T19:27:57.967Z,1694460477.967 [Default:CheckIn:E] Stopped
2023-09-11T19:27:57.968Z,1694460477.968 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T19:27:57.968Z,1694460477.968 [Default:CheckIn] Stopped
2023-09-11T19:27:57.968Z,1694460477.968 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T19:27:57.968Z,1694460477.968 [Default:CheckIn](INFO): Running loop #32
2023-09-11T19:27:57.968Z,1694460477.968 [Default:CheckIn] Running Loop=32
2023-09-11T19:27:57.968Z,1694460477.968 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T19:27:57.968Z,1694460477.968 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T19:27:59.966Z,1694460479.966 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192759.00,A,3648.32014,N,12148.05528,W,5.210,250.38,110923,,,D*73
2023-09-11T19:27:59.969Z,1694460479.969 [NAL9602](INFO): GPS fix at 20230911T192759: (36.805336, -121.800921)
2023-09-11T19:27:59.979Z,1694460479.979 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T19:27:59.979Z,1694460479.979 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T19:28:08.439Z,1694460488.439 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20230911T161945/Courier0100.lzma
2023-09-11T19:28:09.442Z,1694460489.442 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0100.lzma.bak
2023-09-11T19:28:09.442Z,1694460489.442 [DataOverHttps](INFO): SBD MOMSN=18760961
2023-09-11T19:28:24.659Z,1694460504.659 [NAL9602](INFO): SBD MO Status=0, MOMSN=44627, MT Status=0, MTMSN=0
2023-09-11T19:28:24.659Z,1694460504.659 [NAL9602](INFO): No messages in MT queue
2023-09-11T19:28:27.963Z,1694460507.963 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230911T161945/Courier0103.lzma
2023-09-11T19:28:28.966Z,1694460508.966 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0103.lzma.bak
2023-09-11T19:28:28.966Z,1694460508.966 [DataOverHttps](INFO): SBD MOMSN=18760965
2023-09-11T19:28:44.736Z,1694460524.736 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20230911T161945/Express0101.lzma
2023-09-11T19:28:45.738Z,1694460525.738 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0101.lzma.bak
2023-09-11T19:28:45.738Z,1694460525.738 [DataOverHttps](INFO): SBD MOMSN=18760968
2023-09-11T19:28:55.431Z,1694460535.431 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T19:29:04.256Z,1694460544.256 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20230911T161945/Express0104.lzma
2023-09-11T19:29:05.258Z,1694460545.258 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0104.lzma.bak
2023-09-11T19:29:05.258Z,1694460545.258 [DataOverHttps](INFO): SBD MOMSN=18760975
2023-09-11T19:29:06.356Z,1694460546.356 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T19:29:06.357Z,1694460546.357 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T19:29:06.357Z,1694460546.357 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T19:34:06.922Z,1694460846.922 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T19:34:06.923Z,1694460846.923 [Default:CheckIn:C.Wait] Stopped
2023-09-11T19:34:06.923Z,1694460846.923 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T19:34:06.923Z,1694460846.923 [Default:CheckIn:D] Running Loop=1
2023-09-11T19:34:07.324Z,1694460847.324 [Default:CheckIn:D] Stopped
2023-09-11T19:34:07.324Z,1694460847.324 [Default:CheckIn:E] Running Loop=1
2023-09-11T19:34:07.740Z,1694460847.740 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 191.343490 min 
2023-09-11T19:34:07.740Z,1694460847.740 [Default:CheckIn:E] Stopped
2023-09-11T19:34:07.740Z,1694460847.740 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T19:34:07.740Z,1694460847.740 [Default:CheckIn] Stopped
2023-09-11T19:34:07.740Z,1694460847.740 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T19:34:07.740Z,1694460847.740 [Default:CheckIn](INFO): Running loop #33
2023-09-11T19:34:07.740Z,1694460847.740 [Default:CheckIn] Running Loop=33
2023-09-11T19:34:07.741Z,1694460847.741 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T19:34:07.741Z,1694460847.741 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T19:34:09.743Z,1694460849.743 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193409.00,A,3648.35158,N,12148.71686,W,5.676,272.44,110923,,,D*71
2023-09-11T19:34:09.745Z,1694460849.745 [NAL9602](INFO): GPS fix at 20230911T193409: (36.805860, -121.811948)
2023-09-11T19:34:09.756Z,1694460849.756 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T19:34:09.756Z,1694460849.756 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T19:34:16.663Z,1694460856.663 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230911T161945/Courier0106.lzma
2023-09-11T19:34:17.667Z,1694460857.667 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0106.lzma.bak
2023-09-11T19:34:17.667Z,1694460857.667 [DataOverHttps](INFO): SBD MOMSN=18760992
2023-09-11T19:34:36.052Z,1694460876.052 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20230911T161945/Express0107.lzma
2023-09-11T19:34:37.055Z,1694460877.055 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0107.lzma.bak
2023-09-11T19:34:37.055Z,1694460877.055 [DataOverHttps](INFO): SBD MOMSN=18760995
2023-09-11T19:34:38.109Z,1694460878.109 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T19:34:38.109Z,1694460878.109 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T19:34:38.109Z,1694460878.109 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T19:34:58.289Z,1694460898.289 [NAL9602](INFO): SBD MO Status=2, MOMSN=44628, MT Status=2, MTMSN=0
2023-09-11T19:34:58.290Z,1694460898.290 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-11T19:35:18.899Z,1694460918.899 [NAL9602](INFO): SBD MO Status=0, MOMSN=44628, MT Status=0, MTMSN=0
2023-09-11T19:35:18.899Z,1694460918.899 [NAL9602](INFO): No messages in MT queue
2023-09-11T19:35:49.597Z,1694460949.597 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T19:37:40.488Z,1694461060.488 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-09-11T19:38:11.637Z,1694461091.637 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-09-11T19:38:42.768Z,1694461122.768 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-09-11T19:39:13.904Z,1694461153.904 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-09-11T19:39:38.691Z,1694461178.691 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T19:39:38.691Z,1694461178.691 [Default:CheckIn:C.Wait] Stopped
2023-09-11T19:39:38.691Z,1694461178.691 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T19:39:38.691Z,1694461178.691 [Default:CheckIn:D] Running Loop=1
2023-09-11T19:39:39.091Z,1694461179.091 [Default:CheckIn:D] Stopped
2023-09-11T19:39:39.091Z,1694461179.091 [Default:CheckIn:E] Running Loop=1
2023-09-11T19:39:39.495Z,1694461179.495 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 196.872949 min 
2023-09-11T19:39:39.495Z,1694461179.495 [Default:CheckIn:E] Stopped
2023-09-11T19:39:39.496Z,1694461179.496 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T19:39:39.496Z,1694461179.496 [Default:CheckIn] Stopped
2023-09-11T19:39:39.496Z,1694461179.496 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T19:39:39.496Z,1694461179.496 [Default:CheckIn](INFO): Running loop #34
2023-09-11T19:39:39.496Z,1694461179.496 [Default:CheckIn] Running Loop=34
2023-09-11T19:39:39.496Z,1694461179.496 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T19:39:39.496Z,1694461179.496 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T19:39:41.507Z,1694461181.507 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193940.00,A,3648.39665,N,12149.33232,W,5.637,269.01,110923,,,D*76
2023-09-11T19:39:41.548Z,1694461181.548 [NAL9602](INFO): GPS fix at 20230911T193940: (36.806611, -121.822205)
2023-09-11T19:39:41.559Z,1694461181.559 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T19:39:41.559Z,1694461181.559 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T19:39:45.029Z,1694461185.029 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-09-11T19:39:50.049Z,1694461190.049 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.771271
2023-09-11T19:39:57.263Z,1694461197.263 [NAL9602](INFO): SBD MO Status=0, MOMSN=44629, MT Status=0, MTMSN=0
2023-09-11T19:39:57.263Z,1694461197.263 [NAL9602](INFO): No messages in MT queue
2023-09-11T19:40:14.275Z,1694461214.275 [NAL9602](INFO): SBD MO Status=1, MOMSN=44630, MT Status=0, MTMSN=0
2023-09-11T19:40:14.324Z,1694461214.324 [NAL9602](INFO): Sent 72 bytes from file Logs/20230911T161945/Courier0109.lzma
2023-09-11T19:40:14.324Z,1694461214.324 [NAL9602](INFO): Packets left to send: 0
2023-09-11T19:40:21.172Z,1694461221.172 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-09-11T19:40:21.185Z,1694461221.185 [NAL9602](INFO): SBD MO Status=1, MOMSN=44631, MT Status=0, MTMSN=0
2023-09-11T19:40:21.240Z,1694461221.240 [NAL9602](INFO): Sent 144 bytes from file Logs/20230911T161945/Express0110.lzma
2023-09-11T19:40:21.241Z,1694461221.241 [NAL9602](INFO): Packets left to send: 0
2023-09-11T19:40:38.688Z,1694461238.688 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002798
2023-09-11T19:40:39.786Z,1694461239.786 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T19:40:39.786Z,1694461239.786 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T19:40:39.786Z,1694461239.786 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T19:40:41.787Z,1694461241.787 [NAL9602](INFO): SBD MO Status=0, MOMSN=44632, MT Status=0, MTMSN=0
2023-09-11T19:41:12.505Z,1694461272.505 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T19:43:44.240Z,1694461424.240 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-09-11T19:44:15.364Z,1694461455.364 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-09-11T19:44:36.568Z,1694461476.568 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T19:44:46.528Z,1694461486.528 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-09-11T19:44:50.706Z,1694461490.706 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T19:45:04.848Z,1694461504.848 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T19:45:17.660Z,1694461517.660 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-09-11T19:45:18.182Z,1694461518.182 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T19:45:27.053Z,1694461527.053 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=181.123291
2023-09-11T19:45:31.572Z,1694461531.572 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T19:45:40.492Z,1694461540.492 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T19:45:40.492Z,1694461540.492 [Default:CheckIn:C.Wait] Stopped
2023-09-11T19:45:40.492Z,1694461540.492 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T19:45:40.492Z,1694461540.492 [Default:CheckIn:D] Running Loop=1
2023-09-11T19:45:40.874Z,1694461540.874 [Default:CheckIn:D] Stopped
2023-09-11T19:45:40.874Z,1694461540.874 [Default:CheckIn:E] Running Loop=1
2023-09-11T19:45:41.280Z,1694461541.280 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 202.902653 min 
2023-09-11T19:45:41.280Z,1694461541.280 [Default:CheckIn:E] Stopped
2023-09-11T19:45:41.280Z,1694461541.280 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T19:45:41.280Z,1694461541.280 [Default:CheckIn] Stopped
2023-09-11T19:45:41.281Z,1694461541.281 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T19:45:41.281Z,1694461541.281 [Default:CheckIn](INFO): Running loop #35
2023-09-11T19:45:41.281Z,1694461541.281 [Default:CheckIn] Running Loop=35
2023-09-11T19:45:41.281Z,1694461541.281 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T19:45:41.281Z,1694461541.281 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T19:45:43.291Z,1694461543.291 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194542.00,A,3648.43459,N,12149.48621,W,2.313,310.56,110923,,,D*7C
2023-09-11T19:45:43.304Z,1694461543.304 [NAL9602](INFO): GPS fix at 20230911T194542: (36.807243, -121.824770)
2023-09-11T19:45:43.314Z,1694461543.314 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T19:45:43.314Z,1694461543.314 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T19:45:45.306Z,1694461545.306 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T19:45:59.446Z,1694461559.446 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T19:46:13.645Z,1694461573.645 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T19:46:19.269Z,1694461579.269 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-09-11T19:46:26.172Z,1694461586.172 [NAL9602](INFO): SBD MO Status=1, MOMSN=44633, MT Status=0, MTMSN=0
2023-09-11T19:46:26.227Z,1694461586.227 [NAL9602](INFO): Sent 73 bytes from file Logs/20230911T161945/Courier0112.lzma
2023-09-11T19:46:26.227Z,1694461586.227 [NAL9602](INFO): Packets left to send: 0
2023-09-11T19:46:29.110Z,1694461589.110 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T19:46:36.763Z,1694461596.763 [NAL9602](INFO): SBD MO Status=1, MOMSN=44634, MT Status=0, MTMSN=0
2023-09-11T19:46:36.812Z,1694461596.812 [NAL9602](INFO): Sent 143 bytes from file Logs/20230911T161945/Express0113.lzma
2023-09-11T19:46:36.813Z,1694461596.813 [NAL9602](INFO): Packets left to send: 0
2023-09-11T19:46:36.905Z,1694461596.905 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003575
2023-09-11T19:46:37.989Z,1694461597.989 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T19:46:37.989Z,1694461597.989 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T19:46:37.989Z,1694461597.989 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T19:46:43.239Z,1694461603.239 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-09-11T19:46:48.883Z,1694461608.883 [NAL9602](INFO): SBD MO Status=0, MOMSN=44635, MT Status=0, MTMSN=0
2023-09-11T19:47:19.589Z,1694461639.589 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T19:49:18.822Z,1694461758.822 [BPC1](INFO): Calculating totals. Valid battery stick count: 40. Valid reserve battery stick count: 5.
2023-09-11T19:49:18.824Z,1694461758.824 [BPC1](INFO): Received data from all battery sticks.
2023-09-11T19:51:38.717Z,1694461898.717 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T19:51:38.717Z,1694461898.717 [Default:CheckIn:C.Wait] Stopped
2023-09-11T19:51:38.717Z,1694461898.717 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T19:51:38.718Z,1694461898.718 [Default:CheckIn:D] Running Loop=1
2023-09-11T19:51:39.123Z,1694461899.123 [Default:CheckIn:D] Stopped
2023-09-11T19:51:39.123Z,1694461899.123 [Default:CheckIn:E] Running Loop=1
2023-09-11T19:51:39.528Z,1694461899.528 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 208.873486 min 
2023-09-11T19:51:39.528Z,1694461899.528 [Default:CheckIn:E] Stopped
2023-09-11T19:51:39.529Z,1694461899.529 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T19:51:39.529Z,1694461899.529 [Default:CheckIn] Stopped
2023-09-11T19:51:39.529Z,1694461899.529 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T19:51:39.529Z,1694461899.529 [Default:CheckIn](INFO): Running loop #36
2023-09-11T19:51:39.529Z,1694461899.529 [Default:CheckIn] Running Loop=36
2023-09-11T19:51:39.529Z,1694461899.529 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T19:51:39.529Z,1694461899.529 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T19:51:41.549Z,1694461901.549 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195140.00,A,3647.91058,N,12150.47339,W,22.898,224.90,110923,,,D*43
2023-09-11T19:51:41.552Z,1694461901.552 [NAL9602](INFO): GPS fix at 20230911T195140: (36.798510, -121.841223)
2023-09-11T19:51:41.562Z,1694461901.562 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T19:51:41.562Z,1694461901.562 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T19:51:48.783Z,1694461908.783 [DataOverHttps](INFO): Sending 83 bytes from file Logs/20230911T161945/Courier0115.lzma
2023-09-11T19:51:49.786Z,1694461909.786 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Courier0115.lzma.bak
2023-09-11T19:51:49.787Z,1694461909.787 [DataOverHttps](INFO): SBD MOMSN=18761035
2023-09-11T19:51:59.315Z,1694461919.315 [NAL9602](INFO): SBD MO Status=2, MOMSN=44636, MT Status=2, MTMSN=0
2023-09-11T19:51:59.315Z,1694461919.315 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-11T19:52:05.700Z,1694461925.700 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20230911T161945/Express0116.lzma
2023-09-11T19:52:06.702Z,1694461926.702 [DataOverHttps](INFO): Moved sent file to Logs/20230911T161945/Express0116.lzma.bak
2023-09-11T19:52:06.702Z,1694461926.702 [DataOverHttps](INFO): SBD MOMSN=18761038
2023-09-11T19:52:07.817Z,1694461927.817 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T19:52:07.817Z,1694461927.817 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T19:52:07.817Z,1694461927.817 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T19:52:19.112Z,1694461939.112 [NAL9602](INFO): SBD MO Status=0, MOMSN=44636, MT Status=0, MTMSN=0
2023-09-11T19:52:19.113Z,1694461939.113 [NAL9602](INFO): No messages in MT queue
2023-09-11T19:52:49.813Z,1694461969.813 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T19:57:08.485Z,1694462228.485 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-11T19:57:08.485Z,1694462228.485 [Default:CheckIn:C.Wait] Stopped
2023-09-11T19:57:08.485Z,1694462228.485 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-11T19:57:08.485Z,1694462228.485 [Default:CheckIn:D] Running Loop=1
2023-09-11T19:57:08.882Z,1694462228.882 [Default:CheckIn:D] Stopped
2023-09-11T19:57:08.882Z,1694462228.882 [Default:CheckIn:E] Running Loop=1
2023-09-11T19:57:09.293Z,1694462229.293 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 214.369466 min 
2023-09-11T19:57:09.294Z,1694462229.294 [Default:CheckIn:E] Stopped
2023-09-11T19:57:09.294Z,1694462229.294 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-11T19:57:09.294Z,1694462229.294 [Default:CheckIn] Stopped
2023-09-11T19:57:09.294Z,1694462229.294 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-11T19:57:09.294Z,1694462229.294 [Default:CheckIn](INFO): Running loop #37
2023-09-11T19:57:09.294Z,1694462229.294 [Default:CheckIn] Running Loop=37
2023-09-11T19:57:09.294Z,1694462229.294 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-11T19:57:09.294Z,1694462229.294 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-11T19:57:11.303Z,1694462231.303 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195710.00,A,3647.78301,N,12150.80820,W,0.700,68.64,110923,,,D*4F
2023-09-11T19:57:11.305Z,1694462231.305 [NAL9602](INFO): GPS fix at 20230911T195710: (36.796383, -121.846803)
2023-09-11T19:57:11.333Z,1694462231.333 [Default:CheckIn:Read_GPS] Stopped
2023-09-11T19:57:11.333Z,1694462231.333 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-11T19:57:12.115Z,1694462232.115 [Default:CheckIn:Read_Iridium] Stopped
2023-09-11T19:57:12.115Z,1694462232.115 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-11T19:57:12.115Z,1694462232.115 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-11T19:57:30.287Z,1694462250.287 [NAL9602](INFO): SBD MO Status=0, MOMSN=44637, MT Status=0, MTMSN=0
2023-09-11T19:57:30.287Z,1694462250.287 [NAL9602](INFO): No messages in MT queue
2023-09-11T19:58:00.988Z,1694462280.988 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-11T19:58:21.077Z,1694462301.077 [DataOverHttps](IMPORTANT): SBD MTMSN=20230911T195820