2023-09-27T16:38:04.443Z,1695832684.443 [Supervisor](DEBUG): Initializing supervisor.
2023-09-27T16:38:04.448Z,1695832684.448 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-09-27T16:38:04.449Z,1695832684.449 [SyncHandler](INFO): Protected caller Thread ID is 4699
2023-09-27T16:38:04.449Z,1695832684.449 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-09-27T16:38:04.450Z,1695832684.450 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-09-27T16:38:04.451Z,1695832684.451 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 4700
2023-09-27T16:38:04.455Z,1695832684.455 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-09-27T16:38:04.472Z,1695832684.472 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-09-27T16:38:04.473Z,1695832684.473 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-09-27T16:38:04.473Z,1695832684.473 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 4701
2023-09-27T16:38:04.477Z,1695832684.477 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-09-27T16:38:04.478Z,1695832684.478 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-09-27T16:38:04.479Z,1695832684.479 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 4702
2023-09-27T16:38:04.481Z,1695832684.481 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-09-27T16:38:04.482Z,1695832684.482 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-09-27T16:38:04.482Z,1695832684.482 [logger ThreadHandler](INFO): Protected caller Thread ID is 4703
2023-09-27T16:38:04.486Z,1695832684.486 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-09-27T16:38:04.486Z,1695832684.486 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-09-27T16:38:04.488Z,1695832684.488 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-09-27T16:38:04.584Z,1695832684.584 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-09-27T16:38:04.585Z,1695832684.585 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-09-27T16:38:05.259Z,1695832685.259 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-09-27T16:38:05.259Z,1695832685.259 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-09-27T16:38:05.472Z,1695832685.472 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-09-27T16:38:05.473Z,1695832685.473 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-09-27T16:38:05.552Z,1695832685.552 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-09-27T16:38:05.681Z,1695832685.681 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-09-27T16:38:05.681Z,1695832685.681 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-09-27T16:38:05.763Z,1695832685.763 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-09-27T16:38:05.872Z,1695832685.872 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-09-27T16:38:05.873Z,1695832685.873 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-09-27T16:38:06.243Z,1695832686.243 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-09-27T16:38:06.243Z,1695832686.243 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-09-27T16:38:06.714Z,1695832686.714 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-09-27T16:38:06.715Z,1695832686.715 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-09-27T16:38:06.926Z,1695832686.926 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-09-27T16:38:06.926Z,1695832686.926 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-09-27T16:38:07.110Z,1695832687.110 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-09-27T16:38:07.111Z,1695832687.111 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-09-27T16:38:07.610Z,1695832687.610 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-09-27T16:38:07.611Z,1695832687.611 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-09-27T16:38:07.888Z,1695832687.888 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-09-27T16:38:07.889Z,1695832687.889 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-09-27T16:38:08.106Z,1695832688.106 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-09-27T16:38:08.107Z,1695832688.107 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-09-27T16:38:08.480Z,1695832688.480 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-09-27T16:38:08.480Z,1695832688.480 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-09-27T16:38:08.850Z,1695832688.850 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-09-27T16:38:08.852Z,1695832688.852 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2023-09-27T16:38:08.853Z,1695832688.853 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2023-09-27T16:38:08.965Z,1695832688.965 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2023-09-27T16:38:09.251Z,1695832689.251 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2023-09-27T16:38:09.541Z,1695832689.541 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2023-09-27T16:38:09.746Z,1695832689.746 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2023-09-27T16:38:09.844Z,1695832689.844 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2023-09-27T16:38:09.959Z,1695832689.959 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2023-09-27T16:38:10.225Z,1695832690.225 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-09-27T16:38:10.225Z,1695832690.225 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2023-09-27T16:38:10.320Z,1695832690.320 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2023-09-27T16:38:10.418Z,1695832690.418 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2023-09-27T16:38:10.556Z,1695832690.556 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2023-09-27T16:38:10.656Z,1695832690.656 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/root/
2023-09-27T16:38:10.656Z,1695832690.656 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-09-27T16:38:10.667Z,1695832690.667 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-09-27T16:38:10.764Z,1695832690.764 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-09-27T16:38:10.765Z,1695832690.765 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-09-27T16:38:10.815Z,1695832690.815 [VerticalControl](DEBUG): Construct VerticalControl.
2023-09-27T16:38:10.874Z,1695832690.874 [VerticalControl] Loaded
2023-09-27T16:38:10.875Z,1695832690.875 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-09-27T16:38:10.877Z,1695832690.877 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-09-27T16:38:10.918Z,1695832690.918 [HorizontalControl] Loaded
2023-09-27T16:38:10.918Z,1695832690.918 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-09-27T16:38:10.920Z,1695832690.920 [SpeedControl](DEBUG): Construct SpeedControl.
2023-09-27T16:38:10.923Z,1695832690.923 [SpeedControl] Loaded
2023-09-27T16:38:10.923Z,1695832690.923 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-09-27T16:38:10.926Z,1695832690.926 [LoopControl](DEBUG): Construct LoopControl.
2023-09-27T16:38:10.927Z,1695832690.927 [LoopControl] Loaded
2023-09-27T16:38:10.927Z,1695832690.927 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-09-27T16:38:10.927Z,1695832690.927 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-09-27T16:38:10.928Z,1695832690.928 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-09-27T16:38:10.976Z,1695832690.976 [DepthRateCalculator] Loaded
2023-09-27T16:38:10.976Z,1695832690.976 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-09-27T16:38:10.981Z,1695832690.981 [PitchRateCalculator] Loaded
2023-09-27T16:38:10.981Z,1695832690.981 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-09-27T16:38:10.991Z,1695832690.991 [SpeedCalculator] Loaded
2023-09-27T16:38:10.991Z,1695832690.991 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-09-27T16:38:10.995Z,1695832690.995 [YawRateCalculator] Loaded
2023-09-27T16:38:10.996Z,1695832690.996 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-09-27T16:38:11.014Z,1695832691.014 [ElevatorOffsetCalculator] Loaded
2023-09-27T16:38:11.014Z,1695832691.014 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-09-27T16:38:11.014Z,1695832691.014 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-09-27T16:38:11.015Z,1695832691.015 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-09-27T16:38:11.041Z,1695832691.041 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-09-27T16:38:11.042Z,1695832691.042 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-09-27T16:38:11.095Z,1695832691.095 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-09-27T16:38:11.096Z,1695832691.096 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-09-27T16:38:11.393Z,1695832691.393 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-09-27T16:38:11.393Z,1695832691.393 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-09-27T16:38:11.537Z,1695832691.537 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-09-27T16:38:11.537Z,1695832691.537 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-09-27T16:38:11.976Z,1695832691.976 [AHRS_M2] Loaded
2023-09-27T16:38:11.976Z,1695832691.976 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-09-27T16:38:12.011Z,1695832692.011 [BackseatComponent] Loaded
2023-09-27T16:38:12.011Z,1695832692.011 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-09-27T16:38:12.012Z,1695832692.012 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 4098F4E0
2023-09-27T16:38:12.013Z,1695832692.013 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 4785
2023-09-27T16:38:12.015Z,1695832692.015 [LcmUniversalReporter] Loaded
2023-09-27T16:38:12.016Z,1695832692.016 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-09-27T16:38:12.818Z,1695832692.818 [BPC1] Loaded
2023-09-27T16:38:12.819Z,1695832692.819 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-09-27T16:38:12.892Z,1695832692.892 [DataOverHttps] Loaded
2023-09-27T16:38:12.892Z,1695832692.892 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-09-27T16:38:12.893Z,1695832692.893 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409BF4E0
2023-09-27T16:38:12.894Z,1695832692.894 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 4786
2023-09-27T16:38:12.914Z,1695832692.914 [Depth_Keller] Loaded
2023-09-27T16:38:12.914Z,1695832692.914 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-09-27T16:38:12.919Z,1695832692.919 [DropWeight] Loaded
2023-09-27T16:38:12.919Z,1695832692.919 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2023-09-27T16:38:12.982Z,1695832692.982 [NAL9602] Loaded
2023-09-27T16:38:12.982Z,1695832692.982 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-09-27T16:38:13.012Z,1695832693.012 [Onboard] Loaded
2023-09-27T16:38:13.012Z,1695832693.012 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-09-27T16:38:13.013Z,1695832693.013 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409EF4E0
2023-09-27T16:38:13.013Z,1695832693.013 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 4787
2023-09-27T16:38:13.019Z,1695832693.019 [PowerOnly](INFO): Adding load control power supply at /dev/loadB1
2023-09-27T16:38:13.030Z,1695832693.030 [PowerOnly] Loaded
2023-09-27T16:38:13.031Z,1695832693.031 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2023-09-27T16:38:13.042Z,1695832693.042 [Power24vConverter] Loaded
2023-09-27T16:38:13.042Z,1695832693.042 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-09-27T16:38:13.055Z,1695832693.055 [Radio_Surface] Loaded
2023-09-27T16:38:13.056Z,1695832693.056 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-09-27T16:38:13.057Z,1695832693.057 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40A1F4E0
2023-09-27T16:38:13.057Z,1695832693.057 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 4788
2023-09-27T16:38:13.102Z,1695832693.102 [RDI_Pathfinder] Loaded
2023-09-27T16:38:13.103Z,1695832693.103 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2023-09-27T16:38:13.194Z,1695832693.194 [DAT] Loaded
2023-09-27T16:38:13.194Z,1695832693.194 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2023-09-27T16:38:13.195Z,1695832693.195 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40A4F4E0
2023-09-27T16:38:13.196Z,1695832693.196 [DAT ThreadHandler](INFO): Protected caller Thread ID is 4789
2023-09-27T16:38:13.196Z,1695832693.196 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-09-27T16:38:13.197Z,1695832693.197 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-09-27T16:38:13.306Z,1695832693.306 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-09-27T16:38:13.307Z,1695832693.307 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-09-27T16:38:13.320Z,1695832693.320 [NavChart] Loaded
2023-09-27T16:38:13.320Z,1695832693.320 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-09-27T16:38:13.326Z,1695832693.326 [UniversalFixResidualReporter] Loaded
2023-09-27T16:38:13.326Z,1695832693.326 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-09-27T16:38:13.327Z,1695832693.327 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-09-27T16:38:13.327Z,1695832693.327 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-09-27T16:38:13.462Z,1695832693.462 [SBIT](DEBUG): Construct Startup Built In Test.
2023-09-27T16:38:13.471Z,1695832693.471 [SBIT] Loaded
2023-09-27T16:38:13.471Z,1695832693.471 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-09-27T16:38:13.474Z,1695832693.474 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-09-27T16:38:13.486Z,1695832693.486 [IBIT] Loaded
2023-09-27T16:38:13.487Z,1695832693.487 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-09-27T16:38:13.492Z,1695832693.492 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-09-27T16:38:13.595Z,1695832693.595 [CBIT] Loaded
2023-09-27T16:38:13.595Z,1695832693.595 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-09-27T16:38:13.596Z,1695832693.596 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-09-27T16:38:13.596Z,1695832693.596 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-09-27T16:38:13.721Z,1695832693.721 [BuoyancyServo] Loaded
2023-09-27T16:38:13.722Z,1695832693.722 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-09-27T16:38:13.742Z,1695832693.742 [ElevatorServo] Loaded
2023-09-27T16:38:13.743Z,1695832693.743 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-09-27T16:38:13.762Z,1695832693.762 [MassServo] Loaded
2023-09-27T16:38:13.762Z,1695832693.762 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-09-27T16:38:13.781Z,1695832693.781 [RudderServo] Loaded
2023-09-27T16:38:13.781Z,1695832693.781 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-09-27T16:38:13.798Z,1695832693.798 [ThrusterServo] Loaded
2023-09-27T16:38:13.798Z,1695832693.798 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2023-09-27T16:38:13.799Z,1695832693.799 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-09-27T16:38:13.799Z,1695832693.799 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-09-27T16:38:13.857Z,1695832693.857 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-09-27T16:38:13.858Z,1695832693.858 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-09-27T16:38:14.277Z,1695832694.277 [CTD_Seabird] Loaded
2023-09-27T16:38:14.277Z,1695832694.277 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-09-27T16:38:14.278Z,1695832694.278 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B9A4E0
2023-09-27T16:38:14.279Z,1695832694.279 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 4790
2023-09-27T16:38:14.299Z,1695832694.299 [PAR_Licor] Loaded
2023-09-27T16:38:14.299Z,1695832694.299 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-09-27T16:38:14.339Z,1695832694.339 [WetLabsBB2FL] Loaded
2023-09-27T16:38:14.339Z,1695832694.339 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-09-27T16:38:14.343Z,1695832694.343 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40BCA4E0
2023-09-27T16:38:14.344Z,1695832694.344 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 4791
2023-09-27T16:38:14.363Z,1695832694.363 [WetLabsUBAT] Loaded
2023-09-27T16:38:14.363Z,1695832694.363 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread.
2023-09-27T16:38:14.364Z,1695832694.364 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40BFA4E0
2023-09-27T16:38:14.365Z,1695832694.365 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 4792
2023-09-27T16:38:14.365Z,1695832694.365 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-09-27T16:38:14.372Z,1695832694.372 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-09-27T16:38:14.374Z,1695832694.374 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-09-27T16:38:14.386Z,1695832694.386 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-09-27T16:38:14.387Z,1695832694.387 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C2A4E0
2023-09-27T16:38:14.387Z,1695832694.387 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 4793
2023-09-27T16:38:14.391Z,1695832694.391 [Supervisor](INFO): Main Thread ID is 4544
2023-09-27T16:38:14.391Z,1695832694.391 [Supervisor](DEBUG): Running supervisor.
2023-09-27T16:38:14.392Z,1695832694.392 [CommandExec ThreadHandler](INFO): Handler Thread ID is 4794
2023-09-27T16:38:14.393Z,1695832694.393 [CommandExec](INFO): Initializing the command executive.
2023-09-27T16:38:14.394Z,1695832694.394 [CommandLine ThreadHandler](INFO): Handler Thread ID is 4795
2023-09-27T16:38:14.396Z,1695832694.396 [controlThread ThreadHandler](INFO): Handler Thread ID is 4796
2023-09-27T16:38:14.397Z,1695832694.397 [controlThread](DEBUG): Initializing ControlThread
2023-09-27T16:38:14.398Z,1695832694.398 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-09-27T16:38:14.399Z,1695832694.399 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-09-27T16:38:14.400Z,1695832694.400 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-09-27T16:38:14.401Z,1695832694.401 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-09-27T16:38:14.401Z,1695832694.401 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-09-27T16:38:14.401Z,1695832694.401 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-09-27T16:38:14.402Z,1695832694.402 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-09-27T16:38:14.402Z,1695832694.402 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-09-27T16:38:14.402Z,1695832694.402 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-09-27T16:38:14.409Z,1695832694.409 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-09-27T16:38:14.409Z,1695832694.409 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-09-27T16:38:14.410Z,1695832694.410 [SBIT](INFO): Initialize SBIT Component.
2023-09-27T16:38:14.410Z,1695832694.410 [SBIT](IMPORTANT): git: 2023-08-02-8-ga2b2183f7
2023-09-27T16:38:14.410Z,1695832694.410 [SBIT](INFO): git hash: a2b2183f71e07b707bfeaaf571c74c3561721119
2023-09-27T16:38:14.411Z,1695832694.411 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-09-27T16:38:14.412Z,1695832694.412 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2023-09-27T16:38:14.413Z,1695832694.413 [SBIT](INFO): Beginning SBIT in 43.000000 seconds.
2023-09-27T16:38:14.413Z,1695832694.413 [IBIT](INFO): Initialize IBIT Component.
2023-09-27T16:38:14.415Z,1695832694.415 [CBIT](DEBUG): Initialize CBIT Component.
2023-09-27T16:38:14.415Z,1695832694.415 [logger ThreadHandler](INFO): Handler Thread ID is 4797
2023-09-27T16:38:14.426Z,1695832694.426 [CBIT](DEBUG): Initialized mux pins.
2023-09-27T16:38:14.426Z,1695832694.426 [CBIT](DEBUG): Initializing the watchdog timer.
2023-09-27T16:38:14.435Z,1695832694.435 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 4798
2023-09-27T16:38:14.447Z,1695832694.447 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 4799
2023-09-27T16:38:14.448Z,1695832694.448 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-09-27T16:38:14.450Z,1695832694.450 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-09-27T16:38:14.451Z,1695832694.451 [CBIT](DEBUG): Initializing heartbeat.
2023-09-27T16:38:14.459Z,1695832694.459 [Onboard ThreadHandler](INFO): Handler Thread ID is 4800
2023-09-27T16:38:14.476Z,1695832694.476 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 4801
2023-09-27T16:38:14.507Z,1695832694.507 [DAT ThreadHandler](INFO): Handler Thread ID is 4802
2023-09-27T16:38:14.507Z,1695832694.507 [DAT](INFO): Powering up
2023-09-27T16:38:14.508Z,1695832694.508 [DAT](DEBUG): Initializing DAT.
2023-09-27T16:38:14.515Z,1695832694.515 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 4804
2023-09-27T16:38:14.515Z,1695832694.515 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-09-27T16:38:14.520Z,1695832694.520 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 4806
2023-09-27T16:38:14.522Z,1695832694.522 [CBIT](DEBUG): Deactivating GF circuits.
2023-09-27T16:38:14.523Z,1695832694.523 [CBIT](DEBUG): Deactivating emergency mode.
2023-09-27T16:38:14.527Z,1695832694.527 [WetLabsBB2FL](INFO): Powering up
2023-09-27T16:38:14.528Z,1695832694.528 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 4808
2023-09-27T16:38:14.531Z,1695832694.531 [WetLabsUBAT](INFO): Powering up
2023-09-27T16:38:14.532Z,1695832694.532 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 4810
2023-09-27T16:38:14.535Z,1695832694.535 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-09-27T16:38:14.536Z,1695832694.536 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-09-27T16:38:14.536Z,1695832694.536 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-09-27T16:38:14.536Z,1695832694.536 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-09-27T16:38:14.536Z,1695832694.536 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-09-27T16:38:14.536Z,1695832694.536 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-09-27T16:38:14.537Z,1695832694.537 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-09-27T16:38:14.537Z,1695832694.537 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-09-27T16:38:14.562Z,1695832694.562 [CBIT](DEBUG): Backplane powered.
2023-09-27T16:38:14.567Z,1695832694.567 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-09-27T16:38:14.595Z,1695832694.595 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-09-27T16:38:14.631Z,1695832694.631 [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-27T16:38:14.631Z,1695832694.631 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-09-27T16:38:14.717Z,1695832694.717 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-09-27T16:38:14.718Z,1695832694.718 [Default:A.Wait](DEBUG): Construct Wait.
2023-09-27T16:38:14.736Z,1695832694.736 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-09-27T16:38:14.756Z,1695832694.756 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-09-27T16:38:14.783Z,1695832694.783 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-09-27T16:38:14.804Z,1695832694.804 [Default:E.Execute](DEBUG): Construct Execute.
2023-09-27T16:38:14.823Z,1695832694.823 [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-27T16:38:14.834Z,1695832694.834 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,PowerOnly,Power24vConverter,RDI_Pathfinder,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2023-09-27T16:38:14.843Z,1695832694.843 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-09-27T16:38:14.882Z,1695832694.882 [Radio_Surface](INFO): Powering up
2023-09-27T16:38:14.932Z,1695832694.932 [Depth_Keller](ERROR): Pressure or depth reading out of range: -1.000394 decibar, -0.993016 m
2023-09-27T16:38:14.934Z,1695832694.934 [PowerOnly](INFO): Powering up loadControl
2023-09-27T16:38:14.955Z,1695832694.955 [Power24vConverter](INFO): Powering up.
2023-09-27T16:38:14.956Z,1695832694.956 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format
2023-09-27T16:38:14.968Z,1695832694.968 [DepthRateCalculator](ERROR): Depth measurement is not active
2023-09-27T16:38:15.017Z,1695832695.017 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-09-27T16:38:15.030Z,1695832695.030 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-09-27T16:38:15.036Z,1695832695.036 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-09-27T16:38:15.043Z,1695832695.043 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-09-27T16:38:15.044Z,1695832695.044 [MassServo](DEBUG): Initializing EZServoServo.
2023-09-27T16:38:15.051Z,1695832695.051 [MassServo](DEBUG): Initializing MassServo.
2023-09-27T16:38:15.051Z,1695832695.051 [RudderServo](DEBUG): Initializing EZServoServo.
2023-09-27T16:38:15.059Z,1695832695.059 [RudderServo](DEBUG): Initializing RudderServo.
2023-09-27T16:38:15.060Z,1695832695.060 [ThrusterServo](DEBUG): Initializing EZServoServo.
2023-09-27T16:38:15.067Z,1695832695.067 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2023-09-27T16:38:17.134Z,1695832697.134 [WetLabsBB2FL](INFO): Powering down
2023-09-27T16:38:23.803Z,1695832703.803 [WetLabsUBAT](INFO): Powering down
2023-09-27T16:38:26.603Z,1695832706.603 [DAT](INFO): DAT read: 

2023-09-27T16:38:26.604Z,1695832706.604 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2023-09-27T16:38:28.367Z,1695832708.367 [DAT](INFO): DAT read: MF Frequency Band

2023-09-27T16:38:28.368Z,1695832708.368 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2023-09-27T16:38:28.369Z,1695832708.369 [DAT](INFO): DAT read: Sep 27 2023 16:38:22 

2023-09-27T16:38:29.627Z,1695832709.627 [DAT](INFO): DAT read: Features enabled [Bearing]

2023-09-27T16:38:29.629Z,1695832709.629 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2023-09-27T16:38:29.629Z,1695832709.629 [DAT](INFO): commRate: 800
2023-09-27T16:38:31.694Z,1695832711.694 [DAT](INFO): entering command mode
2023-09-27T16:38:31.895Z,1695832711.895 [DAT](INFO): DAT read: 

2023-09-27T16:38:31.895Z,1695832711.895 [DAT](INFO): DAT read: user:1>

2023-09-27T16:38:31.896Z,1695832711.896 [DAT](INFO): setting verbose to 3
2023-09-27T16:38:32.147Z,1695832712.147 [DAT](INFO): DAT read: user:1>

2023-09-27T16:38:32.148Z,1695832712.148 [DAT](INFO): DAT read: Verbose         | 3           

2023-09-27T16:38:32.148Z,1695832712.148 [DAT](INFO): set verbose to 3
2023-09-27T16:38:32.149Z,1695832712.149 [DAT](INFO): setting DatVerbose to 27440
2023-09-27T16:38:32.399Z,1695832712.399 [DAT](INFO): DAT read: user:2>

2023-09-27T16:38:32.400Z,1695832712.400 [DAT](INFO): DAT read: DatVerbose      | 27440       

2023-09-27T16:38:32.400Z,1695832712.400 [DAT](INFO): set DatVerbose to 27440
2023-09-27T16:38:32.401Z,1695832712.401 [DAT](INFO): setting transmit power to 8
2023-09-27T16:38:32.651Z,1695832712.651 [DAT](INFO): DAT read: user:3>

2023-09-27T16:38:32.652Z,1695832712.652 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2023-09-27T16:38:32.652Z,1695832712.652 [DAT](INFO): set transmit power to 8
2023-09-27T16:38:32.653Z,1695832712.653 [DAT](INFO): setting local address to 10
2023-09-27T16:38:32.903Z,1695832712.903 [DAT](INFO): DAT read: user:4>

2023-09-27T16:38:32.904Z,1695832712.904 [DAT](INFO): DAT read: LocalAddr       | 10          

2023-09-27T16:38:32.904Z,1695832712.904 [DAT](INFO): set local address to 10
2023-09-27T16:38:32.905Z,1695832712.905 [DAT](INFO): Setting time to: 16:38:32 And date to:9/27/2023
2023-09-27T16:38:33.155Z,1695832713.155 [DAT](INFO): DAT read: user:5>

2023-09-27T16:38:33.156Z,1695832713.156 [DAT](INFO): DAT read: Wed Sep 27, 2023  16:38:32  

2023-09-27T16:38:33.156Z,1695832713.156 [DAT](INFO): Local DAT time set to Wed Sep 27, 2023  16:38:32  

2023-09-27T16:38:34.659Z,1695832714.659 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for bottom velocity. Device response is::BS,32768,-32768,V
2023-09-27T16:38:43.136Z,1695832723.136 [NAL9602](INFO): Powering up NAL9602
2023-09-27T16:38:54.049Z,1695832734.049 [NAL9602](INFO): NAL9602 initialized
2023-09-27T16:38:58.140Z,1695832738.140 [SBIT](IMPORTANT): Beginning Startup BIT
2023-09-27T16:38:58.148Z,1695832738.148 [CBIT](IMPORTANT): Beginning ground fault scan
2023-09-27T16:39:09.060Z,1695832749.060 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.007282
CHAN A1 (24V): 0.004518
CHAN A2 (12V): -0.005172
CHAN A3 (5V): -0.002219
CHAN B0 (3.3V): 0.000923
CHAN B1 (3.15aV): 0.000021
CHAN B2 (3.15bV): 0.000005
CHAN B3 (GND): 0.001918
OPEN: 0.005514
Full Scale: +/- 1 mA
2023-09-27T16:39:22.460Z,1695832762.460 [CommandExec](IMPORTANT): got command failComponent
2023-09-27T16:39:22.461Z,1695832762.461 [CommandExec](IMPORTANT): Failed components:
2023-09-27T16:39:22.461Z,1695832762.461 [CommandExec](IMPORTANT): No failed Components.
2023-09-27T16:39:35.651Z,1695832775.651 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file).
2023-09-27T16:39:52.234Z,1695832792.234 [SBIT](IMPORTANT): SBIT PASSED
2023-09-27T16:39:52.234Z,1695832792.234 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-09-27T16:39:52.236Z,1695832792.236 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;

2023-09-27T16:39:52.236Z,1695832792.236 [SBIT](IMPORTANT): CBIT.gf24Offset=143 microampere;

2023-09-27T16:39:52.238Z,1695832792.238 [SBIT](IMPORTANT): Express none CTD_Seabird.bin_median_sea_water_salinity;

2023-09-27T16:39:52.238Z,1695832792.238 [SBIT](IMPORTANT): Express none PowerOnly.component_avgCurrent_loadControl;

2023-09-27T16:39:52.238Z,1695832792.238 [SBIT](IMPORTANT): Express none WetLabsUBAT.flow_rate;

2023-09-27T16:39:52.238Z,1695832792.238 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=20 ampere_hour;

2023-09-27T16:39:52.239Z,1695832792.239 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=12 volt;

2023-09-27T16:39:52.239Z,1695832792.239 [SBIT](IMPORTANT): RDI_Pathfinder.loadAtStartup=1 bool;

2023-09-27T16:39:52.240Z,1695832792.240 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=307.497256 cubic_centimeter;

2023-09-27T16:39:52.242Z,1695832792.242 [SBIT](IMPORTANT): VerticalControl.massDefault=5.929260 millimeter;

2023-09-27T16:39:52.242Z,1695832792.242 [SBIT](IMPORTANT): WetLabsUBAT.loadAtStartup=1 bool;

2023-09-27T16:39:52.656Z,1695832792.656 [MissionManager](IMPORTANT): Started mission Startup
2023-09-27T16:39:52.657Z,1695832792.657 [Startup] Running Loop=1
2023-09-27T16:39:52.657Z,1695832792.657 [Startup](DEBUG): Aggregate::initialize Startup
2023-09-27T16:39:52.657Z,1695832792.657 [Startup:A.GoToSurface] Running Loop=1
2023-09-27T16:39:52.657Z,1695832792.657 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-09-27T16:39:52.658Z,1695832792.658 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-09-27T16:39:52.658Z,1695832792.658 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-09-27T16:39:52.659Z,1695832792.659 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-09-27T16:39:52.659Z,1695832792.659 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-09-27T16:39:52.659Z,1695832792.659 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-09-27T16:39:52.661Z,1695832792.661 [Startup:StartupSatComms] Running Loop=1
2023-09-27T16:39:52.661Z,1695832792.661 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-09-27T16:39:52.661Z,1695832792.661 [Startup:StartupSatComms:A] Running Loop=1
2023-09-27T16:39:53.041Z,1695832793.041 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-09-27T16:40:42.525Z,1695832842.525 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005041
2023-09-27T16:40:52.880Z,1695832852.880 [Startup:StartupSatComms:A](INFO): Timed out from 2023-09-27T16:39:52.7Z
2023-09-27T16:40:52.880Z,1695832852.880 [Startup:StartupSatComms:A] Stopped
2023-09-27T16:40:52.880Z,1695832852.880 [Startup:StartupSatComms:B] Running Loop=1
2023-09-27T16:40:53.257Z,1695832853.257 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-09-27T16:41:00.250Z,1695832860.250 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230927T162535/Courier0007.lzma
2023-09-27T16:41:01.253Z,1695832861.253 [DataOverHttps](INFO): Moved sent file to Logs/20230927T162535/Courier0007.lzma.bak
2023-09-27T16:41:01.253Z,1695832861.253 [DataOverHttps](INFO): SBD MOMSN=18909913
2023-09-27T16:41:14.750Z,1695832874.750 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2023-09-27T16:41:14.751Z,1695832874.751 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-09-27T16:41:14.770Z,1695832874.770 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-09-27T16:41:15.136Z,1695832875.136 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-09-27T16:41:15.136Z,1695832875.136 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2023-09-27T16:41:17.158Z,1695832877.158 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20230927T163804/Courier0000.lzma
2023-09-27T16:41:18.160Z,1695832878.160 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Courier0000.lzma.bak
2023-09-27T16:41:18.160Z,1695832878.160 [DataOverHttps](INFO): SBD MOMSN=18909915
2023-09-27T16:41:34.390Z,1695832894.390 [DataOverHttps](INFO): Sending 193 bytes from file Logs/20230927T162535/Express0008.lzma
2023-09-27T16:41:35.392Z,1695832895.392 [DataOverHttps](INFO): Moved sent file to Logs/20230927T162535/Express0008.lzma.bak
2023-09-27T16:41:35.392Z,1695832895.392 [DataOverHttps](INFO): SBD MOMSN=18909918
2023-09-27T16:41:51.315Z,1695832911.315 [DataOverHttps](INFO): Sending 983 bytes from file Logs/20230927T163804/Express0001.lzma
2023-09-27T16:41:52.316Z,1695832912.316 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Express0001.lzma.bak
2023-09-27T16:41:52.316Z,1695832912.316 [DataOverHttps](INFO): SBD MOMSN=18909923
2023-09-27T16:41:53.045Z,1695832913.045 [Startup:StartupSatComms:B](INFO): Timed out from 2023-09-27T16:40:52.9Z
2023-09-27T16:41:53.045Z,1695832913.045 [Startup:StartupSatComms:B] Stopped
2023-09-27T16:41:53.045Z,1695832913.045 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-09-27T16:41:53.045Z,1695832913.045 [Startup:StartupSatComms] Stopped
2023-09-27T16:41:53.045Z,1695832913.045 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-09-27T16:41:53.046Z,1695832913.046 [Startup](INFO): Completed Startup
2023-09-27T16:41:53.046Z,1695832913.046 [MissionManager](INFO): Startup is completed.
2023-09-27T16:41:53.046Z,1695832913.046 [MissionManager](INFO): Uninitializing Mission Startup
2023-09-27T16:41:53.046Z,1695832913.046 [Startup] Stopped
2023-09-27T16:41:53.047Z,1695832913.047 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-09-27T16:41:53.047Z,1695832913.047 [Startup:A.GoToSurface] Stopped
2023-09-27T16:41:53.047Z,1695832913.047 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-09-27T16:41:53.452Z,1695832913.452 [MissionManager](IMPORTANT): Started mission Default
2023-09-27T16:41:53.453Z,1695832913.453 [Default] Running Loop=1
2023-09-27T16:41:53.453Z,1695832913.453 [Default](DEBUG): Aggregate::initialize Default
2023-09-27T16:41:53.453Z,1695832913.453 [Default:B.GoToSurface] Running Loop=1
2023-09-27T16:41:53.453Z,1695832913.453 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-09-27T16:41:53.453Z,1695832913.453 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-09-27T16:41:53.453Z,1695832913.453 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-09-27T16:41:53.454Z,1695832913.454 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-09-27T16:41:53.454Z,1695832913.454 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-09-27T16:41:53.455Z,1695832913.455 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-09-27T16:41:53.455Z,1695832913.455 [Default:A.Wait] Running Loop=1
2023-09-27T16:41:53.455Z,1695832913.455 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-09-27T16:42:06.513Z,1695832926.513 [Default:A.Wait](INFO): Done Waiting.
2023-09-27T16:42:06.513Z,1695832926.513 [Default:A.Wait] Stopped
2023-09-27T16:42:06.513Z,1695832926.513 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-09-27T16:42:06.883Z,1695832926.883 [Default:CheckIn] Running Loop=1
2023-09-27T16:42:06.884Z,1695832926.884 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-27T16:42:06.884Z,1695832926.884 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-27T16:42:07.257Z,1695832927.257 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-09-27T16:43:57.528Z,1695833037.528 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-09-27T16:44:15.716Z,1695833055.716 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2023-09-27T16:44:15.716Z,1695833055.716 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-09-27T16:44:15.742Z,1695833055.742 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-09-27T16:44:16.129Z,1695833056.129 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-09-27T16:44:16.129Z,1695833056.129 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2023-09-27T16:45:00.456Z,1695833100.456 [CommandExec](IMPORTANT): got command ! /etc/rc.d/init.d/settime restart
2023-09-27T16:45:03.235Z,1695833103.235 [CommandExec](IMPORTANT): settime stop or restart
  Setting hardware clock from system clock
  Wed Sep 27 16:45:00 2023  0.000000 seconds
  settime start or restart
  Setting clock frequency and tick values from nonvolatile memory.
      mode:         16386
  -o  offset:       2546
  -f  frequency:    794192
      maxerror:     41133
      esterror:     1068
      status:       1 (PLL)
  -p  timeconstant: 10
      precision:    1
      tolerance:    32768000
  -t  tick:         10000
      time.tv_sec:  1695833100
      time.tv_usec: 824988
      return value: 0 (clock synchronized)
  ping returned from NTP server: 216.239.35.4
  45194 60302.032   43544.0      0.0    3961.0     91.6    794192
  Time set from NTP server: 216.239.35.4
  Setting hardware clock from system clock
  Wed Sep 27 16:45:03 2023  0.000000 seconds
  NTPD already running.
  
2023-09-27T16:45:40.541Z,1695833140.541 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2023-09-27T16:45:40.545Z,1695833140.545 [BPC1](INFO): Received data from all battery sticks.
2023-09-27T16:47:07.026Z,1695833227.026 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-09-27T16:42:06.9Z
2023-09-27T16:47:07.026Z,1695833227.026 [Default:CheckIn:Read_GPS] Stopped
2023-09-27T16:47:07.026Z,1695833227.026 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-27T16:47:07.396Z,1695833227.396 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-09-27T16:47:13.964Z,1695833233.964 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20230927T163804/Courier0004.lzma
2023-09-27T16:47:14.966Z,1695833234.966 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Courier0004.lzma.bak
2023-09-27T16:47:14.966Z,1695833234.966 [DataOverHttps](INFO): SBD MOMSN=18909950
2023-09-27T16:47:16.718Z,1695833236.718 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2023-09-27T16:47:16.718Z,1695833236.718 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-09-27T16:47:16.729Z,1695833236.729 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-09-27T16:47:17.137Z,1695833237.137 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-09-27T16:47:17.137Z,1695833237.137 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2023-09-27T16:47:30.875Z,1695833250.875 [DataOverHttps](INFO): Sending 612 bytes from file Logs/20230927T163804/Express0005.lzma
2023-09-27T16:47:31.858Z,1695833251.858 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Express0005.lzma.bak
2023-09-27T16:47:31.858Z,1695833251.858 [DataOverHttps](INFO): SBD MOMSN=18909952
2023-09-27T16:47:32.905Z,1695833252.905 [Default:CheckIn:Read_Iridium] Stopped
2023-09-27T16:47:32.905Z,1695833252.905 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-27T16:47:32.905Z,1695833252.905 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-27T16:47:49.750Z,1695833269.750 [CommandExec](IMPORTANT): got command burn on
2023-09-27T16:47:49.750Z,1695833269.750 [CommandExec](IMPORTANT): Activating dropweight wire
2023-09-27T16:48:13.594Z,1695833293.594 [CommandExec](IMPORTANT): got command burn off
2023-09-27T16:48:13.594Z,1695833293.594 [CommandExec](IMPORTANT): Deactivating dropweight wire
2023-09-27T16:48:55.254Z,1695833335.254 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-09-27T16:48:55.254Z,1695833335.254 [NAL9602] Data Fault, FailCount= 1
2023-09-27T16:48:55.255Z,1695833335.255 [NAL9602](ERROR): Data Fault
2023-09-27T16:48:55.280Z,1695833335.280 [CBIT](ERROR): Data Fault in component: NAL9602
2023-09-27T16:48:55.662Z,1695833335.662 [NAL9602](INFO): Powering down
2023-09-27T16:48:56.530Z,1695833336.530 [CBIT](INFO): Clearing failed state for component NAL9602
2023-09-27T16:48:56.531Z,1695833336.531 [NAL9602] No Fault, FailCount= 1
2023-09-27T16:49:25.962Z,1695833365.962 [NAL9602](INFO): Powering up NAL9602
2023-09-27T16:49:32.141Z,1695833372.141 [CommandExec](IMPORTANT): got command burn on
2023-09-27T16:49:32.142Z,1695833372.142 [CommandExec](IMPORTANT): Activating dropweight wire
2023-09-27T16:49:36.876Z,1695833376.876 [NAL9602](INFO): NAL9602 initialized
2023-09-27T16:50:09.930Z,1695833409.930 [CommandExec](IMPORTANT): got command burn off
2023-09-27T16:50:09.930Z,1695833409.930 [CommandExec](IMPORTANT): Deactivating dropweight wire
2023-09-27T16:50:17.714Z,1695833417.714 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2023-09-27T16:50:17.714Z,1695833417.714 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-09-27T16:50:17.725Z,1695833417.725 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-09-27T16:50:18.118Z,1695833418.118 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-09-27T16:50:18.118Z,1695833418.118 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2023-09-27T16:50:30.042Z,1695833430.042 [CommandExec](IMPORTANT): got command burn off
2023-09-27T16:50:30.042Z,1695833430.042 [CommandExec](IMPORTANT): Deactivating dropweight wire
2023-09-27T16:50:32.537Z,1695833432.537 [CommandExec](IMPORTANT): got command failComponent
2023-09-27T16:50:32.537Z,1695833432.537 [CommandExec](IMPORTANT): Failed components:
2023-09-27T16:50:32.537Z,1695833432.537 [CommandExec](IMPORTANT): No failed Components.
2023-09-27T16:52:33.430Z,1695833553.430 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-27T16:52:33.431Z,1695833553.431 [Default:CheckIn:C.Wait] Stopped
2023-09-27T16:52:33.431Z,1695833553.431 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-27T16:52:33.431Z,1695833553.431 [Default:CheckIn:D] Running Loop=1
2023-09-27T16:52:33.840Z,1695833553.840 [Default:CheckIn:D] Stopped
2023-09-27T16:52:33.840Z,1695833553.840 [Default:CheckIn:E] Running Loop=1
2023-09-27T16:52:34.235Z,1695833554.235 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.673123 min 
2023-09-27T16:52:34.235Z,1695833554.235 [Default:CheckIn:E] Stopped
2023-09-27T16:52:34.235Z,1695833554.235 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-27T16:52:34.235Z,1695833554.235 [Default:CheckIn] Stopped
2023-09-27T16:52:34.236Z,1695833554.236 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-27T16:52:34.236Z,1695833554.236 [Default:CheckIn](INFO): Running loop #2
2023-09-27T16:52:34.236Z,1695833554.236 [Default:CheckIn] Running Loop=2
2023-09-27T16:52:34.236Z,1695833554.236 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-27T16:52:34.236Z,1695833554.236 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-27T16:53:18.714Z,1695833598.714 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2023-09-27T16:53:18.714Z,1695833598.714 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-09-27T16:53:18.725Z,1695833598.725 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-09-27T16:53:19.119Z,1695833599.119 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-09-27T16:53:19.119Z,1695833599.119 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2023-09-27T16:56:19.662Z,1695833779.662 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2023-09-27T16:56:19.662Z,1695833779.662 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-09-27T16:56:19.681Z,1695833779.681 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-09-27T16:56:20.091Z,1695833780.091 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-09-27T16:56:20.091Z,1695833780.091 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2023-09-27T16:57:34.412Z,1695833854.412 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-09-27T16:52:34.2Z
2023-09-27T16:57:34.412Z,1695833854.412 [Default:CheckIn:Read_GPS] Stopped
2023-09-27T16:57:34.412Z,1695833854.412 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-27T16:57:41.804Z,1695833861.804 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230927T163804/Courier0007.lzma
2023-09-27T16:57:42.806Z,1695833862.806 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Courier0007.lzma.bak
2023-09-27T16:57:42.806Z,1695833862.806 [DataOverHttps](INFO): SBD MOMSN=18910045
2023-09-27T16:57:50.591Z,1695833870.591 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for water velocity. Device response is::WS,-2768,-32768,V
2023-09-27T16:57:58.680Z,1695833878.680 [DataOverHttps](INFO): Sending 314 bytes from file Logs/20230927T163804/Express0008.lzma
2023-09-27T16:57:59.682Z,1695833879.682 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Express0008.lzma.bak
2023-09-27T16:57:59.682Z,1695833879.682 [DataOverHttps](INFO): SBD MOMSN=18910047
2023-09-27T16:58:00.695Z,1695833880.695 [Default:CheckIn:Read_Iridium] Stopped
2023-09-27T16:58:00.695Z,1695833880.695 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-27T16:58:00.695Z,1695833880.695 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-27T16:59:20.686Z,1695833960.686 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2023-09-27T16:59:20.686Z,1695833960.686 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-09-27T16:59:20.697Z,1695833960.697 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-09-27T16:59:21.072Z,1695833961.072 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-09-27T16:59:21.072Z,1695833961.072 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2023-09-27T16:59:40.457Z,1695833980.457 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-09-27T16:59:40.457Z,1695833980.457 [NAL9602] Data Fault, FailCount= 2
2023-09-27T16:59:40.457Z,1695833980.457 [NAL9602](ERROR): Data Fault
2023-09-27T16:59:40.542Z,1695833980.542 [CBIT](ERROR): Data Fault in component: NAL9602
2023-09-27T16:59:40.850Z,1695833980.850 [NAL9602](INFO): Powering down
2023-09-27T16:59:41.681Z,1695833981.681 [CBIT](INFO): Clearing failed state for component NAL9602
2023-09-27T16:59:41.682Z,1695833981.682 [NAL9602] No Fault, FailCount= 2
2023-09-27T17:00:11.146Z,1695834011.146 [NAL9602](INFO): Powering up NAL9602
2023-09-27T17:00:22.068Z,1695834022.068 [NAL9602](INFO): NAL9602 initialized
2023-09-27T17:02:21.674Z,1695834141.674 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2023-09-27T17:02:21.674Z,1695834141.674 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-09-27T17:02:21.720Z,1695834141.720 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-09-27T17:02:22.075Z,1695834142.075 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-09-27T17:02:22.075Z,1695834142.075 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2023-09-27T17:02:26.541Z,1695834146.541 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for bottom velocity. Device response is::BS,-32768,-397
2023-09-27T17:03:01.258Z,1695834181.258 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-27T17:03:01.258Z,1695834181.258 [Default:CheckIn:C.Wait] Stopped
2023-09-27T17:03:01.259Z,1695834181.259 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-27T17:03:01.259Z,1695834181.259 [Default:CheckIn:D] Running Loop=1
2023-09-27T17:03:01.643Z,1695834181.643 [Default:CheckIn:D] Stopped
2023-09-27T17:03:01.643Z,1695834181.643 [Default:CheckIn:E] Running Loop=1
2023-09-27T17:03:02.057Z,1695834182.057 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.136503 min 
2023-09-27T17:03:02.057Z,1695834182.057 [Default:CheckIn:E] Stopped
2023-09-27T17:03:02.057Z,1695834182.057 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-27T17:03:02.057Z,1695834182.057 [Default:CheckIn] Stopped
2023-09-27T17:03:02.057Z,1695834182.057 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-27T17:03:02.057Z,1695834182.057 [Default:CheckIn](INFO): Running loop #3
2023-09-27T17:03:02.057Z,1695834182.057 [Default:CheckIn] Running Loop=3
2023-09-27T17:03:02.057Z,1695834182.057 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-27T17:03:02.058Z,1695834182.058 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-27T17:05:22.684Z,1695834322.684 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2023-09-27T17:05:22.684Z,1695834322.684 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-09-27T17:05:22.695Z,1695834322.695 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-09-27T17:05:23.079Z,1695834323.079 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-09-27T17:05:23.079Z,1695834323.079 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2023-09-27T17:08:02.282Z,1695834482.282 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-09-27T17:03:02.1Z
2023-09-27T17:08:02.282Z,1695834482.282 [Default:CheckIn:Read_GPS] Stopped
2023-09-27T17:08:02.282Z,1695834482.282 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-27T17:08:09.224Z,1695834489.224 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20230927T163804/Courier0010.lzma
2023-09-27T17:08:10.227Z,1695834490.227 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Courier0010.lzma.bak
2023-09-27T17:08:10.227Z,1695834490.227 [DataOverHttps](INFO): SBD MOMSN=18910150
2023-09-27T17:08:23.710Z,1695834503.710 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2023-09-27T17:08:23.710Z,1695834503.710 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-09-27T17:08:23.841Z,1695834503.841 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-09-27T17:08:24.175Z,1695834504.175 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-09-27T17:08:24.175Z,1695834504.175 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2023-09-27T17:08:29.348Z,1695834509.348 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20230927T163804/Express0011.lzma
2023-09-27T17:08:30.350Z,1695834510.350 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Express0011.lzma.bak
2023-09-27T17:08:30.350Z,1695834510.350 [DataOverHttps](INFO): SBD MOMSN=18910152
2023-09-27T17:08:31.397Z,1695834511.397 [Default:CheckIn:Read_Iridium] Stopped
2023-09-27T17:08:31.397Z,1695834511.397 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-27T17:08:31.397Z,1695834511.397 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-27T17:10:25.402Z,1695834625.402 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-09-27T17:10:25.402Z,1695834625.402 [NAL9602] Data Fault, FailCount= 3
2023-09-27T17:10:25.402Z,1695834625.402 [NAL9602](ERROR): Data Fault
2023-09-27T17:10:25.503Z,1695834625.503 [CBIT](ERROR): Data Fault in component: NAL9602
2023-09-27T17:10:25.778Z,1695834625.778 [NAL9602](INFO): Powering down
2023-09-27T17:10:26.681Z,1695834626.681 [CBIT](INFO): Clearing failed state for component NAL9602
2023-09-27T17:10:26.681Z,1695834626.681 [NAL9602] No Fault, FailCount= 3
2023-09-27T17:10:56.070Z,1695834656.070 [NAL9602](INFO): Powering up NAL9602
2023-09-27T17:11:06.983Z,1695834666.983 [NAL9602](INFO): NAL9602 initialized
2023-09-27T17:11:24.796Z,1695834684.796 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2023-09-27T17:11:24.796Z,1695834684.796 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-09-27T17:11:24.807Z,1695834684.807 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-09-27T17:11:25.180Z,1695834685.180 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-09-27T17:11:25.180Z,1695834685.180 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2023-09-27T17:13:28.784Z,1695834808.784 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171327.00,A,3648.17603,N,12147.28081,W,0.175,0.00,270923,,,A*7B
2023-09-27T17:13:28.787Z,1695834808.787 [NAL9602](INFO): GPS fix at 20230927T171327: (36.802934, -121.788014)
2023-09-27T17:13:32.039Z,1695834812.039 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-27T17:13:32.040Z,1695834812.040 [Default:CheckIn:C.Wait] Stopped
2023-09-27T17:13:32.040Z,1695834812.040 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-27T17:13:32.040Z,1695834812.040 [Default:CheckIn:D] Running Loop=1
2023-09-27T17:13:32.511Z,1695834812.511 [Default:CheckIn:D] Stopped
2023-09-27T17:13:32.511Z,1695834812.511 [Default:CheckIn:E] Running Loop=1
2023-09-27T17:13:32.905Z,1695834812.905 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.650970 min 
2023-09-27T17:13:32.905Z,1695834812.905 [Default:CheckIn:E] Stopped
2023-09-27T17:13:32.905Z,1695834812.905 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-27T17:13:32.905Z,1695834812.905 [Default:CheckIn] Stopped
2023-09-27T17:13:32.906Z,1695834812.906 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-27T17:13:32.906Z,1695834812.906 [Default:CheckIn](INFO): Running loop #4
2023-09-27T17:13:32.906Z,1695834812.906 [Default:CheckIn] Running Loop=4
2023-09-27T17:13:32.906Z,1695834812.906 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-27T17:13:32.906Z,1695834812.906 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-27T17:13:34.847Z,1695834814.847 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171333.00,A,3648.17513,N,12147.27915,W,1.244,0.00,270923,,,A*77
2023-09-27T17:13:34.850Z,1695834814.850 [NAL9602](INFO): GPS fix at 20230927T171333: (36.802919, -121.787986)
2023-09-27T17:13:34.888Z,1695834814.888 [Default:CheckIn:Read_GPS] Stopped
2023-09-27T17:13:34.888Z,1695834814.888 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-27T17:13:42.645Z,1695834822.645 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20230927T163804/Courier0013.lzma
2023-09-27T17:13:43.646Z,1695834823.646 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Courier0013.lzma.bak
2023-09-27T17:13:43.646Z,1695834823.646 [DataOverHttps](INFO): SBD MOMSN=18910236
2023-09-27T17:14:00.988Z,1695834840.988 [DataOverHttps](INFO): Sending 298 bytes from file Logs/20230927T163804/Express0014.lzma
2023-09-27T17:14:01.990Z,1695834841.990 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Express0014.lzma.bak
2023-09-27T17:14:01.990Z,1695834841.990 [DataOverHttps](INFO): SBD MOMSN=18910239
2023-09-27T17:14:03.141Z,1695834843.141 [Default:CheckIn:Read_Iridium] Stopped
2023-09-27T17:14:03.141Z,1695834843.141 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-27T17:14:03.141Z,1695834843.141 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-27T17:14:07.176Z,1695834847.176 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-27T17:19:03.781Z,1695835143.781 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-27T17:19:03.781Z,1695835143.781 [Default:CheckIn:C.Wait] Stopped
2023-09-27T17:19:03.781Z,1695835143.781 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-27T17:19:03.781Z,1695835143.781 [Default:CheckIn:D] Running Loop=1
2023-09-27T17:19:04.200Z,1695835144.200 [Default:CheckIn:D] Stopped
2023-09-27T17:19:04.200Z,1695835144.200 [Default:CheckIn:E] Running Loop=1
2023-09-27T17:19:04.621Z,1695835144.621 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 37.179118 min 
2023-09-27T17:19:04.621Z,1695835144.621 [Default:CheckIn:E] Stopped
2023-09-27T17:19:04.621Z,1695835144.621 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-27T17:19:04.621Z,1695835144.621 [Default:CheckIn] Stopped
2023-09-27T17:19:04.621Z,1695835144.621 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-27T17:19:04.621Z,1695835144.621 [Default:CheckIn](INFO): Running loop #5
2023-09-27T17:19:04.621Z,1695835144.621 [Default:CheckIn] Running Loop=5
2023-09-27T17:19:04.621Z,1695835144.621 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-27T17:19:04.621Z,1695835144.621 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-27T17:19:06.605Z,1695835146.605 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171905.00,A,3648.15056,N,12147.22540,W,0.078,33.70,270923,,,D*49
2023-09-27T17:19:06.607Z,1695835146.607 [NAL9602](INFO): GPS fix at 20230927T171905: (36.802509, -121.787090)
2023-09-27T17:19:06.659Z,1695835146.659 [Default:CheckIn:Read_GPS] Stopped
2023-09-27T17:19:06.659Z,1695835146.659 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-27T17:19:14.208Z,1695835154.208 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20230927T163804/Courier0016.lzma
2023-09-27T17:19:15.210Z,1695835155.210 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Courier0016.lzma.bak
2023-09-27T17:19:15.210Z,1695835155.210 [DataOverHttps](INFO): SBD MOMSN=18910243
2023-09-27T17:19:30.842Z,1695835170.842 [NAL9602](INFO): SBD MO Status=2, MOMSN=30565, MT Status=2, MTMSN=0
2023-09-27T17:19:30.842Z,1695835170.842 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-27T17:19:31.548Z,1695835171.548 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230927T163804/Express0017.lzma
2023-09-27T17:19:32.551Z,1695835172.551 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Express0017.lzma.bak
2023-09-27T17:19:32.551Z,1695835172.551 [DataOverHttps](INFO): SBD MOMSN=18910246
2023-09-27T17:19:33.678Z,1695835173.678 [Default:CheckIn:Read_Iridium] Stopped
2023-09-27T17:19:33.678Z,1695835173.678 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-27T17:19:33.678Z,1695835173.678 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-27T17:19:53.464Z,1695835193.464 [NAL9602](INFO): SBD MO Status=0, MOMSN=30565, MT Status=0, MTMSN=0
2023-09-27T17:19:53.464Z,1695835193.464 [NAL9602](INFO): No messages in MT queue
2023-09-27T17:20:24.190Z,1695835224.190 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-27T17:22:38.882Z,1695835358.882 [DataOverHttps](IMPORTANT): SBD MTMSN=20230927T172237
2023-09-27T17:22:46.537Z,1695835366.537 [DataOverHttps](INFO): Received command: ibit
2023-09-27T17:22:46.573Z,1695835366.573 [CommandExec](IMPORTANT): got command ibit
2023-09-27T17:22:46.855Z,1695835366.855 [IBIT](IMPORTANT): Beginning Initiated BIT
2023-09-27T17:22:46.855Z,1695835366.855 [IBIT](IMPORTANT): Beginning control surface checks.
2023-09-27T17:22:46.862Z,1695835366.862 [CBIT](IMPORTANT): Beginning ground fault scan
2023-09-27T17:22:48.429Z,1695835368.429 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172247.00,A,3648.14963,N,12147.21993,W,0.078,33.70,270923,,,D*48
2023-09-27T17:22:48.435Z,1695835368.435 [NAL9602](INFO): GPS fix at 20230927T172247: (36.802494, -121.786999)
2023-09-27T17:22:57.729Z,1695835377.729 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.008983
CHAN A1 (24V): 0.003447
CHAN A2 (12V): -0.005779
CHAN A3 (5V): -0.001259
CHAN B0 (3.3V): 0.000850
CHAN B1 (3.15aV): -0.000032
CHAN B2 (3.15bV): 0.000902
CHAN B3 (GND): 0.001157
OPEN: 0.005426
Full Scale: +/- 1 mA
2023-09-27T17:22:58.923Z,1695835378.923 [NAL9602](INFO): SBD MO Status=0, MOMSN=30566, MT Status=0, MTMSN=0
2023-09-27T17:22:58.923Z,1695835378.923 [NAL9602](INFO): No messages in MT queue
2023-09-27T17:23:00.135Z,1695835380.135 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172259.00,A,3648.14966,N,12147.22061,W,0.194,33.70,270923,,,D*46
2023-09-27T17:23:00.138Z,1695835380.138 [NAL9602](INFO): GPS fix at 20230927T172259: (36.802494, -121.787010)
2023-09-27T17:23:02.959Z,1695835382.959 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172302.00,A,3648.14968,N,12147.22077,W,0.039,33.70,270923,,,D*46
2023-09-27T17:23:02.972Z,1695835382.972 [NAL9602](INFO): GPS fix at 20230927T172302: (36.802495, -121.787013)
2023-09-27T17:23:05.795Z,1695835385.795 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172305.00,A,3648.14972,N,12147.22086,W,0.117,33.70,270923,,,D*49
2023-09-27T17:23:05.799Z,1695835385.799 [NAL9602](INFO): GPS fix at 20230927T172305: (36.802495, -121.787014)
2023-09-27T17:23:09.021Z,1695835389.021 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172308.00,A,3648.14974,N,12147.22095,W,0.078,33.70,270923,,,D*48
2023-09-27T17:23:09.023Z,1695835389.023 [NAL9602](INFO): GPS fix at 20230927T172308: (36.802496, -121.787016)
2023-09-27T17:23:11.851Z,1695835391.851 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172311.00,A,3648.14977,N,12147.22104,W,0.039,33.70,270923,,,D*4F
2023-09-27T17:23:11.854Z,1695835391.854 [NAL9602](INFO): GPS fix at 20230927T172311: (36.802496, -121.787017)
2023-09-27T17:23:15.083Z,1695835395.083 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172314.00,A,3648.14967,N,12147.22103,W,0.078,33.70,270923,,,D*49
2023-09-27T17:23:15.086Z,1695835395.086 [NAL9602](INFO): GPS fix at 20230927T172314: (36.802495, -121.787017)
2023-09-27T17:23:17.907Z,1695835397.907 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172317.00,A,3648.14960,N,12147.22133,W,0.078,33.70,270923,,,D*4E
2023-09-27T17:23:17.918Z,1695835397.918 [NAL9602](INFO): GPS fix at 20230927T172317: (36.802493, -121.787022)
2023-09-27T17:23:21.139Z,1695835401.139 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172320.00,A,3648.14958,N,12147.22163,W,0.078,33.70,270923,,,D*44
2023-09-27T17:23:21.142Z,1695835401.142 [NAL9602](INFO): GPS fix at 20230927T172320: (36.802493, -121.787027)
2023-09-27T17:23:23.977Z,1695835403.977 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172323.00,A,3648.14960,N,12147.22179,W,0.136,33.70,270923,,,D*4C
2023-09-27T17:23:23.980Z,1695835403.980 [NAL9602](INFO): GPS fix at 20230927T172323: (36.802493, -121.787030)
2023-09-27T17:23:26.824Z,1695835406.824 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172326.00,A,3648.14960,N,12147.22181,W,0.058,33.70,270923,,,D*47
2023-09-27T17:23:26.827Z,1695835406.827 [NAL9602](INFO): GPS fix at 20230927T172326: (36.802493, -121.787030)
2023-09-27T17:23:30.027Z,1695835410.027 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172329.00,A,3648.14957,N,12147.22166,W,0.175,33.70,270923,,,D*4B
2023-09-27T17:23:30.030Z,1695835410.030 [NAL9602](INFO): GPS fix at 20230927T172329: (36.802493, -121.787028)
2023-09-27T17:23:32.860Z,1695835412.860 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172332.00,A,3648.14958,N,12147.22160,W,0.058,33.70,270923,,,D*46
2023-09-27T17:23:32.862Z,1695835412.862 [NAL9602](INFO): GPS fix at 20230927T172332: (36.802493, -121.787027)
2023-09-27T17:23:33.295Z,1695835413.295 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 5
Latitude: 36.802494 Longitude: -121.787025
2023-09-27T17:23:33.689Z,1695835413.689 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.690001
2023-09-27T17:23:33.689Z,1695835413.689 [IBIT](IMPORTANT): batteryCapacityThreshold: 20.000000 Ah
2023-09-27T17:23:33.689Z,1695835413.689 [IBIT](IMPORTANT): batteryVoltageThreshold: 12.000000 V
2023-09-27T17:23:34.103Z,1695835414.103 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2023-09-27T17:23:34.104Z,1695835414.104 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2023-09-27T17:23:34.104Z,1695835414.104 [IBIT](IMPORTANT): Pressure:7.885896 PSI
2023-09-27T17:23:34.104Z,1695835414.104 [IBIT](IMPORTANT): Humidity:23.971432 %
2023-09-27T17:23:34.537Z,1695835414.537 [IBIT](IMPORTANT): Vehicle Pitch:2.983137 degrees
2023-09-27T17:23:34.537Z,1695835414.537 [IBIT](IMPORTANT): Vehicle  Roll:-13.670391 degrees
2023-09-27T17:23:34.537Z,1695835414.537 [IBIT](IMPORTANT): Vehicle  Heading:200.783295 degrees
2023-09-27T17:23:34.903Z,1695835414.903 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2023-09-27T17:23:34.903Z,1695835414.903 [IBIT](IMPORTANT): buoyancyNeutral: 307.497253 cc
2023-09-27T17:23:34.904Z,1695835414.904 [IBIT](IMPORTANT): massDefault: 0.592926 cm
2023-09-27T17:23:34.904Z,1695835414.904 [IBIT](IMPORTANT): stopDepth: 215.000000 m
2023-09-27T17:23:34.904Z,1695835414.904 [IBIT](IMPORTANT): abortDepth: 255.000000 m
2023-09-27T17:23:34.905Z,1695835414.905 [IBIT](IMPORTANT): IBIT PASSED
2023-09-27T17:24:05.586Z,1695835445.586 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-27T17:24:34.294Z,1695835474.294 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-27T17:24:34.294Z,1695835474.294 [Default:CheckIn:C.Wait] Stopped
2023-09-27T17:24:34.294Z,1695835474.294 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-27T17:24:34.294Z,1695835474.294 [Default:CheckIn:D] Running Loop=1
2023-09-27T17:24:34.721Z,1695835474.721 [Default:CheckIn:D] Stopped
2023-09-27T17:24:34.721Z,1695835474.721 [Default:CheckIn:E] Running Loop=1
2023-09-27T17:24:35.088Z,1695835475.088 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.687801 min 
2023-09-27T17:24:35.088Z,1695835475.088 [Default:CheckIn:E] Stopped
2023-09-27T17:24:35.088Z,1695835475.088 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-27T17:24:35.089Z,1695835475.089 [Default:CheckIn] Stopped
2023-09-27T17:24:35.089Z,1695835475.089 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-27T17:24:35.089Z,1695835475.089 [Default:CheckIn](INFO): Running loop #6
2023-09-27T17:24:35.089Z,1695835475.089 [Default:CheckIn] Running Loop=6
2023-09-27T17:24:35.089Z,1695835475.089 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-27T17:24:35.089Z,1695835475.089 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-27T17:24:37.102Z,1695835477.102 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172436.00,A,3648.14884,N,12147.22028,W,0.019,33.70,270923,,,D*4D
2023-09-27T17:24:37.104Z,1695835477.104 [NAL9602](INFO): GPS fix at 20230927T172436: (36.802481, -121.787005)
2023-09-27T17:24:37.116Z,1695835477.116 [Default:CheckIn:Read_GPS] Stopped
2023-09-27T17:24:37.116Z,1695835477.116 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-27T17:24:45.060Z,1695835485.060 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230927T163804/Courier0019.lzma
2023-09-27T17:24:46.062Z,1695835486.062 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Courier0019.lzma.bak
2023-09-27T17:24:46.062Z,1695835486.062 [DataOverHttps](INFO): SBD MOMSN=18910330
2023-09-27T17:24:50.465Z,1695835490.465 [NAL9602](INFO): SBD MO Status=0, MOMSN=30567, MT Status=0, MTMSN=0
2023-09-27T17:24:50.466Z,1695835490.466 [NAL9602](INFO): No messages in MT queue
2023-09-27T17:25:02.465Z,1695835502.465 [DataOverHttps](INFO): Sending 811 bytes from file Logs/20230927T163804/Express0020.lzma
2023-09-27T17:25:03.458Z,1695835503.458 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Express0020.lzma.bak
2023-09-27T17:25:03.458Z,1695835503.458 [DataOverHttps](INFO): SBD MOMSN=18910333
2023-09-27T17:25:19.716Z,1695835519.716 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20230927T163804/Express0023.lzma
2023-09-27T17:25:20.718Z,1695835520.718 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Express0023.lzma.bak
2023-09-27T17:25:20.719Z,1695835520.719 [DataOverHttps](INFO): SBD MOMSN=18910360
2023-09-27T17:25:21.130Z,1695835521.130 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-27T17:25:21.943Z,1695835521.943 [Default:CheckIn:Read_Iridium] Stopped
2023-09-27T17:25:21.944Z,1695835521.944 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-27T17:25:21.944Z,1695835521.944 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-27T17:30:22.615Z,1695835822.615 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-27T17:30:22.615Z,1695835822.615 [Default:CheckIn:C.Wait] Stopped
2023-09-27T17:30:22.615Z,1695835822.615 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-27T17:30:22.616Z,1695835822.616 [Default:CheckIn:D] Running Loop=1
2023-09-27T17:30:22.975Z,1695835822.975 [Default:CheckIn:D] Stopped
2023-09-27T17:30:22.975Z,1695835822.975 [Default:CheckIn:E] Running Loop=1
2023-09-27T17:30:23.395Z,1695835823.395 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.492037 min 
2023-09-27T17:30:23.395Z,1695835823.395 [Default:CheckIn:E] Stopped
2023-09-27T17:30:23.395Z,1695835823.395 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-27T17:30:23.395Z,1695835823.395 [Default:CheckIn] Stopped
2023-09-27T17:30:23.395Z,1695835823.395 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-27T17:30:23.395Z,1695835823.395 [Default:CheckIn](INFO): Running loop #7
2023-09-27T17:30:23.396Z,1695835823.396 [Default:CheckIn] Running Loop=7
2023-09-27T17:30:23.396Z,1695835823.396 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-27T17:30:23.396Z,1695835823.396 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-27T17:30:25.375Z,1695835825.375 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173024.00,A,3648.14904,N,12147.22029,W,0.019,33.70,270923,,,D*43
2023-09-27T17:30:25.378Z,1695835825.378 [NAL9602](INFO): GPS fix at 20230927T173024: (36.802484, -121.787005)
2023-09-27T17:30:25.393Z,1695835825.393 [Default:CheckIn:Read_GPS] Stopped
2023-09-27T17:30:25.393Z,1695835825.393 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-27T17:30:33.120Z,1695835833.120 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230927T163804/Courier0025.lzma
2023-09-27T17:30:34.123Z,1695835834.123 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Courier0025.lzma.bak
2023-09-27T17:30:34.123Z,1695835834.123 [DataOverHttps](INFO): SBD MOMSN=18910363
2023-09-27T17:30:49.615Z,1695835849.615 [NAL9602](INFO): SBD MO Status=0, MOMSN=30568, MT Status=0, MTMSN=0
2023-09-27T17:30:49.615Z,1695835849.615 [NAL9602](INFO): No messages in MT queue
2023-09-27T17:30:50.439Z,1695835850.439 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230927T163804/Express0026.lzma
2023-09-27T17:30:51.434Z,1695835851.434 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Express0026.lzma.bak
2023-09-27T17:30:51.434Z,1695835851.434 [DataOverHttps](INFO): SBD MOMSN=18910366
2023-09-27T17:30:52.540Z,1695835852.540 [Default:CheckIn:Read_Iridium] Stopped
2023-09-27T17:30:52.540Z,1695835852.540 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-27T17:30:52.540Z,1695835852.540 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-27T17:31:20.325Z,1695835880.325 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-27T17:35:53.032Z,1695836153.032 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-27T17:35:53.032Z,1695836153.032 [Default:CheckIn:C.Wait] Stopped
2023-09-27T17:35:53.032Z,1695836153.032 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-27T17:35:53.033Z,1695836153.033 [Default:CheckIn:D] Running Loop=1
2023-09-27T17:35:53.448Z,1695836153.448 [Default:CheckIn:D] Stopped
2023-09-27T17:35:53.449Z,1695836153.449 [Default:CheckIn:E] Running Loop=1
2023-09-27T17:35:53.861Z,1695836153.861 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 53.999910 min 
2023-09-27T17:35:53.861Z,1695836153.861 [Default:CheckIn:E] Stopped
2023-09-27T17:35:53.861Z,1695836153.861 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-27T17:35:53.861Z,1695836153.861 [Default:CheckIn] Stopped
2023-09-27T17:35:53.861Z,1695836153.861 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-27T17:35:53.861Z,1695836153.861 [Default:CheckIn](INFO): Running loop #8
2023-09-27T17:35:53.861Z,1695836153.861 [Default:CheckIn] Running Loop=8
2023-09-27T17:35:53.861Z,1695836153.861 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-27T17:35:53.862Z,1695836153.862 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-27T17:35:55.852Z,1695836155.852 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173555.00,A,3648.14923,N,12147.22073,W,0.058,33.70,270923,,,D*4F
2023-09-27T17:35:55.854Z,1695836155.854 [NAL9602](INFO): GPS fix at 20230927T173555: (36.802487, -121.787012)
2023-09-27T17:35:55.866Z,1695836155.866 [Default:CheckIn:Read_GPS] Stopped
2023-09-27T17:35:55.866Z,1695836155.866 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-27T17:36:03.596Z,1695836163.596 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230927T163804/Courier0028.lzma
2023-09-27T17:36:04.599Z,1695836164.599 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Courier0028.lzma.bak
2023-09-27T17:36:04.599Z,1695836164.599 [DataOverHttps](INFO): SBD MOMSN=18910459
2023-09-27T17:36:12.496Z,1695836172.496 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,23092709371675,35.0, +24.0,   0.0,1531

2023-09-27T17:36:16.047Z,1695836176.047 [NAL9602](INFO): SBD MO Status=0, MOMSN=30569, MT Status=0, MTMSN=0
2023-09-27T17:36:16.047Z,1695836176.047 [NAL9602](INFO): No messages in MT queue
2023-09-27T17:36:24.148Z,1695836184.148 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20230927T163804/Express0029.lzma
2023-09-27T17:36:25.151Z,1695836185.151 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Express0029.lzma.bak
2023-09-27T17:36:25.151Z,1695836185.151 [DataOverHttps](INFO): SBD MOMSN=18910462
2023-09-27T17:36:26.237Z,1695836186.237 [Default:CheckIn:Read_Iridium] Stopped
2023-09-27T17:36:26.237Z,1695836186.237 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-27T17:36:26.237Z,1695836186.237 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-27T17:36:46.817Z,1695836206.817 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-27T17:41:26.873Z,1695836486.873 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-27T17:41:26.873Z,1695836486.873 [Default:CheckIn:C.Wait] Stopped
2023-09-27T17:41:26.873Z,1695836486.873 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-27T17:41:26.873Z,1695836486.873 [Default:CheckIn:D] Running Loop=1
2023-09-27T17:41:27.273Z,1695836487.273 [Default:CheckIn:D] Stopped
2023-09-27T17:41:27.274Z,1695836487.274 [Default:CheckIn:E] Running Loop=1
2023-09-27T17:41:27.682Z,1695836487.682 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 59.563680 min 
2023-09-27T17:41:27.682Z,1695836487.682 [Default:CheckIn:E] Stopped
2023-09-27T17:41:27.682Z,1695836487.682 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-27T17:41:27.682Z,1695836487.682 [Default:CheckIn] Stopped
2023-09-27T17:41:27.682Z,1695836487.682 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-27T17:41:27.682Z,1695836487.682 [Default:CheckIn](INFO): Running loop #9
2023-09-27T17:41:27.682Z,1695836487.682 [Default:CheckIn] Running Loop=9
2023-09-27T17:41:27.682Z,1695836487.682 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-27T17:41:27.683Z,1695836487.683 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-27T17:41:29.692Z,1695836489.692 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174129.00,A,3648.14958,N,12147.22069,W,0.039,33.70,270923,,,D*47
2023-09-27T17:41:29.704Z,1695836489.704 [NAL9602](INFO): GPS fix at 20230927T174129: (36.802493, -121.787012)
2023-09-27T17:41:29.715Z,1695836489.715 [Default:CheckIn:Read_GPS] Stopped
2023-09-27T17:41:29.715Z,1695836489.715 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-27T17:41:37.484Z,1695836497.484 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230927T163804/Courier0031.lzma
2023-09-27T17:41:38.487Z,1695836498.487 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Courier0031.lzma.bak
2023-09-27T17:41:38.487Z,1695836498.487 [DataOverHttps](INFO): SBD MOMSN=18910466
2023-09-27T17:41:40.999Z,1695836500.999 [NAL9602](INFO): SBD MO Status=0, MOMSN=30570, MT Status=0, MTMSN=0
2023-09-27T17:41:40.000Z,1695836501.000 [NAL9602](INFO): No messages in MT queue
2023-09-27T17:41:54.832Z,1695836514.832 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230927T163804/Express0032.lzma
2023-09-27T17:41:55.834Z,1695836515.834 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Express0032.lzma.bak
2023-09-27T17:41:55.834Z,1695836515.834 [DataOverHttps](INFO): SBD MOMSN=18910469
2023-09-27T17:41:57.189Z,1695836517.189 [Default:CheckIn:Read_Iridium] Stopped
2023-09-27T17:41:57.190Z,1695836517.190 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-27T17:41:57.190Z,1695836517.190 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-27T17:42:11.705Z,1695836531.705 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-27T17:46:57.770Z,1695836817.770 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-27T17:46:57.770Z,1695836817.770 [Default:CheckIn:C.Wait] Stopped
2023-09-27T17:46:57.771Z,1695836817.771 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-27T17:46:57.771Z,1695836817.771 [Default:CheckIn:D] Running Loop=1
2023-09-27T17:46:58.189Z,1695836818.189 [Default:CheckIn:D] Stopped
2023-09-27T17:46:58.189Z,1695836818.189 [Default:CheckIn:E] Running Loop=1
2023-09-27T17:46:58.622Z,1695836818.622 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 65.078935 min 
2023-09-27T17:46:58.622Z,1695836818.622 [Default:CheckIn:E] Stopped
2023-09-27T17:46:58.622Z,1695836818.622 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-27T17:46:58.622Z,1695836818.622 [Default:CheckIn] Stopped
2023-09-27T17:46:58.622Z,1695836818.622 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-27T17:46:58.622Z,1695836818.622 [Default:CheckIn](INFO): Running loop #10
2023-09-27T17:46:58.622Z,1695836818.622 [Default:CheckIn] Running Loop=10
2023-09-27T17:46:58.622Z,1695836818.622 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-27T17:46:58.622Z,1695836818.622 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-27T17:47:00.583Z,1695836820.583 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174659.00,A,3648.14988,N,12147.22040,W,0.019,33.70,270923,,,D*43
2023-09-27T17:47:00.585Z,1695836820.585 [NAL9602](INFO): GPS fix at 20230927T174659: (36.802498, -121.787007)
2023-09-27T17:47:00.617Z,1695836820.617 [Default:CheckIn:Read_GPS] Stopped
2023-09-27T17:47:00.618Z,1695836820.618 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-27T17:47:08.120Z,1695836828.120 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230927T163804/Courier0034.lzma
2023-09-27T17:47:09.122Z,1695836829.122 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Courier0034.lzma.bak
2023-09-27T17:47:09.122Z,1695836829.122 [DataOverHttps](INFO): SBD MOMSN=18910544
2023-09-27T17:47:23.636Z,1695836843.636 [NAL9602](INFO): SBD MO Status=2, MOMSN=30571, MT Status=2, MTMSN=0
2023-09-27T17:47:23.636Z,1695836843.636 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-27T17:47:25.716Z,1695836845.716 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230927T163804/Express0035.lzma
2023-09-27T17:47:26.718Z,1695836846.718 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Express0035.lzma.bak
2023-09-27T17:47:26.718Z,1695836846.718 [DataOverHttps](INFO): SBD MOMSN=18910547
2023-09-27T17:47:27.738Z,1695836847.738 [Default:CheckIn:Read_Iridium] Stopped
2023-09-27T17:47:27.738Z,1695836847.738 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-27T17:47:27.739Z,1695836847.739 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-27T17:49:00.625Z,1695836940.625 [NAL9602](INFO): SBD MO Status=0, MOMSN=30571, MT Status=0, MTMSN=0
2023-09-27T17:49:00.625Z,1695836940.625 [NAL9602](INFO): No messages in MT queue
2023-09-27T17:49:31.329Z,1695836971.329 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-27T17:52:22.843Z,1695837142.843 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-09-27T17:52:28.405Z,1695837148.405 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-27T17:52:28.405Z,1695837148.405 [Default:CheckIn:C.Wait] Stopped
2023-09-27T17:52:28.405Z,1695837148.405 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-27T17:52:28.405Z,1695837148.405 [Default:CheckIn:D] Running Loop=1
2023-09-27T17:52:28.822Z,1695837148.822 [Default:CheckIn:D] Stopped
2023-09-27T17:52:28.823Z,1695837148.823 [Default:CheckIn:E] Running Loop=1
2023-09-27T17:52:29.218Z,1695837149.218 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 70.589494 min 
2023-09-27T17:52:29.219Z,1695837149.219 [Default:CheckIn:E] Stopped
2023-09-27T17:52:29.219Z,1695837149.219 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-27T17:52:29.219Z,1695837149.219 [Default:CheckIn] Stopped
2023-09-27T17:52:29.219Z,1695837149.219 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-27T17:52:29.219Z,1695837149.219 [Default:CheckIn](INFO): Running loop #11
2023-09-27T17:52:29.219Z,1695837149.219 [Default:CheckIn] Running Loop=11
2023-09-27T17:52:29.219Z,1695837149.219 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-27T17:52:29.219Z,1695837149.219 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-27T17:52:31.216Z,1695837151.216 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175230.00,A,3648.15040,N,12147.22049,W,0.019,33.70,270923,,,D*4C
2023-09-27T17:52:31.218Z,1695837151.218 [NAL9602](INFO): GPS fix at 20230927T175230: (36.802507, -121.787008)
2023-09-27T17:52:31.230Z,1695837151.230 [Default:CheckIn:Read_GPS] Stopped
2023-09-27T17:52:31.230Z,1695837151.230 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-27T17:52:38.656Z,1695837158.656 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20230927T163804/Courier0037.lzma
2023-09-27T17:52:39.658Z,1695837159.658 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Courier0037.lzma.bak
2023-09-27T17:52:39.658Z,1695837159.658 [DataOverHttps](INFO): SBD MOMSN=18910551
2023-09-27T17:52:46.567Z,1695837166.567 [NAL9602](INFO): SBD MO Status=0, MOMSN=30572, MT Status=0, MTMSN=0
2023-09-27T17:52:46.567Z,1695837166.567 [NAL9602](INFO): No messages in MT queue
2023-09-27T17:52:56.148Z,1695837176.148 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230927T163804/Express0038.lzma
2023-09-27T17:52:57.150Z,1695837177.150 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Express0038.lzma.bak
2023-09-27T17:52:57.150Z,1695837177.150 [DataOverHttps](INFO): SBD MOMSN=18910554
2023-09-27T17:52:58.292Z,1695837178.292 [Default:CheckIn:Read_Iridium] Stopped
2023-09-27T17:52:58.292Z,1695837178.292 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-27T17:52:58.293Z,1695837178.293 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-27T17:53:09.609Z,1695837189.609 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2023-09-27T17:53:09.613Z,1695837189.613 [BPC1](INFO): Received data from all battery sticks.
2023-09-27T17:53:17.264Z,1695837197.264 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-27T17:57:58.897Z,1695837478.897 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-27T17:57:58.897Z,1695837478.897 [Default:CheckIn:C.Wait] Stopped
2023-09-27T17:57:58.897Z,1695837478.897 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-27T17:57:58.897Z,1695837478.897 [Default:CheckIn:D] Running Loop=1
2023-09-27T17:57:59.298Z,1695837479.298 [Default:CheckIn:D] Stopped
2023-09-27T17:57:59.298Z,1695837479.298 [Default:CheckIn:E] Running Loop=1
2023-09-27T17:57:59.713Z,1695837479.713 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 76.097412 min 
2023-09-27T17:57:59.713Z,1695837479.713 [Default:CheckIn:E] Stopped
2023-09-27T17:57:59.714Z,1695837479.714 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-27T17:57:59.714Z,1695837479.714 [Default:CheckIn] Stopped
2023-09-27T17:57:59.714Z,1695837479.714 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-27T17:57:59.714Z,1695837479.714 [Default:CheckIn](INFO): Running loop #12
2023-09-27T17:57:59.714Z,1695837479.714 [Default:CheckIn] Running Loop=12
2023-09-27T17:57:59.714Z,1695837479.714 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-27T17:57:59.714Z,1695837479.714 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-27T17:58:01.710Z,1695837481.710 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175801.00,A,3648.14909,N,12147.22014,W,0.039,0.00,270923,,,D*7C
2023-09-27T17:58:01.713Z,1695837481.713 [NAL9602](INFO): GPS fix at 20230927T175801: (36.802485, -121.787002)
2023-09-27T17:58:01.726Z,1695837481.726 [Default:CheckIn:Read_GPS] Stopped
2023-09-27T17:58:01.726Z,1695837481.726 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-27T17:58:09.376Z,1695837489.376 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20230927T163804/Courier0040.lzma
2023-09-27T17:58:10.378Z,1695837490.378 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Courier0040.lzma.bak
2023-09-27T17:58:10.378Z,1695837490.378 [DataOverHttps](INFO): SBD MOMSN=18910651
2023-09-27T17:58:30.740Z,1695837510.740 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230927T163804/Express0041.lzma
2023-09-27T17:58:31.743Z,1695837511.743 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Express0041.lzma.bak
2023-09-27T17:58:31.743Z,1695837511.743 [DataOverHttps](INFO): SBD MOMSN=18910654
2023-09-27T17:58:32.885Z,1695837512.885 [Default:CheckIn:Read_Iridium] Stopped
2023-09-27T17:58:32.885Z,1695837512.885 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-27T17:58:32.885Z,1695837512.885 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-27T17:59:07.211Z,1695837547.211 [NAL9602](INFO): SBD MO Status=0, MOMSN=30573, MT Status=0, MTMSN=0
2023-09-27T17:59:07.211Z,1695837547.211 [NAL9602](INFO): No messages in MT queue
2023-09-27T17:59:37.919Z,1695837577.919 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-27T18:01:39.694Z,1695837699.694 [DataOverHttps](IMPORTANT): SBD MTMSN=20230927T180138
2023-09-27T18:01:47.276Z,1695837707.276 [DataOverHttps](INFO): Received command: gfscan
2023-09-27T18:01:47.329Z,1695837707.329 [CommandExec](IMPORTANT): got command gfscan
2023-09-27T18:01:47.706Z,1695837707.706 [CBIT](IMPORTANT): Beginning ground fault scan
2023-09-27T18:01:58.635Z,1695837718.635 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.012117
CHAN A1 (24V): 0.001902
CHAN A2 (12V): -0.006608
CHAN A3 (5V): -0.002449
CHAN B0 (3.3V): 0.000446
CHAN B1 (3.15aV): -0.000813
CHAN B2 (3.15bV): -0.000167
CHAN B3 (GND): 0.002063
OPEN: 0.005514
Full Scale: +/- 1 mA
2023-09-27T18:03:33.604Z,1695837813.604 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-27T18:03:33.604Z,1695837813.604 [Default:CheckIn:C.Wait] Stopped
2023-09-27T18:03:33.605Z,1695837813.605 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-27T18:03:33.605Z,1695837813.605 [Default:CheckIn:D] Running Loop=1
2023-09-27T18:03:34.005Z,1695837814.005 [Default:CheckIn:D] Stopped
2023-09-27T18:03:34.006Z,1695837814.006 [Default:CheckIn:E] Running Loop=1
2023-09-27T18:03:34.433Z,1695837814.433 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 81.675879 min 
2023-09-27T18:03:34.434Z,1695837814.434 [Default:CheckIn:E] Stopped
2023-09-27T18:03:34.434Z,1695837814.434 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-27T18:03:34.434Z,1695837814.434 [Default:CheckIn] Stopped
2023-09-27T18:03:34.435Z,1695837814.435 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-27T18:03:34.435Z,1695837814.435 [Default:CheckIn](INFO): Running loop #13
2023-09-27T18:03:34.435Z,1695837814.435 [Default:CheckIn] Running Loop=13
2023-09-27T18:03:34.436Z,1695837814.436 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-27T18:03:34.436Z,1695837814.436 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-27T18:03:36.410Z,1695837816.410 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180335.00,A,3648.14843,N,12147.22010,W,0.097,0.00,270923,,,D*75
2023-09-27T18:03:36.412Z,1695837816.412 [NAL9602](INFO): GPS fix at 20230927T180335: (36.802474, -121.787002)
2023-09-27T18:03:36.473Z,1695837816.473 [Default:CheckIn:Read_GPS] Stopped
2023-09-27T18:03:36.473Z,1695837816.473 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-27T18:03:44.088Z,1695837824.088 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230927T163804/Courier0043.lzma
2023-09-27T18:03:45.090Z,1695837825.090 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Courier0043.lzma.bak
2023-09-27T18:03:45.090Z,1695837825.090 [DataOverHttps](INFO): SBD MOMSN=18910660
2023-09-27T18:04:01.593Z,1695837841.593 [DataOverHttps](INFO): Sending 358 bytes from file Logs/20230927T163804/Express0044.lzma
2023-09-27T18:04:02.594Z,1695837842.594 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Express0044.lzma.bak
2023-09-27T18:04:02.594Z,1695837842.594 [DataOverHttps](INFO): SBD MOMSN=18910663
2023-09-27T18:04:03.883Z,1695837843.883 [NAL9602](INFO): SBD MO Status=0, MOMSN=30574, MT Status=0, MTMSN=0
2023-09-27T18:04:03.883Z,1695837843.883 [NAL9602](INFO): No messages in MT queue
2023-09-27T18:04:20.492Z,1695837860.492 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20230927T163804/Express0047.lzma
2023-09-27T18:04:21.494Z,1695837861.494 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Express0047.lzma.bak
2023-09-27T18:04:21.495Z,1695837861.495 [DataOverHttps](INFO): SBD MOMSN=18910670
2023-09-27T18:04:22.611Z,1695837862.611 [Default:CheckIn:Read_Iridium] Stopped
2023-09-27T18:04:22.611Z,1695837862.611 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-27T18:04:22.611Z,1695837862.611 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-27T18:04:34.612Z,1695837874.612 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-27T18:09:23.097Z,1695838163.097 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-27T18:09:23.097Z,1695838163.097 [Default:CheckIn:C.Wait] Stopped
2023-09-27T18:09:23.097Z,1695838163.097 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-27T18:09:23.097Z,1695838163.097 [Default:CheckIn:D] Running Loop=1
2023-09-27T18:09:23.501Z,1695838163.501 [Default:CheckIn:D] Stopped
2023-09-27T18:09:23.501Z,1695838163.501 [Default:CheckIn:E] Running Loop=1
2023-09-27T18:09:23.913Z,1695838163.913 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 87.500789 min 
2023-09-27T18:09:23.913Z,1695838163.913 [Default:CheckIn:E] Stopped
2023-09-27T18:09:23.914Z,1695838163.914 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-27T18:09:23.914Z,1695838163.914 [Default:CheckIn] Stopped
2023-09-27T18:09:23.914Z,1695838163.914 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-27T18:09:23.914Z,1695838163.914 [Default:CheckIn](INFO): Running loop #14
2023-09-27T18:09:23.914Z,1695838163.914 [Default:CheckIn] Running Loop=14
2023-09-27T18:09:23.914Z,1695838163.914 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-27T18:09:23.914Z,1695838163.914 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-27T18:09:25.914Z,1695838165.914 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180925.00,A,3648.13772,N,12147.20445,W,0.039,219.78,270923,,,D*73
2023-09-27T18:09:25.917Z,1695838165.917 [NAL9602](INFO): GPS fix at 20230927T180925: (36.802295, -121.786741)
2023-09-27T18:09:25.953Z,1695838165.953 [Default:CheckIn:Read_GPS] Stopped
2023-09-27T18:09:25.953Z,1695838165.953 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-27T18:09:33.696Z,1695838173.696 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230927T163804/Courier0049.lzma
2023-09-27T18:09:34.698Z,1695838174.698 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Courier0049.lzma.bak
2023-09-27T18:09:34.698Z,1695838174.698 [DataOverHttps](INFO): SBD MOMSN=18910758
2023-09-27T18:09:39.243Z,1695838179.243 [NAL9602](INFO): SBD MO Status=0, MOMSN=30575, MT Status=0, MTMSN=0
2023-09-27T18:09:39.243Z,1695838179.243 [NAL9602](INFO): No messages in MT queue
2023-09-27T18:09:51.012Z,1695838191.012 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230927T163804/Express0050.lzma
2023-09-27T18:09:52.014Z,1695838192.014 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Express0050.lzma.bak
2023-09-27T18:09:52.014Z,1695838192.014 [DataOverHttps](INFO): SBD MOMSN=18910761
2023-09-27T18:09:53.391Z,1695838193.391 [Default:CheckIn:Read_Iridium] Stopped
2023-09-27T18:09:53.392Z,1695838193.392 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-27T18:09:53.392Z,1695838193.392 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-27T18:10:09.947Z,1695838209.947 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-27T18:14:24.573Z,1695838464.573 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude. Device response is::BD,        +     +0.00,        +0.00,   0.00,5531.32
2023-09-27T18:14:54.039Z,1695838494.039 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-27T18:14:54.039Z,1695838494.039 [Default:CheckIn:C.Wait] Stopped
2023-09-27T18:14:54.040Z,1695838494.040 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-27T18:14:54.040Z,1695838494.040 [Default:CheckIn:D] Running Loop=1
2023-09-27T18:14:54.525Z,1695838494.525 [Default:CheckIn:D] Stopped
2023-09-27T18:14:54.525Z,1695838494.525 [Default:CheckIn:E] Running Loop=1
2023-09-27T18:14:54.882Z,1695838494.882 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 93.017879 min 
2023-09-27T18:14:54.882Z,1695838494.882 [Default:CheckIn:E] Stopped
2023-09-27T18:14:54.883Z,1695838494.883 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-27T18:14:54.883Z,1695838494.883 [Default:CheckIn] Stopped
2023-09-27T18:14:54.883Z,1695838494.883 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-27T18:14:54.883Z,1695838494.883 [Default:CheckIn](INFO): Running loop #15
2023-09-27T18:14:54.883Z,1695838494.883 [Default:CheckIn] Running Loop=15
2023-09-27T18:14:54.883Z,1695838494.883 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-27T18:14:54.883Z,1695838494.883 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-27T18:14:56.876Z,1695838496.876 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181456.00,A,3648.13828,N,12147.20449,W,0.039,219.78,270923,,,A*72
2023-09-27T18:14:56.882Z,1695838496.882 [NAL9602](INFO): GPS fix at 20230927T181456: (36.802305, -121.786742)
2023-09-27T18:14:56.893Z,1695838496.893 [Default:CheckIn:Read_GPS] Stopped
2023-09-27T18:14:56.894Z,1695838496.894 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-27T18:15:04.148Z,1695838504.148 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230927T163804/Courier0052.lzma
2023-09-27T18:15:05.151Z,1695838505.151 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Courier0052.lzma.bak
2023-09-27T18:15:05.151Z,1695838505.151 [DataOverHttps](INFO): SBD MOMSN=18910767
2023-09-27T18:15:21.332Z,1695838521.332 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230927T163804/Express0053.lzma
2023-09-27T18:15:22.334Z,1695838522.334 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Express0053.lzma.bak
2023-09-27T18:15:22.334Z,1695838522.334 [DataOverHttps](INFO): SBD MOMSN=18910770
2023-09-27T18:15:23.540Z,1695838523.540 [Default:CheckIn:Read_Iridium] Stopped
2023-09-27T18:15:23.540Z,1695838523.540 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-27T18:15:23.540Z,1695838523.540 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-27T18:15:44.939Z,1695838544.939 [NAL9602](INFO): SBD MO Status=2, MOMSN=30576, MT Status=2, MTMSN=0
2023-09-27T18:15:44.939Z,1695838544.939 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-27T18:15:52.615Z,1695838552.615 [NAL9602](INFO): SBD MO Status=0, MOMSN=30576, MT Status=0, MTMSN=0
2023-09-27T18:15:52.615Z,1695838552.615 [NAL9602](INFO): No messages in MT queue
2023-09-27T18:16:23.332Z,1695838583.332 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-27T18:20:24.201Z,1695838824.201 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-27T18:20:24.201Z,1695838824.201 [Default:CheckIn:C.Wait] Stopped
2023-09-27T18:20:24.201Z,1695838824.201 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-27T18:20:24.201Z,1695838824.201 [Default:CheckIn:D] Running Loop=1
2023-09-27T18:20:24.630Z,1695838824.630 [Default:CheckIn:D] Stopped
2023-09-27T18:20:24.630Z,1695838824.630 [Default:CheckIn:E] Running Loop=1
2023-09-27T18:20:25.022Z,1695838825.022 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 98.519621 min 
2023-09-27T18:20:25.022Z,1695838825.022 [Default:CheckIn:E] Stopped
2023-09-27T18:20:25.022Z,1695838825.022 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-27T18:20:25.022Z,1695838825.022 [Default:CheckIn] Stopped
2023-09-27T18:20:25.022Z,1695838825.022 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-27T18:20:25.022Z,1695838825.022 [Default:CheckIn](INFO): Running loop #16
2023-09-27T18:20:25.022Z,1695838825.022 [Default:CheckIn] Running Loop=16
2023-09-27T18:20:25.022Z,1695838825.022 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-27T18:20:25.022Z,1695838825.022 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-27T18:20:27.011Z,1695838827.011 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182026.00,A,3648.13826,N,12147.20524,W,0.117,219.78,270923,,,A*7B
2023-09-27T18:20:27.018Z,1695838827.018 [NAL9602](INFO): GPS fix at 20230927T182026: (36.802304, -121.786754)
2023-09-27T18:20:27.030Z,1695838827.030 [Default:CheckIn:Read_GPS] Stopped
2023-09-27T18:20:27.030Z,1695838827.030 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-27T18:20:35.024Z,1695838835.024 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230927T163804/Courier0055.lzma
2023-09-27T18:20:36.026Z,1695838836.026 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Courier0055.lzma.bak
2023-09-27T18:20:36.026Z,1695838836.026 [DataOverHttps](INFO): SBD MOMSN=18910863
2023-09-27T18:20:52.408Z,1695838852.408 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20230927T163804/Express0056.lzma
2023-09-27T18:20:53.410Z,1695838853.410 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Express0056.lzma.bak
2023-09-27T18:20:53.411Z,1695838853.411 [DataOverHttps](INFO): SBD MOMSN=18910866
2023-09-27T18:20:54.540Z,1695838854.540 [Default:CheckIn:Read_Iridium] Stopped
2023-09-27T18:20:54.540Z,1695838854.540 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-27T18:20:54.540Z,1695838854.540 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-27T18:21:04.584Z,1695838864.584 [NAL9602](INFO): SBD MO Status=0, MOMSN=30577, MT Status=0, MTMSN=0
2023-09-27T18:21:04.584Z,1695838864.584 [NAL9602](INFO): No messages in MT queue
2023-09-27T18:21:35.294Z,1695838895.294 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-27T18:25:55.101Z,1695839155.101 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-27T18:25:55.102Z,1695839155.102 [Default:CheckIn:C.Wait] Stopped
2023-09-27T18:25:55.102Z,1695839155.102 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-27T18:25:55.102Z,1695839155.102 [Default:CheckIn:D] Running Loop=1
2023-09-27T18:25:55.494Z,1695839155.494 [Default:CheckIn:D] Stopped
2023-09-27T18:25:55.494Z,1695839155.494 [Default:CheckIn:E] Running Loop=1
2023-09-27T18:25:55.901Z,1695839155.901 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 104.034025 min 
2023-09-27T18:25:55.902Z,1695839155.902 [Default:CheckIn:E] Stopped
2023-09-27T18:25:55.902Z,1695839155.902 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-27T18:25:55.902Z,1695839155.902 [Default:CheckIn] Stopped
2023-09-27T18:25:55.902Z,1695839155.902 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-27T18:25:55.902Z,1695839155.902 [Default:CheckIn](INFO): Running loop #17
2023-09-27T18:25:55.902Z,1695839155.902 [Default:CheckIn] Running Loop=17
2023-09-27T18:25:55.902Z,1695839155.902 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-27T18:25:55.902Z,1695839155.902 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-27T18:25:57.902Z,1695839157.902 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182557.00,A,3648.13740,N,12147.20460,W,0.058,219.78,270923,,,D*79
2023-09-27T18:25:57.905Z,1695839157.905 [NAL9602](INFO): GPS fix at 20230927T182557: (36.802290, -121.786743)
2023-09-27T18:25:57.929Z,1695839157.929 [Default:CheckIn:Read_GPS] Stopped
2023-09-27T18:25:57.929Z,1695839157.929 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-27T18:26:05.268Z,1695839165.268 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230927T163804/Courier0058.lzma
2023-09-27T18:26:06.270Z,1695839166.270 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Courier0058.lzma.bak
2023-09-27T18:26:06.271Z,1695839166.271 [DataOverHttps](INFO): SBD MOMSN=18910872
2023-09-27T18:26:25.945Z,1695839185.945 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230927T163804/Express0059.lzma
2023-09-27T18:26:26.947Z,1695839186.947 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Express0059.lzma.bak
2023-09-27T18:26:26.947Z,1695839186.947 [DataOverHttps](INFO): SBD MOMSN=18910878
2023-09-27T18:26:28.254Z,1695839188.254 [NAL9602](INFO): SBD MO Status=2, MOMSN=30578, MT Status=2, MTMSN=0
2023-09-27T18:26:28.254Z,1695839188.254 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-27T18:26:28.266Z,1695839188.266 [Default:CheckIn:Read_Iridium] Stopped
2023-09-27T18:26:28.266Z,1695839188.266 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-27T18:26:28.266Z,1695839188.266 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-27T18:27:11.887Z,1695839231.887 [NAL9602](INFO): SBD MO Status=2, MOMSN=30578, MT Status=2, MTMSN=0
2023-09-27T18:27:11.888Z,1695839231.888 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-27T18:27:21.180Z,1695839241.180 [NAL9602](INFO): SBD MO Status=0, MOMSN=30578, MT Status=0, MTMSN=0
2023-09-27T18:27:21.180Z,1695839241.180 [NAL9602](INFO): No messages in MT queue
2023-09-27T18:27:51.898Z,1695839271.898 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-27T18:31:28.925Z,1695839488.925 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-27T18:31:28.925Z,1695839488.925 [Default:CheckIn:C.Wait] Stopped
2023-09-27T18:31:28.925Z,1695839488.925 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-27T18:31:28.925Z,1695839488.925 [Default:CheckIn:D] Running Loop=1
2023-09-27T18:31:29.334Z,1695839489.334 [Default:CheckIn:D] Stopped
2023-09-27T18:31:29.334Z,1695839489.334 [Default:CheckIn:E] Running Loop=1
2023-09-27T18:31:29.739Z,1695839489.739 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 109.598014 min 
2023-09-27T18:31:29.739Z,1695839489.739 [Default:CheckIn:E] Stopped
2023-09-27T18:31:29.739Z,1695839489.739 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-27T18:31:29.739Z,1695839489.739 [Default:CheckIn] Stopped
2023-09-27T18:31:29.739Z,1695839489.739 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-27T18:31:29.740Z,1695839489.740 [Default:CheckIn](INFO): Running loop #18
2023-09-27T18:31:29.740Z,1695839489.740 [Default:CheckIn] Running Loop=18
2023-09-27T18:31:29.740Z,1695839489.740 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-27T18:31:29.740Z,1695839489.740 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-27T18:31:31.738Z,1695839491.738 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183131.00,A,3648.19770,N,12147.16558,W,4.471,31.05,270923,,,D*43
2023-09-27T18:31:31.741Z,1695839491.741 [NAL9602](INFO): GPS fix at 20230927T183131: (36.803295, -121.786093)
2023-09-27T18:31:31.769Z,1695839491.769 [Default:CheckIn:Read_GPS] Stopped
2023-09-27T18:31:31.769Z,1695839491.769 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-27T18:31:39.296Z,1695839499.296 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230927T163804/Courier0061.lzma
2023-09-27T18:31:40.298Z,1695839500.298 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Courier0061.lzma.bak
2023-09-27T18:31:40.298Z,1695839500.298 [DataOverHttps](INFO): SBD MOMSN=18910956
2023-09-27T18:31:56.764Z,1695839516.764 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230927T163804/Express0062.lzma
2023-09-27T18:31:57.770Z,1695839517.770 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Express0062.lzma.bak
2023-09-27T18:31:57.770Z,1695839517.770 [DataOverHttps](INFO): SBD MOMSN=18910960
2023-09-27T18:31:58.845Z,1695839518.845 [Default:CheckIn:Read_Iridium] Stopped
2023-09-27T18:31:58.845Z,1695839518.845 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-27T18:31:58.845Z,1695839518.845 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-27T18:32:02.847Z,1695839522.847 [NAL9602](INFO): SBD MO Status=0, MOMSN=30579, MT Status=0, MTMSN=0
2023-09-27T18:32:02.847Z,1695839522.847 [NAL9602](INFO): No messages in MT queue
2023-09-27T18:32:33.565Z,1695839553.565 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-27T18:34:10.554Z,1695839650.554 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for bottom velocity. Device response is::BS,-3278,-32768,V
2023-09-27T18:36:59.433Z,1695839819.433 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-27T18:36:59.433Z,1695839819.433 [Default:CheckIn:C.Wait] Stopped
2023-09-27T18:36:59.433Z,1695839819.433 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-27T18:36:59.433Z,1695839819.433 [Default:CheckIn:D] Running Loop=1
2023-09-27T18:36:59.828Z,1695839819.828 [Default:CheckIn:D] Stopped
2023-09-27T18:36:59.828Z,1695839819.828 [Default:CheckIn:E] Running Loop=1
2023-09-27T18:37:00.228Z,1695839820.228 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 115.106258 min 
2023-09-27T18:37:00.228Z,1695839820.228 [Default:CheckIn:E] Stopped
2023-09-27T18:37:00.228Z,1695839820.228 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-27T18:37:00.228Z,1695839820.228 [Default:CheckIn] Stopped
2023-09-27T18:37:00.228Z,1695839820.228 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-27T18:37:00.229Z,1695839820.229 [Default:CheckIn](INFO): Running loop #19
2023-09-27T18:37:00.229Z,1695839820.229 [Default:CheckIn] Running Loop=19
2023-09-27T18:37:00.229Z,1695839820.229 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-27T18:37:00.229Z,1695839820.229 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-27T18:37:02.241Z,1695839822.241 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183701.00,A,3648.40502,N,12147.38283,W,10.089,231.17,270923,,,D*47
2023-09-27T18:37:02.243Z,1695839822.243 [NAL9602](INFO): GPS fix at 20230927T183701: (36.806750, -121.789714)
2023-09-27T18:37:02.255Z,1695839822.255 [Default:CheckIn:Read_GPS] Stopped
2023-09-27T18:37:02.255Z,1695839822.255 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-27T18:37:10.228Z,1695839830.228 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230927T163804/Courier0064.lzma
2023-09-27T18:37:11.230Z,1695839831.230 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Courier0064.lzma.bak
2023-09-27T18:37:11.230Z,1695839831.230 [DataOverHttps](INFO): SBD MOMSN=18910968
2023-09-27T18:37:24.863Z,1695839844.863 [NAL9602](INFO): SBD MO Status=2, MOMSN=30580, MT Status=2, MTMSN=0
2023-09-27T18:37:24.863Z,1695839844.863 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-27T18:37:27.780Z,1695839847.780 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230927T163804/Express0065.lzma
2023-09-27T18:37:28.783Z,1695839848.783 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Express0065.lzma.bak
2023-09-27T18:37:28.783Z,1695839848.783 [DataOverHttps](INFO): SBD MOMSN=18910977
2023-09-27T18:37:30.125Z,1695839850.125 [Default:CheckIn:Read_Iridium] Stopped
2023-09-27T18:37:30.125Z,1695839850.125 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-27T18:37:30.125Z,1695839850.125 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-27T18:37:41.023Z,1695839861.023 [NAL9602](INFO): SBD MO Status=2, MOMSN=30580, MT Status=2, MTMSN=0
2023-09-27T18:37:41.024Z,1695839861.024 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-27T18:38:11.323Z,1695839891.323 [NAL9602](INFO): SBD MO Status=0, MOMSN=30580, MT Status=0, MTMSN=0
2023-09-27T18:38:11.323Z,1695839891.323 [NAL9602](INFO): No messages in MT queue
2023-09-27T18:38:42.024Z,1695839922.024 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-27T18:42:30.808Z,1695840150.808 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-27T18:42:30.808Z,1695840150.808 [Default:CheckIn:C.Wait] Stopped
2023-09-27T18:42:30.808Z,1695840150.808 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-27T18:42:30.808Z,1695840150.808 [Default:CheckIn:D] Running Loop=1
2023-09-27T18:42:31.172Z,1695840151.172 [Default:CheckIn:D] Stopped
2023-09-27T18:42:31.172Z,1695840151.172 [Default:CheckIn:E] Running Loop=1
2023-09-27T18:42:31.567Z,1695840151.567 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 120.628646 min 
2023-09-27T18:42:31.567Z,1695840151.567 [Default:CheckIn:E] Stopped
2023-09-27T18:42:31.567Z,1695840151.567 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-27T18:42:31.567Z,1695840151.567 [Default:CheckIn] Stopped
2023-09-27T18:42:31.567Z,1695840151.567 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-27T18:42:31.568Z,1695840151.568 [Default:CheckIn](INFO): Running loop #20
2023-09-27T18:42:31.568Z,1695840151.568 [Default:CheckIn] Running Loop=20
2023-09-27T18:42:31.568Z,1695840151.568 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-27T18:42:31.568Z,1695840151.568 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-27T18:42:33.583Z,1695840153.583 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184232.00,A,3648.13999,N,12148.70229,W,14.423,249.01,270923,,,D*46
2023-09-27T18:42:33.586Z,1695840153.586 [NAL9602](INFO): GPS fix at 20230927T184232: (36.802333, -121.811705)
2023-09-27T18:42:33.597Z,1695840153.597 [Default:CheckIn:Read_GPS] Stopped
2023-09-27T18:42:33.597Z,1695840153.597 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-27T18:42:41.676Z,1695840161.676 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230927T163804/Courier0067.lzma
2023-09-27T18:42:42.678Z,1695840162.678 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Courier0067.lzma.bak
2023-09-27T18:42:42.678Z,1695840162.678 [DataOverHttps](INFO): SBD MOMSN=18911059
2023-09-27T18:42:45.747Z,1695840165.747 [NAL9602](INFO): SBD MO Status=0, MOMSN=30581, MT Status=0, MTMSN=0
2023-09-27T18:42:45.747Z,1695840165.747 [NAL9602](INFO): No messages in MT queue
2023-09-27T18:42:59.376Z,1695840179.376 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20230927T163804/Express0068.lzma
2023-09-27T18:43:00.378Z,1695840180.378 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Express0068.lzma.bak
2023-09-27T18:43:00.379Z,1695840180.379 [DataOverHttps](INFO): SBD MOMSN=18911062
2023-09-27T18:43:01.501Z,1695840181.501 [Default:CheckIn:Read_Iridium] Stopped
2023-09-27T18:43:01.501Z,1695840181.501 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-27T18:43:01.501Z,1695840181.501 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-27T18:43:16.441Z,1695840196.441 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-27T18:44:08.073Z,1695840248.073 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting.
2023-09-27T18:44:09.077Z,1695840249.077 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.023170
2023-09-27T18:44:43.213Z,1695840283.213 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-09-27T18:45:14.957Z,1695840314.957 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002943
2023-09-27T18:48:02.075Z,1695840482.075 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-27T18:48:02.075Z,1695840482.075 [Default:CheckIn:C.Wait] Stopped
2023-09-27T18:48:02.075Z,1695840482.075 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-27T18:48:02.075Z,1695840482.075 [Default:CheckIn:D] Running Loop=1
2023-09-27T18:48:02.532Z,1695840482.532 [Default:CheckIn:D] Stopped
2023-09-27T18:48:02.533Z,1695840482.533 [Default:CheckIn:E] Running Loop=1
2023-09-27T18:48:02.893Z,1695840482.893 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 126.151326 min 
2023-09-27T18:48:02.893Z,1695840482.893 [Default:CheckIn:E] Stopped
2023-09-27T18:48:02.893Z,1695840482.893 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-27T18:48:02.893Z,1695840482.893 [Default:CheckIn] Stopped
2023-09-27T18:48:02.894Z,1695840482.894 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-27T18:48:02.894Z,1695840482.894 [Default:CheckIn](INFO): Running loop #21
2023-09-27T18:48:02.894Z,1695840482.894 [Default:CheckIn] Running Loop=21
2023-09-27T18:48:02.894Z,1695840482.894 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-27T18:48:02.894Z,1695840482.894 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-27T18:48:04.895Z,1695840484.895 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184804.00,A,3647.85626,N,12150.32494,W,14.229,263.52,270923,,,D*4F
2023-09-27T18:48:04.898Z,1695840484.898 [NAL9602](INFO): GPS fix at 20230927T184804: (36.797604, -121.838749)
2023-09-27T18:48:04.933Z,1695840484.933 [Default:CheckIn:Read_GPS] Stopped
2023-09-27T18:48:04.934Z,1695840484.934 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-27T18:48:17.430Z,1695840497.430 [NAL9602](INFO): SBD MO Status=2, MOMSN=30582, MT Status=2, MTMSN=0
2023-09-27T18:48:17.430Z,1695840497.430 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-27T18:48:19.241Z,1695840499.241 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.259460
2023-09-27T18:48:26.719Z,1695840506.719 [NAL9602](INFO): SBD MO Status=0, MOMSN=30582, MT Status=0, MTMSN=0
2023-09-27T18:48:26.719Z,1695840506.719 [NAL9602](INFO): No messages in MT queue
2023-09-27T18:48:50.369Z,1695840530.369 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-09-27T18:48:52.235Z,1695840532.235 [NAL9602](INFO): SBD MO Status=2, MOMSN=30583, MT Status=2, MTMSN=0
2023-09-27T18:48:52.235Z,1695840532.235 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-27T18:49:09.250Z,1695840549.250 [NAL9602](INFO): SBD MO Status=2, MOMSN=30583, MT Status=2, MTMSN=0
2023-09-27T18:49:09.250Z,1695840549.250 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-27T18:49:26.188Z,1695840566.188 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002892
2023-09-27T18:49:27.917Z,1695840567.917 [NAL9602](INFO): SBD MO Status=2, MOMSN=30583, MT Status=2, MTMSN=0
2023-09-27T18:49:27.917Z,1695840567.917 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-09-27T18:49:33.936Z,1695840573.936 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230927T163804/Courier0070.lzma
2023-09-27T18:49:34.938Z,1695840574.938 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Courier0070.lzma.bak
2023-09-27T18:49:34.938Z,1695840574.938 [DataOverHttps](INFO): SBD MOMSN=18911150
2023-09-27T18:49:51.268Z,1695840591.268 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20230927T163804/Express0071.lzma
2023-09-27T18:49:52.271Z,1695840592.271 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Express0071.lzma.bak
2023-09-27T18:49:52.271Z,1695840592.271 [DataOverHttps](INFO): SBD MOMSN=18911153
2023-09-27T18:49:53.386Z,1695840593.386 [Default:CheckIn:Read_Iridium] Stopped
2023-09-27T18:49:53.386Z,1695840593.386 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-27T18:49:53.386Z,1695840593.386 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-27T18:49:58.617Z,1695840598.617 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-27T18:52:00.069Z,1695840720.069 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.239410
2023-09-27T18:52:45.293Z,1695840765.293 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-09-27T18:53:20.438Z,1695840800.438 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-09-27T18:53:46.531Z,1695840826.531 [RDI_Pathfinder](ERROR): only read 0 of 4 data items for bottom velocity. Device response is::BS-32768,-32768,V
2023-09-27T18:53:55.577Z,1695840835.577 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-09-27T18:54:17.486Z,1695840857.486 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003100
2023-09-27T18:54:53.970Z,1695840893.970 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-09-27T18:54:53.970Z,1695840893.970 [Default:CheckIn:C.Wait] Stopped
2023-09-27T18:54:53.971Z,1695840893.971 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-09-27T18:54:53.971Z,1695840893.971 [Default:CheckIn:D] Running Loop=1
2023-09-27T18:54:54.383Z,1695840894.383 [Default:CheckIn:D] Stopped
2023-09-27T18:54:54.383Z,1695840894.383 [Default:CheckIn:E] Running Loop=1
2023-09-27T18:54:54.805Z,1695840894.805 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 133.015503 min 
2023-09-27T18:54:54.805Z,1695840894.805 [Default:CheckIn:E] Stopped
2023-09-27T18:54:54.805Z,1695840894.805 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-09-27T18:54:54.805Z,1695840894.805 [Default:CheckIn] Stopped
2023-09-27T18:54:54.805Z,1695840894.805 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-09-27T18:54:54.806Z,1695840894.806 [Default:CheckIn](INFO): Running loop #22
2023-09-27T18:54:54.806Z,1695840894.806 [Default:CheckIn] Running Loop=22
2023-09-27T18:54:54.806Z,1695840894.806 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-09-27T18:54:54.806Z,1695840894.806 [Default:CheckIn:Read_GPS] Running Loop=1
2023-09-27T18:54:56.853Z,1695840896.853 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185456.00,A,3647.81943,N,12150.83706,W,0.914,77.09,270923,,,D*46
2023-09-27T18:54:56.856Z,1695840896.856 [NAL9602](INFO): GPS fix at 20230927T185456: (36.796990, -121.847284)
2023-09-27T18:54:56.903Z,1695840896.903 [Default:CheckIn:Read_GPS] Stopped
2023-09-27T18:54:56.903Z,1695840896.903 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-09-27T18:55:05.628Z,1695840905.628 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230927T163804/Courier0073.lzma
2023-09-27T18:55:06.631Z,1695840906.631 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Courier0073.lzma.bak
2023-09-27T18:55:06.631Z,1695840906.631 [DataOverHttps](INFO): SBD MOMSN=18911157
2023-09-27T18:55:13.764Z,1695840913.764 [NAL9602](INFO): SBD MO Status=1, MOMSN=30583, MT Status=0, MTMSN=0
2023-09-27T18:55:13.764Z,1695840913.764 [NAL9602](INFO): No messages in MT queue
2023-09-27T18:55:24.487Z,1695840924.487 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20230927T163804/Express0074.lzma
2023-09-27T18:55:25.483Z,1695840925.483 [DataOverHttps](INFO): Moved sent file to Logs/20230927T163804/Express0074.lzma.bak
2023-09-27T18:55:25.483Z,1695840925.483 [DataOverHttps](INFO): SBD MOMSN=18911160
2023-09-27T18:55:26.740Z,1695840926.740 [Default:CheckIn:Read_Iridium] Stopped
2023-09-27T18:55:26.740Z,1695840926.740 [Default:CheckIn:C.Wait] Running Loop=1
2023-09-27T18:55:26.740Z,1695840926.740 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-09-27T18:55:44.461Z,1695840944.461 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-27T18:56:10.118Z,1695840970.118 [DataOverHttps](IMPORTANT): SBD MTMSN=20230927T185609