2023-06-26T15:49:18.755Z,1687794558.755 [Supervisor](DEBUG): Initializing supervisor. 2023-06-26T15:49:18.759Z,1687794558.759 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2023-06-26T15:49:18.760Z,1687794558.760 [SyncHandler](INFO): Protected caller Thread ID is 839 2023-06-26T15:49:18.760Z,1687794558.760 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2023-06-26T15:49:18.761Z,1687794558.761 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2023-06-26T15:49:18.762Z,1687794558.762 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 840 2023-06-26T15:49:18.766Z,1687794558.766 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2023-06-26T15:49:18.783Z,1687794558.783 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2023-06-26T15:49:18.784Z,1687794558.784 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2023-06-26T15:49:18.784Z,1687794558.784 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 841 2023-06-26T15:49:18.788Z,1687794558.788 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2023-06-26T15:49:18.789Z,1687794558.789 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2023-06-26T15:49:18.790Z,1687794558.790 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 842 2023-06-26T15:49:18.792Z,1687794558.792 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2023-06-26T15:49:18.793Z,1687794558.793 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2023-06-26T15:49:18.794Z,1687794558.794 [logger ThreadHandler](INFO): Protected caller Thread ID is 843 2023-06-26T15:49:18.797Z,1687794558.797 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2023-06-26T15:49:18.798Z,1687794558.798 [Supervisor](INFO): Looking for Config files in directory: Config/ 2023-06-26T15:49:18.802Z,1687794558.802 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2023-06-26T15:49:18.899Z,1687794558.899 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2023-06-26T15:49:18.901Z,1687794558.901 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2023-06-26T15:49:19.580Z,1687794559.580 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2023-06-26T15:49:19.582Z,1687794559.582 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2023-06-26T15:49:19.804Z,1687794559.804 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2023-06-26T15:49:19.805Z,1687794559.805 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2023-06-26T15:49:19.930Z,1687794559.930 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2023-06-26T15:49:20.059Z,1687794560.059 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2023-06-26T15:49:20.061Z,1687794560.061 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2023-06-26T15:49:20.142Z,1687794560.142 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2023-06-26T15:49:20.249Z,1687794560.249 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2023-06-26T15:49:20.249Z,1687794560.249 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2023-06-26T15:49:20.620Z,1687794560.620 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2023-06-26T15:49:20.620Z,1687794560.620 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2023-06-26T15:49:21.092Z,1687794561.092 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2023-06-26T15:49:21.094Z,1687794561.094 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2023-06-26T15:49:21.311Z,1687794561.311 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2023-06-26T15:49:21.311Z,1687794561.311 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2023-06-26T15:49:21.510Z,1687794561.510 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2023-06-26T15:49:21.512Z,1687794561.512 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2023-06-26T15:49:22.015Z,1687794562.015 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2023-06-26T15:49:22.509Z,1687794562.509 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2023-06-26T15:49:22.872Z,1687794562.872 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2023-06-26T15:49:22.873Z,1687794562.873 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2023-06-26T15:49:23.086Z,1687794563.086 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2023-06-26T15:49:23.087Z,1687794563.087 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2023-06-26T15:49:23.455Z,1687794563.455 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2023-06-26T15:49:23.455Z,1687794563.455 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2023-06-26T15:49:23.794Z,1687794563.794 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2023-06-26T15:49:23.796Z,1687794563.796 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/ 2023-06-26T15:49:23.799Z,1687794563.799 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg 2023-06-26T15:49:23.883Z,1687794563.883 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg 2023-06-26T15:49:24.039Z,1687794564.039 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg 2023-06-26T15:49:24.140Z,1687794564.140 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg 2023-06-26T15:49:24.225Z,1687794564.225 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg 2023-06-26T15:49:24.318Z,1687794564.318 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg 2023-06-26T15:49:24.428Z,1687794564.428 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg 2023-06-26T15:49:24.691Z,1687794564.691 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2023-06-26T15:49:24.692Z,1687794564.692 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg 2023-06-26T15:49:24.786Z,1687794564.786 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg 2023-06-26T15:49:24.885Z,1687794564.885 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg 2023-06-26T15:49:25.023Z,1687794565.023 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg 2023-06-26T15:49:25.124Z,1687794565.124 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2023-06-26T15:49:25.136Z,1687794565.136 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2023-06-26T15:49:25.262Z,1687794565.262 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2023-06-26T15:49:25.263Z,1687794565.263 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2023-06-26T15:49:25.330Z,1687794565.330 [VerticalControl](DEBUG): Construct VerticalControl. 2023-06-26T15:49:25.390Z,1687794565.390 [VerticalControl] Loaded 2023-06-26T15:49:25.391Z,1687794565.391 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2023-06-26T15:49:25.394Z,1687794565.394 [HorizontalControl](DEBUG): Construct HorizontalControl. 2023-06-26T15:49:25.434Z,1687794565.434 [HorizontalControl] Loaded 2023-06-26T15:49:25.435Z,1687794565.435 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2023-06-26T15:49:25.437Z,1687794565.437 [SpeedControl](DEBUG): Construct SpeedControl. 2023-06-26T15:49:25.440Z,1687794565.440 [SpeedControl] Loaded 2023-06-26T15:49:25.440Z,1687794565.440 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2023-06-26T15:49:25.443Z,1687794565.443 [LoopControl](DEBUG): Construct LoopControl. 2023-06-26T15:49:25.443Z,1687794565.443 [LoopControl] Loaded 2023-06-26T15:49:25.444Z,1687794565.444 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2023-06-26T15:49:25.444Z,1687794565.444 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2023-06-26T15:49:25.445Z,1687794565.445 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2023-06-26T15:49:25.513Z,1687794565.513 [DepthRateCalculator] Loaded 2023-06-26T15:49:25.514Z,1687794565.514 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2023-06-26T15:49:25.518Z,1687794565.518 [PitchRateCalculator] Loaded 2023-06-26T15:49:25.519Z,1687794565.519 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2023-06-26T15:49:25.529Z,1687794565.529 [SpeedCalculator] Loaded 2023-06-26T15:49:25.529Z,1687794565.529 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2023-06-26T15:49:25.533Z,1687794565.533 [YawRateCalculator] Loaded 2023-06-26T15:49:25.533Z,1687794565.533 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2023-06-26T15:49:25.552Z,1687794565.552 [ElevatorOffsetCalculator] Loaded 2023-06-26T15:49:25.552Z,1687794565.552 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2023-06-26T15:49:25.552Z,1687794565.552 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2023-06-26T15:49:25.553Z,1687794565.553 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2023-06-26T15:49:25.596Z,1687794565.596 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2023-06-26T15:49:25.597Z,1687794565.597 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2023-06-26T15:49:25.678Z,1687794565.678 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2023-06-26T15:49:25.679Z,1687794565.679 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2023-06-26T15:49:26.036Z,1687794566.036 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2023-06-26T15:49:26.037Z,1687794566.037 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2023-06-26T15:49:26.220Z,1687794566.220 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2023-06-26T15:49:26.220Z,1687794566.220 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2023-06-26T15:49:26.982Z,1687794566.982 [AHRS_M2] Loaded 2023-06-26T15:49:26.983Z,1687794566.983 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2023-06-26T15:49:27.232Z,1687794567.232 [BackseatComponent] Loaded 2023-06-26T15:49:27.232Z,1687794567.232 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2023-06-26T15:49:27.233Z,1687794567.233 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 4098B4E0 2023-06-26T15:49:27.234Z,1687794567.234 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 926 2023-06-26T15:49:27.236Z,1687794567.236 [LcmUniversalReporter] Loaded 2023-06-26T15:49:27.237Z,1687794567.237 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2023-06-26T15:49:28.045Z,1687794568.045 [BPC1] Loaded 2023-06-26T15:49:28.046Z,1687794568.046 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2023-06-26T15:49:28.185Z,1687794568.185 [DataOverHttps] Loaded 2023-06-26T15:49:28.186Z,1687794568.186 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2023-06-26T15:49:28.187Z,1687794568.187 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409BB4E0 2023-06-26T15:49:28.187Z,1687794568.187 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 927 2023-06-26T15:49:28.208Z,1687794568.208 [Depth_Keller] Loaded 2023-06-26T15:49:28.208Z,1687794568.208 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2023-06-26T15:49:28.213Z,1687794568.213 [DropWeight] Loaded 2023-06-26T15:49:28.213Z,1687794568.213 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2023-06-26T15:49:28.276Z,1687794568.276 [NAL9602] Loaded 2023-06-26T15:49:28.276Z,1687794568.276 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2023-06-26T15:49:28.305Z,1687794568.305 [Onboard] Loaded 2023-06-26T15:49:28.306Z,1687794568.306 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2023-06-26T15:49:28.307Z,1687794568.307 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409EB4E0 2023-06-26T15:49:28.307Z,1687794568.307 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 928 2023-06-26T15:49:28.313Z,1687794568.313 [PowerOnly](INFO): Adding load control power supply at /dev/loadB1 2023-06-26T15:49:28.324Z,1687794568.324 [PowerOnly] Loaded 2023-06-26T15:49:28.325Z,1687794568.325 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread. 2023-06-26T15:49:28.336Z,1687794568.336 [Power24vConverter] Loaded 2023-06-26T15:49:28.336Z,1687794568.336 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2023-06-26T15:49:28.350Z,1687794568.350 [Radio_Surface] Loaded 2023-06-26T15:49:28.350Z,1687794568.350 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2023-06-26T15:49:28.351Z,1687794568.351 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40A1B4E0 2023-06-26T15:49:28.351Z,1687794568.351 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 929 2023-06-26T15:49:28.395Z,1687794568.395 [RDI_Pathfinder] Loaded 2023-06-26T15:49:28.396Z,1687794568.396 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread. 2023-06-26T15:49:28.488Z,1687794568.488 [DAT] Loaded 2023-06-26T15:49:28.488Z,1687794568.488 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2023-06-26T15:49:28.489Z,1687794568.489 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40A4B4E0 2023-06-26T15:49:28.490Z,1687794568.490 [DAT ThreadHandler](INFO): Protected caller Thread ID is 930 2023-06-26T15:49:28.490Z,1687794568.490 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2023-06-26T15:49:28.491Z,1687794568.491 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2023-06-26T15:49:29.297Z,1687794569.297 [DeadReckonUsingMultipleVelocitySources] Loaded 2023-06-26T15:49:29.298Z,1687794569.298 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2023-06-26T15:49:29.312Z,1687794569.312 [NavChart] Loaded 2023-06-26T15:49:29.312Z,1687794569.312 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2023-06-26T15:49:29.318Z,1687794569.318 [UniversalFixResidualReporter] Loaded 2023-06-26T15:49:29.318Z,1687794569.318 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2023-06-26T15:49:29.318Z,1687794569.318 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2023-06-26T15:49:29.320Z,1687794569.320 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2023-06-26T15:49:29.504Z,1687794569.504 [SBIT](DEBUG): Construct Startup Built In Test. 2023-06-26T15:49:29.513Z,1687794569.513 [SBIT] Loaded 2023-06-26T15:49:29.513Z,1687794569.513 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2023-06-26T15:49:29.516Z,1687794569.516 [IBIT](DEBUG): Construct Initiated Built In Test. 2023-06-26T15:49:29.529Z,1687794569.529 [IBIT] Loaded 2023-06-26T15:49:29.529Z,1687794569.529 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2023-06-26T15:49:29.535Z,1687794569.535 [CBIT](DEBUG): Construct Continuous Built In Test. 2023-06-26T15:49:29.640Z,1687794569.640 [CBIT] Loaded 2023-06-26T15:49:29.640Z,1687794569.640 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2023-06-26T15:49:29.641Z,1687794569.641 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2023-06-26T15:49:29.642Z,1687794569.642 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2023-06-26T15:49:29.800Z,1687794569.800 [BuoyancyServo] Loaded 2023-06-26T15:49:29.801Z,1687794569.801 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2023-06-26T15:49:29.821Z,1687794569.821 [ElevatorServo] Loaded 2023-06-26T15:49:29.821Z,1687794569.821 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2023-06-26T15:49:29.841Z,1687794569.841 [MassServo] Loaded 2023-06-26T15:49:29.841Z,1687794569.841 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2023-06-26T15:49:29.860Z,1687794569.860 [RudderServo] Loaded 2023-06-26T15:49:29.860Z,1687794569.860 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2023-06-26T15:49:29.877Z,1687794569.877 [ThrusterServo] Loaded 2023-06-26T15:49:29.878Z,1687794569.878 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2023-06-26T15:49:29.878Z,1687794569.878 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2023-06-26T15:49:29.879Z,1687794569.879 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2023-06-26T15:49:29.895Z,1687794569.895 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2023-06-26T15:49:29.895Z,1687794569.895 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2023-06-26T15:49:30.115Z,1687794570.115 [CTD_Seabird] Loaded 2023-06-26T15:49:30.115Z,1687794570.115 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2023-06-26T15:49:30.116Z,1687794570.116 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B934E0 2023-06-26T15:49:30.117Z,1687794570.117 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 931 2023-06-26T15:49:30.137Z,1687794570.137 [PAR_Licor] Loaded 2023-06-26T15:49:30.137Z,1687794570.137 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2023-06-26T15:49:30.168Z,1687794570.168 [WetLabsBB2FL] Loaded 2023-06-26T15:49:30.169Z,1687794570.169 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2023-06-26T15:49:30.170Z,1687794570.170 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40BC34E0 2023-06-26T15:49:30.170Z,1687794570.170 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 932 2023-06-26T15:49:30.190Z,1687794570.190 [WetLabsUBAT] Loaded 2023-06-26T15:49:30.190Z,1687794570.190 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread. 2023-06-26T15:49:30.191Z,1687794570.191 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40BF34E0 2023-06-26T15:49:30.191Z,1687794570.191 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 933 2023-06-26T15:49:30.192Z,1687794570.192 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2023-06-26T15:49:30.199Z,1687794570.199 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2023-06-26T15:49:30.201Z,1687794570.201 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2023-06-26T15:49:30.213Z,1687794570.213 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2023-06-26T15:49:30.214Z,1687794570.214 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C234E0 2023-06-26T15:49:30.214Z,1687794570.214 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 934 2023-06-26T15:49:30.219Z,1687794570.219 [Supervisor](INFO): Main Thread ID is 829 2023-06-26T15:49:30.219Z,1687794570.219 [Supervisor](DEBUG): Running supervisor. 2023-06-26T15:49:30.219Z,1687794570.219 [CommandExec ThreadHandler](INFO): Handler Thread ID is 935 2023-06-26T15:49:30.220Z,1687794570.220 [CommandExec](INFO): Initializing the command executive. 2023-06-26T15:49:30.221Z,1687794570.221 [CommandLine ThreadHandler](INFO): Handler Thread ID is 936 2023-06-26T15:49:30.224Z,1687794570.224 [controlThread ThreadHandler](INFO): Handler Thread ID is 937 2023-06-26T15:49:30.224Z,1687794570.224 [controlThread](DEBUG): Initializing ControlThread 2023-06-26T15:49:30.225Z,1687794570.225 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2023-06-26T15:49:30.227Z,1687794570.227 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2023-06-26T15:49:30.227Z,1687794570.227 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2023-06-26T15:49:30.228Z,1687794570.228 [LoopControl](DEBUG): Initialize LoopControlComponent. 2023-06-26T15:49:30.228Z,1687794570.228 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2023-06-26T15:49:30.228Z,1687794570.228 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2023-06-26T15:49:30.229Z,1687794570.229 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2023-06-26T15:49:30.229Z,1687794570.229 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2023-06-26T15:49:30.229Z,1687794570.229 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2023-06-26T15:49:30.234Z,1687794570.234 [NavChart](DEBUG): Initialize NavChart Navigation. 2023-06-26T15:49:30.235Z,1687794570.235 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2023-06-26T15:49:30.235Z,1687794570.235 [SBIT](INFO): Initialize SBIT Component. 2023-06-26T15:49:30.236Z,1687794570.236 [SBIT](IMPORTANT): git: 2023-06-23_A 2023-06-26T15:49:30.236Z,1687794570.236 [SBIT](INFO): git hash: d5c7c3780b11f381d18531846c6551c96d01c0bb 2023-06-26T15:49:30.236Z,1687794570.236 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2023-06-26T15:49:30.237Z,1687794570.237 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019 Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021 2023-06-26T15:49:30.238Z,1687794570.238 [SBIT](INFO): Beginning SBIT in 46.000000 seconds. 2023-06-26T15:49:30.239Z,1687794570.239 [IBIT](INFO): Initialize IBIT Component. 2023-06-26T15:49:30.240Z,1687794570.240 [CBIT](DEBUG): Initialize CBIT Component. 2023-06-26T15:49:30.241Z,1687794570.241 [logger ThreadHandler](INFO): Handler Thread ID is 938 2023-06-26T15:49:30.252Z,1687794570.252 [CBIT](DEBUG): Initialized mux pins. 2023-06-26T15:49:30.252Z,1687794570.252 [CBIT](DEBUG): Initializing the watchdog timer. 2023-06-26T15:49:30.260Z,1687794570.260 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 939 2023-06-26T15:49:30.272Z,1687794570.272 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 940 2023-06-26T15:49:30.273Z,1687794570.273 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2023-06-26T15:49:30.276Z,1687794570.276 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2023-06-26T15:49:30.276Z,1687794570.276 [CBIT](DEBUG): Initializing heartbeat. 2023-06-26T15:49:30.284Z,1687794570.284 [Onboard ThreadHandler](INFO): Handler Thread ID is 941 2023-06-26T15:49:30.302Z,1687794570.302 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 942 2023-06-26T15:49:30.320Z,1687794570.320 [DAT ThreadHandler](INFO): Handler Thread ID is 943 2023-06-26T15:49:30.321Z,1687794570.321 [DAT](INFO): Powering up 2023-06-26T15:49:30.321Z,1687794570.321 [DAT](DEBUG): Initializing DAT. 2023-06-26T15:49:30.326Z,1687794570.326 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 945 2023-06-26T15:49:30.326Z,1687794570.326 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2023-06-26T15:49:30.332Z,1687794570.332 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 947 2023-06-26T15:49:30.338Z,1687794570.338 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 949 2023-06-26T15:49:30.340Z,1687794570.340 [WetLabsBB2FL](INFO): Powering up 2023-06-26T15:49:30.342Z,1687794570.342 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 951 2023-06-26T15:49:30.345Z,1687794570.345 [WetLabsUBAT](INFO): Powering up 2023-06-26T15:49:30.348Z,1687794570.348 [CBIT](DEBUG): Deactivating GF circuits. 2023-06-26T15:49:30.348Z,1687794570.348 [CBIT](DEBUG): Deactivating emergency mode. 2023-06-26T15:49:30.351Z,1687794570.351 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2023-06-26T15:49:30.351Z,1687794570.351 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2023-06-26T15:49:30.351Z,1687794570.351 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2023-06-26T15:49:30.351Z,1687794570.351 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2023-06-26T15:49:30.351Z,1687794570.351 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2023-06-26T15:49:30.351Z,1687794570.351 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2023-06-26T15:49:30.352Z,1687794570.352 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2023-06-26T15:49:30.352Z,1687794570.352 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2023-06-26T15:49:30.388Z,1687794570.388 [CBIT](DEBUG): Backplane powered. 2023-06-26T15:49:30.393Z,1687794570.393 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml 2023-06-26T15:49:30.429Z,1687794570.429 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2023-06-26T15:49:30.446Z,1687794570.446 [MissionManager](DEBUG): 2023-06-26T15:49:30.446Z,1687794570.446 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml 2023-06-26T15:49:30.548Z,1687794570.548 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2023-06-26T15:49:30.549Z,1687794570.549 [Default:A.Wait](DEBUG): Construct Wait. 2023-06-26T15:49:30.552Z,1687794570.552 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2023-06-26T15:49:30.593Z,1687794570.593 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2023-06-26T15:49:30.595Z,1687794570.595 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2023-06-26T15:49:30.608Z,1687794570.608 [Default:E.Execute](DEBUG): Construct Execute. 2023-06-26T15:49:30.625Z,1687794570.625 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2023-06-26T15:49:30.630Z,1687794570.630 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,PowerOnly,Power24vConverter,RDI_Pathfinder,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2023-06-26T15:49:30.653Z,1687794570.653 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2023-06-26T15:49:30.708Z,1687794570.708 [Radio_Surface](INFO): Powering up 2023-06-26T15:49:30.806Z,1687794570.806 [Depth_Keller](ERROR): Pressure or depth reading out of range: -1.000394 decibar, -0.993016 m 2023-06-26T15:49:30.808Z,1687794570.808 [PowerOnly](INFO): Powering up loadControl 2023-06-26T15:49:30.825Z,1687794570.825 [Power24vConverter](INFO): Powering up. 2023-06-26T15:49:30.826Z,1687794570.826 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format 2023-06-26T15:49:30.838Z,1687794570.838 [DepthRateCalculator](ERROR): Depth measurement is not active 2023-06-26T15:49:30.890Z,1687794570.890 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2023-06-26T15:49:30.896Z,1687794570.896 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2023-06-26T15:49:30.897Z,1687794570.897 [ElevatorServo](DEBUG): Initializing EZServoServo. 2023-06-26T15:49:30.904Z,1687794570.904 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2023-06-26T15:49:30.905Z,1687794570.905 [MassServo](DEBUG): Initializing EZServoServo. 2023-06-26T15:49:30.912Z,1687794570.912 [MassServo](DEBUG): Initializing MassServo. 2023-06-26T15:49:30.913Z,1687794570.913 [RudderServo](DEBUG): Initializing EZServoServo. 2023-06-26T15:49:30.920Z,1687794570.920 [RudderServo](DEBUG): Initializing RudderServo. 2023-06-26T15:49:30.921Z,1687794570.921 [ThrusterServo](DEBUG): Initializing EZServoServo. 2023-06-26T15:49:30.928Z,1687794570.928 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2023-06-26T15:49:32.948Z,1687794572.948 [WetLabsBB2FL](INFO): Powering down 2023-06-26T15:49:39.672Z,1687794579.672 [WetLabsUBAT](INFO): Powering down 2023-06-26T15:49:42.416Z,1687794582.416 [DAT](INFO): DAT read: 2023-06-26T15:49:42.418Z,1687794582.418 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2023-06-26T15:49:44.181Z,1687794584.181 [DAT](INFO): DAT read: MF Frequency Band 2023-06-26T15:49:44.182Z,1687794584.182 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2023-06-26T15:49:44.183Z,1687794584.183 [DAT](INFO): DAT read: Jun 26 2023 15:49:38 2023-06-26T15:49:45.441Z,1687794585.441 [DAT](INFO): DAT read: Features enabled [Bearing] 2023-06-26T15:49:45.442Z,1687794585.442 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2023-06-26T15:49:45.445Z,1687794585.445 [DAT](INFO): commRate: 800 2023-06-26T15:49:47.508Z,1687794587.508 [DAT](INFO): entering command mode 2023-06-26T15:49:47.708Z,1687794587.708 [DAT](INFO): DAT read: 2023-06-26T15:49:47.709Z,1687794587.709 [DAT](INFO): DAT read: user:1> 2023-06-26T15:49:47.709Z,1687794587.709 [DAT](INFO): setting verbose to 3 2023-06-26T15:49:47.961Z,1687794587.961 [DAT](INFO): DAT read: user:1> 2023-06-26T15:49:47.962Z,1687794587.962 [DAT](INFO): DAT read: Verbose | 3 2023-06-26T15:49:47.962Z,1687794587.962 [DAT](INFO): set verbose to 3 2023-06-26T15:49:47.963Z,1687794587.963 [DAT](INFO): setting DatVerbose to 27440 2023-06-26T15:49:48.213Z,1687794588.213 [DAT](INFO): DAT read: user:2> 2023-06-26T15:49:48.214Z,1687794588.214 [DAT](INFO): DAT read: DatVerbose | 27440 2023-06-26T15:49:48.214Z,1687794588.214 [DAT](INFO): set DatVerbose to 27440 2023-06-26T15:49:48.215Z,1687794588.215 [DAT](INFO): setting transmit power to 8 2023-06-26T15:49:48.466Z,1687794588.466 [DAT](INFO): DAT read: user:3> 2023-06-26T15:49:48.469Z,1687794588.469 [DAT](INFO): DAT read: TxPower | 8 (Max) 2023-06-26T15:49:48.469Z,1687794588.469 [DAT](INFO): set transmit power to 8 2023-06-26T15:49:48.469Z,1687794588.469 [DAT](INFO): setting local address to 10 2023-06-26T15:49:48.717Z,1687794588.717 [DAT](INFO): DAT read: user:4> 2023-06-26T15:49:48.718Z,1687794588.718 [DAT](INFO): DAT read: LocalAddr | 10 2023-06-26T15:49:48.718Z,1687794588.718 [DAT](INFO): set local address to 10 2023-06-26T15:49:48.719Z,1687794588.719 [DAT](INFO): Setting time to: 15:49:48 And date to:6/26/2023 2023-06-26T15:49:48.989Z,1687794588.989 [DAT](INFO): DAT read: user:5> 2023-06-26T15:49:48.990Z,1687794588.990 [DAT](INFO): DAT read: Mon Jun 26, 2023 15:49:48 2023-06-26T15:49:48.990Z,1687794588.990 [DAT](INFO): Local DAT time set to Mon Jun 26, 2023 15:49:48 2023-06-26T15:49:58.513Z,1687794598.513 [NAL9602](INFO): Powering up NAL9602 2023-06-26T15:50:09.421Z,1687794609.421 [NAL9602](INFO): NAL9602 initialized 2023-06-26T15:50:16.751Z,1687794616.751 [SBIT](IMPORTANT): Beginning Startup BIT 2023-06-26T15:50:16.759Z,1687794616.759 [CBIT](IMPORTANT): Beginning ground fault scan 2023-06-26T15:50:24.202Z,1687794624.202 [CBIT](INFO): A/D timeout, 6 tries over 163 ms 2023-06-26T15:50:28.081Z,1687794628.081 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.008123 CHAN A1 (24V): 0.002613 CHAN A2 (12V): -0.006441 CHAN A3 (5V): -0.001666 CHAN B0 (3.3V): nan CHAN B1 (3.15aV): 0.000579 CHAN B2 (3.15bV): -0.000467 CHAN B3 (GND): 0.002201 OPEN: -0.003573 Full Scale: +/- 1 mA 2023-06-26T15:51:10.485Z,1687794670.485 [SBIT](IMPORTANT): SBIT PASSED 2023-06-26T15:51:10.486Z,1687794670.486 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2023-06-26T15:51:10.486Z,1687794670.486 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count; 2023-06-26T15:51:10.486Z,1687794670.486 [SBIT](IMPORTANT): CBIT.gf24Offset=143 microampere; 2023-06-26T15:51:10.487Z,1687794670.487 [SBIT](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 0.300000 liter_per_second; 2023-06-26T15:51:10.487Z,1687794670.487 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=295.498135 cubic_centimeter; 2023-06-26T15:51:10.487Z,1687794670.487 [SBIT](IMPORTANT): VerticalControl.massDefault=6.676639 millimeter; 2023-06-26T15:51:10.487Z,1687794670.487 [SBIT](IMPORTANT): WetLabsUBAT.loadAtStartup=1 bool; 2023-06-26T15:51:10.858Z,1687794670.858 [MissionManager](IMPORTANT): Started mission Startup 2023-06-26T15:51:10.858Z,1687794670.858 [Startup] Running Loop=1 2023-06-26T15:51:10.859Z,1687794670.859 [Startup](DEBUG): Aggregate::initialize Startup 2023-06-26T15:51:10.859Z,1687794670.859 [Startup:A.GoToSurface] Running Loop=1 2023-06-26T15:51:10.859Z,1687794670.859 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2023-06-26T15:51:10.859Z,1687794670.859 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2023-06-26T15:51:10.860Z,1687794670.860 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2023-06-26T15:51:10.860Z,1687794670.860 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2023-06-26T15:51:10.861Z,1687794670.861 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2023-06-26T15:51:10.861Z,1687794670.861 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2023-06-26T15:51:10.862Z,1687794670.862 [Startup:StartupSatComms] Running Loop=1 2023-06-26T15:51:10.863Z,1687794670.863 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2023-06-26T15:51:10.863Z,1687794670.863 [Startup:StartupSatComms:A] Running Loop=1 2023-06-26T15:51:11.260Z,1687794671.260 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2023-06-26T15:52:10.641Z,1687794730.641 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2023-06-26T15:52:11.098Z,1687794731.098 [Startup:StartupSatComms:A](INFO): Timed out from 2023-06-26T15:51:10.9Z 2023-06-26T15:52:11.098Z,1687794731.098 [Startup:StartupSatComms:A] Stopped 2023-06-26T15:52:11.098Z,1687794731.098 [Startup:StartupSatComms:B] Running Loop=1 2023-06-26T15:52:11.465Z,1687794731.465 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2023-06-26T15:52:30.495Z,1687794750.495 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2023-06-26T15:52:30.495Z,1687794750.495 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-06-26T15:52:30.519Z,1687794750.519 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-06-26T15:52:30.879Z,1687794750.879 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-06-26T15:52:30.881Z,1687794750.881 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2023-06-26T15:53:11.238Z,1687794791.238 [Startup:StartupSatComms:B](INFO): Timed out from 2023-06-26T15:52:11.1Z 2023-06-26T15:53:11.238Z,1687794791.238 [Startup:StartupSatComms:B] Stopped 2023-06-26T15:53:11.238Z,1687794791.238 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2023-06-26T15:53:11.238Z,1687794791.238 [Startup:StartupSatComms] Stopped 2023-06-26T15:53:11.238Z,1687794791.238 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2023-06-26T15:53:11.239Z,1687794791.239 [Startup](INFO): Completed Startup 2023-06-26T15:53:11.239Z,1687794791.239 [MissionManager](INFO): Startup is completed. 2023-06-26T15:53:11.239Z,1687794791.239 [MissionManager](INFO): Uninitializing Mission Startup 2023-06-26T15:53:11.239Z,1687794791.239 [Startup] Stopped 2023-06-26T15:53:11.239Z,1687794791.239 [Startup](DEBUG): Aggregate::uninitialize Startup 2023-06-26T15:53:11.239Z,1687794791.239 [Startup:A.GoToSurface] Stopped 2023-06-26T15:53:11.240Z,1687794791.240 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2023-06-26T15:53:11.654Z,1687794791.654 [MissionManager](IMPORTANT): Started mission Default 2023-06-26T15:53:11.654Z,1687794791.654 [Default] Running Loop=1 2023-06-26T15:53:11.654Z,1687794791.654 [Default](DEBUG): Aggregate::initialize Default 2023-06-26T15:53:11.654Z,1687794791.654 [Default:B.GoToSurface] Running Loop=1 2023-06-26T15:53:11.654Z,1687794791.654 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2023-06-26T15:53:11.655Z,1687794791.655 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2023-06-26T15:53:11.655Z,1687794791.655 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2023-06-26T15:53:11.655Z,1687794791.655 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2023-06-26T15:53:11.660Z,1687794791.660 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2023-06-26T15:53:11.660Z,1687794791.660 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2023-06-26T15:53:11.661Z,1687794791.661 [Default:A.Wait] Running Loop=1 2023-06-26T15:53:11.661Z,1687794791.661 [Default:A.Wait](DEBUG): Initialize Wait Component. 2023-06-26T15:53:23.895Z,1687794803.895 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005096 2023-06-26T15:53:24.986Z,1687794804.986 [Default:A.Wait](INFO): Done Waiting. 2023-06-26T15:53:24.987Z,1687794804.987 [Default:A.Wait] Stopped 2023-06-26T15:53:24.987Z,1687794804.987 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T15:53:25.377Z,1687794805.377 [Default:CheckIn] Running Loop=1 2023-06-26T15:53:25.377Z,1687794805.377 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T15:53:25.377Z,1687794805.377 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T15:53:25.783Z,1687794805.783 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2023-06-26T15:53:46.005Z,1687794826.005 [NAL9602](INFO): SBD MO Status=2, MOMSN=26240, MT Status=2, MTMSN=0 2023-06-26T15:53:46.005Z,1687794826.005 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-06-26T15:55:07.311Z,1687794907.311 [NAL9602](INFO): SBD MO Status=0, MOMSN=26240, MT Status=0, MTMSN=0 2023-06-26T15:55:07.311Z,1687794907.311 [NAL9602](INFO): No messages in MT queue 2023-06-26T15:55:31.441Z,1687794931.441 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2023-06-26T15:55:31.441Z,1687794931.441 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-06-26T15:55:31.452Z,1687794931.452 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-06-26T15:55:31.858Z,1687794931.858 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-06-26T15:55:31.858Z,1687794931.858 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2023-06-26T15:55:34.647Z,1687794934.647 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155533.00,A,3648.17114,N,12147.28559,W,0.175,0.00,260623,,,A*71 2023-06-26T15:55:34.650Z,1687794934.650 [NAL9602](INFO): GPS fix at 20230626T155533: (36.802852, -121.788093) 2023-06-26T15:55:34.719Z,1687794934.719 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T15:55:34.719Z,1687794934.719 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T15:55:35.090Z,1687794935.090 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2023-06-26T15:55:44.293Z,1687794944.293 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20230626T145543/Courier0016.lzma 2023-06-26T15:55:45.294Z,1687794945.294 [DataOverHttps](INFO): Moved sent file to Logs/20230626T145543/Courier0016.lzma.bak 2023-06-26T15:55:45.294Z,1687794945.294 [DataOverHttps](INFO): SBD MOMSN=18432192 2023-06-26T15:56:03.356Z,1687794963.356 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20230626T154918/Courier0000.lzma 2023-06-26T15:56:04.358Z,1687794964.358 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0000.lzma.bak 2023-06-26T15:56:04.358Z,1687794964.358 [DataOverHttps](INFO): SBD MOMSN=18432194 2023-06-26T15:56:06.969Z,1687794966.969 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T15:56:20.724Z,1687794980.724 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20230626T154918/Courier0004.lzma 2023-06-26T15:56:21.726Z,1687794981.726 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0004.lzma.bak 2023-06-26T15:56:21.726Z,1687794981.726 [DataOverHttps](INFO): SBD MOMSN=18432198 2023-06-26T15:56:42.066Z,1687795002.066 [DataOverHttps](INFO): Sending 260 bytes from file Logs/20230626T145543/Express0017.lzma 2023-06-26T15:56:43.038Z,1687795003.038 [DataOverHttps](INFO): Moved sent file to Logs/20230626T145543/Express0017.lzma.bak 2023-06-26T15:56:43.038Z,1687795003.038 [DataOverHttps](INFO): SBD MOMSN=18432201 2023-06-26T15:56:59.558Z,1687795019.558 [DataOverHttps](INFO): Sending 827 bytes from file Logs/20230626T154918/Express0001.lzma 2023-06-26T15:57:00.558Z,1687795020.558 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0001.lzma.bak 2023-06-26T15:57:00.558Z,1687795020.558 [DataOverHttps](INFO): SBD MOMSN=18432221 2023-06-26T15:57:17.088Z,1687795037.088 [DataOverHttps](INFO): Sending 220 bytes from file Logs/20230626T154918/Express0005.lzma 2023-06-26T15:57:18.090Z,1687795038.090 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0005.lzma.bak 2023-06-26T15:57:18.090Z,1687795038.090 [DataOverHttps](INFO): SBD MOMSN=18432239 2023-06-26T15:57:19.354Z,1687795039.354 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T15:57:19.354Z,1687795039.354 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T15:57:19.354Z,1687795039.354 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T15:57:52.882Z,1687795072.882 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2023-06-26T15:57:52.890Z,1687795072.890 [BPC1](INFO): Received data from all battery sticks. 2023-06-26T16:02:19.995Z,1687795339.995 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T16:02:19.995Z,1687795339.995 [Default:CheckIn:C.Wait] Stopped 2023-06-26T16:02:19.995Z,1687795339.995 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T16:02:19.995Z,1687795339.995 [Default:CheckIn:D] Running Loop=1 2023-06-26T16:02:20.461Z,1687795340.461 [Default:CheckIn:D] Stopped 2023-06-26T16:02:20.461Z,1687795340.461 [Default:CheckIn:E] Running Loop=1 2023-06-26T16:02:20.831Z,1687795340.831 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 9.146777 min 2023-06-26T16:02:20.831Z,1687795340.831 [Default:CheckIn:E] Stopped 2023-06-26T16:02:20.831Z,1687795340.831 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T16:02:20.831Z,1687795340.831 [Default:CheckIn] Stopped 2023-06-26T16:02:20.831Z,1687795340.831 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T16:02:20.831Z,1687795340.831 [Default:CheckIn](INFO): Running loop #2 2023-06-26T16:02:20.831Z,1687795340.831 [Default:CheckIn] Running Loop=2 2023-06-26T16:02:20.831Z,1687795340.831 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T16:02:20.832Z,1687795340.832 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T16:02:22.827Z,1687795342.827 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160222.00,A,3648.13885,N,12147.22686,W,0.039,63.04,260623,,,D*43 2023-06-26T16:02:22.829Z,1687795342.829 [NAL9602](INFO): GPS fix at 20230626T160222: (36.802314, -121.787114) 2023-06-26T16:02:22.877Z,1687795342.877 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T16:02:22.878Z,1687795342.878 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T16:02:33.393Z,1687795353.393 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20230626T154918/Courier0007.lzma 2023-06-26T16:02:34.397Z,1687795354.397 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0007.lzma.bak 2023-06-26T16:02:34.398Z,1687795354.398 [DataOverHttps](INFO): SBD MOMSN=18432243 2023-06-26T16:02:37.403Z,1687795357.403 [NAL9602](INFO): SBD MO Status=0, MOMSN=26241, MT Status=0, MTMSN=0 2023-06-26T16:02:37.403Z,1687795357.403 [NAL9602](INFO): No messages in MT queue 2023-06-26T16:02:50.835Z,1687795370.835 [DataOverHttps](INFO): Sending 162 bytes from file Logs/20230626T154918/Express0008.lzma 2023-06-26T16:02:51.838Z,1687795371.838 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0008.lzma.bak 2023-06-26T16:02:51.838Z,1687795371.838 [DataOverHttps](INFO): SBD MOMSN=18432246 2023-06-26T16:02:53.173Z,1687795373.173 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T16:02:53.173Z,1687795373.173 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T16:02:53.173Z,1687795373.173 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T16:03:08.109Z,1687795388.109 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T16:04:49.681Z,1687795489.681 [DataOverHttps](IMPORTANT): SBD MTMSN=20230626T160449 2023-06-26T16:04:59.604Z,1687795499.604 [DataOverHttps](INFO): Received command: failc 2023-06-26T16:04:59.632Z,1687795499.632 [CommandExec](IMPORTANT): got command failComponent 2023-06-26T16:04:59.633Z,1687795499.633 [CommandExec](IMPORTANT): Failed components: 2023-06-26T16:04:59.633Z,1687795499.633 [CommandExec](IMPORTANT): No failed Components. 2023-06-26T16:05:00.605Z,1687795500.605 [DataOverHttps](IMPORTANT): SBD MTMSN=20230626T160500 2023-06-26T16:05:08.307Z,1687795508.307 [DataOverHttps](INFO): Received command: ibit 2023-06-26T16:05:08.385Z,1687795508.385 [CommandExec](IMPORTANT): got command ibit 2023-06-26T16:05:08.616Z,1687795508.616 [IBIT](IMPORTANT): Beginning Initiated BIT 2023-06-26T16:05:08.616Z,1687795508.616 [IBIT](IMPORTANT): Beginning control surface checks. 2023-06-26T16:05:08.619Z,1687795508.619 [CBIT](IMPORTANT): Beginning ground fault scan 2023-06-26T16:05:10.191Z,1687795510.191 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160509.00,A,3648.13979,N,12147.22802,W,0.117,63.04,260623,,,D*40 2023-06-26T16:05:10.193Z,1687795510.193 [NAL9602](INFO): GPS fix at 20230626T160509: (36.802330, -121.787134) 2023-06-26T16:05:19.504Z,1687795519.504 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.010203 CHAN A1 (24V): 0.001942 CHAN A2 (12V): -0.007147 CHAN A3 (5V): -0.001768 CHAN B0 (3.3V): 0.000372 CHAN B1 (3.15aV): 0.000248 CHAN B2 (3.15bV): 0.000163 CHAN B3 (GND): 0.001922 OPEN: 0.004982 Full Scale: +/- 1 mA 2023-06-26T16:05:20.698Z,1687795520.698 [NAL9602](INFO): SBD MO Status=0, MOMSN=26242, MT Status=0, MTMSN=0 2023-06-26T16:05:20.699Z,1687795520.699 [NAL9602](INFO): No messages in MT queue 2023-06-26T16:05:21.911Z,1687795521.911 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160521.00,A,3648.13998,N,12147.22789,W,0.058,63.04,260623,,,D*43 2023-06-26T16:05:21.923Z,1687795521.923 [NAL9602](INFO): GPS fix at 20230626T160521: (36.802333, -121.787132) 2023-06-26T16:05:24.752Z,1687795524.752 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160524.00,A,3648.13996,N,12147.22769,W,0.097,63.04,260623,,,D*45 2023-06-26T16:05:24.754Z,1687795524.754 [NAL9602](INFO): GPS fix at 20230626T160524: (36.802333, -121.787128) 2023-06-26T16:05:27.568Z,1687795527.569 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160527.00,A,3648.13993,N,12147.22759,W,0.000,63.04,260623,,,D*4E 2023-06-26T16:05:27.571Z,1687795527.571 [NAL9602](INFO): GPS fix at 20230626T160527: (36.802332, -121.787126) 2023-06-26T16:05:30.794Z,1687795530.794 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160530.00,A,3648.13988,N,12147.22753,W,0.019,63.04,260623,,,D*40 2023-06-26T16:05:30.796Z,1687795530.796 [NAL9602](INFO): GPS fix at 20230626T160530: (36.802331, -121.787126) 2023-06-26T16:05:33.625Z,1687795533.625 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160533.00,A,3648.13990,N,12147.22756,W,0.019,63.04,260623,,,D*4F 2023-06-26T16:05:33.627Z,1687795533.627 [NAL9602](INFO): GPS fix at 20230626T160533: (36.802332, -121.787126) 2023-06-26T16:05:36.863Z,1687795536.863 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160536.00,A,3648.13990,N,12147.22752,W,0.019,63.04,260623,,,D*4E 2023-06-26T16:05:36.865Z,1687795536.865 [NAL9602](INFO): GPS fix at 20230626T160536: (36.802332, -121.787125) 2023-06-26T16:05:39.683Z,1687795539.683 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160539.00,A,3648.13991,N,12147.22752,W,0.078,63.04,260623,,,D*47 2023-06-26T16:05:39.685Z,1687795539.685 [NAL9602](INFO): GPS fix at 20230626T160539: (36.802332, -121.787125) 2023-06-26T16:05:42.523Z,1687795542.523 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160542.00,A,3648.13994,N,12147.22753,W,0.019,63.04,260623,,,D*48 2023-06-26T16:05:42.530Z,1687795542.530 [NAL9602](INFO): GPS fix at 20230626T160542: (36.802332, -121.787126) 2023-06-26T16:05:45.744Z,1687795545.744 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160545.00,A,3648.13995,N,12147.22761,W,0.078,63.04,260623,,,D*48 2023-06-26T16:05:45.747Z,1687795545.747 [NAL9602](INFO): GPS fix at 20230626T160545: (36.802332, -121.787127) 2023-06-26T16:05:48.570Z,1687795548.570 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160548.00,A,3648.13994,N,12147.22761,W,0.097,63.04,260623,,,D*45 2023-06-26T16:05:48.572Z,1687795548.572 [NAL9602](INFO): GPS fix at 20230626T160548: (36.802332, -121.787127) 2023-06-26T16:05:51.807Z,1687795551.807 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160551.00,A,3648.13988,N,12147.22751,W,0.039,63.04,260623,,,D*47 2023-06-26T16:05:51.810Z,1687795551.810 [NAL9602](INFO): GPS fix at 20230626T160551: (36.802331, -121.787125) 2023-06-26T16:05:54.635Z,1687795554.635 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160554.00,A,3648.13985,N,12147.22739,W,0.136,63.04,260623,,,D*4F 2023-06-26T16:05:54.638Z,1687795554.638 [NAL9602](INFO): GPS fix at 20230626T160554: (36.802331, -121.787123) 2023-06-26T16:05:55.091Z,1687795555.091 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 5 Latitude: 36.802330 Longitude: -121.787125 2023-06-26T16:05:55.459Z,1687795555.459 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 0.000000 Voltage: 16.690001 2023-06-26T16:05:55.459Z,1687795555.459 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah 2023-06-26T16:05:55.459Z,1687795555.459 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V 2023-06-26T16:05:55.875Z,1687795555.875 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2023-06-26T16:05:55.875Z,1687795555.875 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2023-06-26T16:05:55.876Z,1687795555.876 [IBIT](IMPORTANT): Pressure:7.870332 PSI 2023-06-26T16:05:55.876Z,1687795555.876 [IBIT](IMPORTANT): Humidity:23.617386 % 2023-06-26T16:05:56.266Z,1687795556.266 [IBIT](IMPORTANT): Vehicle Pitch:-0.097142 degrees 2023-06-26T16:05:56.266Z,1687795556.266 [IBIT](IMPORTANT): Vehicle Roll:2.100495 degrees 2023-06-26T16:05:56.267Z,1687795556.267 [IBIT](IMPORTANT): Vehicle Heading:24.488174 degrees 2023-06-26T16:05:56.718Z,1687795556.718 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2023-06-26T16:05:56.719Z,1687795556.719 [IBIT](IMPORTANT): buoyancyNeutral: 295.498138 cc 2023-06-26T16:05:56.724Z,1687795556.724 [IBIT](IMPORTANT): massDefault: 0.667664 cm 2023-06-26T16:05:56.724Z,1687795556.724 [IBIT](IMPORTANT): stopDepth: 215.000000 m 2023-06-26T16:05:56.725Z,1687795556.725 [IBIT](IMPORTANT): abortDepth: 255.000000 m 2023-06-26T16:05:56.725Z,1687795556.725 [IBIT](IMPORTANT): IBIT PASSED 2023-06-26T16:06:27.379Z,1687795587.379 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T16:07:53.848Z,1687795673.848 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T16:07:53.848Z,1687795673.848 [Default:CheckIn:C.Wait] Stopped 2023-06-26T16:07:53.848Z,1687795673.848 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T16:07:53.848Z,1687795673.848 [Default:CheckIn:D] Running Loop=1 2023-06-26T16:07:54.256Z,1687795674.256 [Default:CheckIn:D] Stopped 2023-06-26T16:07:54.256Z,1687795674.256 [Default:CheckIn:E] Running Loop=1 2023-06-26T16:07:54.679Z,1687795674.679 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 14.710024 min 2023-06-26T16:07:54.679Z,1687795674.679 [Default:CheckIn:E] Stopped 2023-06-26T16:07:54.679Z,1687795674.679 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T16:07:54.679Z,1687795674.679 [Default:CheckIn] Stopped 2023-06-26T16:07:54.679Z,1687795674.679 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T16:07:54.679Z,1687795674.679 [Default:CheckIn](INFO): Running loop #3 2023-06-26T16:07:54.680Z,1687795674.680 [Default:CheckIn] Running Loop=3 2023-06-26T16:07:54.680Z,1687795674.680 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T16:07:54.680Z,1687795674.680 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T16:07:56.663Z,1687795676.663 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160756.00,A,3648.13941,N,12147.22845,W,0.058,63.04,260623,,,D*4A 2023-06-26T16:07:56.665Z,1687795676.665 [NAL9602](INFO): GPS fix at 20230626T160756: (36.802323, -121.787141) 2023-06-26T16:07:56.732Z,1687795676.732 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T16:07:56.732Z,1687795676.732 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T16:08:04.775Z,1687795684.775 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230626T154918/Courier0010.lzma 2023-06-26T16:08:05.778Z,1687795685.778 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0010.lzma.bak 2023-06-26T16:08:05.778Z,1687795685.778 [DataOverHttps](INFO): SBD MOMSN=18432273 2023-06-26T16:08:12.445Z,1687795692.445 [NAL9602](INFO): SBD MO Status=0, MOMSN=26243, MT Status=0, MTMSN=0 2023-06-26T16:08:12.445Z,1687795692.445 [NAL9602](INFO): No messages in MT queue 2023-06-26T16:08:22.461Z,1687795702.461 [DataOverHttps](INFO): Sending 866 bytes from file Logs/20230626T154918/Express0011.lzma 2023-06-26T16:08:23.462Z,1687795703.462 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0011.lzma.bak 2023-06-26T16:08:23.462Z,1687795703.462 [DataOverHttps](INFO): SBD MOMSN=18432276 2023-06-26T16:08:43.151Z,1687795723.151 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20230626T154918/Express0014.lzma 2023-06-26T16:08:43.161Z,1687795723.161 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T16:08:44.154Z,1687795724.154 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0014.lzma.bak 2023-06-26T16:08:44.154Z,1687795724.154 [DataOverHttps](INFO): SBD MOMSN=18432306 2023-06-26T16:08:45.195Z,1687795725.195 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T16:08:45.196Z,1687795725.196 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T16:08:45.196Z,1687795725.196 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T16:11:26.476Z,1687795886.476 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2023-06-26T16:13:45.797Z,1687796025.797 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T16:13:45.797Z,1687796025.797 [Default:CheckIn:C.Wait] Stopped 2023-06-26T16:13:45.797Z,1687796025.797 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T16:13:45.797Z,1687796025.797 [Default:CheckIn:D] Running Loop=1 2023-06-26T16:13:46.195Z,1687796026.195 [Default:CheckIn:D] Stopped 2023-06-26T16:13:46.195Z,1687796026.195 [Default:CheckIn:E] Running Loop=1 2023-06-26T16:13:46.645Z,1687796026.645 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.575688 min 2023-06-26T16:13:46.645Z,1687796026.645 [Default:CheckIn:E] Stopped 2023-06-26T16:13:46.645Z,1687796026.645 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T16:13:46.645Z,1687796026.645 [Default:CheckIn] Stopped 2023-06-26T16:13:46.645Z,1687796026.645 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T16:13:46.645Z,1687796026.645 [Default:CheckIn](INFO): Running loop #4 2023-06-26T16:13:46.645Z,1687796026.645 [Default:CheckIn] Running Loop=4 2023-06-26T16:13:46.646Z,1687796026.646 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T16:13:46.646Z,1687796026.646 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T16:13:48.609Z,1687796028.609 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161348.00,A,3648.14072,N,12147.22709,W,0.019,63.04,260623,,,D*4C 2023-06-26T16:13:48.611Z,1687796028.611 [NAL9602](INFO): GPS fix at 20230626T161348: (36.802345, -121.787118) 2023-06-26T16:13:48.642Z,1687796028.642 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T16:13:48.642Z,1687796028.642 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T16:13:56.347Z,1687796036.347 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230626T154918/Courier0016.lzma 2023-06-26T16:13:57.350Z,1687796037.350 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0016.lzma.bak 2023-06-26T16:13:57.350Z,1687796037.350 [DataOverHttps](INFO): SBD MOMSN=18432316 2023-06-26T16:14:03.554Z,1687796043.554 [NAL9602](INFO): SBD MO Status=0, MOMSN=26244, MT Status=0, MTMSN=0 2023-06-26T16:14:03.555Z,1687796043.555 [NAL9602](INFO): No messages in MT queue 2023-06-26T16:14:13.723Z,1687796053.723 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230626T154918/Express0017.lzma 2023-06-26T16:14:14.726Z,1687796054.726 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0017.lzma.bak 2023-06-26T16:14:14.726Z,1687796054.726 [DataOverHttps](INFO): SBD MOMSN=18432319 2023-06-26T16:14:16.096Z,1687796056.096 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T16:14:16.096Z,1687796056.096 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T16:14:16.096Z,1687796056.096 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T16:14:34.265Z,1687796074.265 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T16:19:16.719Z,1687796356.719 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T16:19:16.719Z,1687796356.719 [Default:CheckIn:C.Wait] Stopped 2023-06-26T16:19:16.719Z,1687796356.719 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T16:19:16.724Z,1687796356.724 [Default:CheckIn:D] Running Loop=1 2023-06-26T16:19:17.090Z,1687796357.090 [Default:CheckIn:D] Stopped 2023-06-26T16:19:17.090Z,1687796357.090 [Default:CheckIn:E] Running Loop=1 2023-06-26T16:19:17.507Z,1687796357.507 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 26.090588 min 2023-06-26T16:19:17.507Z,1687796357.507 [Default:CheckIn:E] Stopped 2023-06-26T16:19:17.507Z,1687796357.507 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T16:19:17.507Z,1687796357.507 [Default:CheckIn] Stopped 2023-06-26T16:19:17.507Z,1687796357.507 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T16:19:17.507Z,1687796357.507 [Default:CheckIn](INFO): Running loop #5 2023-06-26T16:19:17.507Z,1687796357.507 [Default:CheckIn] Running Loop=5 2023-06-26T16:19:17.507Z,1687796357.507 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T16:19:17.507Z,1687796357.507 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T16:19:19.507Z,1687796359.507 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161919.00,A,3648.13906,N,12147.22580,W,0.039,63.04,260623,,,D*4E 2023-06-26T16:19:19.510Z,1687796359.510 [NAL9602](INFO): GPS fix at 20230626T161919: (36.802318, -121.787097) 2023-06-26T16:19:19.543Z,1687796359.543 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T16:19:19.543Z,1687796359.543 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T16:19:27.639Z,1687796367.639 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230626T154918/Courier0019.lzma 2023-06-26T16:19:28.642Z,1687796368.642 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0019.lzma.bak 2023-06-26T16:19:28.642Z,1687796368.642 [DataOverHttps](INFO): SBD MOMSN=18432329 2023-06-26T16:19:33.643Z,1687796373.643 [NAL9602](INFO): SBD MO Status=0, MOMSN=26245, MT Status=0, MTMSN=0 2023-06-26T16:19:33.643Z,1687796373.643 [NAL9602](INFO): No messages in MT queue 2023-06-26T16:19:44.947Z,1687796384.947 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230626T154918/Express0020.lzma 2023-06-26T16:19:45.950Z,1687796385.950 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0020.lzma.bak 2023-06-26T16:19:45.950Z,1687796385.950 [DataOverHttps](INFO): SBD MOMSN=18432332 2023-06-26T16:19:47.010Z,1687796387.010 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T16:19:47.010Z,1687796387.010 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T16:19:47.010Z,1687796387.010 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T16:20:04.355Z,1687796404.355 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T16:24:47.619Z,1687796687.619 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T16:24:47.619Z,1687796687.619 [Default:CheckIn:C.Wait] Stopped 2023-06-26T16:24:47.619Z,1687796687.619 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T16:24:47.619Z,1687796687.619 [Default:CheckIn:D] Running Loop=1 2023-06-26T16:24:48.025Z,1687796688.025 [Default:CheckIn:D] Stopped 2023-06-26T16:24:48.025Z,1687796688.025 [Default:CheckIn:E] Running Loop=1 2023-06-26T16:24:48.474Z,1687796688.474 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.606185 min 2023-06-26T16:24:48.474Z,1687796688.474 [Default:CheckIn:E] Stopped 2023-06-26T16:24:48.474Z,1687796688.474 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T16:24:48.474Z,1687796688.474 [Default:CheckIn] Stopped 2023-06-26T16:24:48.474Z,1687796688.474 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T16:24:48.475Z,1687796688.475 [Default:CheckIn](INFO): Running loop #6 2023-06-26T16:24:48.475Z,1687796688.475 [Default:CheckIn] Running Loop=6 2023-06-26T16:24:48.475Z,1687796688.475 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T16:24:48.475Z,1687796688.475 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T16:24:50.452Z,1687796690.452 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162450.00,A,3648.14624,N,12147.22634,W,0.272,38.64,260623,,,D*4C 2023-06-26T16:24:50.455Z,1687796690.455 [NAL9602](INFO): GPS fix at 20230626T162450: (36.802437, -121.787106) 2023-06-26T16:24:50.504Z,1687796690.504 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T16:24:50.504Z,1687796690.504 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T16:24:51.257Z,1687796691.257 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T16:24:51.257Z,1687796691.257 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T16:24:51.258Z,1687796691.258 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T16:26:29.015Z,1687796789.015 [NAL9602](INFO): SBD MO Status=0, MOMSN=26246, MT Status=0, MTMSN=0 2023-06-26T16:26:29.015Z,1687796789.015 [NAL9602](INFO): No messages in MT queue 2023-06-26T16:26:59.726Z,1687796819.726 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T16:29:51.836Z,1687796991.836 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T16:29:51.836Z,1687796991.836 [Default:CheckIn:C.Wait] Stopped 2023-06-26T16:29:51.836Z,1687796991.836 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T16:29:51.837Z,1687796991.837 [Default:CheckIn:D] Running Loop=1 2023-06-26T16:29:52.240Z,1687796992.240 [Default:CheckIn:D] Stopped 2023-06-26T16:29:52.240Z,1687796992.240 [Default:CheckIn:E] Running Loop=1 2023-06-26T16:29:52.641Z,1687796992.641 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2023-06-26T16:29:52.650Z,1687796992.650 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 36.676432 min 2023-06-26T16:29:52.651Z,1687796992.651 [Default:CheckIn:E] Stopped 2023-06-26T16:29:52.651Z,1687796992.651 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T16:29:52.651Z,1687796992.651 [Default:CheckIn] Stopped 2023-06-26T16:29:52.651Z,1687796992.651 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T16:29:52.651Z,1687796992.651 [Default:CheckIn](INFO): Running loop #7 2023-06-26T16:29:52.651Z,1687796992.651 [Default:CheckIn] Running Loop=7 2023-06-26T16:29:52.651Z,1687796992.651 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T16:29:52.651Z,1687796992.651 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T16:29:54.655Z,1687796994.655 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162954.00,A,3648.14912,N,12147.22359,W,0.058,38.64,260623,,,D*4B 2023-06-26T16:29:54.666Z,1687796994.666 [NAL9602](INFO): GPS fix at 20230626T162954: (36.802485, -121.787060) 2023-06-26T16:29:54.697Z,1687796994.697 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T16:29:54.697Z,1687796994.697 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T16:30:02.815Z,1687797002.815 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230626T154918/Courier0022.lzma 2023-06-26T16:30:03.818Z,1687797003.818 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0022.lzma.bak 2023-06-26T16:30:03.818Z,1687797003.818 [DataOverHttps](INFO): SBD MOMSN=18432460 2023-06-26T16:30:05.966Z,1687797005.966 [NAL9602](INFO): SBD MO Status=0, MOMSN=26247, MT Status=0, MTMSN=0 2023-06-26T16:30:05.967Z,1687797005.967 [NAL9602](INFO): No messages in MT queue 2023-06-26T16:30:20.087Z,1687797020.087 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230626T154918/Courier0025.lzma 2023-06-26T16:30:21.094Z,1687797021.094 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0025.lzma.bak 2023-06-26T16:30:21.094Z,1687797021.094 [DataOverHttps](INFO): SBD MOMSN=18432463 2023-06-26T16:30:36.705Z,1687797036.705 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T16:30:41.483Z,1687797041.483 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230626T154918/Express0023.lzma 2023-06-26T16:30:42.486Z,1687797042.486 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0023.lzma.bak 2023-06-26T16:30:42.486Z,1687797042.486 [DataOverHttps](INFO): SBD MOMSN=18432466 2023-06-26T16:30:52.488Z,1687797052.488 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2023-06-26T16:30:58.998Z,1687797058.998 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230626T154918/Express0026.lzma 2023-06-26T16:30:59.998Z,1687797059.998 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0026.lzma.bak 2023-06-26T16:30:59.998Z,1687797059.998 [DataOverHttps](INFO): SBD MOMSN=18432469 2023-06-26T16:31:01.356Z,1687797061.356 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T16:31:01.356Z,1687797061.356 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T16:31:01.356Z,1687797061.356 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T16:36:01.930Z,1687797361.930 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T16:36:01.930Z,1687797361.930 [Default:CheckIn:C.Wait] Stopped 2023-06-26T16:36:01.930Z,1687797361.930 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T16:36:01.930Z,1687797361.930 [Default:CheckIn:D] Running Loop=1 2023-06-26T16:36:02.341Z,1687797362.341 [Default:CheckIn:D] Stopped 2023-06-26T16:36:02.341Z,1687797362.341 [Default:CheckIn:E] Running Loop=1 2023-06-26T16:36:02.766Z,1687797362.766 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.844788 min 2023-06-26T16:36:02.766Z,1687797362.766 [Default:CheckIn:E] Stopped 2023-06-26T16:36:02.766Z,1687797362.766 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T16:36:02.766Z,1687797362.766 [Default:CheckIn] Stopped 2023-06-26T16:36:02.766Z,1687797362.766 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T16:36:02.766Z,1687797362.766 [Default:CheckIn](INFO): Running loop #8 2023-06-26T16:36:02.766Z,1687797362.766 [Default:CheckIn] Running Loop=8 2023-06-26T16:36:02.766Z,1687797362.766 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T16:36:02.766Z,1687797362.766 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T16:36:04.751Z,1687797364.751 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163604.00,A,3648.14902,N,12147.22171,W,0.039,159.29,260623,,,D*71 2023-06-26T16:36:04.753Z,1687797364.753 [NAL9602](INFO): GPS fix at 20230626T163604: (36.802484, -121.787029) 2023-06-26T16:36:04.804Z,1687797364.804 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T16:36:04.804Z,1687797364.804 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T16:36:12.779Z,1687797372.779 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230626T154918/Courier0028.lzma 2023-06-26T16:36:13.782Z,1687797373.782 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0028.lzma.bak 2023-06-26T16:36:13.782Z,1687797373.782 [DataOverHttps](INFO): SBD MOMSN=18432474 2023-06-26T16:36:24.607Z,1687797384.607 [NAL9602](INFO): SBD MO Status=0, MOMSN=26248, MT Status=0, MTMSN=0 2023-06-26T16:36:24.607Z,1687797384.607 [NAL9602](INFO): No messages in MT queue 2023-06-26T16:36:33.375Z,1687797393.375 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230626T154918/Express0029.lzma 2023-06-26T16:36:34.381Z,1687797394.381 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0029.lzma.bak 2023-06-26T16:36:34.381Z,1687797394.381 [DataOverHttps](INFO): SBD MOMSN=18432477 2023-06-26T16:36:35.528Z,1687797395.528 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T16:36:35.528Z,1687797395.528 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T16:36:35.528Z,1687797395.528 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T16:36:55.308Z,1687797415.308 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T16:41:36.127Z,1687797696.128 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T16:41:36.128Z,1687797696.128 [Default:CheckIn:C.Wait] Stopped 2023-06-26T16:41:36.128Z,1687797696.128 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T16:41:36.128Z,1687797696.128 [Default:CheckIn:D] Running Loop=1 2023-06-26T16:41:36.558Z,1687797696.558 [Default:CheckIn:D] Stopped 2023-06-26T16:41:36.558Z,1687797696.558 [Default:CheckIn:E] Running Loop=1 2023-06-26T16:41:36.941Z,1687797696.941 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.415068 min 2023-06-26T16:41:36.941Z,1687797696.941 [Default:CheckIn:E] Stopped 2023-06-26T16:41:36.941Z,1687797696.941 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T16:41:36.941Z,1687797696.941 [Default:CheckIn] Stopped 2023-06-26T16:41:36.941Z,1687797696.941 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T16:41:36.941Z,1687797696.941 [Default:CheckIn](INFO): Running loop #9 2023-06-26T16:41:36.941Z,1687797696.941 [Default:CheckIn] Running Loop=9 2023-06-26T16:41:36.941Z,1687797696.941 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T16:41:36.941Z,1687797696.941 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T16:41:38.947Z,1687797698.947 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164138.00,A,3648.14889,N,12147.22336,W,0.039,159.29,260623,,,D*7D 2023-06-26T16:41:38.950Z,1687797698.950 [NAL9602](INFO): GPS fix at 20230626T164138: (36.802481, -121.787056) 2023-06-26T16:41:38.962Z,1687797698.962 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T16:41:38.962Z,1687797698.962 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T16:41:47.071Z,1687797707.071 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230626T154918/Courier0031.lzma 2023-06-26T16:41:48.076Z,1687797708.076 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0031.lzma.bak 2023-06-26T16:41:48.076Z,1687797708.076 [DataOverHttps](INFO): SBD MOMSN=18432481 2023-06-26T16:42:04.847Z,1687797724.847 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230626T154918/Express0032.lzma 2023-06-26T16:42:05.850Z,1687797725.850 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0032.lzma.bak 2023-06-26T16:42:05.850Z,1687797725.850 [DataOverHttps](INFO): SBD MOMSN=18432484 2023-06-26T16:42:07.237Z,1687797727.237 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T16:42:07.237Z,1687797727.237 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T16:42:07.238Z,1687797727.238 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T16:42:11.271Z,1687797731.271 [NAL9602](INFO): SBD MO Status=0, MOMSN=26249, MT Status=0, MTMSN=0 2023-06-26T16:42:11.271Z,1687797731.271 [NAL9602](INFO): No messages in MT queue 2023-06-26T16:42:41.973Z,1687797761.973 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T16:45:22.482Z,1687797922.482 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2023-06-26T16:47:07.937Z,1687798027.937 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T16:47:07.937Z,1687798027.937 [Default:CheckIn:C.Wait] Stopped 2023-06-26T16:47:07.937Z,1687798027.937 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T16:47:07.937Z,1687798027.937 [Default:CheckIn:D] Running Loop=1 2023-06-26T16:47:08.361Z,1687798028.361 [Default:CheckIn:D] Stopped 2023-06-26T16:47:08.361Z,1687798028.361 [Default:CheckIn:E] Running Loop=1 2023-06-26T16:47:08.766Z,1687798028.766 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 53.945105 min 2023-06-26T16:47:08.767Z,1687798028.767 [Default:CheckIn:E] Stopped 2023-06-26T16:47:08.767Z,1687798028.767 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T16:47:08.767Z,1687798028.767 [Default:CheckIn] Stopped 2023-06-26T16:47:08.767Z,1687798028.767 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T16:47:08.767Z,1687798028.767 [Default:CheckIn](INFO): Running loop #10 2023-06-26T16:47:08.767Z,1687798028.767 [Default:CheckIn] Running Loop=10 2023-06-26T16:47:08.767Z,1687798028.767 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T16:47:08.767Z,1687798028.767 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T16:47:10.747Z,1687798030.747 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164710.00,A,3648.14970,N,12147.22343,W,0.039,159.29,260623,,,D*74 2023-06-26T16:47:10.749Z,1687798030.749 [NAL9602](INFO): GPS fix at 20230626T164710: (36.802495, -121.787057) 2023-06-26T16:47:10.796Z,1687798030.796 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T16:47:10.796Z,1687798030.796 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T16:47:18.431Z,1687798038.431 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230626T154918/Courier0034.lzma 2023-06-26T16:47:19.434Z,1687798039.434 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0034.lzma.bak 2023-06-26T16:47:19.434Z,1687798039.434 [DataOverHttps](INFO): SBD MOMSN=18432488 2023-06-26T16:47:22.881Z,1687798042.881 [NAL9602](INFO): SBD MO Status=0, MOMSN=26250, MT Status=0, MTMSN=0 2023-06-26T16:47:22.881Z,1687798042.881 [NAL9602](INFO): No messages in MT queue 2023-06-26T16:47:35.823Z,1687798055.823 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230626T154918/Express0035.lzma 2023-06-26T16:47:36.826Z,1687798056.826 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0035.lzma.bak 2023-06-26T16:47:36.826Z,1687798056.826 [DataOverHttps](INFO): SBD MOMSN=18432491 2023-06-26T16:47:37.843Z,1687798057.843 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T16:47:37.843Z,1687798057.843 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T16:47:37.843Z,1687798057.843 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T16:47:53.573Z,1687798073.573 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T16:48:38.448Z,1687798118.448 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2023-06-26T16:52:38.511Z,1687798358.511 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T16:52:38.511Z,1687798358.511 [Default:CheckIn:C.Wait] Stopped 2023-06-26T16:52:38.511Z,1687798358.511 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T16:52:38.511Z,1687798358.511 [Default:CheckIn:D] Running Loop=1 2023-06-26T16:52:38.906Z,1687798358.906 [Default:CheckIn:D] Stopped 2023-06-26T16:52:38.906Z,1687798358.906 [Default:CheckIn:E] Running Loop=1 2023-06-26T16:52:39.300Z,1687798359.300 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 59.454199 min 2023-06-26T16:52:39.300Z,1687798359.300 [Default:CheckIn:E] Stopped 2023-06-26T16:52:39.300Z,1687798359.300 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T16:52:39.300Z,1687798359.300 [Default:CheckIn] Stopped 2023-06-26T16:52:39.301Z,1687798359.301 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T16:52:39.301Z,1687798359.301 [Default:CheckIn](INFO): Running loop #11 2023-06-26T16:52:39.301Z,1687798359.301 [Default:CheckIn] Running Loop=11 2023-06-26T16:52:39.301Z,1687798359.301 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T16:52:39.301Z,1687798359.301 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T16:52:41.306Z,1687798361.306 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165241.00,A,3648.15015,N,12147.22248,W,0.039,159.29,260623,,,D*75 2023-06-26T16:52:41.308Z,1687798361.308 [NAL9602](INFO): GPS fix at 20230626T165241: (36.802503, -121.787041) 2023-06-26T16:52:41.320Z,1687798361.320 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T16:52:41.320Z,1687798361.320 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T16:52:49.279Z,1687798369.279 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230626T154918/Courier0037.lzma 2023-06-26T16:52:50.282Z,1687798370.282 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0037.lzma.bak 2023-06-26T16:52:50.282Z,1687798370.282 [DataOverHttps](INFO): SBD MOMSN=18432496 2023-06-26T16:53:06.699Z,1687798386.699 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230626T154918/Express0038.lzma 2023-06-26T16:53:07.702Z,1687798387.702 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0038.lzma.bak 2023-06-26T16:53:07.702Z,1687798387.702 [DataOverHttps](INFO): SBD MOMSN=18432499 2023-06-26T16:53:08.805Z,1687798388.805 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T16:53:08.805Z,1687798388.805 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T16:53:08.805Z,1687798388.805 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T16:54:00.489Z,1687798440.489 [NAL9602](INFO): SBD MO Status=0, MOMSN=26251, MT Status=0, MTMSN=0 2023-06-26T16:54:00.489Z,1687798440.489 [NAL9602](INFO): No messages in MT queue 2023-06-26T16:54:31.193Z,1687798471.193 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T16:58:09.363Z,1687798689.363 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T16:58:09.363Z,1687798689.363 [Default:CheckIn:C.Wait] Stopped 2023-06-26T16:58:09.363Z,1687798689.363 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T16:58:09.363Z,1687798689.363 [Default:CheckIn:D] Running Loop=1 2023-06-26T16:58:09.773Z,1687798689.773 [Default:CheckIn:D] Stopped 2023-06-26T16:58:09.773Z,1687798689.773 [Default:CheckIn:E] Running Loop=1 2023-06-26T16:58:10.172Z,1687798690.172 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 64.968640 min 2023-06-26T16:58:10.172Z,1687798690.172 [Default:CheckIn:E] Stopped 2023-06-26T16:58:10.172Z,1687798690.172 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T16:58:10.172Z,1687798690.172 [Default:CheckIn] Stopped 2023-06-26T16:58:10.172Z,1687798690.172 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T16:58:10.173Z,1687798690.173 [Default:CheckIn](INFO): Running loop #12 2023-06-26T16:58:10.173Z,1687798690.173 [Default:CheckIn] Running Loop=12 2023-06-26T16:58:10.173Z,1687798690.173 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T16:58:10.173Z,1687798690.173 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T16:58:12.187Z,1687798692.187 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165811.00,A,3648.15002,N,12147.22163,W,0.019,159.29,260623,,,D*74 2023-06-26T16:58:12.197Z,1687798692.197 [NAL9602](INFO): GPS fix at 20230626T165811: (36.802500, -121.787027) 2023-06-26T16:58:12.209Z,1687798692.209 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T16:58:12.209Z,1687798692.209 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T16:58:19.332Z,1687798699.332 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230626T154918/Courier0040.lzma 2023-06-26T16:58:20.334Z,1687798700.334 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0040.lzma.bak 2023-06-26T16:58:20.334Z,1687798700.334 [DataOverHttps](INFO): SBD MOMSN=18432514 2023-06-26T16:58:36.791Z,1687798716.791 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230626T154918/Express0041.lzma 2023-06-26T16:58:37.794Z,1687798717.794 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0041.lzma.bak 2023-06-26T16:58:37.794Z,1687798717.794 [DataOverHttps](INFO): SBD MOMSN=18432517 2023-06-26T16:58:38.899Z,1687798718.899 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T16:58:38.899Z,1687798718.899 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T16:58:38.899Z,1687798718.899 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T16:59:03.495Z,1687798743.495 [NAL9602](INFO): SBD MO Status=2, MOMSN=26252, MT Status=2, MTMSN=0 2023-06-26T16:59:03.495Z,1687798743.495 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-06-26T17:00:04.899Z,1687798804.899 [NAL9602](INFO): SBD MO Status=0, MOMSN=26252, MT Status=0, MTMSN=0 2023-06-26T17:00:04.899Z,1687798804.899 [NAL9602](INFO): No messages in MT queue 2023-06-26T17:00:35.715Z,1687798835.715 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T17:03:39.453Z,1687799019.453 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T17:03:39.453Z,1687799019.453 [Default:CheckIn:C.Wait] Stopped 2023-06-26T17:03:39.453Z,1687799019.453 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T17:03:39.453Z,1687799019.453 [Default:CheckIn:D] Running Loop=1 2023-06-26T17:03:39.848Z,1687799019.848 [Default:CheckIn:D] Stopped 2023-06-26T17:03:39.849Z,1687799019.849 [Default:CheckIn:E] Running Loop=1 2023-06-26T17:03:40.257Z,1687799020.257 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 70.469906 min 2023-06-26T17:03:40.257Z,1687799020.257 [Default:CheckIn:E] Stopped 2023-06-26T17:03:40.257Z,1687799020.257 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T17:03:40.257Z,1687799020.257 [Default:CheckIn] Stopped 2023-06-26T17:03:40.257Z,1687799020.257 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T17:03:40.257Z,1687799020.257 [Default:CheckIn](INFO): Running loop #13 2023-06-26T17:03:40.257Z,1687799020.257 [Default:CheckIn] Running Loop=13 2023-06-26T17:03:40.257Z,1687799020.257 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T17:03:40.258Z,1687799020.258 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T17:03:42.279Z,1687799022.279 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170341.00,A,3648.14940,N,12147.22138,W,0.019,159.29,260623,,,D*7E 2023-06-26T17:03:42.281Z,1687799022.281 [NAL9602](INFO): GPS fix at 20230626T170341: (36.802490, -121.787023) 2023-06-26T17:03:42.294Z,1687799022.294 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T17:03:42.294Z,1687799022.294 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T17:03:50.071Z,1687799030.071 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230626T154918/Courier0043.lzma 2023-06-26T17:03:51.074Z,1687799031.074 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0043.lzma.bak 2023-06-26T17:03:51.074Z,1687799031.074 [DataOverHttps](INFO): SBD MOMSN=18432522 2023-06-26T17:04:02.894Z,1687799042.894 [NAL9602](INFO): SBD MO Status=2, MOMSN=26253, MT Status=2, MTMSN=0 2023-06-26T17:04:02.895Z,1687799042.895 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-06-26T17:04:07.691Z,1687799047.691 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230626T154918/Express0044.lzma 2023-06-26T17:04:08.694Z,1687799048.694 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0044.lzma.bak 2023-06-26T17:04:08.694Z,1687799048.694 [DataOverHttps](INFO): SBD MOMSN=18432525 2023-06-26T17:04:09.749Z,1687799049.749 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T17:04:09.749Z,1687799049.749 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T17:04:09.749Z,1687799049.749 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T17:04:26.320Z,1687799066.320 [NAL9602](INFO): SBD MO Status=2, MOMSN=26253, MT Status=2, MTMSN=0 2023-06-26T17:04:26.320Z,1687799066.320 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-06-26T17:04:54.181Z,1687799094.181 [NAL9602](INFO): SBD MO Status=0, MOMSN=26253, MT Status=0, MTMSN=0 2023-06-26T17:04:54.181Z,1687799094.181 [NAL9602](INFO): No messages in MT queue 2023-06-26T17:05:14.841Z,1687799114.841 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2023-06-26T17:05:21.246Z,1687799121.246 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2023-06-26T17:05:21.249Z,1687799121.249 [BPC1](INFO): Received data from all battery sticks. 2023-06-26T17:05:24.881Z,1687799124.881 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T17:09:10.425Z,1687799350.425 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T17:09:10.425Z,1687799350.425 [Default:CheckIn:C.Wait] Stopped 2023-06-26T17:09:10.425Z,1687799350.425 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T17:09:10.426Z,1687799350.426 [Default:CheckIn:D] Running Loop=1 2023-06-26T17:09:10.808Z,1687799350.808 [Default:CheckIn:D] Stopped 2023-06-26T17:09:10.808Z,1687799350.808 [Default:CheckIn:E] Running Loop=1 2023-06-26T17:09:11.187Z,1687799351.187 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 75.985897 min 2023-06-26T17:09:11.204Z,1687799351.204 [Default:CheckIn:E] Stopped 2023-06-26T17:09:11.204Z,1687799351.204 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T17:09:11.204Z,1687799351.204 [Default:CheckIn] Stopped 2023-06-26T17:09:11.204Z,1687799351.204 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T17:09:11.204Z,1687799351.204 [Default:CheckIn](INFO): Running loop #14 2023-06-26T17:09:11.204Z,1687799351.204 [Default:CheckIn] Running Loop=14 2023-06-26T17:09:11.204Z,1687799351.204 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T17:09:11.205Z,1687799351.205 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T17:09:13.199Z,1687799353.199 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170912.00,A,3648.14856,N,12147.22251,W,0.078,159.29,260623,,,D*7F 2023-06-26T17:09:13.201Z,1687799353.201 [NAL9602](INFO): GPS fix at 20230626T170912: (36.802476, -121.787042) 2023-06-26T17:09:13.213Z,1687799353.213 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T17:09:13.213Z,1687799353.213 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T17:09:20.811Z,1687799360.811 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20230626T154918/Courier0046.lzma 2023-06-26T17:09:21.814Z,1687799361.814 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0046.lzma.bak 2023-06-26T17:09:21.814Z,1687799361.814 [DataOverHttps](INFO): SBD MOMSN=18432540 2023-06-26T17:09:38.195Z,1687799378.195 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230626T154918/Express0047.lzma 2023-06-26T17:09:39.198Z,1687799379.198 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0047.lzma.bak 2023-06-26T17:09:39.198Z,1687799379.198 [DataOverHttps](INFO): SBD MOMSN=18432543 2023-06-26T17:09:40.309Z,1687799380.309 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T17:09:40.309Z,1687799380.309 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T17:09:40.309Z,1687799380.309 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T17:10:23.091Z,1687799423.091 [NAL9602](INFO): SBD MO Status=0, MOMSN=26254, MT Status=0, MTMSN=0 2023-06-26T17:10:23.091Z,1687799423.091 [NAL9602](INFO): No messages in MT queue 2023-06-26T17:10:53.801Z,1687799453.801 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T17:14:40.908Z,1687799680.908 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T17:14:40.908Z,1687799680.908 [Default:CheckIn:C.Wait] Stopped 2023-06-26T17:14:40.908Z,1687799680.908 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T17:14:40.908Z,1687799680.908 [Default:CheckIn:D] Running Loop=1 2023-06-26T17:14:41.317Z,1687799681.317 [Default:CheckIn:D] Stopped 2023-06-26T17:14:41.317Z,1687799681.317 [Default:CheckIn:E] Running Loop=1 2023-06-26T17:14:41.736Z,1687799681.736 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 81.494377 min 2023-06-26T17:14:41.736Z,1687799681.736 [Default:CheckIn:E] Stopped 2023-06-26T17:14:41.736Z,1687799681.736 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T17:14:41.737Z,1687799681.737 [Default:CheckIn] Stopped 2023-06-26T17:14:41.737Z,1687799681.737 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T17:14:41.737Z,1687799681.737 [Default:CheckIn](INFO): Running loop #15 2023-06-26T17:14:41.737Z,1687799681.737 [Default:CheckIn] Running Loop=15 2023-06-26T17:14:41.737Z,1687799681.737 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T17:14:41.737Z,1687799681.737 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T17:14:43.727Z,1687799683.727 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171443.00,A,3648.15050,N,12147.22190,W,0.039,40.27,260623,,,D*44 2023-06-26T17:14:43.733Z,1687799683.733 [NAL9602](INFO): GPS fix at 20230626T171443: (36.802508, -121.787032) 2023-06-26T17:14:43.759Z,1687799683.759 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T17:14:43.759Z,1687799683.759 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T17:14:44.594Z,1687799684.594 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T17:14:44.594Z,1687799684.594 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T17:14:44.594Z,1687799684.594 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T17:15:28.186Z,1687799728.186 [NAL9602](INFO): SBD MO Status=2, MOMSN=26255, MT Status=2, MTMSN=0 2023-06-26T17:15:28.186Z,1687799728.186 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-06-26T17:15:55.259Z,1687799755.259 [NAL9602](INFO): SBD MO Status=2, MOMSN=26255, MT Status=2, MTMSN=0 2023-06-26T17:15:55.259Z,1687799755.259 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-06-26T17:16:52.623Z,1687799812.623 [NAL9602](INFO): SBD MO Status=2, MOMSN=26255, MT Status=2, MTMSN=0 2023-06-26T17:16:52.623Z,1687799812.623 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-06-26T17:17:02.733Z,1687799822.733 [NAL9602](INFO): SBD MO Status=0, MOMSN=26255, MT Status=0, MTMSN=0 2023-06-26T17:17:02.733Z,1687799822.733 [NAL9602](INFO): No messages in MT queue 2023-06-26T17:17:33.429Z,1687799853.429 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T17:19:45.139Z,1687799985.139 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T17:19:45.139Z,1687799985.139 [Default:CheckIn:C.Wait] Stopped 2023-06-26T17:19:45.139Z,1687799985.139 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T17:19:45.139Z,1687799985.139 [Default:CheckIn:D] Running Loop=1 2023-06-26T17:19:45.552Z,1687799985.552 [Default:CheckIn:D] Stopped 2023-06-26T17:19:45.552Z,1687799985.552 [Default:CheckIn:E] Running Loop=1 2023-06-26T17:19:45.960Z,1687799985.960 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 86.564966 min 2023-06-26T17:19:45.960Z,1687799985.960 [Default:CheckIn:E] Stopped 2023-06-26T17:19:45.961Z,1687799985.961 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T17:19:45.961Z,1687799985.961 [Default:CheckIn] Stopped 2023-06-26T17:19:45.961Z,1687799985.961 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T17:19:45.961Z,1687799985.961 [Default:CheckIn](INFO): Running loop #16 2023-06-26T17:19:45.961Z,1687799985.961 [Default:CheckIn] Running Loop=16 2023-06-26T17:19:45.961Z,1687799985.961 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T17:19:45.961Z,1687799985.961 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T17:19:47.958Z,1687799987.958 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171947.00,A,3648.15104,N,12147.22230,W,0.019,40.27,260623,,,D*46 2023-06-26T17:19:47.960Z,1687799987.960 [NAL9602](INFO): GPS fix at 20230626T171947: (36.802517, -121.787038) 2023-06-26T17:19:47.971Z,1687799987.971 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T17:19:47.971Z,1687799987.971 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T17:19:54.995Z,1687799994.995 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230626T154918/Courier0049.lzma 2023-06-26T17:19:55.998Z,1687799995.998 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0049.lzma.bak 2023-06-26T17:19:55.998Z,1687799995.998 [DataOverHttps](INFO): SBD MOMSN=18432548 2023-06-26T17:20:03.314Z,1687800003.314 [NAL9602](INFO): SBD MO Status=0, MOMSN=26256, MT Status=0, MTMSN=0 2023-06-26T17:20:03.314Z,1687800003.314 [NAL9602](INFO): No messages in MT queue 2023-06-26T17:20:12.359Z,1687800012.359 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230626T154918/Courier0052.lzma 2023-06-26T17:20:13.354Z,1687800013.354 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0052.lzma.bak 2023-06-26T17:20:13.354Z,1687800013.354 [DataOverHttps](INFO): SBD MOMSN=18432551 2023-06-26T17:20:29.911Z,1687800029.911 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230626T154918/Express0050.lzma 2023-06-26T17:20:30.914Z,1687800030.914 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0050.lzma.bak 2023-06-26T17:20:30.914Z,1687800030.914 [DataOverHttps](INFO): SBD MOMSN=18432554 2023-06-26T17:20:34.013Z,1687800034.013 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T17:20:50.219Z,1687800050.219 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230626T154918/Express0053.lzma 2023-06-26T17:20:51.222Z,1687800051.222 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0053.lzma.bak 2023-06-26T17:20:51.222Z,1687800051.222 [DataOverHttps](INFO): SBD MOMSN=18432557 2023-06-26T17:20:52.286Z,1687800052.286 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T17:20:52.286Z,1687800052.286 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T17:20:52.287Z,1687800052.287 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T17:25:52.889Z,1687800352.889 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T17:25:52.889Z,1687800352.889 [Default:CheckIn:C.Wait] Stopped 2023-06-26T17:25:52.889Z,1687800352.889 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T17:25:52.889Z,1687800352.889 [Default:CheckIn:D] Running Loop=1 2023-06-26T17:25:53.293Z,1687800353.293 [Default:CheckIn:D] Stopped 2023-06-26T17:25:53.293Z,1687800353.293 [Default:CheckIn:E] Running Loop=1 2023-06-26T17:25:53.696Z,1687800353.696 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 92.693986 min 2023-06-26T17:25:53.697Z,1687800353.697 [Default:CheckIn:E] Stopped 2023-06-26T17:25:53.697Z,1687800353.697 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T17:25:53.697Z,1687800353.697 [Default:CheckIn] Stopped 2023-06-26T17:25:53.697Z,1687800353.697 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T17:25:53.697Z,1687800353.697 [Default:CheckIn](INFO): Running loop #17 2023-06-26T17:25:53.697Z,1687800353.697 [Default:CheckIn] Running Loop=17 2023-06-26T17:25:53.697Z,1687800353.697 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T17:25:53.697Z,1687800353.697 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T17:25:55.701Z,1687800355.701 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172555.00,A,3648.15067,N,12147.22222,W,0.019,40.27,260623,,,D*4D 2023-06-26T17:25:55.704Z,1687800355.704 [NAL9602](INFO): GPS fix at 20230626T172555: (36.802511, -121.787037) 2023-06-26T17:25:55.734Z,1687800355.734 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T17:25:55.734Z,1687800355.734 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T17:26:03.363Z,1687800363.363 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230626T154918/Courier0055.lzma 2023-06-26T17:26:04.369Z,1687800364.369 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0055.lzma.bak 2023-06-26T17:26:04.369Z,1687800364.369 [DataOverHttps](INFO): SBD MOMSN=18432561 2023-06-26T17:26:21.207Z,1687800381.207 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230626T154918/Express0056.lzma 2023-06-26T17:26:22.210Z,1687800382.210 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0056.lzma.bak 2023-06-26T17:26:22.210Z,1687800382.210 [DataOverHttps](INFO): SBD MOMSN=18432564 2023-06-26T17:26:23.630Z,1687800383.630 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T17:26:23.630Z,1687800383.630 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T17:26:23.630Z,1687800383.630 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T17:27:14.535Z,1687800434.535 [NAL9602](INFO): SBD MO Status=2, MOMSN=26257, MT Status=2, MTMSN=0 2023-06-26T17:27:14.536Z,1687800434.536 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-06-26T17:27:25.031Z,1687800445.031 [NAL9602](INFO): SBD MO Status=0, MOMSN=26257, MT Status=0, MTMSN=0 2023-06-26T17:27:25.031Z,1687800445.031 [NAL9602](INFO): No messages in MT queue 2023-06-26T17:27:55.733Z,1687800475.733 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T17:31:24.228Z,1687800684.228 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T17:31:24.228Z,1687800684.228 [Default:CheckIn:C.Wait] Stopped 2023-06-26T17:31:24.228Z,1687800684.228 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T17:31:24.228Z,1687800684.228 [Default:CheckIn:D] Running Loop=1 2023-06-26T17:31:24.650Z,1687800684.650 [Default:CheckIn:D] Stopped 2023-06-26T17:31:24.650Z,1687800684.650 [Default:CheckIn:E] Running Loop=1 2023-06-26T17:31:25.022Z,1687800685.022 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 98.216602 min 2023-06-26T17:31:25.022Z,1687800685.022 [Default:CheckIn:E] Stopped 2023-06-26T17:31:25.022Z,1687800685.022 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T17:31:25.022Z,1687800685.022 [Default:CheckIn] Stopped 2023-06-26T17:31:25.022Z,1687800685.022 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T17:31:25.022Z,1687800685.022 [Default:CheckIn](INFO): Running loop #18 2023-06-26T17:31:25.023Z,1687800685.023 [Default:CheckIn] Running Loop=18 2023-06-26T17:31:25.023Z,1687800685.023 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T17:31:25.023Z,1687800685.023 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T17:31:27.031Z,1687800687.031 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173126.00,A,3648.14914,N,12147.22167,W,0.039,40.27,260623,,,D*40 2023-06-26T17:31:27.042Z,1687800687.042 [NAL9602](INFO): GPS fix at 20230626T173126: (36.802486, -121.787028) 2023-06-26T17:31:27.053Z,1687800687.053 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T17:31:27.053Z,1687800687.053 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T17:31:35.179Z,1687800695.179 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230626T154918/Courier0058.lzma 2023-06-26T17:31:36.182Z,1687800696.182 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0058.lzma.bak 2023-06-26T17:31:36.182Z,1687800696.182 [DataOverHttps](INFO): SBD MOMSN=18432579 2023-06-26T17:31:44.803Z,1687800704.803 [NAL9602](INFO): SBD MO Status=0, MOMSN=26258, MT Status=0, MTMSN=0 2023-06-26T17:31:44.803Z,1687800704.803 [NAL9602](INFO): No messages in MT queue 2023-06-26T17:31:52.523Z,1687800712.523 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230626T154918/Express0059.lzma 2023-06-26T17:31:53.526Z,1687800713.526 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0059.lzma.bak 2023-06-26T17:31:53.526Z,1687800713.526 [DataOverHttps](INFO): SBD MOMSN=18432587 2023-06-26T17:31:54.572Z,1687800714.572 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T17:31:54.572Z,1687800714.572 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T17:31:54.572Z,1687800714.572 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T17:32:15.509Z,1687800735.509 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T17:36:55.161Z,1687801015.161 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T17:36:55.161Z,1687801015.161 [Default:CheckIn:C.Wait] Stopped 2023-06-26T17:36:55.161Z,1687801015.161 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T17:36:55.161Z,1687801015.161 [Default:CheckIn:D] Running Loop=1 2023-06-26T17:36:55.568Z,1687801015.568 [Default:CheckIn:D] Stopped 2023-06-26T17:36:55.569Z,1687801015.569 [Default:CheckIn:E] Running Loop=1 2023-06-26T17:36:55.982Z,1687801015.982 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 103.731901 min 2023-06-26T17:36:55.982Z,1687801015.982 [Default:CheckIn:E] Stopped 2023-06-26T17:36:55.982Z,1687801015.982 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T17:36:55.982Z,1687801015.982 [Default:CheckIn] Stopped 2023-06-26T17:36:55.982Z,1687801015.982 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T17:36:55.983Z,1687801015.983 [Default:CheckIn](INFO): Running loop #19 2023-06-26T17:36:55.983Z,1687801015.983 [Default:CheckIn] Running Loop=19 2023-06-26T17:36:55.983Z,1687801015.983 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T17:36:55.983Z,1687801015.983 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T17:36:57.979Z,1687801017.979 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173657.00,A,3648.14647,N,12147.22307,W,0.019,185.00,260623,,,D*73 2023-06-26T17:36:57.981Z,1687801017.981 [NAL9602](INFO): GPS fix at 20230626T173657: (36.802441, -121.787051) 2023-06-26T17:36:58.014Z,1687801018.014 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T17:36:58.014Z,1687801018.014 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T17:37:05.995Z,1687801025.995 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230626T154918/Courier0061.lzma 2023-06-26T17:37:06.998Z,1687801026.998 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0061.lzma.bak 2023-06-26T17:37:06.998Z,1687801026.998 [DataOverHttps](INFO): SBD MOMSN=18432598 2023-06-26T17:37:23.392Z,1687801043.392 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230626T154918/Express0062.lzma 2023-06-26T17:37:24.394Z,1687801044.394 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0062.lzma.bak 2023-06-26T17:37:24.394Z,1687801044.394 [DataOverHttps](INFO): SBD MOMSN=18432601 2023-06-26T17:37:25.460Z,1687801045.460 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T17:37:25.460Z,1687801045.460 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T17:37:25.460Z,1687801045.460 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T17:37:29.491Z,1687801049.491 [NAL9602](INFO): SBD MO Status=0, MOMSN=26259, MT Status=0, MTMSN=0 2023-06-26T17:37:29.491Z,1687801049.491 [NAL9602](INFO): No messages in MT queue 2023-06-26T17:38:00.197Z,1687801080.197 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T17:42:26.044Z,1687801346.044 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T17:42:26.044Z,1687801346.044 [Default:CheckIn:C.Wait] Stopped 2023-06-26T17:42:26.044Z,1687801346.044 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T17:42:26.045Z,1687801346.045 [Default:CheckIn:D] Running Loop=1 2023-06-26T17:42:26.467Z,1687801346.467 [Default:CheckIn:D] Stopped 2023-06-26T17:42:26.467Z,1687801346.467 [Default:CheckIn:E] Running Loop=1 2023-06-26T17:42:26.841Z,1687801346.841 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 109.246875 min 2023-06-26T17:42:26.841Z,1687801346.841 [Default:CheckIn:E] Stopped 2023-06-26T17:42:26.841Z,1687801346.841 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T17:42:26.841Z,1687801346.841 [Default:CheckIn] Stopped 2023-06-26T17:42:26.841Z,1687801346.841 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T17:42:26.841Z,1687801346.841 [Default:CheckIn](INFO): Running loop #20 2023-06-26T17:42:26.841Z,1687801346.841 [Default:CheckIn] Running Loop=20 2023-06-26T17:42:26.842Z,1687801346.842 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T17:42:26.842Z,1687801346.842 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T17:42:28.859Z,1687801348.859 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174228.00,A,3648.14939,N,12147.22138,W,0.000,72.04,260623,,,D*45 2023-06-26T17:42:28.861Z,1687801348.861 [NAL9602](INFO): GPS fix at 20230626T174228: (36.802490, -121.787023) 2023-06-26T17:42:28.872Z,1687801348.872 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T17:42:28.873Z,1687801348.873 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T17:42:36.407Z,1687801356.407 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230626T154918/Courier0064.lzma 2023-06-26T17:42:37.410Z,1687801357.410 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0064.lzma.bak 2023-06-26T17:42:37.410Z,1687801357.410 [DataOverHttps](INFO): SBD MOMSN=18432616 2023-06-26T17:42:56.808Z,1687801376.808 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20230626T154918/Express0065.lzma 2023-06-26T17:42:57.810Z,1687801377.810 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0065.lzma.bak 2023-06-26T17:42:57.810Z,1687801377.810 [DataOverHttps](INFO): SBD MOMSN=18432619 2023-06-26T17:42:58.857Z,1687801378.857 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T17:42:58.857Z,1687801378.857 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T17:42:58.857Z,1687801378.857 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T17:44:55.571Z,1687801495.571 [NAL9602](INFO): SBD MO Status=2, MOMSN=26260, MT Status=2, MTMSN=0 2023-06-26T17:44:55.571Z,1687801495.571 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-06-26T17:47:08.491Z,1687801628.491 [NAL9602](INFO): SBD MO Status=0, MOMSN=26260, MT Status=0, MTMSN=0 2023-06-26T17:47:08.491Z,1687801628.491 [NAL9602](INFO): No messages in MT queue 2023-06-26T17:47:39.189Z,1687801659.189 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T17:47:59.399Z,1687801679.399 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T17:47:59.399Z,1687801679.399 [Default:CheckIn:C.Wait] Stopped 2023-06-26T17:47:59.399Z,1687801679.399 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T17:47:59.400Z,1687801679.400 [Default:CheckIn:D] Running Loop=1 2023-06-26T17:47:59.802Z,1687801679.802 [Default:CheckIn:D] Stopped 2023-06-26T17:47:59.802Z,1687801679.802 [Default:CheckIn:E] Running Loop=1 2023-06-26T17:48:00.216Z,1687801680.216 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 114.802466 min 2023-06-26T17:48:00.216Z,1687801680.216 [Default:CheckIn:E] Stopped 2023-06-26T17:48:00.217Z,1687801680.217 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T17:48:00.217Z,1687801680.217 [Default:CheckIn] Stopped 2023-06-26T17:48:00.217Z,1687801680.217 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T17:48:00.217Z,1687801680.217 [Default:CheckIn](INFO): Running loop #21 2023-06-26T17:48:00.217Z,1687801680.217 [Default:CheckIn] Running Loop=21 2023-06-26T17:48:00.217Z,1687801680.217 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T17:48:00.217Z,1687801680.217 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T17:48:02.219Z,1687801682.219 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174802.00,A,3648.14834,N,12147.22251,W,0.194,72.04,260623,,,D*4B 2023-06-26T17:48:02.221Z,1687801682.221 [NAL9602](INFO): GPS fix at 20230626T174802: (36.802472, -121.787042) 2023-06-26T17:48:02.257Z,1687801682.257 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T17:48:02.257Z,1687801682.257 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T17:48:14.620Z,1687801694.620 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-06-26T17:48:16.629Z,1687801696.629 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.239117 2023-06-26T17:48:35.354Z,1687801715.354 [NAL9602](INFO): SBD MO Status=0, MOMSN=26261, MT Status=0, MTMSN=0 2023-06-26T17:48:35.354Z,1687801715.354 [NAL9602](INFO): No messages in MT queue 2023-06-26T17:48:47.768Z,1687801727.768 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-06-26T17:49:02.878Z,1687801742.878 [NAL9602](INFO): SBD MO Status=1, MOMSN=26262, MT Status=0, MTMSN=0 2023-06-26T17:49:02.940Z,1687801742.940 [NAL9602](INFO): Sent 74 bytes from file Logs/20230626T154918/Courier0067.lzma 2023-06-26T17:49:02.940Z,1687801742.940 [NAL9602](INFO): Packets left to send: 0 2023-06-26T17:49:21.526Z,1687801761.526 [NAL9602](INFO): SBD MO Status=1, MOMSN=26263, MT Status=0, MTMSN=0 2023-06-26T17:49:21.596Z,1687801761.596 [NAL9602](INFO): Sent 131 bytes from file Logs/20230626T154918/Express0068.lzma 2023-06-26T17:49:21.596Z,1687801761.596 [NAL9602](INFO): Packets left to send: 0 2023-06-26T17:49:22.908Z,1687801762.908 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-06-26T17:49:32.834Z,1687801772.834 [NAL9602](INFO): SBD MO Status=0, MOMSN=26264, MT Status=0, MTMSN=0 2023-06-26T17:49:32.927Z,1687801772.927 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T17:49:32.927Z,1687801772.927 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T17:49:32.927Z,1687801772.927 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T17:49:35.596Z,1687801775.596 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003201 2023-06-26T17:50:03.541Z,1687801803.541 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T17:54:33.428Z,1687802073.428 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T17:54:33.428Z,1687802073.428 [Default:CheckIn:C.Wait] Stopped 2023-06-26T17:54:33.428Z,1687802073.428 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T17:54:33.429Z,1687802073.429 [Default:CheckIn:D] Running Loop=1 2023-06-26T17:54:33.833Z,1687802073.833 [Default:CheckIn:D] Stopped 2023-06-26T17:54:33.833Z,1687802073.833 [Default:CheckIn:E] Running Loop=1 2023-06-26T17:54:34.248Z,1687802074.248 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 121.369637 min 2023-06-26T17:54:34.248Z,1687802074.248 [Default:CheckIn:E] Stopped 2023-06-26T17:54:34.248Z,1687802074.248 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T17:54:34.248Z,1687802074.248 [Default:CheckIn] Stopped 2023-06-26T17:54:34.248Z,1687802074.248 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T17:54:34.248Z,1687802074.248 [Default:CheckIn](INFO): Running loop #22 2023-06-26T17:54:34.248Z,1687802074.248 [Default:CheckIn] Running Loop=22 2023-06-26T17:54:34.249Z,1687802074.249 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T17:54:34.249Z,1687802074.249 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T17:54:36.247Z,1687802076.247 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175436.00,A,3648.14956,N,12147.22211,W,0.058,72.04,260623,,,D*41 2023-06-26T17:54:36.249Z,1687802076.249 [NAL9602](INFO): GPS fix at 20230626T175436: (36.802493, -121.787035) 2023-06-26T17:54:36.282Z,1687802076.282 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T17:54:36.282Z,1687802076.282 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T17:54:44.051Z,1687802084.051 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230626T154918/Courier0070.lzma 2023-06-26T17:54:45.054Z,1687802085.054 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0070.lzma.bak 2023-06-26T17:54:45.054Z,1687802085.054 [DataOverHttps](INFO): SBD MOMSN=18432631 2023-06-26T17:55:01.299Z,1687802101.299 [DataOverHttps](INFO): Sending 133 bytes from file Logs/20230626T154918/Express0071.lzma 2023-06-26T17:55:02.302Z,1687802102.302 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0071.lzma.bak 2023-06-26T17:55:02.303Z,1687802102.303 [DataOverHttps](INFO): SBD MOMSN=18432634 2023-06-26T17:55:02.910Z,1687802102.910 [NAL9602](INFO): SBD MO Status=2, MOMSN=26265, MT Status=2, MTMSN=0 2023-06-26T17:55:02.911Z,1687802102.911 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-06-26T17:55:03.361Z,1687802103.361 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T17:55:03.361Z,1687802103.361 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T17:55:03.361Z,1687802103.361 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T17:55:20.711Z,1687802120.711 [NAL9602](INFO): SBD MO Status=0, MOMSN=26265, MT Status=0, MTMSN=0 2023-06-26T17:55:20.711Z,1687802120.711 [NAL9602](INFO): No messages in MT queue 2023-06-26T17:55:51.414Z,1687802151.414 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T18:00:04.004Z,1687802404.004 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T18:00:04.004Z,1687802404.004 [Default:CheckIn:C.Wait] Stopped 2023-06-26T18:00:04.004Z,1687802404.004 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T18:00:04.004Z,1687802404.004 [Default:CheckIn:D] Running Loop=1 2023-06-26T18:00:04.423Z,1687802404.423 [Default:CheckIn:D] Stopped 2023-06-26T18:00:04.423Z,1687802404.423 [Default:CheckIn:E] Running Loop=1 2023-06-26T18:00:04.797Z,1687802404.797 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 126.879476 min 2023-06-26T18:00:04.797Z,1687802404.797 [Default:CheckIn:E] Stopped 2023-06-26T18:00:04.797Z,1687802404.797 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T18:00:04.797Z,1687802404.797 [Default:CheckIn] Stopped 2023-06-26T18:00:04.797Z,1687802404.797 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T18:00:04.797Z,1687802404.797 [Default:CheckIn](INFO): Running loop #23 2023-06-26T18:00:04.797Z,1687802404.797 [Default:CheckIn] Running Loop=23 2023-06-26T18:00:04.797Z,1687802404.797 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T18:00:04.798Z,1687802404.798 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T18:00:06.803Z,1687802406.803 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180006.00,A,3648.14993,N,12147.22142,W,0.078,72.04,260623,,,D*42 2023-06-26T18:00:06.815Z,1687802406.815 [NAL9602](INFO): GPS fix at 20230626T180006: (36.802499, -121.787024) 2023-06-26T18:00:06.831Z,1687802406.831 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T18:00:06.831Z,1687802406.831 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T18:00:14.475Z,1687802414.475 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230626T154918/Courier0073.lzma 2023-06-26T18:00:15.478Z,1687802415.478 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0073.lzma.bak 2023-06-26T18:00:15.478Z,1687802415.478 [DataOverHttps](INFO): SBD MOMSN=18432638 2023-06-26T18:00:35.016Z,1687802435.016 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230626T154918/Express0074.lzma 2023-06-26T18:00:36.018Z,1687802436.018 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0074.lzma.bak 2023-06-26T18:00:36.018Z,1687802436.018 [DataOverHttps](INFO): SBD MOMSN=18432641 2023-06-26T18:00:37.203Z,1687802437.203 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T18:00:37.204Z,1687802437.204 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T18:00:37.204Z,1687802437.204 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T18:00:43.222Z,1687802443.222 [NAL9602](INFO): SBD MO Status=2, MOMSN=26266, MT Status=2, MTMSN=0 2023-06-26T18:00:43.223Z,1687802443.223 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-06-26T18:01:06.249Z,1687802466.249 [NAL9602](INFO): SBD MO Status=0, MOMSN=26266, MT Status=0, MTMSN=0 2023-06-26T18:01:06.249Z,1687802466.249 [NAL9602](INFO): No messages in MT queue 2023-06-26T18:01:36.957Z,1687802496.957 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T18:01:56.387Z,1687802516.387 [RDI_Pathfinder](ERROR): only read -1 of 1 data item for altitude 2023-06-26T18:05:37.787Z,1687802737.787 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T18:05:37.787Z,1687802737.787 [Default:CheckIn:C.Wait] Stopped 2023-06-26T18:05:37.789Z,1687802737.789 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T18:05:37.789Z,1687802737.789 [Default:CheckIn:D] Running Loop=1 2023-06-26T18:05:38.201Z,1687802738.201 [Default:CheckIn:D] Stopped 2023-06-26T18:05:38.201Z,1687802738.201 [Default:CheckIn:E] Running Loop=1 2023-06-26T18:05:38.623Z,1687802738.623 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 132.442440 min 2023-06-26T18:05:38.623Z,1687802738.623 [Default:CheckIn:E] Stopped 2023-06-26T18:05:38.624Z,1687802738.624 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T18:05:38.624Z,1687802738.624 [Default:CheckIn] Stopped 2023-06-26T18:05:38.624Z,1687802738.624 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T18:05:38.624Z,1687802738.624 [Default:CheckIn](INFO): Running loop #24 2023-06-26T18:05:38.624Z,1687802738.624 [Default:CheckIn] Running Loop=24 2023-06-26T18:05:38.624Z,1687802738.624 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T18:05:38.624Z,1687802738.624 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T18:05:40.607Z,1687802740.607 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180540.00,A,3648.14941,N,12147.22043,W,0.058,0.00,260623,,,D*79 2023-06-26T18:05:40.609Z,1687802740.609 [NAL9602](INFO): GPS fix at 20230626T180540: (36.802490, -121.787007) 2023-06-26T18:05:40.657Z,1687802740.657 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T18:05:40.657Z,1687802740.657 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T18:05:48.135Z,1687802748.135 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230626T154918/Courier0076.lzma 2023-06-26T18:05:49.139Z,1687802749.139 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0076.lzma.bak 2023-06-26T18:05:49.140Z,1687802749.140 [DataOverHttps](INFO): SBD MOMSN=18432653 2023-06-26T18:05:53.938Z,1687802753.938 [NAL9602](INFO): SBD MO Status=0, MOMSN=26267, MT Status=0, MTMSN=0 2023-06-26T18:05:53.939Z,1687802753.939 [NAL9602](INFO): No messages in MT queue 2023-06-26T18:06:05.783Z,1687802765.783 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230626T154918/Express0077.lzma 2023-06-26T18:06:06.786Z,1687802766.786 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0077.lzma.bak 2023-06-26T18:06:06.786Z,1687802766.786 [DataOverHttps](INFO): SBD MOMSN=18432660 2023-06-26T18:06:08.104Z,1687802768.104 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T18:06:08.105Z,1687802768.105 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T18:06:08.105Z,1687802768.105 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T18:06:24.645Z,1687802784.645 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T18:11:08.543Z,1687803068.543 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T18:11:08.543Z,1687803068.543 [Default:CheckIn:C.Wait] Stopped 2023-06-26T18:11:08.544Z,1687803068.544 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T18:11:08.544Z,1687803068.544 [Default:CheckIn:D] Running Loop=1 2023-06-26T18:11:08.940Z,1687803068.940 [Default:CheckIn:D] Stopped 2023-06-26T18:11:08.940Z,1687803068.940 [Default:CheckIn:E] Running Loop=1 2023-06-26T18:11:09.328Z,1687803069.328 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 137.954769 min 2023-06-26T18:11:09.328Z,1687803069.328 [Default:CheckIn:E] Stopped 2023-06-26T18:11:09.328Z,1687803069.328 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T18:11:09.328Z,1687803069.328 [Default:CheckIn] Stopped 2023-06-26T18:11:09.329Z,1687803069.329 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T18:11:09.329Z,1687803069.329 [Default:CheckIn](INFO): Running loop #25 2023-06-26T18:11:09.329Z,1687803069.329 [Default:CheckIn] Running Loop=25 2023-06-26T18:11:09.329Z,1687803069.329 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T18:11:09.329Z,1687803069.329 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T18:11:11.355Z,1687803071.355 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181111.00,A,3648.14918,N,12147.22199,W,0.058,0.00,260623,,,D*72 2023-06-26T18:11:11.357Z,1687803071.357 [NAL9602](INFO): GPS fix at 20230626T181111: (36.802486, -121.787033) 2023-06-26T18:11:11.369Z,1687803071.369 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T18:11:11.370Z,1687803071.370 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T18:11:18.727Z,1687803078.727 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230626T154918/Courier0079.lzma 2023-06-26T18:11:19.730Z,1687803079.730 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0079.lzma.bak 2023-06-26T18:11:19.730Z,1687803079.730 [DataOverHttps](INFO): SBD MOMSN=18432667 2023-06-26T18:11:36.199Z,1687803096.199 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230626T154918/Express0080.lzma 2023-06-26T18:11:37.198Z,1687803097.198 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0080.lzma.bak 2023-06-26T18:11:37.198Z,1687803097.198 [DataOverHttps](INFO): SBD MOMSN=18432670 2023-06-26T18:11:38.468Z,1687803098.468 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T18:11:38.468Z,1687803098.468 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T18:11:38.468Z,1687803098.468 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T18:11:43.658Z,1687803103.658 [NAL9602](INFO): SBD MO Status=2, MOMSN=26268, MT Status=2, MTMSN=0 2023-06-26T18:11:43.659Z,1687803103.659 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-06-26T18:12:03.457Z,1687803123.457 [NAL9602](INFO): SBD MO Status=0, MOMSN=26268, MT Status=0, MTMSN=0 2023-06-26T18:12:03.457Z,1687803123.457 [NAL9602](INFO): No messages in MT queue 2023-06-26T18:12:34.165Z,1687803154.165 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T18:12:47.101Z,1687803167.101 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6. 2023-06-26T18:12:47.113Z,1687803167.113 [BPC1](INFO): Received data from all battery sticks. 2023-06-26T18:16:39.077Z,1687803399.077 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T18:16:39.078Z,1687803399.078 [Default:CheckIn:C.Wait] Stopped 2023-06-26T18:16:39.078Z,1687803399.078 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T18:16:39.078Z,1687803399.078 [Default:CheckIn:D] Running Loop=1 2023-06-26T18:16:39.467Z,1687803399.467 [Default:CheckIn:D] Stopped 2023-06-26T18:16:39.467Z,1687803399.467 [Default:CheckIn:E] Running Loop=1 2023-06-26T18:16:39.872Z,1687803399.872 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 143.463558 min 2023-06-26T18:16:39.872Z,1687803399.872 [Default:CheckIn:E] Stopped 2023-06-26T18:16:39.872Z,1687803399.872 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T18:16:39.872Z,1687803399.872 [Default:CheckIn] Stopped 2023-06-26T18:16:39.872Z,1687803399.872 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T18:16:39.873Z,1687803399.873 [Default:CheckIn](INFO): Running loop #26 2023-06-26T18:16:39.873Z,1687803399.873 [Default:CheckIn] Running Loop=26 2023-06-26T18:16:39.873Z,1687803399.873 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T18:16:39.873Z,1687803399.873 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T18:16:41.879Z,1687803401.879 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181641.00,A,3648.14971,N,12147.22123,W,0.078,71.49,260623,,,D*47 2023-06-26T18:16:41.882Z,1687803401.882 [NAL9602](INFO): GPS fix at 20230626T181641: (36.802495, -121.787020) 2023-06-26T18:16:41.894Z,1687803401.894 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T18:16:41.894Z,1687803401.894 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T18:16:50.175Z,1687803410.175 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20230626T154918/Courier0082.lzma 2023-06-26T18:16:51.178Z,1687803411.178 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0082.lzma.bak 2023-06-26T18:16:51.178Z,1687803411.178 [DataOverHttps](INFO): SBD MOMSN=18432698 2023-06-26T18:17:07.451Z,1687803427.451 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230626T154918/Express0083.lzma 2023-06-26T18:17:07.733Z,1687803427.733 [NAL9602](INFO): SBD MO Status=0, MOMSN=26269, MT Status=0, MTMSN=0 2023-06-26T18:17:07.733Z,1687803427.733 [NAL9602](INFO): No messages in MT queue 2023-06-26T18:17:08.454Z,1687803428.454 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0083.lzma.bak 2023-06-26T18:17:08.454Z,1687803428.454 [DataOverHttps](INFO): SBD MOMSN=18432702 2023-06-26T18:17:09.784Z,1687803429.784 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T18:17:09.784Z,1687803429.784 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T18:17:09.784Z,1687803429.784 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T18:17:38.446Z,1687803458.446 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T18:22:10.439Z,1687803730.439 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T18:22:10.439Z,1687803730.439 [Default:CheckIn:C.Wait] Stopped 2023-06-26T18:22:10.439Z,1687803730.439 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T18:22:10.439Z,1687803730.439 [Default:CheckIn:D] Running Loop=1 2023-06-26T18:22:10.815Z,1687803730.815 [Default:CheckIn:D] Stopped 2023-06-26T18:22:10.816Z,1687803730.816 [Default:CheckIn:E] Running Loop=1 2023-06-26T18:22:11.223Z,1687803731.223 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 148.986019 min 2023-06-26T18:22:11.223Z,1687803731.223 [Default:CheckIn:E] Stopped 2023-06-26T18:22:11.223Z,1687803731.223 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T18:22:11.223Z,1687803731.223 [Default:CheckIn] Stopped 2023-06-26T18:22:11.223Z,1687803731.223 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T18:22:11.223Z,1687803731.223 [Default:CheckIn](INFO): Running loop #27 2023-06-26T18:22:11.223Z,1687803731.223 [Default:CheckIn] Running Loop=27 2023-06-26T18:22:11.224Z,1687803731.224 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T18:22:11.224Z,1687803731.224 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T18:22:13.254Z,1687803733.254 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182212.00,A,3648.14942,N,12147.22143,W,0.039,71.49,260623,,,D*45 2023-06-26T18:22:13.256Z,1687803733.256 [NAL9602](INFO): GPS fix at 20230626T182212: (36.802490, -121.787024) 2023-06-26T18:22:13.268Z,1687803733.268 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T18:22:13.268Z,1687803733.268 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T18:22:21.363Z,1687803741.363 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230626T154918/Courier0085.lzma 2023-06-26T18:22:22.366Z,1687803742.366 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0085.lzma.bak 2023-06-26T18:22:22.366Z,1687803742.366 [DataOverHttps](INFO): SBD MOMSN=18432720 2023-06-26T18:22:24.544Z,1687803744.544 [NAL9602](INFO): SBD MO Status=0, MOMSN=26270, MT Status=0, MTMSN=0 2023-06-26T18:22:24.544Z,1687803744.544 [NAL9602](INFO): No messages in MT queue 2023-06-26T18:22:42.051Z,1687803762.051 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230626T154918/Express0086.lzma 2023-06-26T18:22:43.054Z,1687803763.054 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0086.lzma.bak 2023-06-26T18:22:43.054Z,1687803763.054 [DataOverHttps](INFO): SBD MOMSN=18432723 2023-06-26T18:22:44.419Z,1687803764.419 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T18:22:44.419Z,1687803764.419 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T18:22:44.419Z,1687803764.419 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T18:22:55.283Z,1687803775.283 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T18:27:44.997Z,1687804064.997 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T18:27:44.997Z,1687804064.997 [Default:CheckIn:C.Wait] Stopped 2023-06-26T18:27:44.997Z,1687804064.997 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T18:27:44.997Z,1687804064.997 [Default:CheckIn:D] Running Loop=1 2023-06-26T18:27:45.378Z,1687804065.378 [Default:CheckIn:D] Stopped 2023-06-26T18:27:45.378Z,1687804065.378 [Default:CheckIn:E] Running Loop=1 2023-06-26T18:27:45.789Z,1687804065.789 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 154.562077 min 2023-06-26T18:27:45.789Z,1687804065.789 [Default:CheckIn:E] Stopped 2023-06-26T18:27:45.789Z,1687804065.789 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T18:27:45.789Z,1687804065.789 [Default:CheckIn] Stopped 2023-06-26T18:27:45.789Z,1687804065.789 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T18:27:45.789Z,1687804065.789 [Default:CheckIn](INFO): Running loop #28 2023-06-26T18:27:45.790Z,1687804065.790 [Default:CheckIn] Running Loop=28 2023-06-26T18:27:45.790Z,1687804065.790 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T18:27:45.790Z,1687804065.790 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T18:27:47.799Z,1687804067.799 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182747.00,A,3648.14991,N,12147.22278,W,0.058,71.49,260623,,,D*42 2023-06-26T18:27:47.810Z,1687804067.810 [NAL9602](INFO): GPS fix at 20230626T182747: (36.802498, -121.787046) 2023-06-26T18:27:47.821Z,1687804067.821 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T18:27:47.821Z,1687804067.821 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T18:27:55.479Z,1687804075.479 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230626T154918/Courier0088.lzma 2023-06-26T18:27:56.482Z,1687804076.482 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0088.lzma.bak 2023-06-26T18:27:56.482Z,1687804076.482 [DataOverHttps](INFO): SBD MOMSN=18432735 2023-06-26T18:28:11.231Z,1687804091.231 [NAL9602](INFO): SBD MO Status=2, MOMSN=26271, MT Status=2, MTMSN=0 2023-06-26T18:28:11.231Z,1687804091.231 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-06-26T18:28:12.891Z,1687804092.891 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20230626T154918/Express0089.lzma 2023-06-26T18:28:13.894Z,1687804093.894 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0089.lzma.bak 2023-06-26T18:28:13.894Z,1687804093.894 [DataOverHttps](INFO): SBD MOMSN=18432738 2023-06-26T18:28:15.286Z,1687804095.286 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T18:28:15.286Z,1687804095.286 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T18:28:15.286Z,1687804095.286 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T18:28:35.870Z,1687804115.870 [NAL9602](INFO): SBD MO Status=2, MOMSN=26271, MT Status=2, MTMSN=0 2023-06-26T18:28:35.870Z,1687804115.870 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-06-26T18:29:11.438Z,1687804151.438 [NAL9602](INFO): SBD MO Status=0, MOMSN=26271, MT Status=0, MTMSN=0 2023-06-26T18:29:11.439Z,1687804151.439 [NAL9602](INFO): No messages in MT queue 2023-06-26T18:29:42.136Z,1687804182.136 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T18:33:15.876Z,1687804395.876 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T18:33:15.876Z,1687804395.876 [Default:CheckIn:C.Wait] Stopped 2023-06-26T18:33:15.876Z,1687804395.876 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T18:33:15.876Z,1687804395.876 [Default:CheckIn:D] Running Loop=1 2023-06-26T18:33:16.303Z,1687804396.303 [Default:CheckIn:D] Stopped 2023-06-26T18:33:16.303Z,1687804396.303 [Default:CheckIn:E] Running Loop=1 2023-06-26T18:33:16.692Z,1687804396.692 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 160.077474 min 2023-06-26T18:33:16.692Z,1687804396.692 [Default:CheckIn:E] Stopped 2023-06-26T18:33:16.692Z,1687804396.692 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T18:33:16.692Z,1687804396.692 [Default:CheckIn] Stopped 2023-06-26T18:33:16.693Z,1687804396.693 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T18:33:16.693Z,1687804396.693 [Default:CheckIn](INFO): Running loop #29 2023-06-26T18:33:16.693Z,1687804396.693 [Default:CheckIn] Running Loop=29 2023-06-26T18:33:16.693Z,1687804396.693 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T18:33:16.693Z,1687804396.693 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T18:33:18.682Z,1687804398.682 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183318.00,A,3648.14930,N,12147.22252,W,0.019,71.49,260623,,,D*4B 2023-06-26T18:33:18.695Z,1687804398.695 [NAL9602](INFO): GPS fix at 20230626T183318: (36.802488, -121.787042) 2023-06-26T18:33:18.725Z,1687804398.725 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T18:33:18.725Z,1687804398.725 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T18:33:26.803Z,1687804406.803 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230626T154918/Courier0091.lzma 2023-06-26T18:33:27.806Z,1687804407.806 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0091.lzma.bak 2023-06-26T18:33:27.806Z,1687804407.806 [DataOverHttps](INFO): SBD MOMSN=18432749 2023-06-26T18:33:32.419Z,1687804412.419 [NAL9602](INFO): SBD MO Status=0, MOMSN=26272, MT Status=0, MTMSN=0 2023-06-26T18:33:32.419Z,1687804412.419 [NAL9602](INFO): No messages in MT queue 2023-06-26T18:33:44.215Z,1687804424.215 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20230626T154918/Express0092.lzma 2023-06-26T18:33:45.218Z,1687804425.218 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0092.lzma.bak 2023-06-26T18:33:45.218Z,1687804425.218 [DataOverHttps](INFO): SBD MOMSN=18432752 2023-06-26T18:33:46.597Z,1687804426.597 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T18:33:46.598Z,1687804426.598 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T18:33:46.598Z,1687804426.598 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T18:34:03.121Z,1687804443.121 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T18:38:47.165Z,1687804727.165 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T18:38:47.165Z,1687804727.165 [Default:CheckIn:C.Wait] Stopped 2023-06-26T18:38:47.165Z,1687804727.165 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T18:38:47.165Z,1687804727.165 [Default:CheckIn:D] Running Loop=1 2023-06-26T18:38:47.572Z,1687804727.572 [Default:CheckIn:D] Stopped 2023-06-26T18:38:47.572Z,1687804727.572 [Default:CheckIn:E] Running Loop=1 2023-06-26T18:38:47.985Z,1687804727.985 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 165.598633 min 2023-06-26T18:38:47.985Z,1687804727.985 [Default:CheckIn:E] Stopped 2023-06-26T18:38:47.985Z,1687804727.985 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T18:38:47.985Z,1687804727.985 [Default:CheckIn] Stopped 2023-06-26T18:38:47.985Z,1687804727.985 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T18:38:47.985Z,1687804727.985 [Default:CheckIn](INFO): Running loop #30 2023-06-26T18:38:47.985Z,1687804727.985 [Default:CheckIn] Running Loop=30 2023-06-26T18:38:47.986Z,1687804727.986 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T18:38:47.986Z,1687804727.986 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T18:38:49.983Z,1687804729.983 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183849.00,A,3648.20702,N,12147.14384,W,4.568,25.18,260623,,,D*41 2023-06-26T18:38:49.986Z,1687804729.986 [NAL9602](INFO): GPS fix at 20230626T183849: (36.803450, -121.785731) 2023-06-26T18:38:49.997Z,1687804729.997 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T18:38:49.998Z,1687804729.998 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T18:38:57.263Z,1687804737.263 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230626T154918/Courier0094.lzma 2023-06-26T18:38:58.266Z,1687804738.266 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0094.lzma.bak 2023-06-26T18:38:58.266Z,1687804738.266 [DataOverHttps](INFO): SBD MOMSN=18432829 2023-06-26T18:39:09.799Z,1687804749.799 [NAL9602](INFO): SBD MO Status=0, MOMSN=26273, MT Status=0, MTMSN=0 2023-06-26T18:39:09.799Z,1687804749.799 [NAL9602](INFO): No messages in MT queue 2023-06-26T18:39:14.775Z,1687804754.775 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230626T154918/Express0095.lzma 2023-06-26T18:39:15.778Z,1687804755.778 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0095.lzma.bak 2023-06-26T18:39:15.778Z,1687804755.778 [DataOverHttps](INFO): SBD MOMSN=18432843 2023-06-26T18:39:17.089Z,1687804757.089 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T18:39:17.089Z,1687804757.089 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T18:39:17.089Z,1687804757.089 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T18:39:40.505Z,1687804780.505 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T18:44:17.725Z,1687805057.725 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T18:44:17.725Z,1687805057.725 [Default:CheckIn:C.Wait] Stopped 2023-06-26T18:44:17.725Z,1687805057.725 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T18:44:17.725Z,1687805057.725 [Default:CheckIn:D] Running Loop=1 2023-06-26T18:44:18.127Z,1687805058.127 [Default:CheckIn:D] Stopped 2023-06-26T18:44:18.127Z,1687805058.127 [Default:CheckIn:E] Running Loop=1 2023-06-26T18:44:18.575Z,1687805058.575 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 171.107878 min 2023-06-26T18:44:18.575Z,1687805058.575 [Default:CheckIn:E] Stopped 2023-06-26T18:44:18.575Z,1687805058.575 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T18:44:18.575Z,1687805058.575 [Default:CheckIn] Stopped 2023-06-26T18:44:18.575Z,1687805058.575 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T18:44:18.575Z,1687805058.575 [Default:CheckIn](INFO): Running loop #31 2023-06-26T18:44:18.575Z,1687805058.575 [Default:CheckIn] Running Loop=31 2023-06-26T18:44:18.576Z,1687805058.576 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T18:44:18.576Z,1687805058.576 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T18:44:20.527Z,1687805060.527 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184420.00,A,3648.39198,N,12147.42699,W,12.188,233.80,260623,,,A*4E 2023-06-26T18:44:20.529Z,1687805060.529 [NAL9602](INFO): GPS fix at 20230626T184420: (36.806533, -121.790450) 2023-06-26T18:44:20.579Z,1687805060.579 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T18:44:20.579Z,1687805060.579 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T18:44:28.491Z,1687805068.491 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230626T154918/Courier0097.lzma 2023-06-26T18:44:29.494Z,1687805069.494 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0097.lzma.bak 2023-06-26T18:44:29.494Z,1687805069.494 [DataOverHttps](INFO): SBD MOMSN=18432848 2023-06-26T18:44:31.434Z,1687805071.434 [NAL9602](INFO): SBD MO Status=0, MOMSN=26274, MT Status=0, MTMSN=0 2023-06-26T18:44:31.434Z,1687805071.434 [NAL9602](INFO): No messages in MT queue 2023-06-26T18:44:45.883Z,1687805085.883 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230626T154918/Express0098.lzma 2023-06-26T18:44:46.886Z,1687805086.886 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0098.lzma.bak 2023-06-26T18:44:46.886Z,1687805086.886 [DataOverHttps](INFO): SBD MOMSN=18432851 2023-06-26T18:44:48.017Z,1687805088.017 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T18:44:48.017Z,1687805088.017 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T18:44:48.017Z,1687805088.017 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T18:45:02.141Z,1687805102.141 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T18:49:48.674Z,1687805388.674 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T18:49:48.674Z,1687805388.674 [Default:CheckIn:C.Wait] Stopped 2023-06-26T18:49:48.674Z,1687805388.674 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T18:49:48.674Z,1687805388.674 [Default:CheckIn:D] Running Loop=1 2023-06-26T18:49:49.069Z,1687805389.069 [Default:CheckIn:D] Stopped 2023-06-26T18:49:49.069Z,1687805389.069 [Default:CheckIn:E] Running Loop=1 2023-06-26T18:49:49.457Z,1687805389.457 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 176.623584 min 2023-06-26T18:49:49.457Z,1687805389.457 [Default:CheckIn:E] Stopped 2023-06-26T18:49:49.457Z,1687805389.457 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T18:49:49.457Z,1687805389.457 [Default:CheckIn] Stopped 2023-06-26T18:49:49.457Z,1687805389.457 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T18:49:49.457Z,1687805389.457 [Default:CheckIn](INFO): Running loop #32 2023-06-26T18:49:49.457Z,1687805389.457 [Default:CheckIn] Running Loop=32 2023-06-26T18:49:49.457Z,1687805389.457 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T18:49:49.457Z,1687805389.457 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T18:49:51.463Z,1687805391.463 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184951.00,A,3648.07539,N,12148.65220,W,13.413,259.84,260623,,,D*40 2023-06-26T18:49:51.465Z,1687805391.465 [NAL9602](INFO): GPS fix at 20230626T184951: (36.801257, -121.810870) 2023-06-26T18:49:51.477Z,1687805391.477 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T18:49:51.477Z,1687805391.477 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T18:50:12.071Z,1687805412.071 [NAL9602](INFO): SBD MO Status=2, MOMSN=26275, MT Status=2, MTMSN=0 2023-06-26T18:50:12.071Z,1687805412.071 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-06-26T18:50:22.599Z,1687805422.599 [NAL9602](INFO): SBD MO Status=0, MOMSN=26275, MT Status=0, MTMSN=0 2023-06-26T18:50:22.599Z,1687805422.599 [NAL9602](INFO): No messages in MT queue 2023-06-26T18:50:33.655Z,1687805433.655 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230626T154918/Courier0100.lzma 2023-06-26T18:50:34.658Z,1687805434.658 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0100.lzma.bak 2023-06-26T18:50:34.658Z,1687805434.658 [DataOverHttps](INFO): SBD MOMSN=18432857 2023-06-26T18:50:51.008Z,1687805451.008 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20230626T154918/Express0101.lzma 2023-06-26T18:50:52.006Z,1687805452.006 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0101.lzma.bak 2023-06-26T18:50:52.006Z,1687805452.006 [DataOverHttps](INFO): SBD MOMSN=18432860 2023-06-26T18:50:53.353Z,1687805453.353 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T18:50:53.365Z,1687805453.365 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T18:50:53.366Z,1687805453.366 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T18:50:53.366Z,1687805453.366 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T18:55:53.949Z,1687805753.949 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T18:55:53.949Z,1687805753.949 [Default:CheckIn:C.Wait] Stopped 2023-06-26T18:55:53.949Z,1687805753.949 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T18:55:53.949Z,1687805753.949 [Default:CheckIn:D] Running Loop=1 2023-06-26T18:55:54.390Z,1687805754.390 [Default:CheckIn:D] Stopped 2023-06-26T18:55:54.391Z,1687805754.391 [Default:CheckIn:E] Running Loop=1 2023-06-26T18:55:54.753Z,1687805754.753 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 182.712272 min 2023-06-26T18:55:54.753Z,1687805754.753 [Default:CheckIn:E] Stopped 2023-06-26T18:55:54.753Z,1687805754.753 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T18:55:54.753Z,1687805754.753 [Default:CheckIn] Stopped 2023-06-26T18:55:54.753Z,1687805754.753 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T18:55:54.753Z,1687805754.753 [Default:CheckIn](INFO): Running loop #33 2023-06-26T18:55:54.754Z,1687805754.754 [Default:CheckIn] Running Loop=33 2023-06-26T18:55:54.754Z,1687805754.754 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T18:55:54.754Z,1687805754.754 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T18:55:56.762Z,1687805756.762 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185556.00,A,3647.68345,N,12150.41057,W,13.937,264.57,260623,,,D*47 2023-06-26T18:55:56.771Z,1687805756.771 [NAL9602](INFO): GPS fix at 20230626T185556: (36.794724, -121.840176) 2023-06-26T18:55:56.797Z,1687805756.797 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T18:55:56.797Z,1687805756.797 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T18:56:05.231Z,1687805765.231 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230626T154918/Courier0103.lzma 2023-06-26T18:56:06.234Z,1687805766.234 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0103.lzma.bak 2023-06-26T18:56:06.234Z,1687805766.234 [DataOverHttps](INFO): SBD MOMSN=18432865 2023-06-26T18:56:13.334Z,1687805773.334 [NAL9602](INFO): SBD MO Status=0, MOMSN=26276, MT Status=0, MTMSN=0 2023-06-26T18:56:13.334Z,1687805773.334 [NAL9602](INFO): No messages in MT queue 2023-06-26T18:56:24.028Z,1687805784.028 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20230626T154918/Express0104.lzma 2023-06-26T18:56:25.030Z,1687805785.030 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0104.lzma.bak 2023-06-26T18:56:25.030Z,1687805785.030 [DataOverHttps](INFO): SBD MOMSN=18432868 2023-06-26T18:56:26.380Z,1687805786.380 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T18:56:26.380Z,1687805786.380 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T18:56:26.380Z,1687805786.380 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T18:56:44.102Z,1687805804.102 [NAL9602](INFO): Not Powering down - fast GPS 2023-06-26T18:59:54.984Z,1687805994.984 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-06-26T19:00:01.008Z,1687806001.008 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.239414 2023-06-26T19:00:49.868Z,1687806049.868 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002893 2023-06-26T19:01:10.405Z,1687806070.405 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2023-06-26T19:01:26.972Z,1687806086.972 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-06-26T19:01:26.972Z,1687806086.972 [Default:CheckIn:C.Wait] Stopped 2023-06-26T19:01:26.972Z,1687806086.972 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-06-26T19:01:26.972Z,1687806086.972 [Default:CheckIn:D] Running Loop=1 2023-06-26T19:01:27.375Z,1687806087.375 [Default:CheckIn:D] Stopped 2023-06-26T19:01:27.376Z,1687806087.376 [Default:CheckIn:E] Running Loop=1 2023-06-26T19:01:27.781Z,1687806087.781 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 188.262028 min 2023-06-26T19:01:27.781Z,1687806087.781 [Default:CheckIn:E] Stopped 2023-06-26T19:01:27.781Z,1687806087.781 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-06-26T19:01:27.781Z,1687806087.781 [Default:CheckIn] Stopped 2023-06-26T19:01:27.781Z,1687806087.781 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-06-26T19:01:27.781Z,1687806087.781 [Default:CheckIn](INFO): Running loop #34 2023-06-26T19:01:27.781Z,1687806087.781 [Default:CheckIn] Running Loop=34 2023-06-26T19:01:27.781Z,1687806087.781 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-06-26T19:01:27.781Z,1687806087.781 [Default:CheckIn:Read_GPS] Running Loop=1 2023-06-26T19:01:29.787Z,1687806089.787 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190129.00,A,3647.67596,N,12150.96776,W,1.633,123.74,260623,,,D*7F 2023-06-26T19:01:29.789Z,1687806089.789 [NAL9602](INFO): GPS fix at 20230626T190129: (36.794599, -121.849463) 2023-06-26T19:01:29.820Z,1687806089.820 [Default:CheckIn:Read_GPS] Stopped 2023-06-26T19:01:29.820Z,1687806089.820 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-06-26T19:01:37.539Z,1687806097.539 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230626T154918/Courier0106.lzma 2023-06-26T19:01:38.545Z,1687806098.545 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Courier0106.lzma.bak 2023-06-26T19:01:38.545Z,1687806098.545 [DataOverHttps](INFO): SBD MOMSN=18432872 2023-06-26T19:01:47.571Z,1687806107.571 [NAL9602](INFO): SBD MO Status=2, MOMSN=26277, MT Status=2, MTMSN=0 2023-06-26T19:01:47.572Z,1687806107.572 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-06-26T19:02:07.118Z,1687806127.118 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20230626T154918/Express0107.lzma 2023-06-26T19:02:08.118Z,1687806128.118 [DataOverHttps](INFO): Moved sent file to Logs/20230626T154918/Express0107.lzma.bak 2023-06-26T19:02:08.118Z,1687806128.118 [DataOverHttps](IMPORTANT): SBD MOMSN=18432877, MTMSN=20230626T190207 2023-06-26T19:02:09.413Z,1687806129.413 [Default:CheckIn:Read_Iridium] Stopped 2023-06-26T19:02:09.413Z,1687806129.413 [Default:CheckIn:C.Wait] Running Loop=1 2023-06-26T19:02:09.413Z,1687806129.413 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-06-26T19:02:12.207Z,1687806132.207 [NAL9602](INFO): SBD MO Status=0, MOMSN=26277, MT Status=0, MTMSN=0 2023-06-26T19:02:12.207Z,1687806132.207 [NAL9602](INFO): No messages in MT queue 2023-06-26T19:02:15.819Z,1687806135.819 [DataOverHttps](INFO): Received command: restart logs