2022-03-15T16:32:09.897Z,1647361929.897 [Supervisor](DEBUG): Initializing supervisor.
2022-03-15T16:32:09.901Z,1647361929.901 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2022-03-15T16:32:09.902Z,1647361929.902 [SyncHandler](INFO): Protected caller Thread ID is 835
2022-03-15T16:32:09.902Z,1647361929.902 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2022-03-15T16:32:09.903Z,1647361929.903 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2022-03-15T16:32:09.904Z,1647361929.904 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 836
2022-03-15T16:32:09.908Z,1647361929.908 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2022-03-15T16:32:09.926Z,1647361929.926 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2022-03-15T16:32:09.927Z,1647361929.927 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2022-03-15T16:32:09.927Z,1647361929.927 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 837
2022-03-15T16:32:09.931Z,1647361929.931 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2022-03-15T16:32:09.932Z,1647361929.932 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2022-03-15T16:32:09.933Z,1647361929.933 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 838
2022-03-15T16:32:09.935Z,1647361929.935 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2022-03-15T16:32:09.936Z,1647361929.936 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2022-03-15T16:32:09.936Z,1647361929.936 [logger ThreadHandler](INFO): Protected caller Thread ID is 839
2022-03-15T16:32:09.940Z,1647361929.940 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2022-03-15T16:32:09.940Z,1647361929.940 [Supervisor](INFO): Looking for Config files in directory: Config/
2022-03-15T16:32:09.943Z,1647361929.943 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2022-03-15T16:32:10.039Z,1647361930.039 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2022-03-15T16:32:10.041Z,1647361930.041 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2022-03-15T16:32:10.663Z,1647361930.663 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2022-03-15T16:32:10.665Z,1647361930.665 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2022-03-15T16:32:10.879Z,1647361930.879 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2022-03-15T16:32:10.881Z,1647361930.881 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2022-03-15T16:32:10.961Z,1647361930.961 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2022-03-15T16:32:11.083Z,1647361931.083 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2022-03-15T16:32:11.085Z,1647361931.085 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2022-03-15T16:32:11.167Z,1647361931.167 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2022-03-15T16:32:11.274Z,1647361931.274 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2022-03-15T16:32:11.274Z,1647361931.274 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2022-03-15T16:32:11.636Z,1647361931.636 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2022-03-15T16:32:11.638Z,1647361931.638 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2022-03-15T16:32:12.197Z,1647361932.197 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2022-03-15T16:32:12.198Z,1647361932.198 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2022-03-15T16:32:12.411Z,1647361932.411 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2022-03-15T16:32:12.411Z,1647361932.411 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2022-03-15T16:32:12.603Z,1647361932.603 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2022-03-15T16:32:12.604Z,1647361932.604 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2022-03-15T16:32:13.065Z,1647361933.065 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2022-03-15T16:32:13.067Z,1647361933.067 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2022-03-15T16:32:13.393Z,1647361933.393 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2022-03-15T16:32:13.796Z,1647361933.796 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2022-03-15T16:32:14.336Z,1647361934.336 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2022-03-15T16:32:14.338Z,1647361934.338 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2022-03-15T16:32:14.701Z,1647361934.701 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2022-03-15T16:32:14.703Z,1647361934.703 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2022-03-15T16:32:15.051Z,1647361935.051 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2022-03-15T16:32:15.053Z,1647361935.053 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2022-03-15T16:32:15.056Z,1647361935.056 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2022-03-15T16:32:15.140Z,1647361935.140 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2022-03-15T16:32:15.297Z,1647361935.297 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2022-03-15T16:32:15.408Z,1647361935.408 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2022-03-15T16:32:15.494Z,1647361935.494 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2022-03-15T16:32:15.589Z,1647361935.589 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2022-03-15T16:32:15.774Z,1647361935.774 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2022-03-15T16:32:16.038Z,1647361936.038 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2022-03-15T16:32:16.038Z,1647361936.038 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2022-03-15T16:32:16.132Z,1647361936.132 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2022-03-15T16:32:16.230Z,1647361936.230 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2022-03-15T16:32:16.369Z,1647361936.369 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2022-03-15T16:32:16.470Z,1647361936.470 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/root/
2022-03-15T16:32:16.470Z,1647361936.470 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2022-03-15T16:32:16.473Z,1647361936.473 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2022-03-15T16:32:16.593Z,1647361936.593 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2022-03-15T16:32:16.595Z,1647361936.595 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2022-03-15T16:32:16.662Z,1647361936.662 [VerticalControl](DEBUG): Construct VerticalControl.
2022-03-15T16:32:16.723Z,1647361936.723 [VerticalControl] Loaded
2022-03-15T16:32:16.723Z,1647361936.723 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2022-03-15T16:32:16.726Z,1647361936.726 [HorizontalControl](DEBUG): Construct HorizontalControl.
2022-03-15T16:32:16.765Z,1647361936.765 [HorizontalControl] Loaded
2022-03-15T16:32:16.765Z,1647361936.765 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2022-03-15T16:32:16.768Z,1647361936.768 [SpeedControl](DEBUG): Construct SpeedControl.
2022-03-15T16:32:16.771Z,1647361936.771 [SpeedControl] Loaded
2022-03-15T16:32:16.771Z,1647361936.771 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2022-03-15T16:32:16.774Z,1647361936.774 [LoopControl](DEBUG): Construct LoopControl.
2022-03-15T16:32:16.774Z,1647361936.774 [LoopControl] Loaded
2022-03-15T16:32:16.775Z,1647361936.775 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2022-03-15T16:32:16.775Z,1647361936.775 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2022-03-15T16:32:16.776Z,1647361936.776 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2022-03-15T16:32:16.845Z,1647361936.845 [DepthRateCalculator] Loaded
2022-03-15T16:32:16.845Z,1647361936.845 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2022-03-15T16:32:16.850Z,1647361936.850 [PitchRateCalculator] Loaded
2022-03-15T16:32:16.850Z,1647361936.850 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2022-03-15T16:32:16.860Z,1647361936.860 [SpeedCalculator] Loaded
2022-03-15T16:32:16.860Z,1647361936.860 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2022-03-15T16:32:16.865Z,1647361936.865 [YawRateCalculator] Loaded
2022-03-15T16:32:16.865Z,1647361936.865 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2022-03-15T16:32:16.882Z,1647361936.882 [ElevatorOffsetCalculator] Loaded
2022-03-15T16:32:16.883Z,1647361936.883 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2022-03-15T16:32:16.883Z,1647361936.883 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2022-03-15T16:32:16.885Z,1647361936.885 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2022-03-15T16:32:16.927Z,1647361936.927 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2022-03-15T16:32:16.929Z,1647361936.929 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2022-03-15T16:32:17.010Z,1647361937.010 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2022-03-15T16:32:17.012Z,1647361937.012 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2022-03-15T16:32:17.374Z,1647361937.374 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2022-03-15T16:32:17.375Z,1647361937.375 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2022-03-15T16:32:17.512Z,1647361937.512 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2022-03-15T16:32:17.513Z,1647361937.513 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2022-03-15T16:32:18.234Z,1647361938.234 [AHRS_M2] Loaded
2022-03-15T16:32:18.234Z,1647361938.234 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2022-03-15T16:32:18.483Z,1647361938.483 [BackseatComponent] Loaded
2022-03-15T16:32:18.484Z,1647361938.484 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2022-03-15T16:32:18.485Z,1647361938.485 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 4096A4E0
2022-03-15T16:32:18.485Z,1647361938.485 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 923
2022-03-15T16:32:18.488Z,1647361938.488 [LcmUniversalReporter] Loaded
2022-03-15T16:32:18.488Z,1647361938.488 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2022-03-15T16:32:19.288Z,1647361939.288 [BPC1] Loaded
2022-03-15T16:32:19.289Z,1647361939.289 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2022-03-15T16:32:19.429Z,1647361939.429 [DataOverHttps] Loaded
2022-03-15T16:32:19.429Z,1647361939.429 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2022-03-15T16:32:19.430Z,1647361939.430 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4099A4E0
2022-03-15T16:32:19.431Z,1647361939.431 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 924
2022-03-15T16:32:19.450Z,1647361939.450 [Depth_Keller] Loaded
2022-03-15T16:32:19.451Z,1647361939.451 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2022-03-15T16:32:19.455Z,1647361939.455 [DropWeight] Loaded
2022-03-15T16:32:19.456Z,1647361939.456 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2022-03-15T16:32:19.515Z,1647361939.515 [NAL9602] Loaded
2022-03-15T16:32:19.515Z,1647361939.515 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2022-03-15T16:32:19.543Z,1647361939.543 [Onboard] Loaded
2022-03-15T16:32:19.543Z,1647361939.543 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2022-03-15T16:32:19.545Z,1647361939.545 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409CA4E0
2022-03-15T16:32:19.545Z,1647361939.545 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 925
2022-03-15T16:32:19.556Z,1647361939.556 [Power24vConverter] Loaded
2022-03-15T16:32:19.557Z,1647361939.557 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2022-03-15T16:32:19.569Z,1647361939.569 [Radio_Surface] Loaded
2022-03-15T16:32:19.570Z,1647361939.570 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2022-03-15T16:32:19.571Z,1647361939.571 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409FA4E0
2022-03-15T16:32:19.571Z,1647361939.571 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 926
2022-03-15T16:32:19.613Z,1647361939.613 [RDI_Pathfinder] Loaded
2022-03-15T16:32:19.613Z,1647361939.613 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2022-03-15T16:32:19.696Z,1647361939.696 [DAT] Loaded
2022-03-15T16:32:19.696Z,1647361939.696 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2022-03-15T16:32:19.698Z,1647361939.698 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40A2A4E0
2022-03-15T16:32:19.698Z,1647361939.698 [DAT ThreadHandler](INFO): Protected caller Thread ID is 927
2022-03-15T16:32:19.698Z,1647361939.698 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2022-03-15T16:32:19.699Z,1647361939.699 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2022-03-15T16:32:20.416Z,1647361940.416 [DeadReckonUsingMultipleVelocitySources] Loaded
2022-03-15T16:32:20.416Z,1647361940.416 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2022-03-15T16:32:20.430Z,1647361940.430 [NavChart] Loaded
2022-03-15T16:32:20.430Z,1647361940.430 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2022-03-15T16:32:20.435Z,1647361940.435 [UniversalFixResidualReporter] Loaded
2022-03-15T16:32:20.436Z,1647361940.436 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2022-03-15T16:32:20.436Z,1647361940.436 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2022-03-15T16:32:20.437Z,1647361940.437 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2022-03-15T16:32:20.608Z,1647361940.608 [SBIT](DEBUG): Construct Startup Built In Test.
2022-03-15T16:32:20.617Z,1647361940.617 [SBIT] Loaded
2022-03-15T16:32:20.618Z,1647361940.618 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2022-03-15T16:32:20.620Z,1647361940.620 [IBIT](DEBUG): Construct Initiated Built In Test.
2022-03-15T16:32:20.633Z,1647361940.633 [IBIT] Loaded
2022-03-15T16:32:20.633Z,1647361940.633 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2022-03-15T16:32:20.639Z,1647361940.639 [CBIT](DEBUG): Construct Continuous Built In Test.
2022-03-15T16:32:20.744Z,1647361940.744 [CBIT] Loaded
2022-03-15T16:32:20.745Z,1647361940.745 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2022-03-15T16:32:20.745Z,1647361940.745 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2022-03-15T16:32:20.746Z,1647361940.746 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2022-03-15T16:32:20.898Z,1647361940.898 [BuoyancyServo] Loaded
2022-03-15T16:32:20.899Z,1647361940.899 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2022-03-15T16:32:20.919Z,1647361940.919 [ElevatorServo] Loaded
2022-03-15T16:32:20.919Z,1647361940.919 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2022-03-15T16:32:20.939Z,1647361940.939 [MassServo] Loaded
2022-03-15T16:32:20.940Z,1647361940.940 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2022-03-15T16:32:20.962Z,1647361940.962 [RudderServo] Loaded
2022-03-15T16:32:20.962Z,1647361940.962 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2022-03-15T16:32:20.979Z,1647361940.979 [ThrusterServo] Loaded
2022-03-15T16:32:20.980Z,1647361940.980 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2022-03-15T16:32:20.980Z,1647361940.980 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2022-03-15T16:32:20.981Z,1647361940.981 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2022-03-15T16:32:20.997Z,1647361940.997 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2022-03-15T16:32:20.997Z,1647361940.997 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2022-03-15T16:32:21.216Z,1647361941.216 [CTD_Seabird] Loaded
2022-03-15T16:32:21.216Z,1647361941.216 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2022-03-15T16:32:21.218Z,1647361941.218 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B744E0
2022-03-15T16:32:21.218Z,1647361941.218 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 928
2022-03-15T16:32:21.238Z,1647361941.238 [PAR_Licor] Loaded
2022-03-15T16:32:21.238Z,1647361941.238 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2022-03-15T16:32:21.269Z,1647361941.269 [WetLabsBB2FL] Loaded
2022-03-15T16:32:21.270Z,1647361941.270 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2022-03-15T16:32:21.271Z,1647361941.271 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40BA44E0
2022-03-15T16:32:21.271Z,1647361941.271 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 929
2022-03-15T16:32:21.291Z,1647361941.291 [WetLabsUBAT] Loaded
2022-03-15T16:32:21.292Z,1647361941.292 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread.
2022-03-15T16:32:21.293Z,1647361941.293 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40BD44E0
2022-03-15T16:32:21.293Z,1647361941.293 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 930
2022-03-15T16:32:21.294Z,1647361941.294 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2022-03-15T16:32:21.300Z,1647361941.300 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2022-03-15T16:32:21.303Z,1647361941.303 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2022-03-15T16:32:21.314Z,1647361941.314 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2022-03-15T16:32:21.315Z,1647361941.315 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C044E0
2022-03-15T16:32:21.315Z,1647361941.315 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 931
2022-03-15T16:32:21.320Z,1647361941.320 [Supervisor](INFO): Main Thread ID is 829
2022-03-15T16:32:21.320Z,1647361941.320 [Supervisor](DEBUG): Running supervisor.
2022-03-15T16:32:21.321Z,1647361941.321 [CommandExec ThreadHandler](INFO): Handler Thread ID is 932
2022-03-15T16:32:21.321Z,1647361941.321 [CommandExec](INFO): Initializing the command executive.
2022-03-15T16:32:21.322Z,1647361941.322 [CommandLine ThreadHandler](INFO): Handler Thread ID is 933
2022-03-15T16:32:21.325Z,1647361941.325 [controlThread ThreadHandler](INFO): Handler Thread ID is 934
2022-03-15T16:32:21.325Z,1647361941.325 [controlThread](DEBUG): Initializing ControlThread
2022-03-15T16:32:21.326Z,1647361941.326 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2022-03-15T16:32:21.327Z,1647361941.327 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2022-03-15T16:32:21.328Z,1647361941.328 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2022-03-15T16:32:21.329Z,1647361941.329 [LoopControl](DEBUG): Initialize LoopControlComponent.
2022-03-15T16:32:21.329Z,1647361941.329 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2022-03-15T16:32:21.329Z,1647361941.329 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2022-03-15T16:32:21.330Z,1647361941.330 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2022-03-15T16:32:21.330Z,1647361941.330 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2022-03-15T16:32:21.330Z,1647361941.330 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2022-03-15T16:32:21.338Z,1647361941.338 [NavChart](DEBUG): Initialize NavChart Navigation.
2022-03-15T16:32:21.339Z,1647361941.339 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2022-03-15T16:32:21.339Z,1647361941.339 [SBIT](INFO): Initialize SBIT Component.
2022-03-15T16:32:21.340Z,1647361941.340 [SBIT](IMPORTANT): git: 2022-03-07_B
2022-03-15T16:32:21.340Z,1647361941.340 [SBIT](INFO): git hash: 63c82b109c583a7b000dfba1885db026b8339462
2022-03-15T16:32:21.340Z,1647361941.340 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2022-03-15T16:32:21.341Z,1647361941.341 [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-03-15T16:32:21.342Z,1647361941.342 [SBIT](INFO): Beginning SBIT in 49.000000 seconds.
2022-03-15T16:32:21.343Z,1647361941.343 [IBIT](INFO): Initialize IBIT Component.
2022-03-15T16:32:21.344Z,1647361941.344 [CBIT](DEBUG): Initialize CBIT Component.
2022-03-15T16:32:21.345Z,1647361941.345 [logger ThreadHandler](INFO): Handler Thread ID is 935
2022-03-15T16:32:21.356Z,1647361941.356 [CBIT](DEBUG): Initialized mux pins.
2022-03-15T16:32:21.356Z,1647361941.356 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2022-03-15T16:32:21.356Z,1647361941.356 [CBIT](DEBUG): Initializing the watchdog timer.
2022-03-15T16:32:21.365Z,1647361941.365 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 936
2022-03-15T16:32:21.376Z,1647361941.376 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 937
2022-03-15T16:32:21.377Z,1647361941.377 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2022-03-15T16:32:21.380Z,1647361941.380 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2022-03-15T16:32:21.381Z,1647361941.381 [CBIT](DEBUG): Initializing heartbeat.
2022-03-15T16:32:21.389Z,1647361941.389 [Onboard ThreadHandler](INFO): Handler Thread ID is 938
2022-03-15T16:32:21.419Z,1647361941.419 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 939
2022-03-15T16:32:21.436Z,1647361941.436 [DAT ThreadHandler](INFO): Handler Thread ID is 940
2022-03-15T16:32:21.437Z,1647361941.437 [DAT](INFO): Powering up
2022-03-15T16:32:21.437Z,1647361941.437 [DAT](DEBUG): Initializing DAT.
2022-03-15T16:32:21.441Z,1647361941.441 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 942
2022-03-15T16:32:21.442Z,1647361941.442 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2022-03-15T16:32:21.445Z,1647361941.445 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 944
2022-03-15T16:32:21.449Z,1647361941.449 [WetLabsBB2FL](INFO): Powering up
2022-03-15T16:32:21.450Z,1647361941.450 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 946
2022-03-15T16:32:21.452Z,1647361941.452 [CBIT](DEBUG): Deactivating GF circuits.
2022-03-15T16:32:21.453Z,1647361941.453 [CBIT](DEBUG): Deactivating emergency mode.
2022-03-15T16:32:21.453Z,1647361941.453 [WetLabsUBAT](INFO): Powering up
2022-03-15T16:32:21.454Z,1647361941.454 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 948
2022-03-15T16:32:21.466Z,1647361941.466 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2022-03-15T16:32:21.466Z,1647361941.466 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2022-03-15T16:32:21.466Z,1647361941.466 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2022-03-15T16:32:21.466Z,1647361941.466 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2022-03-15T16:32:21.466Z,1647361941.466 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2022-03-15T16:32:21.467Z,1647361941.467 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2022-03-15T16:32:21.467Z,1647361941.467 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2022-03-15T16:32:21.467Z,1647361941.467 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2022-03-15T16:32:21.467Z,1647361941.467 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2022-03-15T16:32:21.467Z,1647361941.467 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2022-03-15T16:32:21.467Z,1647361941.467 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2022-03-15T16:32:21.467Z,1647361941.467 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2022-03-15T16:32:21.468Z,1647361941.468 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2022-03-15T16:32:21.468Z,1647361941.468 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2022-03-15T16:32:21.468Z,1647361941.468 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2022-03-15T16:32:21.468Z,1647361941.468 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2022-03-15T16:32:21.488Z,1647361941.488 [CBIT](DEBUG): Backplane powered.
2022-03-15T16:32:21.493Z,1647361941.493 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2022-03-15T16:32:21.536Z,1647361941.536 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2022-03-15T16:32:21.584Z,1647361941.584 [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-03-15T16:32:21.585Z,1647361941.585 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2022-03-15T16:32:21.665Z,1647361941.665 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2022-03-15T16:32:21.666Z,1647361941.666 [Default:A.Wait](DEBUG): Construct Wait.
2022-03-15T16:32:21.668Z,1647361941.668 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2022-03-15T16:32:21.713Z,1647361941.713 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2022-03-15T16:32:21.716Z,1647361941.716 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2022-03-15T16:32:21.733Z,1647361941.733 [Default:E.Execute](DEBUG): Construct Execute.
2022-03-15T16:32:21.752Z,1647361941.752 [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-03-15T16:32:21.757Z,1647361941.757 [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-03-15T16:32:21.768Z,1647361941.768 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2022-03-15T16:32:21.820Z,1647361941.820 [Radio_Surface](INFO): Powering up
2022-03-15T16:32:21.958Z,1647361941.958 [Power24vConverter](INFO): Powering up.
2022-03-15T16:32:22.046Z,1647361942.046 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2022-03-15T16:32:22.052Z,1647361942.052 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2022-03-15T16:32:22.053Z,1647361942.053 [ElevatorServo](DEBUG): Initializing EZServoServo.
2022-03-15T16:32:22.060Z,1647361942.060 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2022-03-15T16:32:22.061Z,1647361942.061 [MassServo](DEBUG): Initializing EZServoServo.
2022-03-15T16:32:22.068Z,1647361942.068 [MassServo](DEBUG): Initializing MassServo.
2022-03-15T16:32:22.069Z,1647361942.069 [RudderServo](DEBUG): Initializing EZServoServo.
2022-03-15T16:32:22.076Z,1647361942.076 [RudderServo](DEBUG): Initializing RudderServo.
2022-03-15T16:32:22.077Z,1647361942.077 [ThrusterServo](DEBUG): Initializing EZServoServo.
2022-03-15T16:32:22.084Z,1647361942.084 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2022-03-15T16:32:22.908Z,1647361942.908 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2022-03-15T16:32:22.908Z,1647361942.908 [RudderServo](FAULT): Rudder failed to initialize
2022-03-15T16:32:22.908Z,1647361942.908 [RudderServo] Communications Fault, FailCount= 1
2022-03-15T16:32:22.908Z,1647361942.908 [RudderServo](ERROR): Communications Fault
2022-03-15T16:32:23.009Z,1647361943.009 [CBIT](ERROR): Communications Fault in component: RudderServo
2022-03-15T16:32:23.215Z,1647361943.215 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-03-15T16:32:23.215Z,1647361943.215 [RudderServo](INFO): Powering down
2022-03-15T16:32:23.844Z,1647361943.844 [RudderServo](DEBUG): Initializing EZServoServo.
2022-03-15T16:32:23.966Z,1647361943.966 [RudderServo](DEBUG): Initializing RudderServo.
2022-03-15T16:32:23.970Z,1647361943.970 [CBIT](INFO): Clearing failed state for component RudderServo
2022-03-15T16:32:23.970Z,1647361943.970 [RudderServo] No Fault, FailCount= 1
2022-03-15T16:32:24.060Z,1647361944.060 [WetLabsBB2FL](INFO): Powering down
2022-03-15T16:32:30.776Z,1647361950.776 [WetLabsUBAT](INFO): Powering down
2022-03-15T16:32:36.058Z,1647361956.058 [DAT](INFO): commRate: 800
2022-03-15T16:32:38.124Z,1647361958.124 [DAT](INFO): entering command mode
2022-03-15T16:32:38.325Z,1647361958.325 [DAT](INFO): setting verbose to 3
2022-03-15T16:32:38.578Z,1647361958.578 [DAT](INFO): set verbose to 3
2022-03-15T16:32:38.578Z,1647361958.578 [DAT](INFO): setting DatVerbose to 27440
2022-03-15T16:32:38.830Z,1647361958.830 [DAT](INFO): set DatVerbose to 27440
2022-03-15T16:32:38.830Z,1647361958.830 [DAT](INFO): setting transmit power to 8
2022-03-15T16:32:39.082Z,1647361959.082 [DAT](INFO): set transmit power to 8
2022-03-15T16:32:39.082Z,1647361959.082 [DAT](INFO): setting local address to 9
2022-03-15T16:32:39.334Z,1647361959.334 [DAT](INFO): set local address to 9
2022-03-15T16:32:39.335Z,1647361959.335 [DAT](INFO): Setting time to: 16:32:39 And date to:3/15/2022
2022-03-15T16:32:39.590Z,1647361959.590 [DAT](INFO): Local DAT time set to Tue Mar 15, 2022  16:32:39  

2022-03-15T16:32:49.686Z,1647361969.686 [NAL9602](INFO): Powering up NAL9602
2022-03-15T16:33:00.594Z,1647361980.594 [NAL9602](INFO): NAL9602 initialized
2022-03-15T16:33:11.128Z,1647361991.128 [SBIT](IMPORTANT): Beginning Startup BIT
2022-03-15T16:33:11.133Z,1647361991.133 [CBIT](IMPORTANT): Beginning ground fault scan
2022-03-15T16:33:22.080Z,1647362002.080 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.008565
CHAN A1 (24V): 0.036387
CHAN A2 (12V): -0.006873
CHAN A3 (5V): -0.002964
CHAN B0 (3.3V): -0.000184
CHAN B1 (3.15aV): 0.000086
CHAN B2 (3.15bV): -0.001223
CHAN B3 (GND): 0.002203
OPEN: -0.004053
Full Scale: +/- 1 mA
2022-03-15T16:34:04.852Z,1647362044.852 [SBIT](IMPORTANT): SBIT PASSED
2022-03-15T16:34:04.852Z,1647362044.852 [SBIT](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2022-03-15T16:34:05.257Z,1647362045.257 [MissionManager](IMPORTANT): Started mission Startup
2022-03-15T16:34:05.258Z,1647362045.258 [Startup] Running Loop=1
2022-03-15T16:34:05.258Z,1647362045.258 [Startup](DEBUG): Aggregate::initialize Startup
2022-03-15T16:34:05.258Z,1647362045.258 [Startup:A.GoToSurface] Running Loop=1
2022-03-15T16:34:05.258Z,1647362045.258 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-03-15T16:34:05.258Z,1647362045.258 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-03-15T16:34:05.259Z,1647362045.259 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-03-15T16:34:05.259Z,1647362045.259 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-03-15T16:34:05.260Z,1647362045.260 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-03-15T16:34:05.261Z,1647362045.261 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-03-15T16:34:05.262Z,1647362045.262 [Startup:StartupSatComms] Running Loop=1
2022-03-15T16:34:05.262Z,1647362045.262 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2022-03-15T16:34:05.262Z,1647362045.262 [Startup:StartupSatComms:A] Running Loop=1
2022-03-15T16:34:05.683Z,1647362045.683 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2022-03-15T16:34:44.229Z,1647362084.229 [CommandExec](IMPORTANT): got command gfscan
2022-03-15T16:34:44.457Z,1647362084.457 [CBIT](IMPORTANT): Beginning ground fault scan
2022-03-15T16:34:55.452Z,1647362095.452 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.007517
CHAN A1 (24V): 0.035904
CHAN A2 (12V): -0.007459
CHAN A3 (5V): -0.001603
CHAN B0 (3.3V): -0.000002
CHAN B1 (3.15aV): -0.000216
CHAN B2 (3.15bV): -0.000163
CHAN B3 (GND): 0.001672
OPEN: 0.005259
Full Scale: +/- 1 mA
2022-03-15T16:35:05.458Z,1647362105.458 [Startup:StartupSatComms:A](INFO): Timed out from 2022-03-15T16:34:05.3Z
2022-03-15T16:35:05.458Z,1647362105.458 [Startup:StartupSatComms:A] Stopped
2022-03-15T16:35:05.458Z,1647362105.458 [Startup:StartupSatComms:B] Running Loop=1
2022-03-15T16:35:05.901Z,1647362105.901 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-03-15T16:35:09.798Z,1647362109.798 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004609
2022-03-15T16:35:20.658Z,1647362120.658 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20220315T162508/Courier0004.lzma
2022-03-15T16:35:21.479Z,1647362121.479 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2022-03-15T16:35:21.479Z,1647362121.479 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-03-15T16:35:21.489Z,1647362121.489 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-03-15T16:35:21.660Z,1647362121.660 [DataOverHttps](INFO): Moved sent file to Logs/20220315T162508/Courier0004.lzma.bak
2022-03-15T16:35:21.660Z,1647362121.660 [DataOverHttps](INFO): SBD MOMSN=16572608
2022-03-15T16:35:21.906Z,1647362121.906 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-03-15T16:35:21.907Z,1647362121.907 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2022-03-15T16:35:26.945Z,1647362126.945 [CommandExec](IMPORTANT): got command burn on
2022-03-15T16:35:26.945Z,1647362126.945 [CommandExec](IMPORTANT): Activating dropweight wire
2022-03-15T16:35:31.008Z,1647362131.008 [CommandExec](IMPORTANT): got command burn off
2022-03-15T16:35:31.008Z,1647362131.008 [CommandExec](IMPORTANT): Deactivating dropweight wire
2022-03-15T16:35:36.858Z,1647362136.858 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20220315T163209/Courier0000.lzma
2022-03-15T16:35:37.860Z,1647362137.860 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Courier0000.lzma.bak
2022-03-15T16:35:37.860Z,1647362137.860 [DataOverHttps](INFO): SBD MOMSN=16572610
2022-03-15T16:35:54.265Z,1647362154.265 [DataOverHttps](INFO): Sending 927 bytes from file Logs/20220315T162508/Express0001.lzma
2022-03-15T16:35:55.264Z,1647362155.264 [DataOverHttps](INFO): Moved sent file to Logs/20220315T162508/Express0001.lzma.bak
2022-03-15T16:35:55.264Z,1647362155.264 [DataOverHttps](INFO): SBD MOMSN=16572613
2022-03-15T16:36:05.560Z,1647362165.560 [Startup:StartupSatComms:B](INFO): Timed out from 2022-03-15T16:35:05.5Z
2022-03-15T16:36:05.560Z,1647362165.560 [Startup:StartupSatComms:B] Stopped
2022-03-15T16:36:05.560Z,1647362165.560 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2022-03-15T16:36:05.560Z,1647362165.560 [Startup:StartupSatComms] Stopped
2022-03-15T16:36:05.560Z,1647362165.560 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2022-03-15T16:36:05.561Z,1647362165.561 [Startup](INFO): Completed Startup
2022-03-15T16:36:05.561Z,1647362165.561 [MissionManager](INFO): Startup is completed.
2022-03-15T16:36:05.561Z,1647362165.561 [MissionManager](INFO): Uninitializing Mission Startup
2022-03-15T16:36:05.561Z,1647362165.561 [Startup] Stopped
2022-03-15T16:36:05.562Z,1647362165.562 [Startup](DEBUG): Aggregate::uninitialize Startup
2022-03-15T16:36:05.562Z,1647362165.562 [Startup:A.GoToSurface] Stopped
2022-03-15T16:36:05.562Z,1647362165.562 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-03-15T16:36:05.977Z,1647362165.977 [MissionManager](IMPORTANT): Started mission Default
2022-03-15T16:36:05.977Z,1647362165.977 [Default] Running Loop=1
2022-03-15T16:36:05.977Z,1647362165.977 [Default](DEBUG): Aggregate::initialize Default
2022-03-15T16:36:05.977Z,1647362165.977 [Default:B.GoToSurface] Running Loop=1
2022-03-15T16:36:05.977Z,1647362165.977 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-03-15T16:36:05.978Z,1647362165.978 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-03-15T16:36:05.978Z,1647362165.978 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-03-15T16:36:05.978Z,1647362165.978 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-03-15T16:36:05.979Z,1647362165.979 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-03-15T16:36:05.979Z,1647362165.979 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-03-15T16:36:05.979Z,1647362165.979 [Default:A.Wait] Running Loop=1
2022-03-15T16:36:05.979Z,1647362165.979 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-03-15T16:36:11.197Z,1647362171.197 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20220315T162508/Express0005.lzma
2022-03-15T16:36:12.200Z,1647362172.200 [DataOverHttps](INFO): Moved sent file to Logs/20220315T162508/Express0005.lzma.bak
2022-03-15T16:36:12.200Z,1647362172.200 [DataOverHttps](INFO): SBD MOMSN=16572637
2022-03-15T16:36:19.302Z,1647362179.302 [Default:A.Wait](INFO): Done Waiting.
2022-03-15T16:36:19.302Z,1647362179.302 [Default:A.Wait] Stopped
2022-03-15T16:36:19.302Z,1647362179.302 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-03-15T16:36:19.669Z,1647362179.669 [Default:CheckIn] Running Loop=1
2022-03-15T16:36:19.669Z,1647362179.669 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-03-15T16:36:19.669Z,1647362179.669 [Default:CheckIn:Read_GPS] Running Loop=1
2022-03-15T16:36:20.073Z,1647362180.073 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2022-03-15T16:37:27.899Z,1647362247.899 [CommandExec](IMPORTANT): got command gfscan
2022-03-15T16:37:27.946Z,1647362247.946 [CBIT](IMPORTANT): Beginning ground fault scan
2022-03-15T16:37:38.893Z,1647362258.893 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.007577
CHAN A1 (24V): 0.036101
CHAN A2 (12V): -0.007629
CHAN A3 (5V): -0.001192
CHAN B0 (3.3V): 0.000231
CHAN B1 (3.15aV): -0.000187
CHAN B2 (3.15bV): -0.000426
CHAN B3 (GND): 0.002766
OPEN: 0.005144
Full Scale: +/- 1 mA
2022-03-15T16:38:03.478Z,1647362283.478 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-03-15T16:38:22.495Z,1647362302.495 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2022-03-15T16:38:22.495Z,1647362302.495 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-03-15T16:38:22.506Z,1647362302.506 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-03-15T16:38:22.912Z,1647362302.912 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-03-15T16:38:22.912Z,1647362302.912 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2022-03-15T16:38:59.986Z,1647362339.986 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.659214
2022-03-15T16:39:10.406Z,1647362350.406 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002725
2022-03-15T16:41:00.223Z,1647362460.223 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2022-03-15T16:41:00.226Z,1647362460.226 [BPC1](INFO): Received data from all battery sticks.
2022-03-15T16:41:20.040Z,1647362480.040 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-03-15T16:36:19.7Z
2022-03-15T16:41:20.040Z,1647362480.040 [Default:CheckIn:Read_GPS] Stopped
2022-03-15T16:41:20.040Z,1647362480.040 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-03-15T16:41:20.440Z,1647362480.440 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-03-15T16:41:23.670Z,1647362483.670 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2022-03-15T16:41:23.670Z,1647362483.670 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-03-15T16:41:23.689Z,1647362483.689 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-03-15T16:41:24.097Z,1647362484.097 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-03-15T16:41:24.097Z,1647362484.097 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2022-03-15T16:41:27.642Z,1647362487.642 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20220315T163209/Courier0004.lzma
2022-03-15T16:41:28.644Z,1647362488.644 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Courier0004.lzma.bak
2022-03-15T16:41:28.644Z,1647362488.644 [DataOverHttps](INFO): SBD MOMSN=16572645
2022-03-15T16:41:44.531Z,1647362504.531 [DataOverHttps](INFO): Sending 736 bytes from file Logs/20220315T163209/Express0001.lzma
2022-03-15T16:41:45.532Z,1647362505.532 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Express0001.lzma.bak
2022-03-15T16:41:45.532Z,1647362505.532 [DataOverHttps](INFO): SBD MOMSN=16572647
2022-03-15T16:42:01.466Z,1647362521.466 [DataOverHttps](INFO): Sending 434 bytes from file Logs/20220315T163209/Express0005.lzma
2022-03-15T16:42:02.468Z,1647362522.468 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Express0005.lzma.bak
2022-03-15T16:42:02.468Z,1647362522.468 [DataOverHttps](INFO): SBD MOMSN=16572663
2022-03-15T16:42:03.651Z,1647362523.651 [Default:CheckIn:Read_Iridium] Stopped
2022-03-15T16:42:03.651Z,1647362523.651 [Default:CheckIn:C.Wait] Running Loop=1
2022-03-15T16:42:03.651Z,1647362523.651 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-03-15T16:43:01.404Z,1647362581.404 [NAL9602](FAULT): GPS failed to acquire within timeout.
2022-03-15T16:43:01.404Z,1647362581.404 [NAL9602] Data Fault, FailCount= 1
2022-03-15T16:43:01.404Z,1647362581.404 [NAL9602](ERROR): Data Fault
2022-03-15T16:43:01.425Z,1647362581.425 [CBIT](ERROR): Data Fault in component: NAL9602
2022-03-15T16:43:01.809Z,1647362581.809 [NAL9602](INFO): Powering down
2022-03-15T16:43:02.657Z,1647362582.657 [CBIT](INFO): Clearing failed state for component NAL9602
2022-03-15T16:43:02.657Z,1647362582.657 [NAL9602] No Fault, FailCount= 1
2022-03-15T16:43:32.108Z,1647362612.108 [NAL9602](INFO): Powering up NAL9602
2022-03-15T16:43:43.024Z,1647362623.024 [NAL9602](INFO): NAL9602 initialized
2022-03-15T16:44:24.662Z,1647362664.662 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2022-03-15T16:44:24.662Z,1647362664.662 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-03-15T16:44:24.673Z,1647362664.673 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-03-15T16:44:25.097Z,1647362665.097 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-03-15T16:44:25.097Z,1647362665.097 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2022-03-15T16:47:04.283Z,1647362824.283 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-03-15T16:47:04.283Z,1647362824.283 [Default:CheckIn:C.Wait] Stopped
2022-03-15T16:47:04.283Z,1647362824.283 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-03-15T16:47:04.283Z,1647362824.283 [Default:CheckIn:D] Running Loop=1
2022-03-15T16:47:04.692Z,1647362824.692 [Default:CheckIn:D] Stopped
2022-03-15T16:47:04.692Z,1647362824.692 [Default:CheckIn:E] Running Loop=1
2022-03-15T16:47:05.109Z,1647362825.109 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.978575 min 
2022-03-15T16:47:05.109Z,1647362825.109 [Default:CheckIn:E] Stopped
2022-03-15T16:47:05.109Z,1647362825.109 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-03-15T16:47:05.109Z,1647362825.109 [Default:CheckIn] Stopped
2022-03-15T16:47:05.109Z,1647362825.109 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-03-15T16:47:05.109Z,1647362825.109 [Default:CheckIn](INFO): Running loop #2
2022-03-15T16:47:05.110Z,1647362825.110 [Default:CheckIn] Running Loop=2
2022-03-15T16:47:05.110Z,1647362825.110 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-03-15T16:47:05.110Z,1647362825.110 [Default:CheckIn:Read_GPS] Running Loop=1
2022-03-15T16:47:25.702Z,1647362845.702 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2022-03-15T16:47:25.702Z,1647362845.702 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-03-15T16:47:25.717Z,1647362845.717 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-03-15T16:47:26.130Z,1647362846.130 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-03-15T16:47:26.131Z,1647362846.131 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2022-03-15T16:50:26.670Z,1647363026.670 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2022-03-15T16:50:26.670Z,1647363026.670 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-03-15T16:50:26.705Z,1647363026.705 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-03-15T16:50:27.127Z,1647363027.127 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-03-15T16:50:27.127Z,1647363027.127 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2022-03-15T16:50:31.913Z,1647363031.913 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165030.00,A,3648.13905,N,12147.22354,W,0.272,77.48,150322,,,A*45
2022-03-15T16:50:31.917Z,1647363031.917 [NAL9602](INFO): GPS fix at 20220315T165030: (36.802318, -121.787059)
2022-03-15T16:50:31.928Z,1647363031.928 [Default:CheckIn:Read_GPS] Stopped
2022-03-15T16:50:31.928Z,1647363031.928 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-03-15T16:50:41.226Z,1647363041.226 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20220315T163209/Courier0007.lzma
2022-03-15T16:50:42.228Z,1647363042.228 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Courier0007.lzma.bak
2022-03-15T16:50:42.228Z,1647363042.228 [DataOverHttps](INFO): SBD MOMSN=16572688
2022-03-15T16:50:59.598Z,1647363059.598 [DataOverHttps](INFO): Sending 316 bytes from file Logs/20220315T163209/Express0008.lzma
2022-03-15T16:51:00.600Z,1647363060.600 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Express0008.lzma.bak
2022-03-15T16:51:00.600Z,1647363060.600 [DataOverHttps](INFO): SBD MOMSN=16572691
2022-03-15T16:51:01.863Z,1647363061.863 [Default:CheckIn:Read_Iridium] Stopped
2022-03-15T16:51:01.863Z,1647363061.863 [Default:CheckIn:C.Wait] Running Loop=1
2022-03-15T16:51:01.863Z,1647363061.863 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-03-15T16:51:04.675Z,1647363064.675 [NAL9602](INFO): Not Powering down - fast GPS
2022-03-15T16:54:37.143Z,1647363277.143 [CommandExec](IMPORTANT): got command ibit
2022-03-15T16:54:37.272Z,1647363277.272 [IBIT](IMPORTANT): Beginning Initiated BIT
2022-03-15T16:54:37.272Z,1647363277.272 [IBIT](IMPORTANT): Beginning control surface checks.
2022-03-15T16:54:37.276Z,1647363277.276 [CBIT](IMPORTANT): Beginning ground fault scan
2022-03-15T16:54:38.837Z,1647363278.837 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165437.00,A,3648.13811,N,12147.22494,W,0.019,77.48,150322,,,D*43
2022-03-15T16:54:38.840Z,1647363278.840 [NAL9602](INFO): GPS fix at 20220315T165437: (36.802302, -121.787082)
2022-03-15T16:54:48.223Z,1647363288.223 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.011128
CHAN A1 (24V): 0.036103
CHAN A2 (12V): -0.007230
CHAN A3 (5V): -0.002708
CHAN B0 (3.3V): -0.000154
CHAN B1 (3.15aV): -0.000301
CHAN B2 (3.15bV): -0.000454
CHAN B3 (GND): 0.002397
OPEN: 0.005556
Full Scale: +/- 1 mA
2022-03-15T16:55:23.707Z,1647363323.707 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 2
Latitude: 36.802303 Longitude: -121.787079
2022-03-15T16:55:24.104Z,1647363324.104 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.690001
2022-03-15T16:55:24.104Z,1647363324.104 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2022-03-15T16:55:24.105Z,1647363324.105 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2022-03-15T16:55:24.508Z,1647363324.508 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2022-03-15T16:55:24.508Z,1647363324.508 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2022-03-15T16:55:24.508Z,1647363324.508 [IBIT](IMPORTANT): Pressure:7.660335 PSI
2022-03-15T16:55:24.509Z,1647363324.509 [IBIT](IMPORTANT): Humidity:22.018068 %
2022-03-15T16:55:24.928Z,1647363324.928 [IBIT](IMPORTANT): Vehicle Pitch:-0.438189 degrees
2022-03-15T16:55:24.928Z,1647363324.928 [IBIT](IMPORTANT): Vehicle  Roll:-0.756474 degrees
2022-03-15T16:55:24.929Z,1647363324.929 [IBIT](IMPORTANT): Vehicle  Heading:117.478928 degrees
2022-03-15T16:55:25.343Z,1647363325.343 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2022-03-15T16:55:25.343Z,1647363325.343 [IBIT](IMPORTANT): buoyancyNeutral: 225.000000 cc
2022-03-15T16:55:25.343Z,1647363325.343 [IBIT](IMPORTANT): massDefault: 0.750000 cm
2022-03-15T16:55:25.343Z,1647363325.343 [IBIT](IMPORTANT): stopDepth: 215.000000 m
2022-03-15T16:55:25.344Z,1647363325.344 [IBIT](IMPORTANT): abortDepth: 255.000000 m
2022-03-15T16:55:25.344Z,1647363325.344 [IBIT](IMPORTANT): IBIT PASSED
2022-03-15T16:55:27.321Z,1647363327.321 [NAL9602](INFO): SBD MO Status=2, MOMSN=17885, MT Status=2, MTMSN=0
2022-03-15T16:55:27.321Z,1647363327.321 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-03-15T16:55:58.131Z,1647363358.131 [CommandLine](INFO): End of History
2022-03-15T16:55:58.178Z,1647363358.178 [CommandLine](INFO): End of History
2022-03-15T16:55:58.179Z,1647363358.179 [CommandLine](INFO): End of History
2022-03-15T16:55:58.180Z,1647363358.180 [CommandLine](INFO): End of History
2022-03-15T16:56:02.487Z,1647363362.487 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-03-15T16:56:02.487Z,1647363362.487 [Default:CheckIn:C.Wait] Stopped
2022-03-15T16:56:02.487Z,1647363362.487 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-03-15T16:56:02.487Z,1647363362.487 [Default:CheckIn:D] Running Loop=1
2022-03-15T16:56:02.907Z,1647363362.907 [Default:CheckIn:D] Stopped
2022-03-15T16:56:02.907Z,1647363362.907 [Default:CheckIn:E] Running Loop=1
2022-03-15T16:56:03.300Z,1647363363.300 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 19.948838 min 
2022-03-15T16:56:03.300Z,1647363363.300 [Default:CheckIn:E] Stopped
2022-03-15T16:56:03.300Z,1647363363.300 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-03-15T16:56:03.300Z,1647363363.300 [Default:CheckIn] Stopped
2022-03-15T16:56:03.300Z,1647363363.300 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-03-15T16:56:03.301Z,1647363363.301 [Default:CheckIn](INFO): Running loop #3
2022-03-15T16:56:03.301Z,1647363363.301 [Default:CheckIn] Running Loop=3
2022-03-15T16:56:03.301Z,1647363363.301 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-03-15T16:56:03.301Z,1647363363.301 [Default:CheckIn:Read_GPS] Running Loop=1
2022-03-15T16:56:37.617Z,1647363397.617 [NAL9602](INFO): SBD MO Status=2, MOMSN=17885, MT Status=2, MTMSN=0
2022-03-15T16:56:37.617Z,1647363397.617 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-03-15T16:57:05.085Z,1647363425.085 [NAL9602](INFO): SBD MO Status=0, MOMSN=17885, MT Status=0, MTMSN=0
2022-03-15T16:57:05.085Z,1647363425.085 [NAL9602](INFO): No messages in MT queue
2022-03-15T16:57:06.298Z,1647363426.298 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165705.00,A,3648.13672,N,12147.22541,W,0.156,77.48,150322,,,D*49
2022-03-15T16:57:06.300Z,1647363426.300 [NAL9602](INFO): GPS fix at 20220315T165705: (36.802279, -121.787090)
2022-03-15T16:57:06.339Z,1647363426.339 [Default:CheckIn:Read_GPS] Stopped
2022-03-15T16:57:06.339Z,1647363426.339 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-03-15T16:57:13.853Z,1647363433.853 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220315T163209/Courier0010.lzma
2022-03-15T16:57:14.856Z,1647363434.856 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Courier0010.lzma.bak
2022-03-15T16:57:14.856Z,1647363434.856 [DataOverHttps](INFO): SBD MOMSN=16572702
2022-03-15T16:57:31.208Z,1647363451.208 [DataOverHttps](INFO): Sending 760 bytes from file Logs/20220315T163209/Express0011.lzma
2022-03-15T16:57:32.209Z,1647363452.209 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Express0011.lzma.bak
2022-03-15T16:57:32.209Z,1647363452.209 [DataOverHttps](INFO): SBD MOMSN=16572705
2022-03-15T16:57:33.398Z,1647363453.398 [Default:CheckIn:Read_Iridium] Stopped
2022-03-15T16:57:33.398Z,1647363453.398 [Default:CheckIn:C.Wait] Running Loop=1
2022-03-15T16:57:33.398Z,1647363453.398 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-03-15T16:57:38.615Z,1647363458.615 [NAL9602](INFO): Not Powering down - fast GPS
2022-03-15T16:59:05.957Z,1647363545.957 [CommandExec](IMPORTANT): got command failComponent
2022-03-15T16:59:05.957Z,1647363545.957 [CommandExec](IMPORTANT): Failed components:
2022-03-15T16:59:05.958Z,1647363545.958 [CommandExec](IMPORTANT): No failed Components.
2022-03-15T17:02:34.064Z,1647363754.064 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-03-15T17:02:34.064Z,1647363754.064 [Default:CheckIn:C.Wait] Stopped
2022-03-15T17:02:34.064Z,1647363754.064 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-03-15T17:02:34.064Z,1647363754.064 [Default:CheckIn:D] Running Loop=1
2022-03-15T17:02:34.474Z,1647363754.474 [Default:CheckIn:D] Stopped
2022-03-15T17:02:34.474Z,1647363754.474 [Default:CheckIn:E] Running Loop=1
2022-03-15T17:02:34.892Z,1647363754.892 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 26.474953 min 
2022-03-15T17:02:34.892Z,1647363754.892 [Default:CheckIn:E] Stopped
2022-03-15T17:02:34.892Z,1647363754.892 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-03-15T17:02:34.892Z,1647363754.892 [Default:CheckIn] Stopped
2022-03-15T17:02:34.892Z,1647363754.892 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-03-15T17:02:34.892Z,1647363754.892 [Default:CheckIn](INFO): Running loop #4
2022-03-15T17:02:34.892Z,1647363754.892 [Default:CheckIn] Running Loop=4
2022-03-15T17:02:34.893Z,1647363754.893 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-03-15T17:02:34.893Z,1647363754.893 [Default:CheckIn:Read_GPS] Running Loop=1
2022-03-15T17:02:36.894Z,1647363756.894 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170236.00,A,3648.13766,N,12147.22445,W,0.039,77.48,150322,,,D*41
2022-03-15T17:02:36.897Z,1647363756.897 [NAL9602](INFO): GPS fix at 20220315T170236: (36.802294, -121.787074)
2022-03-15T17:02:36.907Z,1647363756.907 [Default:CheckIn:Read_GPS] Stopped
2022-03-15T17:02:36.907Z,1647363756.907 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-03-15T17:02:44.201Z,1647363764.201 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220315T163209/Courier0013.lzma
2022-03-15T17:02:45.204Z,1647363765.204 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Courier0013.lzma.bak
2022-03-15T17:02:45.204Z,1647363765.204 [DataOverHttps](INFO): SBD MOMSN=16572738
2022-03-15T17:02:58.309Z,1647363778.309 [NAL9602](INFO): SBD MO Status=0, MOMSN=17886, MT Status=0, MTMSN=0
2022-03-15T17:02:58.309Z,1647363778.309 [NAL9602](INFO): No messages in MT queue
2022-03-15T17:03:01.730Z,1647363781.730 [DataOverHttps](INFO): Sending 184 bytes from file Logs/20220315T163209/Express0014.lzma
2022-03-15T17:03:02.732Z,1647363782.732 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Express0014.lzma.bak
2022-03-15T17:03:02.732Z,1647363782.732 [DataOverHttps](INFO): SBD MOMSN=16572741
2022-03-15T17:03:03.967Z,1647363783.967 [Default:CheckIn:Read_Iridium] Stopped
2022-03-15T17:03:03.967Z,1647363783.967 [Default:CheckIn:C.Wait] Running Loop=1
2022-03-15T17:03:03.967Z,1647363783.967 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-03-15T17:03:29.038Z,1647363809.038 [NAL9602](INFO): Not Powering down - fast GPS
2022-03-15T17:08:04.607Z,1647364084.607 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-03-15T17:08:04.607Z,1647364084.607 [Default:CheckIn:C.Wait] Stopped
2022-03-15T17:08:04.607Z,1647364084.607 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-03-15T17:08:04.607Z,1647364084.607 [Default:CheckIn:D] Running Loop=1
2022-03-15T17:08:05.060Z,1647364085.060 [Default:CheckIn:D] Stopped
2022-03-15T17:08:05.061Z,1647364085.061 [Default:CheckIn:E] Running Loop=1
2022-03-15T17:08:05.421Z,1647364085.421 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.984723 min 
2022-03-15T17:08:05.421Z,1647364085.421 [Default:CheckIn:E] Stopped
2022-03-15T17:08:05.421Z,1647364085.421 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-03-15T17:08:05.421Z,1647364085.421 [Default:CheckIn] Stopped
2022-03-15T17:08:05.421Z,1647364085.421 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-03-15T17:08:05.421Z,1647364085.421 [Default:CheckIn](INFO): Running loop #5
2022-03-15T17:08:05.422Z,1647364085.422 [Default:CheckIn] Running Loop=5
2022-03-15T17:08:05.422Z,1647364085.422 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-03-15T17:08:05.422Z,1647364085.422 [Default:CheckIn:Read_GPS] Running Loop=1
2022-03-15T17:08:07.425Z,1647364087.425 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170806.00,A,3648.13880,N,12147.22429,W,0.019,77.48,150322,,,D*47
2022-03-15T17:08:07.427Z,1647364087.427 [NAL9602](INFO): GPS fix at 20220315T170806: (36.802313, -121.787071)
2022-03-15T17:08:07.487Z,1647364087.487 [Default:CheckIn:Read_GPS] Stopped
2022-03-15T17:08:07.487Z,1647364087.487 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-03-15T17:08:17.181Z,1647364097.181 [NAL9602](INFO): SBD MO Status=0, MOMSN=17887, MT Status=0, MTMSN=0
2022-03-15T17:08:17.181Z,1647364097.181 [NAL9602](INFO): No messages in MT queue
2022-03-15T17:08:18.130Z,1647364098.130 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220315T163209/Courier0016.lzma
2022-03-15T17:08:19.132Z,1647364099.132 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Courier0016.lzma.bak
2022-03-15T17:08:19.132Z,1647364099.132 [DataOverHttps](INFO): SBD MOMSN=16572756
2022-03-15T17:08:35.454Z,1647364115.454 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220315T163209/Express0017.lzma
2022-03-15T17:08:36.456Z,1647364116.456 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Express0017.lzma.bak
2022-03-15T17:08:36.456Z,1647364116.456 [DataOverHttps](INFO): SBD MOMSN=16572759
2022-03-15T17:08:37.803Z,1647364117.803 [Default:CheckIn:Read_Iridium] Stopped
2022-03-15T17:08:37.803Z,1647364117.803 [Default:CheckIn:C.Wait] Running Loop=1
2022-03-15T17:08:37.803Z,1647364117.803 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-03-15T17:08:47.889Z,1647364127.889 [NAL9602](INFO): Not Powering down - fast GPS
2022-03-15T17:13:38.371Z,1647364418.371 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-03-15T17:13:38.372Z,1647364418.372 [Default:CheckIn:C.Wait] Stopped
2022-03-15T17:13:38.372Z,1647364418.372 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-03-15T17:13:38.372Z,1647364418.372 [Default:CheckIn:D] Running Loop=1
2022-03-15T17:13:38.777Z,1647364418.777 [Default:CheckIn:D] Stopped
2022-03-15T17:13:38.777Z,1647364418.777 [Default:CheckIn:E] Running Loop=1
2022-03-15T17:13:39.205Z,1647364419.205 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 37.546672 min 
2022-03-15T17:13:39.206Z,1647364419.206 [Default:CheckIn:E] Stopped
2022-03-15T17:13:39.206Z,1647364419.206 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-03-15T17:13:39.206Z,1647364419.206 [Default:CheckIn] Stopped
2022-03-15T17:13:39.206Z,1647364419.206 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-03-15T17:13:39.206Z,1647364419.206 [Default:CheckIn](INFO): Running loop #6
2022-03-15T17:13:39.206Z,1647364419.206 [Default:CheckIn] Running Loop=6
2022-03-15T17:13:39.206Z,1647364419.206 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-03-15T17:13:39.207Z,1647364419.207 [Default:CheckIn:Read_GPS] Running Loop=1
2022-03-15T17:13:41.197Z,1647364421.197 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171340.00,A,3648.13795,N,12147.22534,W,0.019,77.48,150322,,,D*49
2022-03-15T17:13:41.199Z,1647364421.199 [NAL9602](INFO): GPS fix at 20220315T171340: (36.802299, -121.787089)
2022-03-15T17:13:41.253Z,1647364421.253 [Default:CheckIn:Read_GPS] Stopped
2022-03-15T17:13:41.253Z,1647364421.253 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-03-15T17:13:48.809Z,1647364428.809 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220315T163209/Courier0019.lzma
2022-03-15T17:13:49.812Z,1647364429.812 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Courier0019.lzma.bak
2022-03-15T17:13:49.812Z,1647364429.812 [DataOverHttps](INFO): SBD MOMSN=16572772
2022-03-15T17:14:06.242Z,1647364446.242 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20220315T163209/Express0020.lzma
2022-03-15T17:14:07.244Z,1647364447.244 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Express0020.lzma.bak
2022-03-15T17:14:07.244Z,1647364447.244 [DataOverHttps](INFO): SBD MOMSN=16572775
2022-03-15T17:14:08.679Z,1647364448.679 [Default:CheckIn:Read_Iridium] Stopped
2022-03-15T17:14:08.679Z,1647364448.679 [Default:CheckIn:C.Wait] Running Loop=1
2022-03-15T17:14:08.679Z,1647364448.679 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-03-15T17:14:24.083Z,1647364464.083 [NAL9602](INFO): SBD MO Status=2, MOMSN=17888, MT Status=2, MTMSN=0
2022-03-15T17:14:24.083Z,1647364464.083 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-03-15T17:14:42.269Z,1647364482.269 [NAL9602](INFO): SBD MO Status=0, MOMSN=17888, MT Status=0, MTMSN=0
2022-03-15T17:14:42.269Z,1647364482.269 [NAL9602](INFO): No messages in MT queue
2022-03-15T17:15:12.978Z,1647364512.978 [NAL9602](INFO): Not Powering down - fast GPS
2022-03-15T17:19:09.345Z,1647364749.345 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-03-15T17:19:09.345Z,1647364749.345 [Default:CheckIn:C.Wait] Stopped
2022-03-15T17:19:09.345Z,1647364749.345 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-03-15T17:19:09.346Z,1647364749.346 [Default:CheckIn:D] Running Loop=1
2022-03-15T17:19:09.728Z,1647364749.728 [Default:CheckIn:D] Stopped
2022-03-15T17:19:09.728Z,1647364749.728 [Default:CheckIn:E] Running Loop=1
2022-03-15T17:19:10.134Z,1647364750.134 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.062512 min 
2022-03-15T17:19:10.134Z,1647364750.134 [Default:CheckIn:E] Stopped
2022-03-15T17:19:10.134Z,1647364750.134 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-03-15T17:19:10.134Z,1647364750.134 [Default:CheckIn] Stopped
2022-03-15T17:19:10.134Z,1647364750.134 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-03-15T17:19:10.134Z,1647364750.134 [Default:CheckIn](INFO): Running loop #7
2022-03-15T17:19:10.135Z,1647364750.135 [Default:CheckIn] Running Loop=7
2022-03-15T17:19:10.135Z,1647364750.135 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-03-15T17:19:10.135Z,1647364750.135 [Default:CheckIn:Read_GPS] Running Loop=1
2022-03-15T17:19:12.141Z,1647364752.141 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171911.00,A,3648.13715,N,12147.22481,W,0.000,77.48,150322,,,D*48
2022-03-15T17:19:12.152Z,1647364752.152 [NAL9602](INFO): GPS fix at 20220315T171911: (36.802286, -121.787080)
2022-03-15T17:19:12.163Z,1647364752.163 [Default:CheckIn:Read_GPS] Stopped
2022-03-15T17:19:12.163Z,1647364752.163 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-03-15T17:19:19.754Z,1647364759.754 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220315T163209/Courier0022.lzma
2022-03-15T17:19:20.756Z,1647364760.756 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Courier0022.lzma.bak
2022-03-15T17:19:20.756Z,1647364760.756 [DataOverHttps](INFO): SBD MOMSN=16572788
2022-03-15T17:19:29.917Z,1647364769.917 [NAL9602](INFO): SBD MO Status=0, MOMSN=17889, MT Status=0, MTMSN=0
2022-03-15T17:19:29.917Z,1647364769.917 [NAL9602](INFO): No messages in MT queue
2022-03-15T17:19:37.074Z,1647364777.074 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220315T163209/Express0023.lzma
2022-03-15T17:19:38.076Z,1647364778.076 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Express0023.lzma.bak
2022-03-15T17:19:38.076Z,1647364778.076 [DataOverHttps](INFO): SBD MOMSN=16572791
2022-03-15T17:19:39.245Z,1647364779.245 [Default:CheckIn:Read_Iridium] Stopped
2022-03-15T17:19:39.245Z,1647364779.245 [Default:CheckIn:C.Wait] Running Loop=1
2022-03-15T17:19:39.245Z,1647364779.245 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-03-15T17:20:00.618Z,1647364800.618 [NAL9602](INFO): Not Powering down - fast GPS
2022-03-15T17:24:39.815Z,1647365079.815 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-03-15T17:24:39.815Z,1647365079.815 [Default:CheckIn:C.Wait] Stopped
2022-03-15T17:24:39.815Z,1647365079.815 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-03-15T17:24:39.815Z,1647365079.815 [Default:CheckIn:D] Running Loop=1
2022-03-15T17:24:40.217Z,1647365080.217 [Default:CheckIn:D] Stopped
2022-03-15T17:24:40.217Z,1647365080.217 [Default:CheckIn:E] Running Loop=1
2022-03-15T17:24:40.627Z,1647365080.627 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.570667 min 
2022-03-15T17:24:40.627Z,1647365080.627 [Default:CheckIn:E] Stopped
2022-03-15T17:24:40.627Z,1647365080.627 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-03-15T17:24:40.628Z,1647365080.628 [Default:CheckIn] Stopped
2022-03-15T17:24:40.628Z,1647365080.628 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-03-15T17:24:40.628Z,1647365080.628 [Default:CheckIn](INFO): Running loop #8
2022-03-15T17:24:40.628Z,1647365080.628 [Default:CheckIn] Running Loop=8
2022-03-15T17:24:40.628Z,1647365080.628 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-03-15T17:24:40.628Z,1647365080.628 [Default:CheckIn:Read_GPS] Running Loop=1
2022-03-15T17:24:42.629Z,1647365082.629 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172441.00,A,3648.13710,N,12147.22371,W,0.019,77.48,150322,,,D*46
2022-03-15T17:24:42.632Z,1647365082.632 [NAL9602](INFO): GPS fix at 20220315T172441: (36.802285, -121.787062)
2022-03-15T17:24:42.671Z,1647365082.671 [Default:CheckIn:Read_GPS] Stopped
2022-03-15T17:24:42.671Z,1647365082.671 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-03-15T17:24:49.954Z,1647365089.954 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220315T163209/Courier0025.lzma
2022-03-15T17:24:50.956Z,1647365090.956 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Courier0025.lzma.bak
2022-03-15T17:24:50.956Z,1647365090.956 [DataOverHttps](INFO): SBD MOMSN=16572802
2022-03-15T17:25:00.405Z,1647365100.405 [NAL9602](INFO): SBD MO Status=0, MOMSN=17890, MT Status=0, MTMSN=0
2022-03-15T17:25:00.405Z,1647365100.405 [NAL9602](INFO): No messages in MT queue
2022-03-15T17:25:07.266Z,1647365107.266 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20220315T163209/Express0026.lzma
2022-03-15T17:25:08.269Z,1647365108.269 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Express0026.lzma.bak
2022-03-15T17:25:08.269Z,1647365108.269 [DataOverHttps](INFO): SBD MOMSN=16572805
2022-03-15T17:25:09.709Z,1647365109.709 [Default:CheckIn:Read_Iridium] Stopped
2022-03-15T17:25:09.709Z,1647365109.709 [Default:CheckIn:C.Wait] Running Loop=1
2022-03-15T17:25:09.709Z,1647365109.709 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-03-15T17:25:31.112Z,1647365131.112 [NAL9602](INFO): Not Powering down - fast GPS
2022-03-15T17:30:10.369Z,1647365410.369 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-03-15T17:30:10.369Z,1647365410.369 [Default:CheckIn:C.Wait] Stopped
2022-03-15T17:30:10.369Z,1647365410.369 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-03-15T17:30:10.369Z,1647365410.369 [Default:CheckIn:D] Running Loop=1
2022-03-15T17:30:10.779Z,1647365410.779 [Default:CheckIn:D] Stopped
2022-03-15T17:30:10.779Z,1647365410.779 [Default:CheckIn:E] Running Loop=1
2022-03-15T17:30:11.225Z,1647365411.225 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 54.080033 min 
2022-03-15T17:30:11.225Z,1647365411.225 [Default:CheckIn:E] Stopped
2022-03-15T17:30:11.226Z,1647365411.226 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-03-15T17:30:11.226Z,1647365411.226 [Default:CheckIn] Stopped
2022-03-15T17:30:11.250Z,1647365411.250 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-03-15T17:30:11.250Z,1647365411.250 [Default:CheckIn](INFO): Running loop #9
2022-03-15T17:30:11.250Z,1647365411.250 [Default:CheckIn] Running Loop=9
2022-03-15T17:30:11.250Z,1647365411.250 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-03-15T17:30:11.251Z,1647365411.251 [Default:CheckIn:Read_GPS] Running Loop=1
2022-03-15T17:30:13.182Z,1647365413.182 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173012.00,A,3648.16251,N,12147.21451,W,0.039,26.35,150322,,,D*4A
2022-03-15T17:30:13.205Z,1647365413.205 [NAL9602](INFO): GPS fix at 20220315T173012: (36.802709, -121.786908)
2022-03-15T17:30:13.281Z,1647365413.281 [Default:CheckIn:Read_GPS] Stopped
2022-03-15T17:30:13.281Z,1647365413.281 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-03-15T17:30:21.161Z,1647365421.161 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220315T163209/Courier0028.lzma
2022-03-15T17:30:22.164Z,1647365422.164 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Courier0028.lzma.bak
2022-03-15T17:30:22.164Z,1647365422.164 [DataOverHttps](INFO): SBD MOMSN=16572816
2022-03-15T17:30:27.321Z,1647365427.321 [NAL9602](INFO): SBD MO Status=0, MOMSN=17891, MT Status=0, MTMSN=0
2022-03-15T17:30:27.321Z,1647365427.321 [NAL9602](INFO): No messages in MT queue
2022-03-15T17:30:38.574Z,1647365438.574 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220315T163209/Express0029.lzma
2022-03-15T17:30:39.576Z,1647365439.576 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Express0029.lzma.bak
2022-03-15T17:30:39.576Z,1647365439.576 [DataOverHttps](INFO): SBD MOMSN=16572819
2022-03-15T17:30:41.102Z,1647365441.102 [Default:CheckIn:Read_Iridium] Stopped
2022-03-15T17:30:41.102Z,1647365441.102 [Default:CheckIn:C.Wait] Running Loop=1
2022-03-15T17:30:41.102Z,1647365441.102 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-03-15T17:30:58.031Z,1647365458.031 [NAL9602](INFO): Not Powering down - fast GPS
2022-03-15T17:35:41.651Z,1647365741.651 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-03-15T17:35:41.651Z,1647365741.651 [Default:CheckIn:C.Wait] Stopped
2022-03-15T17:35:41.651Z,1647365741.651 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-03-15T17:35:41.651Z,1647365741.651 [Default:CheckIn:D] Running Loop=1
2022-03-15T17:35:42.048Z,1647365742.048 [Default:CheckIn:D] Stopped
2022-03-15T17:35:42.048Z,1647365742.048 [Default:CheckIn:E] Running Loop=1
2022-03-15T17:35:42.461Z,1647365742.461 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 59.601188 min 
2022-03-15T17:35:42.462Z,1647365742.462 [Default:CheckIn:E] Stopped
2022-03-15T17:35:42.462Z,1647365742.462 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-03-15T17:35:42.462Z,1647365742.462 [Default:CheckIn] Stopped
2022-03-15T17:35:42.462Z,1647365742.462 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-03-15T17:35:42.462Z,1647365742.462 [Default:CheckIn](INFO): Running loop #10
2022-03-15T17:35:42.462Z,1647365742.462 [Default:CheckIn] Running Loop=10
2022-03-15T17:35:42.462Z,1647365742.462 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-03-15T17:35:42.463Z,1647365742.463 [Default:CheckIn:Read_GPS] Running Loop=1
2022-03-15T17:35:44.469Z,1647365744.469 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173543.00,A,3648.16383,N,12147.21474,W,0.058,58.01,150322,,,D*4B
2022-03-15T17:35:44.472Z,1647365744.472 [NAL9602](INFO): GPS fix at 20220315T173543: (36.802731, -121.786912)
2022-03-15T17:35:44.506Z,1647365744.506 [Default:CheckIn:Read_GPS] Stopped
2022-03-15T17:35:44.507Z,1647365744.507 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-03-15T17:35:51.941Z,1647365751.941 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220315T163209/Courier0031.lzma
2022-03-15T17:35:52.944Z,1647365752.944 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Courier0031.lzma.bak
2022-03-15T17:35:52.944Z,1647365752.944 [DataOverHttps](INFO): SBD MOMSN=16572830
2022-03-15T17:36:09.394Z,1647365769.394 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220315T163209/Express0032.lzma
2022-03-15T17:36:10.396Z,1647365770.396 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Express0032.lzma.bak
2022-03-15T17:36:10.396Z,1647365770.396 [DataOverHttps](INFO): SBD MOMSN=16572833
2022-03-15T17:36:11.589Z,1647365771.589 [Default:CheckIn:Read_Iridium] Stopped
2022-03-15T17:36:11.589Z,1647365771.589 [Default:CheckIn:C.Wait] Running Loop=1
2022-03-15T17:36:11.589Z,1647365771.589 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-03-15T17:36:13.153Z,1647365773.153 [NAL9602](INFO): SBD MO Status=0, MOMSN=17892, MT Status=0, MTMSN=0
2022-03-15T17:36:13.153Z,1647365773.153 [NAL9602](INFO): No messages in MT queue
2022-03-15T17:36:43.919Z,1647365803.919 [NAL9602](INFO): Not Powering down - fast GPS
2022-03-15T17:41:12.241Z,1647366072.241 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-03-15T17:41:12.241Z,1647366072.241 [Default:CheckIn:C.Wait] Stopped
2022-03-15T17:41:12.241Z,1647366072.241 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-03-15T17:41:12.241Z,1647366072.241 [Default:CheckIn:D] Running Loop=1
2022-03-15T17:41:12.655Z,1647366072.655 [Default:CheckIn:D] Stopped
2022-03-15T17:41:12.655Z,1647366072.655 [Default:CheckIn:E] Running Loop=1
2022-03-15T17:41:13.141Z,1647366073.141 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 65.111304 min 
2022-03-15T17:41:13.141Z,1647366073.141 [Default:CheckIn:E] Stopped
2022-03-15T17:41:13.141Z,1647366073.141 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-03-15T17:41:13.141Z,1647366073.141 [Default:CheckIn] Stopped
2022-03-15T17:41:13.141Z,1647366073.141 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-03-15T17:41:13.141Z,1647366073.141 [Default:CheckIn](INFO): Running loop #11
2022-03-15T17:41:13.141Z,1647366073.141 [Default:CheckIn] Running Loop=11
2022-03-15T17:41:13.141Z,1647366073.141 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-03-15T17:41:13.141Z,1647366073.141 [Default:CheckIn:Read_GPS] Running Loop=1
2022-03-15T17:41:15.077Z,1647366075.077 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174114.00,A,3648.16348,N,12147.21398,W,0.058,58.01,150322,,,D*48
2022-03-15T17:41:15.080Z,1647366075.080 [NAL9602](INFO): GPS fix at 20220315T174114: (36.802725, -121.786900)
2022-03-15T17:41:15.135Z,1647366075.135 [Default:CheckIn:Read_GPS] Stopped
2022-03-15T17:41:15.136Z,1647366075.136 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-03-15T17:41:22.338Z,1647366082.338 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220315T163209/Courier0034.lzma
2022-03-15T17:41:23.340Z,1647366083.340 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Courier0034.lzma.bak
2022-03-15T17:41:23.340Z,1647366083.340 [DataOverHttps](INFO): SBD MOMSN=16572844
2022-03-15T17:41:32.046Z,1647366092.046 [NAL9602](INFO): SBD MO Status=2, MOMSN=17893, MT Status=2, MTMSN=0
2022-03-15T17:41:32.047Z,1647366092.047 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-03-15T17:41:39.730Z,1647366099.730 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220315T163209/Express0035.lzma
2022-03-15T17:41:40.732Z,1647366100.732 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Express0035.lzma.bak
2022-03-15T17:41:40.732Z,1647366100.732 [DataOverHttps](INFO): SBD MOMSN=16572847
2022-03-15T17:41:42.168Z,1647366102.168 [Default:CheckIn:Read_Iridium] Stopped
2022-03-15T17:41:42.168Z,1647366102.168 [Default:CheckIn:C.Wait] Running Loop=1
2022-03-15T17:41:42.168Z,1647366102.168 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-03-15T17:41:49.040Z,1647366109.040 [NAL9602](INFO): SBD MO Status=2, MOMSN=17893, MT Status=2, MTMSN=0
2022-03-15T17:41:49.040Z,1647366109.040 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-03-15T17:42:07.197Z,1647366127.197 [NAL9602](INFO): SBD MO Status=2, MOMSN=17893, MT Status=2, MTMSN=0
2022-03-15T17:42:07.197Z,1647366127.197 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-03-15T17:42:24.169Z,1647366144.169 [NAL9602](INFO): SBD MO Status=2, MOMSN=17893, MT Status=2, MTMSN=0
2022-03-15T17:42:24.169Z,1647366144.169 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-03-15T17:42:33.859Z,1647366153.859 [NAL9602](INFO): SBD MO Status=0, MOMSN=17893, MT Status=0, MTMSN=0
2022-03-15T17:42:33.860Z,1647366153.860 [NAL9602](INFO): No messages in MT queue
2022-03-15T17:43:04.596Z,1647366184.596 [NAL9602](INFO): Not Powering down - fast GPS
2022-03-15T17:46:42.937Z,1647366402.937 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-03-15T17:46:42.937Z,1647366402.937 [Default:CheckIn:C.Wait] Stopped
2022-03-15T17:46:42.937Z,1647366402.937 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-03-15T17:46:42.937Z,1647366402.937 [Default:CheckIn:D] Running Loop=1
2022-03-15T17:46:43.369Z,1647366403.369 [Default:CheckIn:D] Stopped
2022-03-15T17:46:43.369Z,1647366403.369 [Default:CheckIn:E] Running Loop=1
2022-03-15T17:46:43.735Z,1647366403.735 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 70.623193 min 
2022-03-15T17:46:43.735Z,1647366403.735 [Default:CheckIn:E] Stopped
2022-03-15T17:46:43.735Z,1647366403.735 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-03-15T17:46:43.735Z,1647366403.735 [Default:CheckIn] Stopped
2022-03-15T17:46:43.735Z,1647366403.735 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-03-15T17:46:43.735Z,1647366403.735 [Default:CheckIn](INFO): Running loop #12
2022-03-15T17:46:43.735Z,1647366403.735 [Default:CheckIn] Running Loop=12
2022-03-15T17:46:43.735Z,1647366403.735 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-03-15T17:46:43.735Z,1647366403.735 [Default:CheckIn:Read_GPS] Running Loop=1
2022-03-15T17:46:45.749Z,1647366405.749 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174644.00,A,3648.16304,N,12147.21348,W,0.058,58.01,150322,,,D*4F
2022-03-15T17:46:45.751Z,1647366405.751 [NAL9602](INFO): GPS fix at 20220315T174644: (36.802717, -121.786891)
2022-03-15T17:46:45.791Z,1647366405.791 [Default:CheckIn:Read_GPS] Stopped
2022-03-15T17:46:45.791Z,1647366405.791 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-03-15T17:46:53.177Z,1647366413.177 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220315T163209/Courier0037.lzma
2022-03-15T17:46:54.180Z,1647366414.180 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Courier0037.lzma.bak
2022-03-15T17:46:54.180Z,1647366414.180 [DataOverHttps](INFO): SBD MOMSN=16572863
2022-03-15T17:46:54.233Z,1647366414.233 [NAL9602](INFO): SBD MO Status=0, MOMSN=17894, MT Status=0, MTMSN=0
2022-03-15T17:46:54.234Z,1647366414.234 [NAL9602](INFO): No messages in MT queue
2022-03-15T17:47:10.378Z,1647366430.378 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20220315T163209/Express0038.lzma
2022-03-15T17:47:11.380Z,1647366431.380 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Express0038.lzma.bak
2022-03-15T17:47:11.380Z,1647366431.380 [DataOverHttps](INFO): SBD MOMSN=16572866
2022-03-15T17:47:12.832Z,1647366432.832 [Default:CheckIn:Read_Iridium] Stopped
2022-03-15T17:47:12.832Z,1647366432.832 [Default:CheckIn:C.Wait] Running Loop=1
2022-03-15T17:47:12.832Z,1647366432.832 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-03-15T17:47:24.932Z,1647366444.932 [NAL9602](INFO): Not Powering down - fast GPS
2022-03-15T17:48:32.820Z,1647366512.820 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2022-03-15T17:48:32.826Z,1647366512.826 [BPC1](INFO): Received data from all battery sticks.
2022-03-15T17:52:13.475Z,1647366733.475 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-03-15T17:52:13.475Z,1647366733.475 [Default:CheckIn:C.Wait] Stopped
2022-03-15T17:52:13.476Z,1647366733.476 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-03-15T17:52:13.476Z,1647366733.476 [Default:CheckIn:D] Running Loop=1
2022-03-15T17:52:13.821Z,1647366733.821 [Default:CheckIn:D] Stopped
2022-03-15T17:52:13.821Z,1647366733.821 [Default:CheckIn:E] Running Loop=1
2022-03-15T17:52:14.249Z,1647366734.249 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 76.130737 min 
2022-03-15T17:52:14.250Z,1647366734.250 [Default:CheckIn:E] Stopped
2022-03-15T17:52:14.250Z,1647366734.250 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-03-15T17:52:14.250Z,1647366734.250 [Default:CheckIn] Stopped
2022-03-15T17:52:14.250Z,1647366734.250 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-03-15T17:52:14.250Z,1647366734.250 [Default:CheckIn](INFO): Running loop #13
2022-03-15T17:52:14.250Z,1647366734.250 [Default:CheckIn] Running Loop=13
2022-03-15T17:52:14.250Z,1647366734.250 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-03-15T17:52:14.250Z,1647366734.250 [Default:CheckIn:Read_GPS] Running Loop=1
2022-03-15T17:52:16.229Z,1647366736.229 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175215.00,A,3648.20339,N,12147.15423,W,3.207,35.68,150322,,,D*47
2022-03-15T17:52:16.231Z,1647366736.231 [NAL9602](INFO): GPS fix at 20220315T175215: (36.803390, -121.785904)
2022-03-15T17:52:16.279Z,1647366736.279 [Default:CheckIn:Read_GPS] Stopped
2022-03-15T17:52:16.279Z,1647366736.279 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-03-15T17:52:23.441Z,1647366743.441 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20220315T163209/Courier0040.lzma
2022-03-15T17:52:24.444Z,1647366744.444 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Courier0040.lzma.bak
2022-03-15T17:52:24.444Z,1647366744.444 [DataOverHttps](INFO): SBD MOMSN=16572877
2022-03-15T17:52:37.641Z,1647366757.641 [NAL9602](INFO): SBD MO Status=2, MOMSN=17895, MT Status=2, MTMSN=0
2022-03-15T17:52:37.641Z,1647366757.641 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-03-15T17:52:40.766Z,1647366760.766 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220315T163209/Express0041.lzma
2022-03-15T17:52:41.768Z,1647366761.768 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Express0041.lzma.bak
2022-03-15T17:52:41.768Z,1647366761.768 [DataOverHttps](INFO): SBD MOMSN=16572880
2022-03-15T17:52:42.907Z,1647366762.907 [Default:CheckIn:Read_Iridium] Stopped
2022-03-15T17:52:42.907Z,1647366762.907 [Default:CheckIn:C.Wait] Running Loop=1
2022-03-15T17:52:42.907Z,1647366762.907 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-03-15T17:52:53.805Z,1647366773.805 [NAL9602](INFO): SBD MO Status=2, MOMSN=17895, MT Status=2, MTMSN=0
2022-03-15T17:52:53.805Z,1647366773.805 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-03-15T17:53:12.384Z,1647366792.384 [NAL9602](INFO): SBD MO Status=0, MOMSN=17895, MT Status=0, MTMSN=0
2022-03-15T17:53:12.384Z,1647366792.384 [NAL9602](INFO): No messages in MT queue
2022-03-15T17:53:43.096Z,1647366823.096 [NAL9602](INFO): Not Powering down - fast GPS
2022-03-15T17:57:43.481Z,1647367063.481 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-03-15T17:57:43.482Z,1647367063.482 [Default:CheckIn:C.Wait] Stopped
2022-03-15T17:57:43.482Z,1647367063.482 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-03-15T17:57:43.482Z,1647367063.482 [Default:CheckIn:D] Running Loop=1
2022-03-15T17:57:43.898Z,1647367063.898 [Default:CheckIn:D] Stopped
2022-03-15T17:57:43.898Z,1647367063.898 [Default:CheckIn:E] Running Loop=1
2022-03-15T17:57:44.288Z,1647367064.288 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 81.632023 min 
2022-03-15T17:57:44.288Z,1647367064.288 [Default:CheckIn:E] Stopped
2022-03-15T17:57:44.288Z,1647367064.288 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-03-15T17:57:44.288Z,1647367064.288 [Default:CheckIn] Stopped
2022-03-15T17:57:44.289Z,1647367064.289 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-03-15T17:57:44.289Z,1647367064.289 [Default:CheckIn](INFO): Running loop #14
2022-03-15T17:57:44.289Z,1647367064.289 [Default:CheckIn] Running Loop=14
2022-03-15T17:57:44.289Z,1647367064.289 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-03-15T17:57:44.289Z,1647367064.289 [Default:CheckIn:Read_GPS] Running Loop=1
2022-03-15T17:57:46.301Z,1647367066.301 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175745.00,A,3648.50734,N,12147.20625,W,7.911,240.02,150322,,,D*7F
2022-03-15T17:57:46.304Z,1647367066.304 [NAL9602](INFO): GPS fix at 20220315T175745: (36.808456, -121.786771)
2022-03-15T17:57:46.315Z,1647367066.315 [Default:CheckIn:Read_GPS] Stopped
2022-03-15T17:57:46.315Z,1647367066.315 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-03-15T17:57:54.446Z,1647367074.446 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220315T163209/Courier0043.lzma
2022-03-15T17:57:55.448Z,1647367075.448 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Courier0043.lzma.bak
2022-03-15T17:57:55.448Z,1647367075.448 [DataOverHttps](INFO): SBD MOMSN=16572897
2022-03-15T17:58:08.121Z,1647367088.121 [NAL9602](INFO): SBD MO Status=2, MOMSN=17896, MT Status=2, MTMSN=0
2022-03-15T17:58:08.121Z,1647367088.121 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-03-15T17:58:12.586Z,1647367092.586 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20220315T163209/Express0044.lzma
2022-03-15T17:58:13.588Z,1647367093.588 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Express0044.lzma.bak
2022-03-15T17:58:13.588Z,1647367093.588 [DataOverHttps](INFO): SBD MOMSN=16572900
2022-03-15T17:58:15.033Z,1647367095.033 [Default:CheckIn:Read_Iridium] Stopped
2022-03-15T17:58:15.033Z,1647367095.033 [Default:CheckIn:C.Wait] Running Loop=1
2022-03-15T17:58:15.034Z,1647367095.034 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-03-15T17:58:15.387Z,1647367095.387 [NAL9602](INFO): SBD MO Status=0, MOMSN=17896, MT Status=0, MTMSN=0
2022-03-15T17:58:15.387Z,1647367095.387 [NAL9602](INFO): No messages in MT queue
2022-03-15T17:58:46.113Z,1647367126.113 [NAL9602](INFO): Not Powering down - fast GPS
2022-03-15T18:03:01.179Z,1647367381.179 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2022-03-15T18:03:15.591Z,1647367395.591 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-03-15T18:03:15.591Z,1647367395.591 [Default:CheckIn:C.Wait] Stopped
2022-03-15T18:03:15.591Z,1647367395.591 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-03-15T18:03:15.591Z,1647367395.591 [Default:CheckIn:D] Running Loop=1
2022-03-15T18:03:16.001Z,1647367396.001 [Default:CheckIn:D] Stopped
2022-03-15T18:03:16.001Z,1647367396.001 [Default:CheckIn:E] Running Loop=1
2022-03-15T18:03:16.410Z,1647367396.410 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 87.167074 min 
2022-03-15T18:03:16.410Z,1647367396.410 [Default:CheckIn:E] Stopped
2022-03-15T18:03:16.410Z,1647367396.410 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-03-15T18:03:16.410Z,1647367396.410 [Default:CheckIn] Stopped
2022-03-15T18:03:16.411Z,1647367396.411 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-03-15T18:03:16.411Z,1647367396.411 [Default:CheckIn](INFO): Running loop #15
2022-03-15T18:03:16.411Z,1647367396.411 [Default:CheckIn] Running Loop=15
2022-03-15T18:03:16.411Z,1647367396.411 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-03-15T18:03:16.411Z,1647367396.411 [Default:CheckIn:Read_GPS] Running Loop=1
2022-03-15T18:03:18.417Z,1647367398.417 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180317.00,A,3648.02326,N,12149.05787,W,22.665,265.88,150322,,,D*48
2022-03-15T18:03:18.428Z,1647367398.428 [NAL9602](INFO): GPS fix at 20220315T180317: (36.800388, -121.817631)
2022-03-15T18:03:18.439Z,1647367398.439 [Default:CheckIn:Read_GPS] Stopped
2022-03-15T18:03:18.440Z,1647367398.440 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-03-15T18:03:37.618Z,1647367417.618 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220315T163209/Courier0046.lzma
2022-03-15T18:03:37.805Z,1647367417.805 [NAL9602](INFO): SBD MO Status=0, MOMSN=17897, MT Status=0, MTMSN=0
2022-03-15T18:03:37.805Z,1647367417.805 [NAL9602](INFO): No messages in MT queue
2022-03-15T18:03:38.620Z,1647367418.620 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Courier0046.lzma.bak
2022-03-15T18:03:38.621Z,1647367418.621 [DataOverHttps](INFO): SBD MOMSN=16572915
2022-03-15T18:03:58.074Z,1647367438.074 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20220315T163209/Express0047.lzma
2022-03-15T18:03:59.079Z,1647367439.079 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Express0047.lzma.bak
2022-03-15T18:03:59.080Z,1647367439.080 [DataOverHttps](INFO): SBD MOMSN=16572918
2022-03-15T18:04:00.443Z,1647367440.443 [Default:CheckIn:Read_Iridium] Stopped
2022-03-15T18:04:00.443Z,1647367440.443 [Default:CheckIn:C.Wait] Running Loop=1
2022-03-15T18:04:00.443Z,1647367440.443 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-03-15T18:04:08.505Z,1647367448.505 [NAL9602](INFO): Not Powering down - fast GPS
2022-03-15T18:08:04.558Z,1647367684.558 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-03-15T18:08:09.579Z,1647367689.579 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.236835
2022-03-15T18:08:52.386Z,1647367732.386 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.006165
2022-03-15T18:09:01.064Z,1647367741.064 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-03-15T18:09:01.064Z,1647367741.064 [Default:CheckIn:C.Wait] Stopped
2022-03-15T18:09:01.064Z,1647367741.064 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-03-15T18:09:01.065Z,1647367741.065 [Default:CheckIn:D] Running Loop=1
2022-03-15T18:09:01.448Z,1647367741.448 [Default:CheckIn:D] Stopped
2022-03-15T18:09:01.448Z,1647367741.448 [Default:CheckIn:E] Running Loop=1
2022-03-15T18:09:01.842Z,1647367741.842 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 92.924520 min 
2022-03-15T18:09:01.843Z,1647367741.843 [Default:CheckIn:E] Stopped
2022-03-15T18:09:01.843Z,1647367741.843 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-03-15T18:09:01.843Z,1647367741.843 [Default:CheckIn] Stopped
2022-03-15T18:09:01.843Z,1647367741.843 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-03-15T18:09:01.843Z,1647367741.843 [Default:CheckIn](INFO): Running loop #16
2022-03-15T18:09:01.843Z,1647367741.843 [Default:CheckIn] Running Loop=16
2022-03-15T18:09:01.843Z,1647367741.843 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-03-15T18:09:01.843Z,1647367741.843 [Default:CheckIn:Read_GPS] Running Loop=1
2022-03-15T18:09:03.845Z,1647367743.845 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180903.00,A,3647.74765,N,12151.12697,W,12.538,267.92,150322,,,D*44
2022-03-15T18:09:03.847Z,1647367743.847 [NAL9602](INFO): GPS fix at 20220315T180903: (36.795794, -121.852116)
2022-03-15T18:09:03.879Z,1647367743.879 [Default:CheckIn:Read_GPS] Stopped
2022-03-15T18:09:03.879Z,1647367743.879 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-03-15T18:09:11.242Z,1647367751.242 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220315T163209/Courier0049.lzma
2022-03-15T18:09:12.244Z,1647367752.244 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Courier0049.lzma.bak
2022-03-15T18:09:12.244Z,1647367752.244 [DataOverHttps](INFO): SBD MOMSN=16572924
2022-03-15T18:09:20.001Z,1647367760.001 [NAL9602](INFO): SBD MO Status=0, MOMSN=17898, MT Status=0, MTMSN=0
2022-03-15T18:09:20.001Z,1647367760.001 [NAL9602](INFO): No messages in MT queue
2022-03-15T18:09:28.722Z,1647367768.722 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20220315T163209/Express0050.lzma
2022-03-15T18:09:29.724Z,1647367769.724 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Express0050.lzma.bak
2022-03-15T18:09:29.724Z,1647367769.724 [DataOverHttps](INFO): SBD MOMSN=16572927
2022-03-15T18:09:30.923Z,1647367770.923 [Default:CheckIn:Read_Iridium] Stopped
2022-03-15T18:09:30.923Z,1647367770.923 [Default:CheckIn:C.Wait] Running Loop=1
2022-03-15T18:09:30.923Z,1647367770.923 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-03-15T18:09:50.703Z,1647367790.703 [NAL9602](INFO): Not Powering down - fast GPS
2022-03-15T18:13:00.058Z,1647367980.058 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-03-15T18:13:02.067Z,1647367982.067 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.247559
2022-03-15T18:13:14.603Z,1647367994.603 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002689
2022-03-15T18:14:31.517Z,1647368071.517 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-03-15T18:14:31.517Z,1647368071.517 [Default:CheckIn:C.Wait] Stopped
2022-03-15T18:14:31.517Z,1647368071.517 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-03-15T18:14:31.517Z,1647368071.517 [Default:CheckIn:D] Running Loop=1
2022-03-15T18:14:31.917Z,1647368071.917 [Default:CheckIn:D] Stopped
2022-03-15T18:14:31.917Z,1647368071.917 [Default:CheckIn:E] Running Loop=1
2022-03-15T18:14:32.334Z,1647368072.334 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 98.432340 min 
2022-03-15T18:14:32.334Z,1647368072.334 [Default:CheckIn:E] Stopped
2022-03-15T18:14:32.334Z,1647368072.334 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-03-15T18:14:32.334Z,1647368072.334 [Default:CheckIn] Stopped
2022-03-15T18:14:32.334Z,1647368072.334 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-03-15T18:14:32.334Z,1647368072.334 [Default:CheckIn](INFO): Running loop #17
2022-03-15T18:14:32.335Z,1647368072.335 [Default:CheckIn] Running Loop=17
2022-03-15T18:14:32.335Z,1647368072.335 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-03-15T18:14:32.335Z,1647368072.335 [Default:CheckIn:Read_GPS] Running Loop=1
2022-03-15T18:14:34.337Z,1647368074.337 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181433.00,A,3647.86975,N,12151.19613,W,0.350,259.38,150322,,,D*78
2022-03-15T18:14:34.347Z,1647368074.347 [NAL9602](INFO): GPS fix at 20220315T181433: (36.797829, -121.853269)
2022-03-15T18:14:34.358Z,1647368074.358 [Default:CheckIn:Read_GPS] Stopped
2022-03-15T18:14:34.358Z,1647368074.358 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-03-15T18:14:41.965Z,1647368081.965 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220315T163209/Courier0052.lzma
2022-03-15T18:14:42.968Z,1647368082.968 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Courier0052.lzma.bak
2022-03-15T18:14:42.968Z,1647368082.968 [DataOverHttps](INFO): SBD MOMSN=16572946
2022-03-15T18:14:59.334Z,1647368099.334 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220315T163209/Express0053.lzma
2022-03-15T18:15:00.336Z,1647368100.336 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Express0053.lzma.bak
2022-03-15T18:15:00.336Z,1647368100.336 [DataOverHttps](INFO): SBD MOMSN=16572949
2022-03-15T18:15:01.812Z,1647368101.812 [Default:CheckIn:Read_Iridium] Stopped
2022-03-15T18:15:01.812Z,1647368101.812 [Default:CheckIn:C.Wait] Running Loop=1
2022-03-15T18:15:01.812Z,1647368101.812 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-03-15T18:15:05.119Z,1647368105.119 [NAL9602](INFO): SBD MO Status=0, MOMSN=17899, MT Status=0, MTMSN=0
2022-03-15T18:15:05.119Z,1647368105.119 [NAL9602](INFO): No messages in MT queue
2022-03-15T18:15:35.743Z,1647368135.743 [NAL9602](INFO): Not Powering down - fast GPS
2022-03-15T18:16:07.434Z,1647368167.434 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-03-15T18:16:09.444Z,1647368169.444 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.256626
2022-03-15T18:16:23.446Z,1647368183.446 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002794
2022-03-15T18:18:21.099Z,1647368301.099 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2022-03-15T18:20:02.481Z,1647368402.481 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-03-15T18:20:02.481Z,1647368402.481 [Default:CheckIn:C.Wait] Stopped
2022-03-15T18:20:02.481Z,1647368402.481 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-03-15T18:20:02.481Z,1647368402.481 [Default:CheckIn:D] Running Loop=1
2022-03-15T18:20:02.869Z,1647368402.869 [Default:CheckIn:D] Stopped
2022-03-15T18:20:02.869Z,1647368402.869 [Default:CheckIn:E] Running Loop=1
2022-03-15T18:20:03.294Z,1647368403.294 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 103.948201 min 
2022-03-15T18:20:03.294Z,1647368403.294 [Default:CheckIn:E] Stopped
2022-03-15T18:20:03.295Z,1647368403.295 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-03-15T18:20:03.295Z,1647368403.295 [Default:CheckIn] Stopped
2022-03-15T18:20:03.295Z,1647368403.295 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-03-15T18:20:03.295Z,1647368403.295 [Default:CheckIn](INFO): Running loop #18
2022-03-15T18:20:03.295Z,1647368403.295 [Default:CheckIn] Running Loop=18
2022-03-15T18:20:03.295Z,1647368403.295 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-03-15T18:20:03.295Z,1647368403.295 [Default:CheckIn:Read_GPS] Running Loop=1
2022-03-15T18:20:05.289Z,1647368405.289 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182004.00,A,3647.89370,N,12151.21168,W,1.886,272.73,150322,,,D*7C
2022-03-15T18:20:05.291Z,1647368405.291 [NAL9602](INFO): GPS fix at 20220315T182004: (36.798228, -121.853528)
2022-03-15T18:20:05.373Z,1647368405.373 [Default:CheckIn:Read_GPS] Stopped
2022-03-15T18:20:05.373Z,1647368405.373 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-03-15T18:20:16.343Z,1647368416.343 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-03-15T18:20:17.816Z,1647368417.816 [NAL9602](INFO): SBD MO Status=0, MOMSN=17900, MT Status=0, MTMSN=0
2022-03-15T18:20:17.816Z,1647368417.816 [NAL9602](INFO): No messages in MT queue
2022-03-15T18:20:18.351Z,1647368418.351 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.239319
2022-03-15T18:20:37.315Z,1647368437.315 [NAL9602](INFO): SBD MO Status=1, MOMSN=17901, MT Status=0, MTMSN=0
2022-03-15T18:20:37.369Z,1647368437.369 [NAL9602](INFO): Sent 70 bytes from file Logs/20220315T163209/Courier0055.lzma
2022-03-15T18:20:37.370Z,1647368437.370 [NAL9602](INFO): Packets left to send: 0
2022-03-15T18:20:49.474Z,1647368449.474 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-03-15T18:20:59.601Z,1647368459.601 [NAL9602](INFO): SBD MO Status=1, MOMSN=17902, MT Status=0, MTMSN=0
2022-03-15T18:20:59.655Z,1647368459.655 [NAL9602](INFO): Sent 130 bytes from file Logs/20220315T163209/Express0056.lzma
2022-03-15T18:20:59.655Z,1647368459.655 [NAL9602](INFO): Packets left to send: 0
2022-03-15T18:21:05.406Z,1647368465.406 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002698
2022-03-15T18:21:06.469Z,1647368466.469 [NAL9602](INFO): SBD MO Status=0, MOMSN=17903, MT Status=0, MTMSN=0
2022-03-15T18:21:06.540Z,1647368466.540 [Default:CheckIn:Read_Iridium] Stopped
2022-03-15T18:21:06.540Z,1647368466.540 [Default:CheckIn:C.Wait] Running Loop=1
2022-03-15T18:21:06.540Z,1647368466.540 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-03-15T18:21:37.171Z,1647368497.171 [NAL9602](INFO): Not Powering down - fast GPS
2022-03-15T18:24:38.363Z,1647368678.363 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.879269
2022-03-15T18:25:10.490Z,1647368710.490 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-03-15T18:25:44.199Z,1647368744.199 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002673
2022-03-15T18:26:07.133Z,1647368767.133 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-03-15T18:26:07.134Z,1647368767.134 [Default:CheckIn:C.Wait] Stopped
2022-03-15T18:26:07.134Z,1647368767.134 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-03-15T18:26:07.135Z,1647368767.135 [Default:CheckIn:D] Running Loop=1
2022-03-15T18:26:07.509Z,1647368767.509 [Default:CheckIn:D] Stopped
2022-03-15T18:26:07.509Z,1647368767.509 [Default:CheckIn:E] Running Loop=1
2022-03-15T18:26:07.918Z,1647368767.918 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 110.025529 min 
2022-03-15T18:26:07.919Z,1647368767.919 [Default:CheckIn:E] Stopped
2022-03-15T18:26:07.919Z,1647368767.919 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-03-15T18:26:07.919Z,1647368767.919 [Default:CheckIn] Stopped
2022-03-15T18:26:07.919Z,1647368767.919 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-03-15T18:26:07.919Z,1647368767.919 [Default:CheckIn](INFO): Running loop #19
2022-03-15T18:26:07.919Z,1647368767.919 [Default:CheckIn] Running Loop=19
2022-03-15T18:26:07.919Z,1647368767.919 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-03-15T18:26:07.919Z,1647368767.919 [Default:CheckIn:Read_GPS] Running Loop=1
2022-03-15T18:26:09.925Z,1647368769.925 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182609.00,A,3647.82116,N,12150.83282,W,2.371,61.71,150322,,,D*42
2022-03-15T18:26:09.937Z,1647368769.937 [NAL9602](INFO): GPS fix at 20220315T182609: (36.797019, -121.847214)
2022-03-15T18:26:09.953Z,1647368769.953 [Default:CheckIn:Read_GPS] Stopped
2022-03-15T18:26:09.953Z,1647368769.953 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-03-15T18:26:27.293Z,1647368787.293 [NAL9602](INFO): SBD MO Status=0, MOMSN=17904, MT Status=0, MTMSN=0
2022-03-15T18:26:27.293Z,1647368787.293 [NAL9602](INFO): No messages in MT queue
2022-03-15T18:26:40.954Z,1647368800.954 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-03-15T18:26:58.003Z,1647368818.003 [NAL9602](INFO): Not Powering down - fast GPS
2022-03-15T18:26:59.028Z,1647368819.028 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.240604
2022-03-15T18:27:13.845Z,1647368833.845 [NAL9602](INFO): SBD MO Status=1, MOMSN=17905, MT Status=0, MTMSN=0
2022-03-15T18:27:13.910Z,1647368833.910 [NAL9602](INFO): Sent 72 bytes from file Logs/20220315T163209/Courier0058.lzma
2022-03-15T18:27:13.911Z,1647368833.911 [NAL9602](INFO): Packets left to send: 0
2022-03-15T18:27:32.126Z,1647368852.126 [NAL9602](INFO): SBD MO Status=1, MOMSN=17906, MT Status=0, MTMSN=0
2022-03-15T18:27:32.180Z,1647368852.180 [NAL9602](INFO): Sent 142 bytes from file Logs/20220315T163209/Express0059.lzma
2022-03-15T18:27:32.180Z,1647368852.180 [NAL9602](INFO): Packets left to send: 0
2022-03-15T18:27:42.221Z,1647368862.221 [NAL9602](INFO): SBD MO Status=0, MOMSN=17907, MT Status=0, MTMSN=0
2022-03-15T18:27:42.315Z,1647368862.315 [Default:CheckIn:Read_Iridium] Stopped
2022-03-15T18:27:42.315Z,1647368862.315 [Default:CheckIn:C.Wait] Running Loop=1
2022-03-15T18:27:42.315Z,1647368862.315 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-03-15T18:28:12.917Z,1647368892.917 [NAL9602](INFO): Not Powering down - fast GPS
2022-03-15T18:28:41.019Z,1647368921.019 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-03-15T18:29:13.718Z,1647368953.718 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002676
2022-03-15T18:32:42.813Z,1647369162.813 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-03-15T18:32:42.813Z,1647369162.813 [Default:CheckIn:C.Wait] Stopped
2022-03-15T18:32:42.813Z,1647369162.813 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-03-15T18:32:42.813Z,1647369162.813 [Default:CheckIn:D] Running Loop=1
2022-03-15T18:32:43.235Z,1647369163.235 [Default:CheckIn:D] Stopped
2022-03-15T18:32:43.235Z,1647369163.235 [Default:CheckIn:E] Running Loop=1
2022-03-15T18:32:43.614Z,1647369163.614 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 116.620964 min 
2022-03-15T18:32:43.614Z,1647369163.614 [Default:CheckIn:E] Stopped
2022-03-15T18:32:43.615Z,1647369163.615 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-03-15T18:32:43.615Z,1647369163.615 [Default:CheckIn] Stopped
2022-03-15T18:32:43.615Z,1647369163.615 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-03-15T18:32:43.615Z,1647369163.615 [Default:CheckIn](INFO): Running loop #20
2022-03-15T18:32:43.615Z,1647369163.615 [Default:CheckIn] Running Loop=20
2022-03-15T18:32:43.615Z,1647369163.615 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-03-15T18:32:43.615Z,1647369163.615 [Default:CheckIn:Read_GPS] Running Loop=1
2022-03-15T18:32:45.627Z,1647369165.627 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183244.00,A,3647.85717,N,12150.62087,W,4.549,81.07,150322,,,A*47
2022-03-15T18:32:45.629Z,1647369165.629 [NAL9602](INFO): GPS fix at 20220315T183244: (36.797620, -121.843681)
2022-03-15T18:32:45.640Z,1647369165.640 [Default:CheckIn:Read_GPS] Stopped
2022-03-15T18:32:45.640Z,1647369165.640 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-03-15T18:32:53.261Z,1647369173.261 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220315T163209/Courier0061.lzma
2022-03-15T18:32:54.264Z,1647369174.264 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Courier0061.lzma.bak
2022-03-15T18:32:54.265Z,1647369174.265 [DataOverHttps](INFO): SBD MOMSN=16573012
2022-03-15T18:33:10.550Z,1647369190.550 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220315T163209/Express0062.lzma
2022-03-15T18:33:11.552Z,1647369191.552 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Express0062.lzma.bak
2022-03-15T18:33:11.552Z,1647369191.552 [DataOverHttps](INFO): SBD MOMSN=16573015
2022-03-15T18:33:12.703Z,1647369192.703 [Default:CheckIn:Read_Iridium] Stopped
2022-03-15T18:33:12.703Z,1647369192.703 [Default:CheckIn:C.Wait] Running Loop=1
2022-03-15T18:33:12.703Z,1647369192.703 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-03-15T18:33:15.113Z,1647369195.113 [NAL9602](INFO): SBD MO Status=0, MOMSN=17908, MT Status=0, MTMSN=0
2022-03-15T18:33:15.113Z,1647369195.113 [NAL9602](INFO): No messages in MT queue
2022-03-15T18:33:45.819Z,1647369225.819 [NAL9602](INFO): Not Powering down - fast GPS
2022-03-15T18:38:13.436Z,1647369493.436 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-03-15T18:38:13.436Z,1647369493.436 [Default:CheckIn:C.Wait] Stopped
2022-03-15T18:38:13.436Z,1647369493.436 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-03-15T18:38:13.436Z,1647369493.436 [Default:CheckIn:D] Running Loop=1
2022-03-15T18:38:13.763Z,1647369493.763 [Default:CheckIn:D] Stopped
2022-03-15T18:38:13.763Z,1647369493.763 [Default:CheckIn:E] Running Loop=1
2022-03-15T18:38:14.145Z,1647369494.145 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 122.129769 min 
2022-03-15T18:38:14.146Z,1647369494.146 [Default:CheckIn:E] Stopped
2022-03-15T18:38:14.146Z,1647369494.146 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-03-15T18:38:14.146Z,1647369494.146 [Default:CheckIn] Stopped
2022-03-15T18:38:14.146Z,1647369494.146 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-03-15T18:38:14.146Z,1647369494.146 [Default:CheckIn](INFO): Running loop #21
2022-03-15T18:38:14.146Z,1647369494.146 [Default:CheckIn] Running Loop=21
2022-03-15T18:38:14.146Z,1647369494.146 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-03-15T18:38:14.147Z,1647369494.147 [Default:CheckIn:Read_GPS] Running Loop=1
2022-03-15T18:38:16.149Z,1647369496.149 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183815.00,A,3647.84331,N,12150.56089,W,0.914,172.85,150322,,,D*73
2022-03-15T18:38:16.151Z,1647369496.151 [NAL9602](INFO): GPS fix at 20220315T183815: (36.797388, -121.842681)
2022-03-15T18:38:16.190Z,1647369496.190 [Default:CheckIn:Read_GPS] Stopped
2022-03-15T18:38:16.191Z,1647369496.191 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-03-15T18:38:26.822Z,1647369506.822 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220315T163209/Courier0064.lzma
2022-03-15T18:38:27.824Z,1647369507.824 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Courier0064.lzma.bak
2022-03-15T18:38:27.824Z,1647369507.824 [DataOverHttps](INFO): SBD MOMSN=16573024
2022-03-15T18:38:33.521Z,1647369513.521 [NAL9602](INFO): SBD MO Status=0, MOMSN=17909, MT Status=0, MTMSN=0
2022-03-15T18:38:33.521Z,1647369513.521 [NAL9602](INFO): No messages in MT queue
2022-03-15T18:38:44.166Z,1647369524.166 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220315T163209/Express0065.lzma
2022-03-15T18:38:45.168Z,1647369525.168 [DataOverHttps](INFO): Moved sent file to Logs/20220315T163209/Express0065.lzma.bak
2022-03-15T18:38:45.168Z,1647369525.168 [DataOverHttps](INFO): SBD MOMSN=16573027
2022-03-15T18:38:46.463Z,1647369526.463 [Default:CheckIn:Read_Iridium] Stopped
2022-03-15T18:38:46.463Z,1647369526.463 [Default:CheckIn:C.Wait] Running Loop=1
2022-03-15T18:38:46.463Z,1647369526.463 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-03-15T18:38:54.191Z,1647369534.191 [DataOverHttps](IMPORTANT): SBD MTMSN=20220315T183853
2022-03-15T18:39:01.714Z,1647369541.714 [DataOverHttps](INFO): Received command: restart logs