2022-09-22T15:03:04.493Z,1663858984.493 [Supervisor](DEBUG): Initializing supervisor.
2022-09-22T15:03:04.498Z,1663858984.498 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2022-09-22T15:03:04.498Z,1663858984.498 [SyncHandler](INFO): Protected caller Thread ID is 1001
2022-09-22T15:03:04.498Z,1663858984.498 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2022-09-22T15:03:04.499Z,1663858984.499 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2022-09-22T15:03:04.500Z,1663858984.500 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1002
2022-09-22T15:03:04.504Z,1663858984.504 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2022-09-22T15:03:04.523Z,1663858984.523 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2022-09-22T15:03:04.524Z,1663858984.524 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2022-09-22T15:03:04.524Z,1663858984.524 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 1003
2022-09-22T15:03:04.528Z,1663858984.528 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2022-09-22T15:03:04.529Z,1663858984.529 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2022-09-22T15:03:04.530Z,1663858984.530 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1004
2022-09-22T15:03:04.532Z,1663858984.532 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2022-09-22T15:03:04.533Z,1663858984.533 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2022-09-22T15:03:04.533Z,1663858984.533 [logger ThreadHandler](INFO): Protected caller Thread ID is 1005
2022-09-22T15:03:04.537Z,1663858984.537 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2022-09-22T15:03:04.537Z,1663858984.537 [Supervisor](INFO): Looking for Config files in directory: Config/
2022-09-22T15:03:04.539Z,1663858984.539 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2022-09-22T15:03:04.636Z,1663858984.636 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2022-09-22T15:03:04.637Z,1663858984.637 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2022-09-22T15:03:05.334Z,1663858985.334 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2022-09-22T15:03:05.335Z,1663858985.335 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2022-09-22T15:03:05.573Z,1663858985.573 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2022-09-22T15:03:05.573Z,1663858985.573 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2022-09-22T15:03:05.652Z,1663858985.652 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2022-09-22T15:03:05.779Z,1663858985.779 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2022-09-22T15:03:05.780Z,1663858985.780 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2022-09-22T15:03:05.861Z,1663858985.861 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2022-09-22T15:03:05.972Z,1663858985.972 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2022-09-22T15:03:05.972Z,1663858985.972 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2022-09-22T15:03:06.369Z,1663858986.369 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2022-09-22T15:03:06.370Z,1663858986.370 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2022-09-22T15:03:06.975Z,1663858986.975 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2022-09-22T15:03:06.975Z,1663858986.975 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2022-09-22T15:03:07.204Z,1663858987.204 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2022-09-22T15:03:07.205Z,1663858987.205 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2022-09-22T15:03:07.408Z,1663858987.408 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2022-09-22T15:03:07.408Z,1663858987.408 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2022-09-22T15:03:07.912Z,1663858987.912 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2022-09-22T15:03:07.912Z,1663858987.912 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2022-09-22T15:03:08.219Z,1663858988.219 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2022-09-22T15:03:08.220Z,1663858988.220 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2022-09-22T15:03:08.447Z,1663858988.447 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2022-09-22T15:03:08.448Z,1663858988.448 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2022-09-22T15:03:09.752Z,1663858989.752 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2022-09-22T15:03:09.752Z,1663858989.752 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2022-09-22T15:03:10.116Z,1663858990.116 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2022-09-22T15:03:10.118Z,1663858990.118 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2022-09-22T15:03:10.118Z,1663858990.118 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2022-09-22T15:03:10.204Z,1663858990.204 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2022-09-22T15:03:10.369Z,1663858990.369 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2022-09-22T15:03:10.482Z,1663858990.482 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2022-09-22T15:03:10.568Z,1663858990.568 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2022-09-22T15:03:10.664Z,1663858990.664 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2022-09-22T15:03:10.860Z,1663858990.860 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2022-09-22T15:03:11.135Z,1663858991.135 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2022-09-22T15:03:11.135Z,1663858991.135 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2022-09-22T15:03:11.231Z,1663858991.231 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2022-09-22T15:03:11.333Z,1663858991.333 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2022-09-22T15:03:11.481Z,1663858991.481 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2022-09-22T15:03:11.583Z,1663858991.583 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2022-09-22T15:03:11.599Z,1663858991.599 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2022-09-22T15:03:11.702Z,1663858991.702 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2022-09-22T15:03:11.703Z,1663858991.703 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2022-09-22T15:03:11.757Z,1663858991.757 [VerticalControl](DEBUG): Construct VerticalControl.
2022-09-22T15:03:11.821Z,1663858991.821 [VerticalControl] Loaded
2022-09-22T15:03:11.821Z,1663858991.821 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2022-09-22T15:03:11.824Z,1663858991.824 [HorizontalControl](DEBUG): Construct HorizontalControl.
2022-09-22T15:03:11.865Z,1663858991.865 [HorizontalControl] Loaded
2022-09-22T15:03:11.866Z,1663858991.866 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2022-09-22T15:03:11.868Z,1663858991.868 [SpeedControl](DEBUG): Construct SpeedControl.
2022-09-22T15:03:11.872Z,1663858991.872 [SpeedControl] Loaded
2022-09-22T15:03:11.872Z,1663858991.872 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2022-09-22T15:03:11.874Z,1663858991.874 [LoopControl](DEBUG): Construct LoopControl.
2022-09-22T15:03:11.875Z,1663858991.875 [LoopControl] Loaded
2022-09-22T15:03:11.875Z,1663858991.875 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2022-09-22T15:03:11.876Z,1663858991.876 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2022-09-22T15:03:11.876Z,1663858991.876 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2022-09-22T15:03:11.930Z,1663858991.930 [DepthRateCalculator] Loaded
2022-09-22T15:03:11.930Z,1663858991.930 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2022-09-22T15:03:11.935Z,1663858991.935 [PitchRateCalculator] Loaded
2022-09-22T15:03:11.935Z,1663858991.935 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2022-09-22T15:03:11.946Z,1663858991.946 [SpeedCalculator] Loaded
2022-09-22T15:03:11.947Z,1663858991.947 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2022-09-22T15:03:11.951Z,1663858991.951 [YawRateCalculator] Loaded
2022-09-22T15:03:11.951Z,1663858991.951 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2022-09-22T15:03:11.970Z,1663858991.970 [ElevatorOffsetCalculator] Loaded
2022-09-22T15:03:11.970Z,1663858991.970 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2022-09-22T15:03:11.970Z,1663858991.970 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2022-09-22T15:03:11.971Z,1663858991.971 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2022-09-22T15:03:11.999Z,1663858991.999 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2022-09-22T15:03:11.999Z,1663858991.999 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2022-09-22T15:03:12.060Z,1663858992.060 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2022-09-22T15:03:12.060Z,1663858992.060 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2022-09-22T15:03:12.393Z,1663858992.393 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2022-09-22T15:03:12.394Z,1663858992.394 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2022-09-22T15:03:12.507Z,1663858992.507 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2022-09-22T15:03:12.507Z,1663858992.507 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2022-09-22T15:03:12.945Z,1663858992.945 [AHRS_M2] Loaded
2022-09-22T15:03:12.945Z,1663858992.945 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2022-09-22T15:03:12.981Z,1663858992.981 [BackseatComponent] Loaded
2022-09-22T15:03:12.981Z,1663858992.981 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2022-09-22T15:03:12.982Z,1663858992.982 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 4096D4E0
2022-09-22T15:03:12.983Z,1663858992.983 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 1087
2022-09-22T15:03:12.986Z,1663858992.986 [LcmUniversalReporter] Loaded
2022-09-22T15:03:12.986Z,1663858992.986 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2022-09-22T15:03:13.829Z,1663858993.829 [BPC1] Loaded
2022-09-22T15:03:13.829Z,1663858993.829 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2022-09-22T15:03:13.904Z,1663858993.904 [DataOverHttps] Loaded
2022-09-22T15:03:13.904Z,1663858993.904 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2022-09-22T15:03:13.905Z,1663858993.905 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4099D4E0
2022-09-22T15:03:13.906Z,1663858993.906 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1088
2022-09-22T15:03:13.926Z,1663858993.926 [Depth_Keller] Loaded
2022-09-22T15:03:13.927Z,1663858993.927 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2022-09-22T15:03:13.932Z,1663858993.932 [DropWeight] Loaded
2022-09-22T15:03:13.932Z,1663858993.932 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2022-09-22T15:03:13.995Z,1663858993.995 [NAL9602] Loaded
2022-09-22T15:03:13.995Z,1663858993.995 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2022-09-22T15:03:14.025Z,1663858994.025 [Onboard] Loaded
2022-09-22T15:03:14.025Z,1663858994.025 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2022-09-22T15:03:14.026Z,1663858994.026 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409CD4E0
2022-09-22T15:03:14.027Z,1663858994.027 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1089
2022-09-22T15:03:14.039Z,1663858994.039 [Power24vConverter] Loaded
2022-09-22T15:03:14.039Z,1663858994.039 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2022-09-22T15:03:14.052Z,1663858994.052 [Radio_Surface] Loaded
2022-09-22T15:03:14.052Z,1663858994.052 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2022-09-22T15:03:14.054Z,1663858994.054 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409FD4E0
2022-09-22T15:03:14.054Z,1663858994.054 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1090
2022-09-22T15:03:14.099Z,1663858994.099 [RDI_Pathfinder] Loaded
2022-09-22T15:03:14.100Z,1663858994.100 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2022-09-22T15:03:14.189Z,1663858994.189 [DAT] Loaded
2022-09-22T15:03:14.189Z,1663858994.189 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2022-09-22T15:03:14.190Z,1663858994.190 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40A2D4E0
2022-09-22T15:03:14.190Z,1663858994.190 [DAT ThreadHandler](INFO): Protected caller Thread ID is 1091
2022-09-22T15:03:14.191Z,1663858994.191 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2022-09-22T15:03:14.191Z,1663858994.191 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2022-09-22T15:03:14.487Z,1663858994.487 [DeadReckonUsingMultipleVelocitySources] Loaded
2022-09-22T15:03:14.487Z,1663858994.487 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2022-09-22T15:03:14.519Z,1663858994.519 [NavChart] Loaded
2022-09-22T15:03:14.519Z,1663858994.519 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2022-09-22T15:03:14.525Z,1663858994.525 [UniversalFixResidualReporter] Loaded
2022-09-22T15:03:14.526Z,1663858994.526 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2022-09-22T15:03:14.526Z,1663858994.526 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2022-09-22T15:03:14.527Z,1663858994.527 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2022-09-22T15:03:14.926Z,1663858994.926 [SBIT](DEBUG): Construct Startup Built In Test.
2022-09-22T15:03:14.972Z,1663858994.972 [SBIT] Loaded
2022-09-22T15:03:14.973Z,1663858994.973 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2022-09-22T15:03:14.976Z,1663858994.976 [IBIT](DEBUG): Construct Initiated Built In Test.
2022-09-22T15:03:14.989Z,1663858994.989 [IBIT] Loaded
2022-09-22T15:03:14.990Z,1663858994.990 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2022-09-22T15:03:14.996Z,1663858994.996 [CBIT](DEBUG): Construct Continuous Built In Test.
2022-09-22T15:03:15.106Z,1663858995.106 [CBIT] Loaded
2022-09-22T15:03:15.106Z,1663858995.106 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2022-09-22T15:03:15.107Z,1663858995.107 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2022-09-22T15:03:15.107Z,1663858995.107 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2022-09-22T15:03:15.240Z,1663858995.240 [BuoyancyServo] Loaded
2022-09-22T15:03:15.240Z,1663858995.240 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2022-09-22T15:03:15.262Z,1663858995.262 [ElevatorServo] Loaded
2022-09-22T15:03:15.262Z,1663858995.262 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2022-09-22T15:03:15.282Z,1663858995.282 [MassServo] Loaded
2022-09-22T15:03:15.282Z,1663858995.282 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2022-09-22T15:03:15.302Z,1663858995.302 [RudderServo] Loaded
2022-09-22T15:03:15.302Z,1663858995.302 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2022-09-22T15:03:15.321Z,1663858995.321 [ThrusterServo] Loaded
2022-09-22T15:03:15.321Z,1663858995.321 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2022-09-22T15:03:15.321Z,1663858995.321 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2022-09-22T15:03:15.322Z,1663858995.322 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2022-09-22T15:03:15.333Z,1663858995.333 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2022-09-22T15:03:15.334Z,1663858995.334 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2022-09-22T15:03:15.514Z,1663858995.514 [CTD_Seabird] Loaded
2022-09-22T15:03:15.514Z,1663858995.514 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2022-09-22T15:03:15.516Z,1663858995.516 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B774E0
2022-09-22T15:03:15.516Z,1663858995.516 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1092
2022-09-22T15:03:15.537Z,1663858995.537 [PAR_Licor] Loaded
2022-09-22T15:03:15.537Z,1663858995.537 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2022-09-22T15:03:15.571Z,1663858995.571 [WetLabsBB2FL] Loaded
2022-09-22T15:03:15.571Z,1663858995.571 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2022-09-22T15:03:15.572Z,1663858995.572 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40BA74E0
2022-09-22T15:03:15.572Z,1663858995.572 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1093
2022-09-22T15:03:15.594Z,1663858995.594 [WetLabsUBAT] Loaded
2022-09-22T15:03:15.594Z,1663858995.594 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread.
2022-09-22T15:03:15.595Z,1663858995.595 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40BD74E0
2022-09-22T15:03:15.595Z,1663858995.595 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 1094
2022-09-22T15:03:15.596Z,1663858995.596 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2022-09-22T15:03:15.602Z,1663858995.602 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2022-09-22T15:03:15.605Z,1663858995.605 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2022-09-22T15:03:15.616Z,1663858995.616 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2022-09-22T15:03:15.617Z,1663858995.617 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C074E0
2022-09-22T15:03:15.617Z,1663858995.617 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1095
2022-09-22T15:03:15.622Z,1663858995.622 [Supervisor](INFO): Main Thread ID is 832
2022-09-22T15:03:15.622Z,1663858995.622 [Supervisor](DEBUG): Running supervisor.
2022-09-22T15:03:15.623Z,1663858995.623 [CommandExec ThreadHandler](INFO): Handler Thread ID is 1096
2022-09-22T15:03:15.623Z,1663858995.623 [CommandExec](INFO): Initializing the command executive.
2022-09-22T15:03:15.625Z,1663858995.625 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1097
2022-09-22T15:03:15.627Z,1663858995.627 [controlThread ThreadHandler](INFO): Handler Thread ID is 1098
2022-09-22T15:03:15.627Z,1663858995.627 [controlThread](DEBUG): Initializing ControlThread
2022-09-22T15:03:15.628Z,1663858995.628 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2022-09-22T15:03:15.630Z,1663858995.630 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2022-09-22T15:03:15.630Z,1663858995.630 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2022-09-22T15:03:15.631Z,1663858995.631 [LoopControl](DEBUG): Initialize LoopControlComponent.
2022-09-22T15:03:15.631Z,1663858995.631 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2022-09-22T15:03:15.632Z,1663858995.632 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2022-09-22T15:03:15.632Z,1663858995.632 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2022-09-22T15:03:15.632Z,1663858995.632 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2022-09-22T15:03:15.633Z,1663858995.633 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2022-09-22T15:03:15.640Z,1663858995.640 [NavChart](DEBUG): Initialize NavChart Navigation.
2022-09-22T15:03:15.640Z,1663858995.640 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2022-09-22T15:03:15.641Z,1663858995.641 [SBIT](INFO): Initialize SBIT Component.
2022-09-22T15:03:15.641Z,1663858995.641 [SBIT](IMPORTANT): git: 2022-06-07-3-g3731f8b3f
2022-09-22T15:03:15.641Z,1663858995.641 [SBIT](INFO): git hash: 3731f8b3f5f07755356c125fa6a04ab4ea762347
2022-09-22T15:03:15.642Z,1663858995.642 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2022-09-22T15:03:15.643Z,1663858995.643 [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
2022-09-22T15:03:15.644Z,1663858995.644 [SBIT](INFO): Beginning SBIT in 50.000000 seconds.
2022-09-22T15:03:15.644Z,1663858995.644 [IBIT](INFO): Initialize IBIT Component.
2022-09-22T15:03:15.645Z,1663858995.645 [CBIT](DEBUG): Initialize CBIT Component.
2022-09-22T15:03:15.646Z,1663858995.646 [logger ThreadHandler](INFO): Handler Thread ID is 1099
2022-09-22T15:03:15.657Z,1663858995.657 [CBIT](DEBUG): Initialized mux pins.
2022-09-22T15:03:15.658Z,1663858995.658 [CBIT](DEBUG): Initializing the watchdog timer.
2022-09-22T15:03:15.666Z,1663858995.666 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 1100
2022-09-22T15:03:15.678Z,1663858995.678 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1101
2022-09-22T15:03:15.679Z,1663858995.679 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2022-09-22T15:03:15.681Z,1663858995.681 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2022-09-22T15:03:15.682Z,1663858995.682 [CBIT](DEBUG): Initializing heartbeat.
2022-09-22T15:03:15.690Z,1663858995.690 [Onboard ThreadHandler](INFO): Handler Thread ID is 1102
2022-09-22T15:03:15.707Z,1663858995.707 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1103
2022-09-22T15:03:15.738Z,1663858995.738 [DAT ThreadHandler](INFO): Handler Thread ID is 1104
2022-09-22T15:03:15.738Z,1663858995.738 [DAT](INFO): Powering up
2022-09-22T15:03:15.739Z,1663858995.739 [DAT](DEBUG): Initializing DAT.
2022-09-22T15:03:15.746Z,1663858995.746 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1106
2022-09-22T15:03:15.747Z,1663858995.747 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2022-09-22T15:03:15.751Z,1663858995.751 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1108
2022-09-22T15:03:15.754Z,1663858995.754 [CBIT](DEBUG): Deactivating GF circuits.
2022-09-22T15:03:15.754Z,1663858995.754 [CBIT](DEBUG): Deactivating emergency mode.
2022-09-22T15:03:15.755Z,1663858995.755 [WetLabsBB2FL](INFO): Powering up
2022-09-22T15:03:15.756Z,1663858995.756 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 1110
2022-09-22T15:03:15.758Z,1663858995.758 [WetLabsUBAT](INFO): Powering up
2022-09-22T15:03:15.770Z,1663858995.770 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1112
2022-09-22T15:03:15.773Z,1663858995.773 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2022-09-22T15:03:15.773Z,1663858995.773 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2022-09-22T15:03:15.773Z,1663858995.773 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2022-09-22T15:03:15.773Z,1663858995.773 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2022-09-22T15:03:15.774Z,1663858995.774 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2022-09-22T15:03:15.774Z,1663858995.774 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2022-09-22T15:03:15.774Z,1663858995.774 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2022-09-22T15:03:15.774Z,1663858995.774 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2022-09-22T15:03:15.789Z,1663858995.789 [CBIT](DEBUG): Backplane powered.
2022-09-22T15:03:15.794Z,1663858995.794 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2022-09-22T15:03:15.823Z,1663858995.823 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2022-09-22T15:03:15.856Z,1663858995.856 [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>


2022-09-22T15:03:15.856Z,1663858995.856 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2022-09-22T15:03:15.942Z,1663858995.942 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2022-09-22T15:03:15.943Z,1663858995.943 [Default:A.Wait](DEBUG): Construct Wait.
2022-09-22T15:03:15.946Z,1663858995.946 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2022-09-22T15:03:15.998Z,1663858995.998 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2022-09-22T15:03:16.001Z,1663858996.001 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2022-09-22T15:03:16.023Z,1663858996.023 [Default:E.Execute](DEBUG): Construct Execute.
2022-09-22T15:03:16.033Z,1663858996.033 [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="P2H">
                <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>


2022-09-22T15:03:16.038Z,1663858996.038 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,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,
2022-09-22T15:03:16.058Z,1663858996.058 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2022-09-22T15:03:16.114Z,1663858996.114 [Radio_Surface](INFO): Powering up
2022-09-22T15:03:16.122Z,1663858996.122 [Depth_Keller](ERROR): Pressure reading out of range: 824.648376 decibar
2022-09-22T15:03:16.123Z,1663858996.123 [Power24vConverter](INFO): Powering up.
2022-09-22T15:03:16.124Z,1663858996.124 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format
2022-09-22T15:03:16.194Z,1663858996.194 [DepthRateCalculator](ERROR): Depth measurement is not active
2022-09-22T15:03:16.219Z,1663858996.219 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2022-09-22T15:03:16.226Z,1663858996.226 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2022-09-22T15:03:16.227Z,1663858996.227 [ElevatorServo](DEBUG): Initializing EZServoServo.
2022-09-22T15:03:16.234Z,1663858996.234 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2022-09-22T15:03:16.235Z,1663858996.235 [MassServo](DEBUG): Initializing EZServoServo.
2022-09-22T15:03:16.242Z,1663858996.242 [MassServo](DEBUG): Initializing MassServo.
2022-09-22T15:03:16.243Z,1663858996.243 [RudderServo](DEBUG): Initializing EZServoServo.
2022-09-22T15:03:16.250Z,1663858996.250 [RudderServo](DEBUG): Initializing RudderServo.
2022-09-22T15:03:16.251Z,1663858996.251 [ThrusterServo](DEBUG): Initializing EZServoServo.
2022-09-22T15:03:16.258Z,1663858996.258 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2022-09-22T15:03:17.209Z,1663858997.209 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2022-09-22T15:03:17.210Z,1663858997.210 [RudderServo](FAULT): Rudder failed to initialize
2022-09-22T15:03:17.210Z,1663858997.210 [RudderServo] Communications Fault, FailCount= 1
2022-09-22T15:03:17.210Z,1663858997.210 [RudderServo](ERROR): Communications Fault
2022-09-22T15:03:17.310Z,1663858997.310 [CBIT](ERROR): Communications Fault in component: RudderServo
2022-09-22T15:03:17.522Z,1663858997.522 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-09-22T15:03:17.523Z,1663858997.523 [RudderServo](INFO): Powering down
2022-09-22T15:03:18.153Z,1663858998.153 [RudderServo](DEBUG): Initializing EZServoServo.
2022-09-22T15:03:18.274Z,1663858998.274 [RudderServo](DEBUG): Initializing RudderServo.
2022-09-22T15:03:18.278Z,1663858998.278 [CBIT](INFO): Clearing failed state for component RudderServo
2022-09-22T15:03:18.279Z,1663858998.279 [RudderServo] No Fault, FailCount= 1
2022-09-22T15:03:18.365Z,1663858998.365 [WetLabsBB2FL](INFO): Powering down
2022-09-22T15:03:25.026Z,1663859005.026 [WetLabsUBAT](INFO): Powering down
2022-09-22T15:03:27.586Z,1663859007.586 [DAT](INFO): DAT read: 

2022-09-22T15:03:27.588Z,1663859007.588 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2022-09-22T15:03:29.350Z,1663859009.350 [DAT](INFO): DAT read: MF Frequency Band

2022-09-22T15:03:29.351Z,1663859009.351 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2022-09-22T15:03:29.352Z,1663859009.352 [DAT](INFO): DAT read: Sep 22 2022 15:03:18 

2022-09-22T15:03:30.359Z,1663859010.359 [DAT](INFO): DAT read: Features enabled [Bearing]

2022-09-22T15:03:30.360Z,1663859010.360 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2022-09-22T15:03:30.360Z,1663859010.360 [DAT](INFO): commRate: 800
2022-09-22T15:03:32.426Z,1663859012.426 [DAT](INFO): entering command mode
2022-09-22T15:03:32.626Z,1663859012.626 [DAT](INFO): DAT read: 

2022-09-22T15:03:32.627Z,1663859012.627 [DAT](INFO): DAT read: user:1>

2022-09-22T15:03:32.627Z,1663859012.627 [DAT](INFO): setting verbose to 3
2022-09-22T15:03:32.878Z,1663859012.878 [DAT](INFO): DAT read: user:1>

2022-09-22T15:03:32.879Z,1663859012.879 [DAT](INFO): DAT read: Verbose         | 3           

2022-09-22T15:03:32.880Z,1663859012.880 [DAT](INFO): set verbose to 3
2022-09-22T15:03:32.880Z,1663859012.880 [DAT](INFO): setting DatVerbose to 27440
2022-09-22T15:03:33.130Z,1663859013.130 [DAT](INFO): DAT read: user:2>

2022-09-22T15:03:33.131Z,1663859013.131 [DAT](INFO): DAT read: DatVerbose      | 27440       

2022-09-22T15:03:33.131Z,1663859013.131 [DAT](INFO): set DatVerbose to 27440
2022-09-22T15:03:33.132Z,1663859013.132 [DAT](INFO): setting transmit power to 8
2022-09-22T15:03:33.382Z,1663859013.382 [DAT](INFO): DAT read: user:3>

2022-09-22T15:03:33.383Z,1663859013.383 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2022-09-22T15:03:33.383Z,1663859013.383 [DAT](INFO): set transmit power to 8
2022-09-22T15:03:33.384Z,1663859013.384 [DAT](INFO): setting local address to 9
2022-09-22T15:03:33.636Z,1663859013.636 [DAT](INFO): DAT read: user:4>

2022-09-22T15:03:33.640Z,1663859013.640 [DAT](INFO): DAT read: LocalAddr       | 9           

2022-09-22T15:03:33.641Z,1663859013.641 [DAT](INFO): set local address to 9
2022-09-22T15:03:44.391Z,1663859024.391 [NAL9602](INFO): Powering up NAL9602
2022-09-22T15:03:55.299Z,1663859035.299 [NAL9602](INFO): NAL9602 initialized
2022-09-22T15:04:06.209Z,1663859046.209 [NAL9602](INFO): SBD MO Status=0, MOMSN=20474, MT Status=0, MTMSN=0
2022-09-22T15:04:06.209Z,1663859046.209 [NAL9602](INFO): No messages in MT queue
2022-09-22T15:04:06.229Z,1663859046.229 [SBIT](IMPORTANT): Beginning Startup BIT
2022-09-22T15:04:06.233Z,1663859046.233 [CBIT](IMPORTANT): Beginning ground fault scan
2022-09-22T15:04:17.224Z,1663859057.224 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.008848
CHAN A1 (24V): 0.002296
CHAN A2 (12V): -0.006226
CHAN A3 (5V): -0.001828
CHAN B0 (3.3V): 0.000167
CHAN B1 (3.15aV): 0.000248
CHAN B2 (3.15bV): -0.000101
CHAN B3 (GND): 0.001983
OPEN: 0.005503
Full Scale: +/- 1 mA
2022-09-22T15:04:19.545Z,1663859059.545 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150418.00,A,3648.18451,N,12147.27890,W,0.039,0.00,220922,,,A*73
2022-09-22T15:04:19.548Z,1663859059.548 [NAL9602](INFO): GPS fix at 20220922T150418: (36.803075, -121.787982)
2022-09-22T15:04:51.876Z,1663859091.876 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-22T15:04:59.995Z,1663859099.995 [SBIT](IMPORTANT): SBIT PASSED
2022-09-22T15:04:59.995Z,1663859099.995 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2022-09-22T15:04:59.996Z,1663859099.996 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;

2022-09-22T15:04:59.996Z,1663859099.996 [SBIT](IMPORTANT): CBIT.gf24Offset=143 microampere;

2022-09-22T15:04:59.996Z,1663859099.996 [SBIT](IMPORTANT): CBIT.gfScanTimeout=2 hour;

2022-09-22T15:04:59.996Z,1663859099.996 [SBIT](IMPORTANT): DAT.baud=115200 bit_per_second;

2022-09-22T15:04:59.996Z,1663859099.996 [SBIT](IMPORTANT): DAT.loadAtStartup=1 bool;

2022-09-22T15:04:59.997Z,1663859099.997 [SBIT](IMPORTANT): DAT.surfaceThreshold=0 meter;

2022-09-22T15:04:59.997Z,1663859099.997 [SBIT](IMPORTANT): DAT.verbosity=2 count;

2022-09-22T15:04:59.997Z,1663859099.997 [SBIT](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 0.300000 liter_per_second;

2022-09-22T15:04:59.997Z,1663859099.997 [SBIT](IMPORTANT): Express none _.adinos;

2022-09-22T15:04:59.997Z,1663859099.997 [SBIT](IMPORTANT): Express none _.aother;

2022-09-22T15:04:59.997Z,1663859099.997 [SBIT](IMPORTANT): Express linearApproximation _.dinoflagellates 10000000000.000000 none;

2022-09-22T15:04:59.997Z,1663859099.997 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=24 ampere_hour;

2022-09-22T15:04:59.998Z,1663859099.998 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=13 volt;

2022-09-22T15:04:59.998Z,1663859099.998 [SBIT](IMPORTANT): Power24vConverter.simulateHardware=0 bool;

2022-09-22T15:04:59.998Z,1663859099.998 [SBIT](IMPORTANT): RDI_Pathfinder.loadAtStartup=1 bool;

2022-09-22T15:04:59.998Z,1663859099.998 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=209.634716 cubic_centimeter;

2022-09-22T15:04:59.998Z,1663859099.998 [SBIT](IMPORTANT): VerticalControl.massDefault=7.723761 millimeter;

2022-09-22T15:05:00.363Z,1663859100.363 [MissionManager](IMPORTANT): Started mission Startup
2022-09-22T15:05:00.363Z,1663859100.363 [Startup] Running Loop=1
2022-09-22T15:05:00.363Z,1663859100.363 [Startup](DEBUG): Aggregate::initialize Startup
2022-09-22T15:05:00.363Z,1663859100.363 [Startup:A.GoToSurface] Running Loop=1
2022-09-22T15:05:00.363Z,1663859100.363 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-09-22T15:05:00.364Z,1663859100.364 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-09-22T15:05:00.364Z,1663859100.364 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-09-22T15:05:00.364Z,1663859100.364 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-09-22T15:05:00.365Z,1663859100.365 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-09-22T15:05:00.365Z,1663859100.365 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-09-22T15:05:00.367Z,1663859100.367 [Startup:StartupSatComms] Running Loop=1
2022-09-22T15:05:00.367Z,1663859100.367 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2022-09-22T15:05:00.367Z,1663859100.367 [Startup:StartupSatComms:A] Running Loop=1
2022-09-22T15:05:00.767Z,1663859100.767 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2022-09-22T15:05:02.370Z,1663859102.370 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150501.00,A,3648.18403,N,12147.27879,W,0.019,0.00,220922,,,A*78
2022-09-22T15:05:02.372Z,1663859102.372 [NAL9602](INFO): GPS fix at 20220922T150501: (36.803067, -121.787980)
2022-09-22T15:05:02.384Z,1663859102.384 [Startup:StartupSatComms:A] Stopped
2022-09-22T15:05:02.384Z,1663859102.384 [Startup:StartupSatComms:B] Running Loop=1
2022-09-22T15:05:02.796Z,1663859102.796 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-09-22T15:05:32.796Z,1663859132.796 [NAL9602](INFO): SBD MO Status=2, MOMSN=20475, MT Status=2, MTMSN=0
2022-09-22T15:05:32.796Z,1663859132.796 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-22T15:05:52.607Z,1663859152.607 [NAL9602](INFO): SBD MO Status=2, MOMSN=20475, MT Status=2, MTMSN=0
2022-09-22T15:05:52.607Z,1663859152.607 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-22T15:06:02.409Z,1663859162.409 [Startup:StartupSatComms:B](INFO): Timed out from 2022-09-22T15:05:02.4Z
2022-09-22T15:06:02.409Z,1663859162.409 [Startup:StartupSatComms:B] Stopped
2022-09-22T15:06:02.409Z,1663859162.409 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2022-09-22T15:06:02.409Z,1663859162.409 [Startup:StartupSatComms] Stopped
2022-09-22T15:06:02.409Z,1663859162.409 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2022-09-22T15:06:02.410Z,1663859162.410 [Startup](INFO): Completed Startup
2022-09-22T15:06:02.410Z,1663859162.410 [MissionManager](INFO): Startup is completed.
2022-09-22T15:06:02.410Z,1663859162.410 [MissionManager](INFO): Uninitializing Mission Startup
2022-09-22T15:06:02.410Z,1663859162.410 [Startup] Stopped
2022-09-22T15:06:02.411Z,1663859162.411 [Startup](DEBUG): Aggregate::uninitialize Startup
2022-09-22T15:06:02.411Z,1663859162.411 [Startup:A.GoToSurface] Stopped
2022-09-22T15:06:02.411Z,1663859162.411 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-09-22T15:06:02.822Z,1663859162.822 [MissionManager](IMPORTANT): Started mission Default
2022-09-22T15:06:02.822Z,1663859162.822 [Default] Running Loop=1
2022-09-22T15:06:02.822Z,1663859162.822 [Default](DEBUG): Aggregate::initialize Default
2022-09-22T15:06:02.822Z,1663859162.822 [Default:B.GoToSurface] Running Loop=1
2022-09-22T15:06:02.823Z,1663859162.823 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-09-22T15:06:02.823Z,1663859162.823 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-09-22T15:06:02.823Z,1663859162.823 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-09-22T15:06:02.823Z,1663859162.823 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-09-22T15:06:02.824Z,1663859162.824 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-09-22T15:06:02.824Z,1663859162.824 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-09-22T15:06:02.824Z,1663859162.824 [Default:A.Wait] Running Loop=1
2022-09-22T15:06:02.824Z,1663859162.824 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-09-22T15:06:15.733Z,1663859175.733 [NAL9602](INFO): SBD MO Status=2, MOMSN=20475, MT Status=2, MTMSN=0
2022-09-22T15:06:15.733Z,1663859175.733 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-22T15:06:16.215Z,1663859176.215 [Default:A.Wait](INFO): Done Waiting.
2022-09-22T15:06:16.215Z,1663859176.215 [Default:A.Wait] Stopped
2022-09-22T15:06:16.215Z,1663859176.215 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-09-22T15:06:16.554Z,1663859176.554 [Default:CheckIn] Running Loop=1
2022-09-22T15:06:16.554Z,1663859176.554 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-22T15:06:16.554Z,1663859176.554 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-22T15:06:16.957Z,1663859176.957 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2022-09-22T15:06:18.565Z,1663859178.565 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150617.00,A,3648.18445,N,12147.27915,W,0.019,0.00,220922,,,A*75
2022-09-22T15:06:18.567Z,1663859178.567 [NAL9602](INFO): GPS fix at 20220922T150617: (36.803074, -121.787986)
2022-09-22T15:06:18.577Z,1663859178.577 [Default:CheckIn:Read_GPS] Stopped
2022-09-22T15:06:18.578Z,1663859178.578 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-22T15:06:18.995Z,1663859178.995 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-09-22T15:06:27.198Z,1663859187.198 [NAL9602](INFO): SBD MO Status=1, MOMSN=20475, MT Status=0, MTMSN=0
2022-09-22T15:06:27.246Z,1663859187.246 [NAL9602](INFO): Sent 39 bytes from file Logs/20220922T145649/Courier0004.lzma
2022-09-22T15:06:27.246Z,1663859187.246 [NAL9602](INFO): Packets left to send: 0
2022-09-22T15:06:37.732Z,1663859197.732 [NAL9602](INFO): SBD MO Status=1, MOMSN=20476, MT Status=0, MTMSN=0
2022-09-22T15:06:37.786Z,1663859197.786 [NAL9602](INFO): Sent 267 bytes from file Logs/20220922T150304/Courier0000.lzma
2022-09-22T15:06:37.786Z,1663859197.786 [NAL9602](INFO): Packets left to send: 0
2022-09-22T15:06:39.447Z,1663859199.447 [DataOverHttps](IMPORTANT): SBD MTMSN=20220922T150639
2022-09-22T15:06:39.452Z,1663859199.452 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004751
2022-09-22T15:06:47.089Z,1663859207.089 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220922T150304/Courier0004.lzma
2022-09-22T15:06:47.091Z,1663859207.091 [DataOverHttps](INFO): Received command: ibit
2022-09-22T15:06:47.103Z,1663859207.103 [CommandExec](IMPORTANT): got command ibit
2022-09-22T15:06:47.223Z,1663859207.223 [IBIT](IMPORTANT): Beginning Initiated BIT
2022-09-22T15:06:47.223Z,1663859207.223 [IBIT](IMPORTANT): Beginning control surface checks.
2022-09-22T15:06:47.230Z,1663859207.230 [CBIT](IMPORTANT): Beginning ground fault scan
2022-09-22T15:06:48.277Z,1663859208.277 [DataOverHttps](INFO): Moved sent file to Logs/20220922T150304/Courier0004.lzma.bak
2022-09-22T15:06:48.277Z,1663859208.277 [DataOverHttps](INFO): SBD MOMSN=17196710
2022-09-22T15:06:53.976Z,1663859213.976 [NAL9602](INFO): SBD MO Status=1, MOMSN=20477, MT Status=0, MTMSN=0
2022-09-22T15:06:54.026Z,1663859214.026 [NAL9602](INFO): Sent 73 bytes from file Logs/20220922T150304/Courier0004.lzma
2022-09-22T15:06:54.026Z,1663859214.026 [NAL9602](INFO): Packets left to send: 0
2022-09-22T15:06:55.192Z,1663859215.192 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150654.00,A,3648.18481,N,12147.27869,W,0.039,0.00,220922,,,A*72
2022-09-22T15:06:55.195Z,1663859215.195 [NAL9602](INFO): GPS fix at 20220922T150654: (36.803080, -121.787978)
2022-09-22T15:06:58.415Z,1663859218.415 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150657.00,A,3648.18476,N,12147.27881,W,0.058,0.00,220922,,,A*78
2022-09-22T15:06:58.417Z,1663859218.417 [NAL9602](INFO): GPS fix at 20220922T150657: (36.803079, -121.787980)
2022-09-22T15:06:58.460Z,1663859218.460 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.008969
CHAN A1 (24V): 0.002684
CHAN A2 (12V): -0.006050
CHAN A3 (5V): -0.001265
CHAN B0 (3.3V): 0.000567
CHAN B1 (3.15aV): 0.000499
CHAN B2 (3.15bV): 0.000208
CHAN B3 (GND): 0.001254
OPEN: 0.005506
Full Scale: +/- 1 mA
2022-09-22T15:07:01.257Z,1663859221.257 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150700.00,A,3648.18467,N,12147.27894,W,0.019,0.00,220922,,,A*7A
2022-09-22T15:07:01.259Z,1663859221.259 [NAL9602](INFO): GPS fix at 20220922T150700: (36.803078, -121.787982)
2022-09-22T15:07:04.481Z,1663859224.481 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150703.00,A,3648.18455,N,12147.27906,W,0.000,0.00,220922,,,A*7A
2022-09-22T15:07:04.483Z,1663859224.483 [NAL9602](INFO): GPS fix at 20220922T150703: (36.803076, -121.787984)
2022-09-22T15:07:05.037Z,1663859225.037 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220922T150304/Courier0007.lzma
2022-09-22T15:07:06.040Z,1663859226.040 [DataOverHttps](INFO): Moved sent file to Logs/20220922T150304/Courier0007.lzma.bak
2022-09-22T15:07:06.040Z,1663859226.040 [DataOverHttps](INFO): SBD MOMSN=17196719
2022-09-22T15:07:07.310Z,1663859227.310 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150706.00,A,3648.18442,N,12147.27915,W,0.019,0.00,220922,,,A*73
2022-09-22T15:07:07.313Z,1663859227.313 [NAL9602](INFO): GPS fix at 20220922T150706: (36.803074, -121.787986)
2022-09-22T15:07:10.156Z,1663859230.156 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150709.00,A,3648.18425,N,12147.27921,W,0.039,0.00,220922,,,A*78
2022-09-22T15:07:10.163Z,1663859230.163 [NAL9602](INFO): GPS fix at 20220922T150709: (36.803071, -121.787987)
2022-09-22T15:07:13.427Z,1663859233.427 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150712.00,A,3648.18415,N,12147.27926,W,0.156,0.00,220922,,,A*7E
2022-09-22T15:07:13.429Z,1663859233.429 [NAL9602](INFO): GPS fix at 20220922T150712: (36.803069, -121.787988)
2022-09-22T15:07:16.196Z,1663859236.196 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150715.00,A,3648.18398,N,12147.27930,W,0.039,0.00,220922,,,A*74
2022-09-22T15:07:16.199Z,1663859236.199 [NAL9602](INFO): GPS fix at 20220922T150715: (36.803066, -121.787988)
2022-09-22T15:07:19.425Z,1663859239.425 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150718.00,A,3648.18383,N,12147.27930,W,0.097,0.00,220922,,,A*77
2022-09-22T15:07:19.427Z,1663859239.427 [NAL9602](INFO): GPS fix at 20220922T150718: (36.803064, -121.787988)
2022-09-22T15:07:22.252Z,1663859242.252 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150721.00,A,3648.18373,N,12147.27930,W,0.019,0.00,220922,,,A*74
2022-09-22T15:07:22.254Z,1663859242.254 [NAL9602](INFO): GPS fix at 20220922T150721: (36.803062, -121.787988)
2022-09-22T15:07:23.333Z,1663859243.333 [DataOverHttps](INFO): Sending 199 bytes from file Logs/20220922T145649/Express0005.lzma
2022-09-22T15:07:24.335Z,1663859244.335 [DataOverHttps](INFO): Moved sent file to Logs/20220922T145649/Express0005.lzma.bak
2022-09-22T15:07:24.335Z,1663859244.335 [DataOverHttps](INFO): SBD MOMSN=17196721
2022-09-22T15:07:25.488Z,1663859245.488 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150724.00,A,3648.18359,N,12147.27927,W,0.019,0.00,220922,,,A*7F
2022-09-22T15:07:25.491Z,1663859245.491 [NAL9602](INFO): GPS fix at 20220922T150724: (36.803060, -121.787988)
2022-09-22T15:07:28.312Z,1663859248.312 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150727.00,A,3648.18349,N,12147.27926,W,0.019,0.00,220922,,,A*7C
2022-09-22T15:07:28.315Z,1663859248.315 [NAL9602](INFO): GPS fix at 20220922T150727: (36.803058, -121.787988)
2022-09-22T15:07:31.141Z,1663859251.141 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150730.00,A,3648.18344,N,12147.27927,W,0.000,0.00,220922,,,A*7E
2022-09-22T15:07:31.152Z,1663859251.152 [NAL9602](INFO): GPS fix at 20220922T150730: (36.803057, -121.787988)
2022-09-22T15:07:33.592Z,1663859253.592 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 4
Latitude: 36.803059 Longitude: -121.787987
2022-09-22T15:07:34.023Z,1663859254.023 [IBIT](FAULT): Warning: Battery Data not active. Expected only when running primaries. Threshold checking not active.
2022-09-22T15:07:34.376Z,1663859254.376 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150733.00,A,3648.18339,N,12147.27923,W,0.019,0.00,220922,,,A*7B
2022-09-22T15:07:34.379Z,1663859254.379 [NAL9602](INFO): GPS fix at 20220922T150733: (36.803056, -121.787987)
2022-09-22T15:07:34.395Z,1663859254.395 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2022-09-22T15:07:34.396Z,1663859254.396 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2022-09-22T15:07:34.396Z,1663859254.396 [IBIT](IMPORTANT): Pressure:7.786436 PSI
2022-09-22T15:07:34.396Z,1663859254.396 [IBIT](IMPORTANT): Humidity:22.927603 %
2022-09-22T15:07:34.816Z,1663859254.816 [IBIT](IMPORTANT): Vehicle Pitch:-0.157372 degrees
2022-09-22T15:07:34.816Z,1663859254.816 [IBIT](IMPORTANT): Vehicle  Roll:-5.831839 degrees
2022-09-22T15:07:34.816Z,1663859254.816 [IBIT](IMPORTANT): Vehicle  Heading:194.795761 degrees
2022-09-22T15:07:35.211Z,1663859255.211 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2022-09-22T15:07:35.211Z,1663859255.211 [IBIT](IMPORTANT): buoyancyNeutral: 209.634720 cc
2022-09-22T15:07:35.211Z,1663859255.211 [IBIT](IMPORTANT): massDefault: 0.772376 cm
2022-09-22T15:07:35.211Z,1663859255.211 [IBIT](IMPORTANT): stopDepth: 215.000000 m
2022-09-22T15:07:35.212Z,1663859255.212 [IBIT](IMPORTANT): abortDepth: 255.000000 m
2022-09-22T15:07:35.212Z,1663859255.212 [IBIT](IMPORTANT): IBIT PASSED
2022-09-22T15:07:35.603Z,1663859255.603 [Default:CheckIn:Read_Iridium] Stopped
2022-09-22T15:07:35.603Z,1663859255.603 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-22T15:07:35.603Z,1663859255.603 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-22T15:07:41.263Z,1663859261.263 [DataOverHttps](INFO): Sending 1099 bytes from file Logs/20220922T150304/Express0001.lzma
2022-09-22T15:07:42.263Z,1663859262.263 [DataOverHttps](INFO): Moved sent file to Logs/20220922T150304/Express0001.lzma.bak
2022-09-22T15:07:42.263Z,1663859262.263 [DataOverHttps](INFO): SBD MOMSN=17196726
2022-09-22T15:08:06.696Z,1663859286.696 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-22T15:10:07.571Z,1663859407.571 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2022-09-22T15:10:07.574Z,1663859407.574 [BPC1](INFO): Received data from all battery sticks.
2022-09-22T15:12:36.244Z,1663859556.244 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-22T15:12:36.245Z,1663859556.245 [Default:CheckIn:C.Wait] Stopped
2022-09-22T15:12:36.245Z,1663859556.245 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-22T15:12:36.245Z,1663859556.245 [Default:CheckIn:D] Running Loop=1
2022-09-22T15:12:36.653Z,1663859556.653 [Default:CheckIn:D] Stopped
2022-09-22T15:12:36.653Z,1663859556.653 [Default:CheckIn:E] Running Loop=1
2022-09-22T15:12:37.061Z,1663859557.061 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.563842 min 
2022-09-22T15:12:37.061Z,1663859557.061 [Default:CheckIn:E] Stopped
2022-09-22T15:12:37.061Z,1663859557.061 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-22T15:12:37.061Z,1663859557.061 [Default:CheckIn] Stopped
2022-09-22T15:12:37.062Z,1663859557.062 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-22T15:12:37.062Z,1663859557.062 [Default:CheckIn](INFO): Running loop #2
2022-09-22T15:12:37.062Z,1663859557.062 [Default:CheckIn] Running Loop=2
2022-09-22T15:12:37.062Z,1663859557.062 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-22T15:12:37.062Z,1663859557.062 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-22T15:12:39.064Z,1663859559.064 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151238.00,A,3648.13991,N,12147.22677,W,0.078,66.95,220922,,,A*47
2022-09-22T15:12:39.067Z,1663859559.067 [NAL9602](INFO): GPS fix at 20220922T151238: (36.802332, -121.787113)
2022-09-22T15:12:39.098Z,1663859559.098 [Default:CheckIn:Read_GPS] Stopped
2022-09-22T15:12:39.098Z,1663859559.098 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-22T15:12:46.593Z,1663859566.593 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20220922T150304/Courier0010.lzma
2022-09-22T15:12:47.596Z,1663859567.596 [DataOverHttps](INFO): Moved sent file to Logs/20220922T150304/Courier0010.lzma.bak
2022-09-22T15:12:47.596Z,1663859567.596 [DataOverHttps](INFO): SBD MOMSN=17196760
2022-09-22T15:12:55.224Z,1663859575.224 [NAL9602](INFO): SBD MO Status=0, MOMSN=20478, MT Status=0, MTMSN=0
2022-09-22T15:12:55.225Z,1663859575.225 [NAL9602](INFO): No messages in MT queue
2022-09-22T15:13:04.101Z,1663859584.101 [DataOverHttps](INFO): Sending 228 bytes from file Logs/20220922T150304/Express0005.lzma
2022-09-22T15:13:05.103Z,1663859585.103 [DataOverHttps](INFO): Moved sent file to Logs/20220922T150304/Express0005.lzma.bak
2022-09-22T15:13:05.103Z,1663859585.103 [DataOverHttps](INFO): SBD MOMSN=17196763
2022-09-22T15:13:21.381Z,1663859601.381 [DataOverHttps](INFO): Sending 249 bytes from file Logs/20220922T150304/Express0008.lzma
2022-09-22T15:13:22.384Z,1663859602.384 [DataOverHttps](INFO): Moved sent file to Logs/20220922T150304/Express0008.lzma.bak
2022-09-22T15:13:22.385Z,1663859602.385 [DataOverHttps](INFO): SBD MOMSN=17196766
2022-09-22T15:13:25.923Z,1663859605.923 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-22T15:13:38.930Z,1663859618.930 [DataOverHttps](INFO): Sending 697 bytes from file Logs/20220922T150304/Express0011.lzma
2022-09-22T15:13:39.931Z,1663859619.931 [DataOverHttps](INFO): Moved sent file to Logs/20220922T150304/Express0011.lzma.bak
2022-09-22T15:13:39.931Z,1663859619.931 [DataOverHttps](INFO): SBD MOMSN=17196773
2022-09-22T15:13:41.294Z,1663859621.294 [Default:CheckIn:Read_Iridium] Stopped
2022-09-22T15:13:41.294Z,1663859621.294 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-22T15:13:41.294Z,1663859621.294 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-22T15:18:41.962Z,1663859921.962 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-22T15:18:41.962Z,1663859921.962 [Default:CheckIn:C.Wait] Stopped
2022-09-22T15:18:41.962Z,1663859921.962 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-22T15:18:41.962Z,1663859921.962 [Default:CheckIn:D] Running Loop=1
2022-09-22T15:18:42.345Z,1663859922.345 [Default:CheckIn:D] Stopped
2022-09-22T15:18:42.345Z,1663859922.345 [Default:CheckIn:E] Running Loop=1
2022-09-22T15:18:42.752Z,1663859922.752 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.658709 min 
2022-09-22T15:18:42.752Z,1663859922.752 [Default:CheckIn:E] Stopped
2022-09-22T15:18:42.752Z,1663859922.752 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-22T15:18:42.752Z,1663859922.752 [Default:CheckIn] Stopped
2022-09-22T15:18:42.752Z,1663859922.752 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-22T15:18:42.752Z,1663859922.752 [Default:CheckIn](INFO): Running loop #3
2022-09-22T15:18:42.752Z,1663859922.752 [Default:CheckIn] Running Loop=3
2022-09-22T15:18:42.752Z,1663859922.752 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-22T15:18:42.753Z,1663859922.753 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-22T15:18:44.760Z,1663859924.760 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151844.00,A,3648.13924,N,12147.22614,W,0.019,66.95,220922,,,D*4F
2022-09-22T15:18:44.772Z,1663859924.772 [NAL9602](INFO): GPS fix at 20220922T151844: (36.802321, -121.787102)
2022-09-22T15:18:44.783Z,1663859924.783 [Default:CheckIn:Read_GPS] Stopped
2022-09-22T15:18:44.783Z,1663859924.783 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-22T15:18:52.849Z,1663859932.849 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220922T150304/Courier0013.lzma
2022-09-22T15:18:53.851Z,1663859933.851 [DataOverHttps](INFO): Moved sent file to Logs/20220922T150304/Courier0013.lzma.bak
2022-09-22T15:18:53.851Z,1663859933.851 [DataOverHttps](INFO): SBD MOMSN=17196793
2022-09-22T15:18:58.088Z,1663859938.088 [NAL9602](INFO): SBD MO Status=0, MOMSN=20479, MT Status=0, MTMSN=0
2022-09-22T15:18:58.088Z,1663859938.088 [NAL9602](INFO): No messages in MT queue
2022-09-22T15:19:10.185Z,1663859950.185 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20220922T150304/Express0014.lzma
2022-09-22T15:19:11.295Z,1663859951.295 [DataOverHttps](INFO): Moved sent file to Logs/20220922T150304/Express0014.lzma.bak
2022-09-22T15:19:11.295Z,1663859951.295 [DataOverHttps](INFO): SBD MOMSN=17196796
2022-09-22T15:19:12.240Z,1663859952.240 [Default:CheckIn:Read_Iridium] Stopped
2022-09-22T15:19:12.240Z,1663859952.240 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-22T15:19:12.240Z,1663859952.240 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-22T15:19:28.797Z,1663859968.797 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-22T15:21:06.022Z,1663860066.022 [CommandExec](IMPORTANT): got command failComponent
2022-09-22T15:21:06.023Z,1663860066.023 [CommandExec](IMPORTANT): Failed components:
2022-09-22T15:21:06.023Z,1663860066.023 [CommandExec](IMPORTANT): No failed Components.
2022-09-22T15:24:12.839Z,1663860252.839 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-22T15:24:12.839Z,1663860252.839 [Default:CheckIn:C.Wait] Stopped
2022-09-22T15:24:12.839Z,1663860252.839 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-22T15:24:12.839Z,1663860252.839 [Default:CheckIn:D] Running Loop=1
2022-09-22T15:24:13.245Z,1663860253.245 [Default:CheckIn:D] Stopped
2022-09-22T15:24:13.245Z,1663860253.245 [Default:CheckIn:E] Running Loop=1
2022-09-22T15:24:13.718Z,1663860253.718 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.173710 min 
2022-09-22T15:24:13.718Z,1663860253.718 [Default:CheckIn:E] Stopped
2022-09-22T15:24:13.718Z,1663860253.718 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-22T15:24:13.718Z,1663860253.718 [Default:CheckIn] Stopped
2022-09-22T15:24:13.719Z,1663860253.719 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-22T15:24:13.719Z,1663860253.719 [Default:CheckIn](INFO): Running loop #4
2022-09-22T15:24:13.719Z,1663860253.719 [Default:CheckIn] Running Loop=4
2022-09-22T15:24:13.719Z,1663860253.719 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-22T15:24:13.719Z,1663860253.719 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-22T15:24:15.675Z,1663860255.675 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,152415.00,A,3648.13824,N,12147.22555,W,0.058,66.95,220922,,,D*46
2022-09-22T15:24:15.678Z,1663860255.678 [NAL9602](INFO): GPS fix at 20220922T152415: (36.802304, -121.787092)
2022-09-22T15:24:15.727Z,1663860255.727 [Default:CheckIn:Read_GPS] Stopped
2022-09-22T15:24:15.727Z,1663860255.727 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-22T15:24:25.836Z,1663860265.836 [NAL9602](INFO): SBD MO Status=0, MOMSN=20480, MT Status=0, MTMSN=0
2022-09-22T15:24:25.836Z,1663860265.836 [NAL9602](INFO): No messages in MT queue
2022-09-22T15:24:26.645Z,1663860266.645 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20220922T150304/Courier0016.lzma
2022-09-22T15:24:27.653Z,1663860267.653 [DataOverHttps](INFO): Moved sent file to Logs/20220922T150304/Courier0016.lzma.bak
2022-09-22T15:24:27.654Z,1663860267.654 [DataOverHttps](INFO): SBD MOMSN=17196800
2022-09-22T15:24:44.161Z,1663860284.161 [DataOverHttps](INFO): Sending 184 bytes from file Logs/20220922T150304/Express0017.lzma
2022-09-22T15:24:45.163Z,1663860285.163 [DataOverHttps](INFO): Moved sent file to Logs/20220922T150304/Express0017.lzma.bak
2022-09-22T15:24:45.163Z,1663860285.163 [DataOverHttps](INFO): SBD MOMSN=17196803
2022-09-22T15:24:46.470Z,1663860286.470 [Default:CheckIn:Read_Iridium] Stopped
2022-09-22T15:24:46.470Z,1663860286.470 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-22T15:24:46.470Z,1663860286.470 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-22T15:24:56.539Z,1663860296.539 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-22T15:29:47.059Z,1663860587.059 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-22T15:29:47.059Z,1663860587.059 [Default:CheckIn:C.Wait] Stopped
2022-09-22T15:29:47.059Z,1663860587.059 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-22T15:29:47.059Z,1663860587.059 [Default:CheckIn:D] Running Loop=1
2022-09-22T15:29:47.448Z,1663860587.448 [Default:CheckIn:D] Stopped
2022-09-22T15:29:47.448Z,1663860587.448 [Default:CheckIn:E] Running Loop=1
2022-09-22T15:29:47.877Z,1663860587.877 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.743754 min 
2022-09-22T15:29:47.877Z,1663860587.877 [Default:CheckIn:E] Stopped
2022-09-22T15:29:47.877Z,1663860587.877 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-22T15:29:47.882Z,1663860587.882 [Default:CheckIn] Stopped
2022-09-22T15:29:47.882Z,1663860587.882 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-22T15:29:47.883Z,1663860587.883 [Default:CheckIn](INFO): Running loop #5
2022-09-22T15:29:47.883Z,1663860587.883 [Default:CheckIn] Running Loop=5
2022-09-22T15:29:47.884Z,1663860587.884 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-22T15:29:47.884Z,1663860587.884 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-22T15:29:49.848Z,1663860589.848 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,152949.00,A,3648.14219,N,12147.22836,W,0.097,10.90,220922,,,D*4E
2022-09-22T15:29:49.851Z,1663860589.851 [NAL9602](INFO): GPS fix at 20220922T152949: (36.802370, -121.787139)
2022-09-22T15:29:49.885Z,1663860589.885 [Default:CheckIn:Read_GPS] Stopped
2022-09-22T15:29:49.885Z,1663860589.885 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-22T15:29:57.573Z,1663860597.573 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220922T150304/Courier0019.lzma
2022-09-22T15:29:58.575Z,1663860598.575 [DataOverHttps](INFO): Moved sent file to Logs/20220922T150304/Courier0019.lzma.bak
2022-09-22T15:29:58.575Z,1663860598.575 [DataOverHttps](INFO): SBD MOMSN=17196810
2022-09-22T15:30:07.660Z,1663860607.660 [NAL9602](INFO): SBD MO Status=2, MOMSN=20481, MT Status=2, MTMSN=0
2022-09-22T15:30:07.661Z,1663860607.661 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-22T15:30:14.937Z,1663860614.937 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220922T150304/Express0020.lzma
2022-09-22T15:30:15.939Z,1663860615.939 [DataOverHttps](INFO): Moved sent file to Logs/20220922T150304/Express0020.lzma.bak
2022-09-22T15:30:15.939Z,1663860615.939 [DataOverHttps](INFO): SBD MOMSN=17196813
2022-09-22T15:30:16.970Z,1663860616.970 [Default:CheckIn:Read_Iridium] Stopped
2022-09-22T15:30:16.970Z,1663860616.970 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-22T15:30:16.970Z,1663860616.970 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-22T15:31:41.815Z,1663860701.815 [NAL9602](FAULT): Timeout waiting for SBDI response.
2022-09-22T15:31:41.815Z,1663860701.815 [NAL9602] Data Fault, FailCount= 1
2022-09-22T15:31:41.815Z,1663860701.815 [NAL9602](ERROR): Data Fault
2022-09-22T15:31:41.886Z,1663860701.886 [CBIT](ERROR): Data Fault in component: NAL9602
2022-09-22T15:31:42.223Z,1663860702.223 [NAL9602](INFO): Powering down
2022-09-22T15:31:43.039Z,1663860703.039 [CBIT](INFO): Clearing failed state for component NAL9602
2022-09-22T15:31:43.039Z,1663860703.039 [NAL9602] No Fault, FailCount= 1
2022-09-22T15:32:12.515Z,1663860732.515 [NAL9602](INFO): Powering up NAL9602
2022-09-22T15:32:23.423Z,1663860743.423 [NAL9602](INFO): NAL9602 initialized
2022-09-22T15:32:54.531Z,1663860774.531 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-22T15:35:17.571Z,1663860917.571 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-22T15:35:17.571Z,1663860917.571 [Default:CheckIn:C.Wait] Stopped
2022-09-22T15:35:17.571Z,1663860917.571 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-22T15:35:17.571Z,1663860917.571 [Default:CheckIn:D] Running Loop=1
2022-09-22T15:35:17.992Z,1663860917.992 [Default:CheckIn:D] Stopped
2022-09-22T15:35:17.992Z,1663860917.992 [Default:CheckIn:E] Running Loop=1
2022-09-22T15:35:18.373Z,1663860918.373 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.252830 min 
2022-09-22T15:35:18.373Z,1663860918.373 [Default:CheckIn:E] Stopped
2022-09-22T15:35:18.373Z,1663860918.373 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-22T15:35:18.373Z,1663860918.373 [Default:CheckIn] Stopped
2022-09-22T15:35:18.373Z,1663860918.373 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-22T15:35:18.373Z,1663860918.373 [Default:CheckIn](INFO): Running loop #6
2022-09-22T15:35:18.373Z,1663860918.373 [Default:CheckIn] Running Loop=6
2022-09-22T15:35:18.374Z,1663860918.374 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-22T15:35:18.374Z,1663860918.374 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-22T15:35:20.384Z,1663860920.384 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153519.00,A,3648.16538,N,12147.21469,W,0.039,165.55,220922,,,A*7E
2022-09-22T15:35:20.387Z,1663860920.387 [NAL9602](INFO): GPS fix at 20220922T153519: (36.802756, -121.786912)
2022-09-22T15:35:20.397Z,1663860920.397 [Default:CheckIn:Read_GPS] Stopped
2022-09-22T15:35:20.398Z,1663860920.398 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-22T15:35:22.400Z,1663860922.400 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-09-22T15:35:28.109Z,1663860928.109 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220922T150304/Courier0022.lzma
2022-09-22T15:35:29.111Z,1663860929.111 [DataOverHttps](INFO): Moved sent file to Logs/20220922T150304/Courier0022.lzma.bak
2022-09-22T15:35:29.111Z,1663860929.111 [DataOverHttps](INFO): SBD MOMSN=17196817
2022-09-22T15:35:45.325Z,1663860945.325 [DataOverHttps](INFO): Sending 188 bytes from file Logs/20220922T150304/Express0023.lzma
2022-09-22T15:35:46.328Z,1663860946.328 [DataOverHttps](INFO): Moved sent file to Logs/20220922T150304/Express0023.lzma.bak
2022-09-22T15:35:46.328Z,1663860946.328 [DataOverHttps](INFO): SBD MOMSN=17196820
2022-09-22T15:35:47.456Z,1663860947.456 [Default:CheckIn:Read_Iridium] Stopped
2022-09-22T15:35:47.456Z,1663860947.456 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-22T15:35:47.456Z,1663860947.456 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-22T15:35:53.102Z,1663860953.102 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-22T15:40:48.079Z,1663861248.079 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-22T15:40:48.079Z,1663861248.079 [Default:CheckIn:C.Wait] Stopped
2022-09-22T15:40:48.079Z,1663861248.079 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-22T15:40:48.079Z,1663861248.079 [Default:CheckIn:D] Running Loop=1
2022-09-22T15:40:48.472Z,1663861248.472 [Default:CheckIn:D] Stopped
2022-09-22T15:40:48.472Z,1663861248.472 [Default:CheckIn:E] Running Loop=1
2022-09-22T15:40:48.876Z,1663861248.876 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.760836 min 
2022-09-22T15:40:48.877Z,1663861248.877 [Default:CheckIn:E] Stopped
2022-09-22T15:40:48.877Z,1663861248.877 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-22T15:40:48.877Z,1663861248.877 [Default:CheckIn] Stopped
2022-09-22T15:40:48.877Z,1663861248.877 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-22T15:40:48.877Z,1663861248.877 [Default:CheckIn](INFO): Running loop #7
2022-09-22T15:40:48.877Z,1663861248.877 [Default:CheckIn] Running Loop=7
2022-09-22T15:40:48.877Z,1663861248.877 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-22T15:40:48.878Z,1663861248.878 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-22T15:40:50.884Z,1663861250.884 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154050.00,A,3648.16364,N,12147.21512,W,0.039,165.55,220922,,,A*73
2022-09-22T15:40:50.887Z,1663861250.887 [NAL9602](INFO): GPS fix at 20220922T154050: (36.802727, -121.786919)
2022-09-22T15:40:50.898Z,1663861250.898 [Default:CheckIn:Read_GPS] Stopped
2022-09-22T15:40:50.898Z,1663861250.898 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-22T15:40:58.429Z,1663861258.429 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220922T150304/Courier0025.lzma
2022-09-22T15:40:59.431Z,1663861259.431 [DataOverHttps](INFO): Moved sent file to Logs/20220922T150304/Courier0025.lzma.bak
2022-09-22T15:40:59.432Z,1663861259.432 [DataOverHttps](INFO): SBD MOMSN=17196824
2022-09-22T15:41:07.865Z,1663861267.865 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2022-09-22T15:41:15.889Z,1663861275.889 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20220922T150304/Express0026.lzma
2022-09-22T15:41:16.892Z,1663861276.892 [DataOverHttps](INFO): Moved sent file to Logs/20220922T150304/Express0026.lzma.bak
2022-09-22T15:41:16.892Z,1663861276.892 [DataOverHttps](INFO): SBD MOMSN=17196827
2022-09-22T15:41:17.982Z,1663861277.982 [Default:CheckIn:Read_Iridium] Stopped
2022-09-22T15:41:17.982Z,1663861277.982 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-22T15:41:17.982Z,1663861277.982 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-22T15:42:01.185Z,1663861321.185 [NAL9602](INFO): SBD MO Status=2, MOMSN=20481, MT Status=2, MTMSN=0
2022-09-22T15:42:01.185Z,1663861321.185 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-22T15:42:28.664Z,1663861348.664 [NAL9602](INFO): SBD MO Status=2, MOMSN=20481, MT Status=2, MTMSN=0
2022-09-22T15:42:28.664Z,1663861348.664 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-22T15:42:44.826Z,1663861364.826 [NAL9602](INFO): SBD MO Status=0, MOMSN=20481, MT Status=0, MTMSN=0
2022-09-22T15:42:44.826Z,1663861364.826 [NAL9602](INFO): No messages in MT queue
2022-09-22T15:43:15.521Z,1663861395.521 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-22T15:46:18.641Z,1663861578.641 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-22T15:46:18.641Z,1663861578.641 [Default:CheckIn:C.Wait] Stopped
2022-09-22T15:46:18.641Z,1663861578.641 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-22T15:46:18.641Z,1663861578.641 [Default:CheckIn:D] Running Loop=1
2022-09-22T15:46:19.048Z,1663861579.048 [Default:CheckIn:D] Stopped
2022-09-22T15:46:19.049Z,1663861579.049 [Default:CheckIn:E] Running Loop=1
2022-09-22T15:46:19.443Z,1663861579.443 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 40.270435 min 
2022-09-22T15:46:19.443Z,1663861579.443 [Default:CheckIn:E] Stopped
2022-09-22T15:46:19.443Z,1663861579.443 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-22T15:46:19.443Z,1663861579.443 [Default:CheckIn] Stopped
2022-09-22T15:46:19.443Z,1663861579.443 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-22T15:46:19.444Z,1663861579.444 [Default:CheckIn](INFO): Running loop #8
2022-09-22T15:46:19.444Z,1663861579.444 [Default:CheckIn] Running Loop=8
2022-09-22T15:46:19.444Z,1663861579.444 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-22T15:46:19.444Z,1663861579.444 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-22T15:46:21.466Z,1663861581.466 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154621.00,A,3648.15521,N,12147.21384,W,0.019,165.55,220922,,,A*7C
2022-09-22T15:46:21.468Z,1663861581.468 [NAL9602](INFO): GPS fix at 20220922T154621: (36.802587, -121.786897)
2022-09-22T15:46:21.479Z,1663861581.479 [Default:CheckIn:Read_GPS] Stopped
2022-09-22T15:46:21.479Z,1663861581.479 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-22T15:46:30.241Z,1663861590.241 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220922T150304/Courier0028.lzma
2022-09-22T15:46:31.243Z,1663861591.243 [DataOverHttps](INFO): Moved sent file to Logs/20220922T150304/Courier0028.lzma.bak
2022-09-22T15:46:31.244Z,1663861591.244 [DataOverHttps](INFO): SBD MOMSN=17196832
2022-09-22T15:46:34.149Z,1663861594.149 [NAL9602](INFO): SBD MO Status=0, MOMSN=20482, MT Status=0, MTMSN=0
2022-09-22T15:46:34.149Z,1663861594.149 [NAL9602](INFO): No messages in MT queue
2022-09-22T15:46:47.608Z,1663861607.608 [DataOverHttps](INFO): Sending 127 bytes from file Logs/20220922T150304/Express0029.lzma
2022-09-22T15:46:48.603Z,1663861608.603 [DataOverHttps](INFO): Moved sent file to Logs/20220922T150304/Express0029.lzma.bak
2022-09-22T15:46:48.603Z,1663861608.603 [DataOverHttps](INFO): SBD MOMSN=17196835
2022-09-22T15:46:49.937Z,1663861609.937 [Default:CheckIn:Read_Iridium] Stopped
2022-09-22T15:46:49.937Z,1663861609.937 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-22T15:46:49.937Z,1663861609.937 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-22T15:47:04.858Z,1663861624.858 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-22T15:51:50.495Z,1663861910.495 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-22T15:51:50.495Z,1663861910.495 [Default:CheckIn:C.Wait] Stopped
2022-09-22T15:51:50.495Z,1663861910.495 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-22T15:51:50.496Z,1663861910.496 [Default:CheckIn:D] Running Loop=1
2022-09-22T15:51:50.914Z,1663861910.914 [Default:CheckIn:D] Stopped
2022-09-22T15:51:50.914Z,1663861910.914 [Default:CheckIn:E] Running Loop=1
2022-09-22T15:51:51.322Z,1663861911.322 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.801530 min 
2022-09-22T15:51:51.322Z,1663861911.322 [Default:CheckIn:E] Stopped
2022-09-22T15:51:51.323Z,1663861911.323 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-22T15:51:51.323Z,1663861911.323 [Default:CheckIn] Stopped
2022-09-22T15:51:51.323Z,1663861911.323 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-22T15:51:51.323Z,1663861911.323 [Default:CheckIn](INFO): Running loop #9
2022-09-22T15:51:51.323Z,1663861911.323 [Default:CheckIn] Running Loop=9
2022-09-22T15:51:51.323Z,1663861911.323 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-22T15:51:51.323Z,1663861911.323 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-22T15:51:53.320Z,1663861913.320 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155153.00,A,3648.16064,N,12147.21507,W,0.019,165.55,220922,,,A*75
2022-09-22T15:51:53.322Z,1663861913.322 [NAL9602](INFO): GPS fix at 20220922T155153: (36.802677, -121.786918)
2022-09-22T15:51:53.333Z,1663861913.333 [Default:CheckIn:Read_GPS] Stopped
2022-09-22T15:51:53.333Z,1663861913.333 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-22T15:52:01.369Z,1663861921.369 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220922T150304/Courier0031.lzma
2022-09-22T15:52:02.371Z,1663861922.371 [DataOverHttps](INFO): Moved sent file to Logs/20220922T150304/Courier0031.lzma.bak
2022-09-22T15:52:02.371Z,1663861922.371 [DataOverHttps](INFO): SBD MOMSN=17196839
2022-09-22T15:52:05.849Z,1663861925.849 [NAL9602](INFO): SBD MO Status=0, MOMSN=20483, MT Status=0, MTMSN=0
2022-09-22T15:52:05.849Z,1663861925.849 [NAL9602](INFO): No messages in MT queue
2022-09-22T15:52:19.603Z,1663861939.603 [DataOverHttps](INFO): Sending 133 bytes from file Logs/20220922T150304/Express0032.lzma
2022-09-22T15:52:20.591Z,1663861940.591 [DataOverHttps](INFO): Moved sent file to Logs/20220922T150304/Express0032.lzma.bak
2022-09-22T15:52:20.592Z,1663861940.592 [DataOverHttps](INFO): SBD MOMSN=17196842
2022-09-22T15:52:21.719Z,1663861941.719 [Default:CheckIn:Read_Iridium] Stopped
2022-09-22T15:52:21.719Z,1663861941.719 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-22T15:52:21.719Z,1663861941.719 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-22T15:52:36.608Z,1663861956.608 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-22T15:57:22.243Z,1663862242.243 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-22T15:57:22.244Z,1663862242.244 [Default:CheckIn:C.Wait] Stopped
2022-09-22T15:57:22.244Z,1663862242.244 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-22T15:57:22.244Z,1663862242.244 [Default:CheckIn:D] Running Loop=1
2022-09-22T15:57:22.659Z,1663862242.659 [Default:CheckIn:D] Stopped
2022-09-22T15:57:22.659Z,1663862242.659 [Default:CheckIn:E] Running Loop=1
2022-09-22T15:57:23.050Z,1663862243.050 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.330611 min 
2022-09-22T15:57:23.051Z,1663862243.051 [Default:CheckIn:E] Stopped
2022-09-22T15:57:23.051Z,1663862243.051 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-22T15:57:23.051Z,1663862243.051 [Default:CheckIn] Stopped
2022-09-22T15:57:23.051Z,1663862243.051 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-22T15:57:23.051Z,1663862243.051 [Default:CheckIn](INFO): Running loop #10
2022-09-22T15:57:23.051Z,1663862243.051 [Default:CheckIn] Running Loop=10
2022-09-22T15:57:23.051Z,1663862243.051 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-22T15:57:23.051Z,1663862243.051 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-22T15:57:25.056Z,1663862245.056 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155724.00,A,3648.30305,N,12147.12830,W,3.752,7.52,220922,,,A*73
2022-09-22T15:57:25.059Z,1663862245.059 [NAL9602](INFO): GPS fix at 20220922T155724: (36.805051, -121.785472)
2022-09-22T15:57:25.069Z,1663862245.069 [Default:CheckIn:Read_GPS] Stopped
2022-09-22T15:57:25.069Z,1663862245.069 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-22T15:57:32.557Z,1663862252.557 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220922T150304/Courier0034.lzma
2022-09-22T15:57:33.562Z,1663862253.562 [DataOverHttps](INFO): Moved sent file to Logs/20220922T150304/Courier0034.lzma.bak
2022-09-22T15:57:33.562Z,1663862253.562 [DataOverHttps](INFO): SBD MOMSN=17196846
2022-09-22T15:57:33.944Z,1663862253.944 [NAL9602](INFO): SBD MO Status=0, MOMSN=20484, MT Status=0, MTMSN=0
2022-09-22T15:57:33.944Z,1663862253.944 [NAL9602](INFO): No messages in MT queue
2022-09-22T15:57:49.869Z,1663862269.869 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20220922T150304/Express0035.lzma
2022-09-22T15:57:50.871Z,1663862270.871 [DataOverHttps](INFO): Moved sent file to Logs/20220922T150304/Express0035.lzma.bak
2022-09-22T15:57:50.872Z,1663862270.872 [DataOverHttps](INFO): SBD MOMSN=17196849
2022-09-22T15:57:52.134Z,1663862272.134 [Default:CheckIn:Read_Iridium] Stopped
2022-09-22T15:57:52.135Z,1663862272.135 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-22T15:57:52.135Z,1663862272.135 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-22T15:58:04.650Z,1663862284.650 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-22T15:59:23.845Z,1663862363.845 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2022-09-22T16:02:52.816Z,1663862572.816 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-22T16:02:52.816Z,1663862572.816 [Default:CheckIn:C.Wait] Stopped
2022-09-22T16:02:52.816Z,1663862572.816 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-22T16:02:52.816Z,1663862572.816 [Default:CheckIn:D] Running Loop=1
2022-09-22T16:02:53.232Z,1663862573.232 [Default:CheckIn:D] Stopped
2022-09-22T16:02:53.232Z,1663862573.232 [Default:CheckIn:E] Running Loop=1
2022-09-22T16:02:53.674Z,1663862573.674 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.840157 min 
2022-09-22T16:02:53.674Z,1663862573.674 [Default:CheckIn:E] Stopped
2022-09-22T16:02:53.674Z,1663862573.674 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-22T16:02:53.674Z,1663862573.674 [Default:CheckIn] Stopped
2022-09-22T16:02:53.674Z,1663862573.674 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-22T16:02:53.674Z,1663862573.674 [Default:CheckIn](INFO): Running loop #11
2022-09-22T16:02:53.675Z,1663862573.675 [Default:CheckIn] Running Loop=11
2022-09-22T16:02:53.675Z,1663862573.675 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-22T16:02:53.675Z,1663862573.675 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-22T16:02:55.646Z,1663862575.646 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160255.00,A,3648.33172,N,12147.52166,W,2.877,235.19,220922,,,D*79
2022-09-22T16:02:55.648Z,1663862575.648 [NAL9602](INFO): GPS fix at 20220922T160255: (36.805529, -121.792028)
2022-09-22T16:02:55.695Z,1663862575.695 [Default:CheckIn:Read_GPS] Stopped
2022-09-22T16:02:55.695Z,1663862575.695 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-22T16:03:03.013Z,1663862583.013 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220922T150304/Courier0037.lzma
2022-09-22T16:03:04.015Z,1663862584.015 [DataOverHttps](INFO): Moved sent file to Logs/20220922T150304/Courier0037.lzma.bak
2022-09-22T16:03:04.016Z,1663862584.016 [DataOverHttps](INFO): SBD MOMSN=17196853
2022-09-22T16:03:15.030Z,1663862595.030 [NAL9602](INFO): SBD MO Status=0, MOMSN=20485, MT Status=0, MTMSN=0
2022-09-22T16:03:15.030Z,1663862595.030 [NAL9602](INFO): No messages in MT queue
2022-09-22T16:03:20.401Z,1663862600.401 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20220922T150304/Express0038.lzma
2022-09-22T16:03:21.403Z,1663862601.403 [DataOverHttps](INFO): Moved sent file to Logs/20220922T150304/Express0038.lzma.bak
2022-09-22T16:03:21.404Z,1663862601.404 [DataOverHttps](INFO): SBD MOMSN=17196856
2022-09-22T16:03:22.717Z,1663862602.717 [Default:CheckIn:Read_Iridium] Stopped
2022-09-22T16:03:22.717Z,1663862602.717 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-22T16:03:22.717Z,1663862602.717 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-22T16:03:45.721Z,1663862625.721 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-22T16:04:49.970Z,1663862689.970 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2022-09-22T16:07:31.286Z,1663862851.286 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.247482
2022-09-22T16:08:14.039Z,1663862894.039 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003200
2022-09-22T16:08:23.336Z,1663862903.336 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-22T16:08:23.336Z,1663862903.336 [Default:CheckIn:C.Wait] Stopped
2022-09-22T16:08:23.336Z,1663862903.336 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-22T16:08:23.336Z,1663862903.336 [Default:CheckIn:D] Running Loop=1
2022-09-22T16:08:23.797Z,1663862903.797 [Default:CheckIn:D] Stopped
2022-09-22T16:08:23.797Z,1663862903.797 [Default:CheckIn:E] Running Loop=1
2022-09-22T16:08:24.153Z,1663862904.153 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.349577 min 
2022-09-22T16:08:24.153Z,1663862904.153 [Default:CheckIn:E] Stopped
2022-09-22T16:08:24.153Z,1663862904.153 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-22T16:08:24.153Z,1663862904.153 [Default:CheckIn] Stopped
2022-09-22T16:08:24.153Z,1663862904.153 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-22T16:08:24.166Z,1663862904.166 [Default:CheckIn](INFO): Running loop #12
2022-09-22T16:08:24.166Z,1663862904.166 [Default:CheckIn] Running Loop=12
2022-09-22T16:08:24.166Z,1663862904.166 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-22T16:08:24.166Z,1663862904.166 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-22T16:08:26.152Z,1663862906.152 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160826.00,A,3648.16360,N,12149.10428,W,21.343,257.97,220922,,,D*49
2022-09-22T16:08:26.155Z,1663862906.155 [NAL9602](INFO): GPS fix at 20220922T160826: (36.802727, -121.818405)
2022-09-22T16:08:26.188Z,1663862906.188 [Default:CheckIn:Read_GPS] Stopped
2022-09-22T16:08:26.188Z,1663862906.188 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-22T16:08:33.789Z,1663862913.789 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220922T150304/Courier0040.lzma
2022-09-22T16:08:34.791Z,1663862914.791 [DataOverHttps](INFO): Moved sent file to Logs/20220922T150304/Courier0040.lzma.bak
2022-09-22T16:08:34.791Z,1663862914.791 [DataOverHttps](INFO): SBD MOMSN=17196860
2022-09-22T16:08:40.304Z,1663862920.304 [NAL9602](INFO): SBD MO Status=0, MOMSN=20486, MT Status=0, MTMSN=0
2022-09-22T16:08:40.304Z,1663862920.304 [NAL9602](INFO): No messages in MT queue
2022-09-22T16:08:52.201Z,1663862932.201 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20220922T150304/Express0041.lzma
2022-09-22T16:08:53.203Z,1663862933.203 [DataOverHttps](INFO): Moved sent file to Logs/20220922T150304/Express0041.lzma.bak
2022-09-22T16:08:53.204Z,1663862933.204 [DataOverHttps](INFO): SBD MOMSN=17196863
2022-09-22T16:08:54.442Z,1663862934.442 [Default:CheckIn:Read_Iridium] Stopped
2022-09-22T16:08:54.442Z,1663862934.442 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-22T16:08:54.442Z,1663862934.442 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-22T16:09:10.999Z,1663862950.999 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-22T16:12:57.902Z,1663863177.902 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-09-22T16:13:01.918Z,1663863181.918 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.239677
2022-09-22T16:13:20.921Z,1663863200.921 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002777
2022-09-22T16:13:55.031Z,1663863235.031 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-22T16:13:55.031Z,1663863235.031 [Default:CheckIn:C.Wait] Stopped
2022-09-22T16:13:55.031Z,1663863235.031 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-22T16:13:55.031Z,1663863235.031 [Default:CheckIn:D] Running Loop=1
2022-09-22T16:13:55.442Z,1663863235.442 [Default:CheckIn:D] Stopped
2022-09-22T16:13:55.442Z,1663863235.442 [Default:CheckIn:E] Running Loop=1
2022-09-22T16:13:55.859Z,1663863235.859 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 67.876982 min 
2022-09-22T16:13:55.859Z,1663863235.859 [Default:CheckIn:E] Stopped
2022-09-22T16:13:55.859Z,1663863235.859 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-22T16:13:55.859Z,1663863235.859 [Default:CheckIn] Stopped
2022-09-22T16:13:55.860Z,1663863235.860 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-22T16:13:55.860Z,1663863235.860 [Default:CheckIn](INFO): Running loop #13
2022-09-22T16:13:55.860Z,1663863235.860 [Default:CheckIn] Running Loop=13
2022-09-22T16:13:55.860Z,1663863235.860 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-22T16:13:55.860Z,1663863235.860 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-22T16:13:57.841Z,1663863237.841 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161357.00,A,3647.82191,N,12150.82210,W,0.292,57.44,220922,,,D*47
2022-09-22T16:13:57.844Z,1663863237.844 [NAL9602](INFO): GPS fix at 20220922T161357: (36.797032, -121.847035)
2022-09-22T16:13:57.896Z,1663863237.896 [Default:CheckIn:Read_GPS] Stopped
2022-09-22T16:13:57.896Z,1663863237.896 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-22T16:14:24.100Z,1663863264.100 [NAL9602](INFO): SBD MO Status=0, MOMSN=20487, MT Status=0, MTMSN=0
2022-09-22T16:14:24.100Z,1663863264.100 [NAL9602](INFO): No messages in MT queue
2022-09-22T16:14:29.014Z,1663863269.014 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-09-22T16:14:46.082Z,1663863286.082 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.246616
2022-09-22T16:15:11.841Z,1663863311.841 [NAL9602](INFO): SBD MO Status=1, MOMSN=20488, MT Status=0, MTMSN=0
2022-09-22T16:15:11.906Z,1663863311.906 [NAL9602](INFO): Sent 73 bytes from file Logs/20220922T150304/Courier0043.lzma
2022-09-22T16:15:11.906Z,1663863311.906 [NAL9602](INFO): Packets left to send: 0
2022-09-22T16:15:17.206Z,1663863317.206 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-09-22T16:15:22.844Z,1663863322.844 [NAL9602](INFO): SBD MO Status=1, MOMSN=20489, MT Status=0, MTMSN=0
2022-09-22T16:15:22.892Z,1663863322.892 [NAL9602](INFO): Sent 144 bytes from file Logs/20220922T150304/Express0044.lzma
2022-09-22T16:15:22.892Z,1663863322.892 [NAL9602](INFO): Packets left to send: 0
2022-09-22T16:15:29.986Z,1663863329.986 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003176
2022-09-22T16:15:31.332Z,1663863331.332 [Default:CheckIn:Read_Iridium] Stopped
2022-09-22T16:15:31.332Z,1663863331.332 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-22T16:15:31.332Z,1663863331.332 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-22T16:15:32.130Z,1663863332.130 [NAL9602](INFO): SBD MO Status=0, MOMSN=20490, MT Status=0, MTMSN=0
2022-09-22T16:16:02.834Z,1663863362.834 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-22T16:17:29.353Z,1663863449.353 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2022-09-22T16:17:35.759Z,1663863455.759 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2022-09-22T16:17:35.761Z,1663863455.761 [BPC1](INFO): Received data from all battery sticks.
2022-09-22T16:18:24.350Z,1663863504.350 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-09-22T16:18:31.378Z,1663863511.378 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.255501
2022-09-22T16:19:32.390Z,1663863572.390 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003178
2022-09-22T16:20:32.044Z,1663863632.044 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-22T16:20:32.044Z,1663863632.044 [Default:CheckIn:C.Wait] Stopped
2022-09-22T16:20:32.044Z,1663863632.044 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-22T16:20:32.044Z,1663863632.044 [Default:CheckIn:D] Running Loop=1
2022-09-22T16:20:32.375Z,1663863632.375 [Default:CheckIn:D] Stopped
2022-09-22T16:20:32.375Z,1663863632.375 [Default:CheckIn:E] Running Loop=1
2022-09-22T16:20:32.781Z,1663863632.781 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 74.492537 min 
2022-09-22T16:20:32.781Z,1663863632.781 [Default:CheckIn:E] Stopped
2022-09-22T16:20:32.781Z,1663863632.781 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-22T16:20:32.781Z,1663863632.781 [Default:CheckIn] Stopped
2022-09-22T16:20:32.782Z,1663863632.782 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-22T16:20:32.782Z,1663863632.782 [Default:CheckIn](INFO): Running loop #14
2022-09-22T16:20:32.782Z,1663863632.782 [Default:CheckIn] Running Loop=14
2022-09-22T16:20:32.782Z,1663863632.782 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-22T16:20:32.782Z,1663863632.782 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-22T16:20:34.788Z,1663863634.788 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162034.00,A,3647.79643,N,12150.77630,W,0.311,113.53,220922,,,D*7F
2022-09-22T16:20:34.791Z,1663863634.791 [NAL9602](INFO): GPS fix at 20220922T162034: (36.796607, -121.846272)
2022-09-22T16:20:34.801Z,1663863634.801 [Default:CheckIn:Read_GPS] Stopped
2022-09-22T16:20:34.802Z,1663863634.802 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-22T16:20:42.005Z,1663863642.005 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20220922T150304/Courier0046.lzma
2022-09-22T16:20:43.009Z,1663863643.009 [DataOverHttps](INFO): Moved sent file to Logs/20220922T150304/Courier0046.lzma.bak
2022-09-22T16:20:43.009Z,1663863643.009 [DataOverHttps](IMPORTANT): SBD MOMSN=17196879, MTMSN=20220922T162042
2022-09-22T16:20:46.504Z,1663863646.504 [NAL9602](INFO): SBD MO Status=0, MOMSN=20491, MT Status=0, MTMSN=0
2022-09-22T16:20:46.504Z,1663863646.504 [NAL9602](INFO): No messages in MT queue
2022-09-22T16:20:50.517Z,1663863650.517 [DataOverHttps](INFO): Received command: restart logs