2022-06-28T14:46:35.382Z,1656427595.382 [Supervisor](DEBUG): Initializing supervisor.
2022-06-28T14:46:35.386Z,1656427595.386 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2022-06-28T14:46:35.387Z,1656427595.387 [SyncHandler](INFO): Protected caller Thread ID is 837
2022-06-28T14:46:35.387Z,1656427595.387 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2022-06-28T14:46:35.388Z,1656427595.388 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2022-06-28T14:46:35.389Z,1656427595.389 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 838
2022-06-28T14:46:35.393Z,1656427595.393 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2022-06-28T14:46:35.410Z,1656427595.410 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2022-06-28T14:46:35.411Z,1656427595.411 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2022-06-28T14:46:35.412Z,1656427595.412 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 839
2022-06-28T14:46:35.416Z,1656427595.416 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2022-06-28T14:46:35.417Z,1656427595.417 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2022-06-28T14:46:35.417Z,1656427595.417 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 840
2022-06-28T14:46:35.419Z,1656427595.419 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2022-06-28T14:46:35.420Z,1656427595.420 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2022-06-28T14:46:35.420Z,1656427595.420 [logger ThreadHandler](INFO): Protected caller Thread ID is 841
2022-06-28T14:46:35.424Z,1656427595.424 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2022-06-28T14:46:35.424Z,1656427595.424 [Supervisor](INFO): Looking for Config files in directory: Config/
2022-06-28T14:46:35.429Z,1656427595.429 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2022-06-28T14:46:35.525Z,1656427595.525 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2022-06-28T14:46:35.527Z,1656427595.527 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2022-06-28T14:46:36.164Z,1656427596.164 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2022-06-28T14:46:36.165Z,1656427596.165 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2022-06-28T14:46:36.387Z,1656427596.387 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2022-06-28T14:46:36.388Z,1656427596.388 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2022-06-28T14:46:36.469Z,1656427596.469 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2022-06-28T14:46:36.591Z,1656427596.591 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2022-06-28T14:46:36.593Z,1656427596.593 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2022-06-28T14:46:36.675Z,1656427596.675 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2022-06-28T14:46:36.783Z,1656427596.783 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2022-06-28T14:46:36.784Z,1656427596.784 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2022-06-28T14:46:37.147Z,1656427597.147 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2022-06-28T14:46:37.149Z,1656427597.149 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2022-06-28T14:46:37.707Z,1656427597.707 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2022-06-28T14:46:37.709Z,1656427597.709 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2022-06-28T14:46:37.924Z,1656427597.924 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2022-06-28T14:46:37.926Z,1656427597.926 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2022-06-28T14:46:38.171Z,1656427598.171 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2022-06-28T14:46:38.172Z,1656427598.172 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2022-06-28T14:46:38.636Z,1656427598.636 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2022-06-28T14:46:38.636Z,1656427598.636 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2022-06-28T14:46:38.925Z,1656427598.925 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2022-06-28T14:46:38.928Z,1656427598.928 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2022-06-28T14:46:39.931Z,1656427599.931 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2022-06-28T14:46:39.931Z,1656427599.931 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2022-06-28T14:46:40.298Z,1656427600.298 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2022-06-28T14:46:40.300Z,1656427600.300 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2022-06-28T14:46:40.634Z,1656427600.634 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2022-06-28T14:46:40.636Z,1656427600.636 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2022-06-28T14:46:40.640Z,1656427600.640 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2022-06-28T14:46:40.723Z,1656427600.723 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2022-06-28T14:46:40.879Z,1656427600.879 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2022-06-28T14:46:40.988Z,1656427600.988 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2022-06-28T14:46:41.075Z,1656427601.075 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2022-06-28T14:46:41.169Z,1656427601.169 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2022-06-28T14:46:41.351Z,1656427601.351 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2022-06-28T14:46:41.612Z,1656427601.612 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2022-06-28T14:46:41.612Z,1656427601.612 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2022-06-28T14:46:41.707Z,1656427601.707 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2022-06-28T14:46:41.807Z,1656427601.807 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2022-06-28T14:46:41.947Z,1656427601.947 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2022-06-28T14:46:42.046Z,1656427602.046 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2022-06-28T14:46:42.065Z,1656427602.065 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2022-06-28T14:46:42.186Z,1656427602.186 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2022-06-28T14:46:42.186Z,1656427602.186 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2022-06-28T14:46:42.254Z,1656427602.254 [VerticalControl](DEBUG): Construct VerticalControl.
2022-06-28T14:46:42.314Z,1656427602.314 [VerticalControl] Loaded
2022-06-28T14:46:42.314Z,1656427602.314 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2022-06-28T14:46:42.317Z,1656427602.317 [HorizontalControl](DEBUG): Construct HorizontalControl.
2022-06-28T14:46:42.355Z,1656427602.355 [HorizontalControl] Loaded
2022-06-28T14:46:42.356Z,1656427602.356 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2022-06-28T14:46:42.358Z,1656427602.358 [SpeedControl](DEBUG): Construct SpeedControl.
2022-06-28T14:46:42.361Z,1656427602.361 [SpeedControl] Loaded
2022-06-28T14:46:42.361Z,1656427602.361 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2022-06-28T14:46:42.364Z,1656427602.364 [LoopControl](DEBUG): Construct LoopControl.
2022-06-28T14:46:42.364Z,1656427602.364 [LoopControl] Loaded
2022-06-28T14:46:42.365Z,1656427602.365 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2022-06-28T14:46:42.365Z,1656427602.365 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2022-06-28T14:46:42.366Z,1656427602.366 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2022-06-28T14:46:42.435Z,1656427602.435 [DepthRateCalculator] Loaded
2022-06-28T14:46:42.435Z,1656427602.435 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2022-06-28T14:46:42.440Z,1656427602.440 [PitchRateCalculator] Loaded
2022-06-28T14:46:42.440Z,1656427602.440 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2022-06-28T14:46:42.451Z,1656427602.451 [SpeedCalculator] Loaded
2022-06-28T14:46:42.451Z,1656427602.451 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2022-06-28T14:46:42.455Z,1656427602.455 [YawRateCalculator] Loaded
2022-06-28T14:46:42.455Z,1656427602.455 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2022-06-28T14:46:42.472Z,1656427602.472 [ElevatorOffsetCalculator] Loaded
2022-06-28T14:46:42.473Z,1656427602.473 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2022-06-28T14:46:42.473Z,1656427602.473 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2022-06-28T14:46:42.474Z,1656427602.474 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2022-06-28T14:46:42.516Z,1656427602.516 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2022-06-28T14:46:42.517Z,1656427602.517 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2022-06-28T14:46:42.598Z,1656427602.598 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2022-06-28T14:46:42.599Z,1656427602.599 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2022-06-28T14:46:42.956Z,1656427602.956 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2022-06-28T14:46:42.957Z,1656427602.957 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2022-06-28T14:46:43.094Z,1656427603.094 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2022-06-28T14:46:43.095Z,1656427603.095 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2022-06-28T14:46:43.816Z,1656427603.816 [AHRS_M2] Loaded
2022-06-28T14:46:43.816Z,1656427603.816 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2022-06-28T14:46:44.065Z,1656427604.065 [BackseatComponent] Loaded
2022-06-28T14:46:44.065Z,1656427604.065 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2022-06-28T14:46:44.066Z,1656427604.066 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 4096D4E0
2022-06-28T14:46:44.067Z,1656427604.067 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 924
2022-06-28T14:46:44.069Z,1656427604.069 [LcmUniversalReporter] Loaded
2022-06-28T14:46:44.069Z,1656427604.069 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2022-06-28T14:46:44.865Z,1656427604.865 [BPC1] Loaded
2022-06-28T14:46:44.866Z,1656427604.866 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2022-06-28T14:46:45.008Z,1656427605.008 [DataOverHttps] Loaded
2022-06-28T14:46:45.008Z,1656427605.008 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2022-06-28T14:46:45.009Z,1656427605.009 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4099D4E0
2022-06-28T14:46:45.009Z,1656427605.009 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 925
2022-06-28T14:46:45.029Z,1656427605.029 [Depth_Keller] Loaded
2022-06-28T14:46:45.029Z,1656427605.029 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2022-06-28T14:46:45.034Z,1656427605.034 [DropWeight] Loaded
2022-06-28T14:46:45.034Z,1656427605.034 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2022-06-28T14:46:45.093Z,1656427605.093 [NAL9602] Loaded
2022-06-28T14:46:45.093Z,1656427605.093 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2022-06-28T14:46:45.121Z,1656427605.121 [Onboard] Loaded
2022-06-28T14:46:45.122Z,1656427605.122 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2022-06-28T14:46:45.123Z,1656427605.123 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409CD4E0
2022-06-28T14:46:45.123Z,1656427605.123 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 926
2022-06-28T14:46:45.134Z,1656427605.134 [Power24vConverter] Loaded
2022-06-28T14:46:45.134Z,1656427605.134 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2022-06-28T14:46:45.147Z,1656427605.147 [Radio_Surface] Loaded
2022-06-28T14:46:45.147Z,1656427605.147 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2022-06-28T14:46:45.148Z,1656427605.148 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409FD4E0
2022-06-28T14:46:45.148Z,1656427605.148 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 927
2022-06-28T14:46:45.191Z,1656427605.191 [RDI_Pathfinder] Loaded
2022-06-28T14:46:45.191Z,1656427605.191 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2022-06-28T14:46:45.275Z,1656427605.275 [DAT] Loaded
2022-06-28T14:46:45.276Z,1656427605.276 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2022-06-28T14:46:45.277Z,1656427605.277 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40A2D4E0
2022-06-28T14:46:45.277Z,1656427605.277 [DAT ThreadHandler](INFO): Protected caller Thread ID is 928
2022-06-28T14:46:45.277Z,1656427605.277 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2022-06-28T14:46:45.278Z,1656427605.278 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2022-06-28T14:46:46.127Z,1656427606.127 [DeadReckonUsingMultipleVelocitySources] Loaded
2022-06-28T14:46:46.127Z,1656427606.127 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2022-06-28T14:46:46.140Z,1656427606.140 [NavChart] Loaded
2022-06-28T14:46:46.141Z,1656427606.141 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2022-06-28T14:46:46.146Z,1656427606.146 [UniversalFixResidualReporter] Loaded
2022-06-28T14:46:46.147Z,1656427606.147 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2022-06-28T14:46:46.147Z,1656427606.147 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2022-06-28T14:46:46.149Z,1656427606.149 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2022-06-28T14:46:46.314Z,1656427606.314 [SBIT](DEBUG): Construct Startup Built In Test.
2022-06-28T14:46:46.323Z,1656427606.323 [SBIT] Loaded
2022-06-28T14:46:46.324Z,1656427606.324 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2022-06-28T14:46:46.326Z,1656427606.326 [IBIT](DEBUG): Construct Initiated Built In Test.
2022-06-28T14:46:46.339Z,1656427606.339 [IBIT] Loaded
2022-06-28T14:46:46.340Z,1656427606.340 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2022-06-28T14:46:46.345Z,1656427606.345 [CBIT](DEBUG): Construct Continuous Built In Test.
2022-06-28T14:46:46.449Z,1656427606.449 [CBIT] Loaded
2022-06-28T14:46:46.449Z,1656427606.449 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2022-06-28T14:46:46.450Z,1656427606.450 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2022-06-28T14:46:46.451Z,1656427606.451 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2022-06-28T14:46:46.600Z,1656427606.600 [BuoyancyServo] Loaded
2022-06-28T14:46:46.601Z,1656427606.601 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2022-06-28T14:46:46.621Z,1656427606.621 [ElevatorServo] Loaded
2022-06-28T14:46:46.622Z,1656427606.622 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2022-06-28T14:46:46.640Z,1656427606.640 [MassServo] Loaded
2022-06-28T14:46:46.641Z,1656427606.641 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2022-06-28T14:46:46.659Z,1656427606.659 [RudderServo] Loaded
2022-06-28T14:46:46.659Z,1656427606.659 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2022-06-28T14:46:46.676Z,1656427606.676 [ThrusterServo] Loaded
2022-06-28T14:46:46.677Z,1656427606.677 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2022-06-28T14:46:46.677Z,1656427606.677 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2022-06-28T14:46:46.678Z,1656427606.678 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2022-06-28T14:46:46.693Z,1656427606.693 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2022-06-28T14:46:46.694Z,1656427606.694 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2022-06-28T14:46:46.910Z,1656427606.910 [CTD_Seabird] Loaded
2022-06-28T14:46:46.910Z,1656427606.910 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2022-06-28T14:46:46.911Z,1656427606.911 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B774E0
2022-06-28T14:46:46.911Z,1656427606.911 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 929
2022-06-28T14:46:46.931Z,1656427606.931 [PAR_Licor] Loaded
2022-06-28T14:46:46.931Z,1656427606.931 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2022-06-28T14:46:46.962Z,1656427606.962 [WetLabsBB2FL] Loaded
2022-06-28T14:46:46.962Z,1656427606.962 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2022-06-28T14:46:46.963Z,1656427606.963 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40BA74E0
2022-06-28T14:46:46.964Z,1656427606.964 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 930
2022-06-28T14:46:46.984Z,1656427606.984 [WetLabsUBAT] Loaded
2022-06-28T14:46:46.984Z,1656427606.984 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread.
2022-06-28T14:46:46.985Z,1656427606.985 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40BD74E0
2022-06-28T14:46:46.985Z,1656427606.985 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 931
2022-06-28T14:46:46.986Z,1656427606.986 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2022-06-28T14:46:46.992Z,1656427606.992 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2022-06-28T14:46:46.995Z,1656427606.995 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2022-06-28T14:46:47.005Z,1656427607.005 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2022-06-28T14:46:47.006Z,1656427607.006 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C074E0
2022-06-28T14:46:47.007Z,1656427607.007 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 932
2022-06-28T14:46:47.011Z,1656427607.011 [Supervisor](INFO): Main Thread ID is 830
2022-06-28T14:46:47.011Z,1656427607.011 [Supervisor](DEBUG): Running supervisor.
2022-06-28T14:46:47.012Z,1656427607.012 [CommandExec ThreadHandler](INFO): Handler Thread ID is 933
2022-06-28T14:46:47.012Z,1656427607.012 [CommandExec](INFO): Initializing the command executive.
2022-06-28T14:46:47.014Z,1656427607.014 [CommandLine ThreadHandler](INFO): Handler Thread ID is 934
2022-06-28T14:46:47.016Z,1656427607.016 [controlThread ThreadHandler](INFO): Handler Thread ID is 935
2022-06-28T14:46:47.016Z,1656427607.016 [controlThread](DEBUG): Initializing ControlThread
2022-06-28T14:46:47.017Z,1656427607.017 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2022-06-28T14:46:47.019Z,1656427607.019 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2022-06-28T14:46:47.019Z,1656427607.019 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2022-06-28T14:46:47.020Z,1656427607.020 [LoopControl](DEBUG): Initialize LoopControlComponent.
2022-06-28T14:46:47.020Z,1656427607.020 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2022-06-28T14:46:47.021Z,1656427607.021 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2022-06-28T14:46:47.021Z,1656427607.021 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2022-06-28T14:46:47.021Z,1656427607.021 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2022-06-28T14:46:47.022Z,1656427607.022 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2022-06-28T14:46:47.028Z,1656427607.028 [NavChart](DEBUG): Initialize NavChart Navigation.
2022-06-28T14:46:47.029Z,1656427607.029 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2022-06-28T14:46:47.029Z,1656427607.029 [SBIT](INFO): Initialize SBIT Component.
2022-06-28T14:46:47.029Z,1656427607.029 [SBIT](IMPORTANT): git: 2022-06-07-3-g3731f8b3f
2022-06-28T14:46:47.030Z,1656427607.030 [SBIT](INFO): git hash: 3731f8b3f5f07755356c125fa6a04ab4ea762347
2022-06-28T14:46:47.030Z,1656427607.030 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2022-06-28T14:46:47.031Z,1656427607.031 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2022-06-28T14:46:47.032Z,1656427607.032 [SBIT](INFO): Beginning SBIT in 43.000000 seconds.
2022-06-28T14:46:47.033Z,1656427607.033 [IBIT](INFO): Initialize IBIT Component.
2022-06-28T14:46:47.033Z,1656427607.033 [CBIT](DEBUG): Initialize CBIT Component.
2022-06-28T14:46:47.035Z,1656427607.035 [logger ThreadHandler](INFO): Handler Thread ID is 936
2022-06-28T14:46:47.046Z,1656427607.046 [CBIT](DEBUG): Initialized mux pins.
2022-06-28T14:46:47.046Z,1656427607.046 [CBIT](DEBUG): Initializing the watchdog timer.
2022-06-28T14:46:47.054Z,1656427607.054 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 937
2022-06-28T14:46:47.066Z,1656427607.066 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 938
2022-06-28T14:46:47.067Z,1656427607.067 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2022-06-28T14:46:47.070Z,1656427607.070 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2022-06-28T14:46:47.070Z,1656427607.070 [CBIT](DEBUG): Initializing heartbeat.
2022-06-28T14:46:47.093Z,1656427607.093 [Onboard ThreadHandler](INFO): Handler Thread ID is 939
2022-06-28T14:46:47.115Z,1656427607.115 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 940
2022-06-28T14:46:47.134Z,1656427607.134 [DAT ThreadHandler](INFO): Handler Thread ID is 941
2022-06-28T14:46:47.135Z,1656427607.135 [DAT](INFO): Powering up
2022-06-28T14:46:47.135Z,1656427607.135 [DAT](DEBUG): Initializing DAT.
2022-06-28T14:46:47.139Z,1656427607.139 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 943
2022-06-28T14:46:47.140Z,1656427607.140 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2022-06-28T14:46:47.142Z,1656427607.142 [CBIT](DEBUG): Deactivating GF circuits.
2022-06-28T14:46:47.142Z,1656427607.142 [CBIT](DEBUG): Deactivating emergency mode.
2022-06-28T14:46:47.144Z,1656427607.144 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 945
2022-06-28T14:46:47.146Z,1656427607.146 [WetLabsBB2FL](INFO): Powering up
2022-06-28T14:46:47.148Z,1656427607.148 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 947
2022-06-28T14:46:47.151Z,1656427607.151 [WetLabsUBAT](INFO): Powering up
2022-06-28T14:46:47.152Z,1656427607.152 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 949
2022-06-28T14:46:47.163Z,1656427607.163 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2022-06-28T14:46:47.163Z,1656427607.163 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2022-06-28T14:46:47.163Z,1656427607.163 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2022-06-28T14:46:47.163Z,1656427607.163 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2022-06-28T14:46:47.163Z,1656427607.163 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2022-06-28T14:46:47.164Z,1656427607.164 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2022-06-28T14:46:47.164Z,1656427607.164 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2022-06-28T14:46:47.164Z,1656427607.164 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2022-06-28T14:46:47.178Z,1656427607.178 [CBIT](DEBUG): Backplane powered.
2022-06-28T14:46:47.183Z,1656427607.183 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2022-06-28T14:46:47.222Z,1656427607.222 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2022-06-28T14:46:47.245Z,1656427607.245 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2022-06-28T14:46:47.264Z,1656427607.264 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2022-06-28T14:46:47.338Z,1656427607.338 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2022-06-28T14:46:47.339Z,1656427607.339 [Default:A.Wait](DEBUG): Construct Wait.
2022-06-28T14:46:47.341Z,1656427607.341 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2022-06-28T14:46:47.361Z,1656427607.361 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2022-06-28T14:46:47.383Z,1656427607.383 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2022-06-28T14:46:47.405Z,1656427607.405 [Default:E.Execute](DEBUG): Construct Execute.
2022-06-28T14:46:47.409Z,1656427607.409 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn on</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2022-06-28T14:46:47.413Z,1656427607.413 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,RDI_Pathfinder,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2022-06-28T14:46:47.434Z,1656427607.434 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2022-06-28T14:46:47.518Z,1656427607.518 [Radio_Surface](INFO): Powering up
2022-06-28T14:46:47.608Z,1656427607.608 [Power24vConverter](INFO): Powering up.
2022-06-28T14:46:47.609Z,1656427607.609 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format
2022-06-28T14:46:47.645Z,1656427607.645 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2022-06-28T14:46:47.650Z,1656427607.650 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2022-06-28T14:46:47.651Z,1656427607.651 [ElevatorServo](DEBUG): Initializing EZServoServo.
2022-06-28T14:46:47.658Z,1656427607.658 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2022-06-28T14:46:47.659Z,1656427607.659 [MassServo](DEBUG): Initializing EZServoServo.
2022-06-28T14:46:47.667Z,1656427607.667 [MassServo](DEBUG): Initializing MassServo.
2022-06-28T14:46:47.667Z,1656427607.667 [RudderServo](DEBUG): Initializing EZServoServo.
2022-06-28T14:46:47.674Z,1656427607.674 [RudderServo](DEBUG): Initializing RudderServo.
2022-06-28T14:46:47.675Z,1656427607.675 [ThrusterServo](DEBUG): Initializing EZServoServo.
2022-06-28T14:46:47.682Z,1656427607.682 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2022-06-28T14:46:48.582Z,1656427608.582 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2022-06-28T14:46:48.582Z,1656427608.582 [RudderServo](FAULT): Rudder failed to initialize
2022-06-28T14:46:48.582Z,1656427608.582 [RudderServo] Communications Fault, FailCount= 1
2022-06-28T14:46:48.582Z,1656427608.582 [RudderServo](ERROR): Communications Fault
2022-06-28T14:46:48.682Z,1656427608.682 [CBIT](ERROR): Communications Fault in component: RudderServo
2022-06-28T14:46:48.852Z,1656427608.852 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-06-28T14:46:48.853Z,1656427608.853 [RudderServo](INFO): Powering down
2022-06-28T14:46:49.541Z,1656427609.541 [RudderServo](DEBUG): Initializing EZServoServo.
2022-06-28T14:46:49.659Z,1656427609.659 [RudderServo](DEBUG): Initializing RudderServo.
2022-06-28T14:46:49.663Z,1656427609.663 [CBIT](INFO): Clearing failed state for component RudderServo
2022-06-28T14:46:49.663Z,1656427609.663 [RudderServo] No Fault, FailCount= 1
2022-06-28T14:46:49.758Z,1656427609.758 [WetLabsBB2FL](INFO): Powering down
2022-06-28T14:46:56.478Z,1656427616.478 [WetLabsUBAT](INFO): Powering down
2022-06-28T14:46:59.232Z,1656427619.232 [DAT](INFO): DAT read: 

2022-06-28T14:46:59.236Z,1656427619.236 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2022-06-28T14:47:00.743Z,1656427620.743 [DAT](INFO): DAT read: MF Frequency Band

2022-06-28T14:47:00.744Z,1656427620.744 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2022-06-28T14:47:00.744Z,1656427620.744 [DAT](INFO): DAT read: Jun 28 2022 14:46:52 

2022-06-28T14:47:01.751Z,1656427621.751 [DAT](INFO): DAT read: Features enabled [Bearing]

2022-06-28T14:47:01.752Z,1656427621.752 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2022-06-28T14:47:01.752Z,1656427621.753 [DAT](INFO): commRate: 800
2022-06-28T14:47:03.818Z,1656427623.818 [DAT](INFO): entering command mode
2022-06-28T14:47:04.018Z,1656427624.018 [DAT](INFO): DAT read: 

2022-06-28T14:47:04.019Z,1656427624.019 [DAT](INFO): DAT read: user:1>

2022-06-28T14:47:04.019Z,1656427624.019 [DAT](INFO): setting verbose to 3
2022-06-28T14:47:04.271Z,1656427624.271 [DAT](INFO): DAT read: user:1>

2022-06-28T14:47:04.272Z,1656427624.272 [DAT](INFO): DAT read: Verbose         | 3           

2022-06-28T14:47:04.272Z,1656427624.272 [DAT](INFO): set verbose to 3
2022-06-28T14:47:04.272Z,1656427624.272 [DAT](INFO): setting DatVerbose to 27440
2022-06-28T14:47:04.523Z,1656427624.523 [DAT](INFO): DAT read: user:2>

2022-06-28T14:47:04.524Z,1656427624.524 [DAT](INFO): DAT read: DatVerbose      | 27440       

2022-06-28T14:47:04.524Z,1656427624.524 [DAT](INFO): set DatVerbose to 27440
2022-06-28T14:47:04.524Z,1656427624.524 [DAT](INFO): setting transmit power to 8
2022-06-28T14:47:04.775Z,1656427624.775 [DAT](INFO): DAT read: user:3>

2022-06-28T14:47:04.776Z,1656427624.776 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2022-06-28T14:47:04.776Z,1656427624.776 [DAT](INFO): set transmit power to 8
2022-06-28T14:47:04.776Z,1656427624.776 [DAT](INFO): setting local address to 9
2022-06-28T14:47:05.027Z,1656427625.027 [DAT](INFO): DAT read: user:4>

2022-06-28T14:47:05.028Z,1656427625.028 [DAT](INFO): DAT read: LocalAddr       | 9           

2022-06-28T14:47:05.028Z,1656427625.028 [DAT](INFO): set local address to 9
2022-06-28T14:47:15.368Z,1656427635.368 [NAL9602](INFO): Powering up NAL9602
2022-06-28T14:47:26.268Z,1656427646.268 [NAL9602](INFO): NAL9602 initialized
2022-06-28T14:47:30.744Z,1656427650.744 [SBIT](IMPORTANT): Beginning Startup BIT
2022-06-28T14:47:30.773Z,1656427650.773 [CBIT](IMPORTANT): Beginning ground fault scan
2022-06-28T14:47:41.695Z,1656427661.695 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.009616
CHAN A1 (24V): 0.002238
CHAN A2 (12V): -0.006788
CHAN A3 (5V): -0.001815
CHAN B0 (3.3V): 0.000881
CHAN B1 (3.15aV): -0.000358
CHAN B2 (3.15bV): -0.000487
CHAN B3 (GND): 0.001882
OPEN: -0.002913
Full Scale: +/- 1 mA
2022-06-28T14:47:58.250Z,1656427678.250 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2022-06-28T14:48:08.752Z,1656427688.752 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2022-06-28T14:48:20.068Z,1656427700.068 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2022-06-28T14:48:24.877Z,1656427704.877 [SBIT](IMPORTANT): SBIT PASSED
2022-06-28T14:48:24.877Z,1656427704.877 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2022-06-28T14:48:24.878Z,1656427704.878 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;

2022-06-28T14:48:24.878Z,1656427704.878 [SBIT](IMPORTANT): CBIT.gf24Offset=143 microampere;

2022-06-28T14:48:24.878Z,1656427704.878 [SBIT](IMPORTANT): DAT.baud=115200 bit_per_second;

2022-06-28T14:48:24.878Z,1656427704.878 [SBIT](IMPORTANT): DAT.loadAtStartup=1 bool;

2022-06-28T14:48:24.878Z,1656427704.878 [SBIT](IMPORTANT): DAT.surfaceThreshold=0 meter;

2022-06-28T14:48:24.879Z,1656427704.879 [SBIT](IMPORTANT): DAT.verbosity=2 count;

2022-06-28T14:48:24.879Z,1656427704.879 [SBIT](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 0.300000 liter_per_second;

2022-06-28T14:48:24.879Z,1656427704.879 [SBIT](IMPORTANT): Express none _.adinos;

2022-06-28T14:48:24.879Z,1656427704.879 [SBIT](IMPORTANT): Express none _.aother;

2022-06-28T14:48:24.879Z,1656427704.879 [SBIT](IMPORTANT): Express linearApproximation _.dinoflagellates 10000000000.000000 none;

2022-06-28T14:48:24.879Z,1656427704.879 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=24 ampere_hour;

2022-06-28T14:48:24.879Z,1656427704.879 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=13 volt;

2022-06-28T14:48:24.879Z,1656427704.879 [SBIT](IMPORTANT): Power24vConverter.simulateHardware=0 bool;

2022-06-28T14:48:24.880Z,1656427704.880 [SBIT](IMPORTANT): RDI_Pathfinder.loadAtStartup=1 bool;

2022-06-28T14:48:24.880Z,1656427704.880 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=217.756135 cubic_centimeter;

2022-06-28T14:48:24.880Z,1656427704.880 [SBIT](IMPORTANT): VerticalControl.massDefault=5.941978 millimeter;

2022-06-28T14:48:25.301Z,1656427705.301 [MissionManager](IMPORTANT): Started mission Startup
2022-06-28T14:48:25.301Z,1656427705.301 [Startup] Running Loop=1
2022-06-28T14:48:25.302Z,1656427705.302 [Startup](DEBUG): Aggregate::initialize Startup
2022-06-28T14:48:25.302Z,1656427705.302 [Startup:A.GoToSurface] Running Loop=1
2022-06-28T14:48:25.302Z,1656427705.302 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-06-28T14:48:25.303Z,1656427705.303 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-06-28T14:48:25.303Z,1656427705.303 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-06-28T14:48:25.303Z,1656427705.303 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-06-28T14:48:25.304Z,1656427705.304 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-06-28T14:48:25.304Z,1656427705.304 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-06-28T14:48:25.305Z,1656427705.305 [Startup:StartupSatComms] Running Loop=1
2022-06-28T14:48:25.305Z,1656427705.305 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2022-06-28T14:48:25.305Z,1656427705.305 [Startup:StartupSatComms:A] Running Loop=1
2022-06-28T14:48:25.673Z,1656427705.673 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2022-06-28T14:48:30.971Z,1656427710.971 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2022-06-28T14:48:41.880Z,1656427721.880 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2022-06-28T14:48:52.790Z,1656427732.790 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2022-06-28T14:49:03.695Z,1656427743.695 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2022-06-28T14:49:07.286Z,1656427747.286 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2022-06-28T14:49:14.609Z,1656427754.609 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2022-06-28T14:49:25.108Z,1656427765.108 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2022-06-28T14:49:25.509Z,1656427765.509 [Startup:StartupSatComms:A](INFO): Timed out from 2022-06-28T14:48:25.3Z
2022-06-28T14:49:25.509Z,1656427765.509 [Startup:StartupSatComms:A] Stopped
2022-06-28T14:49:25.509Z,1656427765.509 [Startup:StartupSatComms:B] Running Loop=1
2022-06-28T14:49:25.901Z,1656427765.901 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-06-28T14:49:32.217Z,1656427772.217 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005002
2022-06-28T14:49:38.841Z,1656427778.841 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20220628T143029/Courier0007.lzma
2022-06-28T14:49:39.832Z,1656427779.832 [DataOverHttps](INFO): Moved sent file to Logs/20220628T143029/Courier0007.lzma.bak
2022-06-28T14:49:39.832Z,1656427779.832 [DataOverHttps](INFO): SBD MOMSN=16931991
2022-06-28T14:49:47.323Z,1656427787.323 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2022-06-28T14:49:47.323Z,1656427787.323 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-06-28T14:49:47.338Z,1656427787.338 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-06-28T14:49:47.689Z,1656427787.689 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-06-28T14:49:47.690Z,1656427787.690 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2022-06-28T14:49:55.794Z,1656427795.794 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20220628T144635/Courier0000.lzma
2022-06-28T14:49:56.796Z,1656427796.796 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Courier0000.lzma.bak
2022-06-28T14:49:56.796Z,1656427796.796 [DataOverHttps](INFO): SBD MOMSN=16931993
2022-06-28T14:50:12.841Z,1656427812.841 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20220628T143029/Express0008.lzma
2022-06-28T14:50:13.844Z,1656427813.844 [DataOverHttps](INFO): Moved sent file to Logs/20220628T143029/Express0008.lzma.bak
2022-06-28T14:50:13.844Z,1656427813.844 [DataOverHttps](INFO): SBD MOMSN=16931996
2022-06-28T14:50:25.664Z,1656427825.664 [Startup:StartupSatComms:B](INFO): Timed out from 2022-06-28T14:49:25.5Z
2022-06-28T14:50:25.664Z,1656427825.664 [Startup:StartupSatComms:B] Stopped
2022-06-28T14:50:25.664Z,1656427825.664 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2022-06-28T14:50:25.664Z,1656427825.664 [Startup:StartupSatComms] Stopped
2022-06-28T14:50:25.664Z,1656427825.664 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2022-06-28T14:50:25.665Z,1656427825.665 [Startup](INFO): Completed Startup
2022-06-28T14:50:25.665Z,1656427825.665 [MissionManager](INFO): Startup is completed.
2022-06-28T14:50:25.665Z,1656427825.665 [MissionManager](INFO): Uninitializing Mission Startup
2022-06-28T14:50:25.665Z,1656427825.665 [Startup] Stopped
2022-06-28T14:50:25.665Z,1656427825.665 [Startup](DEBUG): Aggregate::uninitialize Startup
2022-06-28T14:50:25.665Z,1656427825.665 [Startup:A.GoToSurface] Stopped
2022-06-28T14:50:25.666Z,1656427825.666 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-06-28T14:50:26.072Z,1656427826.072 [MissionManager](IMPORTANT): Started mission Default
2022-06-28T14:50:26.072Z,1656427826.072 [Default] Running Loop=1
2022-06-28T14:50:26.072Z,1656427826.072 [Default](DEBUG): Aggregate::initialize Default
2022-06-28T14:50:26.072Z,1656427826.072 [Default:B.GoToSurface] Running Loop=1
2022-06-28T14:50:26.072Z,1656427826.072 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-06-28T14:50:26.072Z,1656427826.072 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-06-28T14:50:26.073Z,1656427826.073 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-06-28T14:50:26.073Z,1656427826.073 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-06-28T14:50:26.073Z,1656427826.073 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-06-28T14:50:26.078Z,1656427826.078 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-06-28T14:50:26.079Z,1656427826.079 [Default:A.Wait] Running Loop=1
2022-06-28T14:50:26.079Z,1656427826.079 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-06-28T14:50:29.000Z,1656427830.000 [DataOverHttps](INFO): Sending 1040 bytes from file Logs/20220628T144635/Express0001.lzma
2022-06-28T14:50:30.000Z,1656427831.000 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Express0001.lzma.bak
2022-06-28T14:50:30.000Z,1656427831.000 [DataOverHttps](INFO): SBD MOMSN=16931998
2022-06-28T14:50:39.427Z,1656427839.427 [Default:A.Wait](INFO): Done Waiting.
2022-06-28T14:50:39.428Z,1656427839.428 [Default:A.Wait] Stopped
2022-06-28T14:50:39.428Z,1656427839.428 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-06-28T14:50:39.796Z,1656427839.796 [Default:CheckIn] Running Loop=1
2022-06-28T14:50:39.797Z,1656427839.797 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-06-28T14:50:39.797Z,1656427839.797 [Default:CheckIn:Read_GPS] Running Loop=1
2022-06-28T14:50:40.201Z,1656427840.201 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2022-06-28T14:51:00.886Z,1656427860.886 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2022-06-28T14:51:13.429Z,1656427873.429 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2022-06-28T14:51:17.814Z,1656427877.814 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2022-06-28T14:51:29.926Z,1656427889.926 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2022-06-28T14:52:00.591Z,1656427920.591 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2022-06-28T14:52:29.668Z,1656427949.668 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-06-28T14:52:48.291Z,1656427968.291 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2022-06-28T14:52:48.291Z,1656427968.291 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-06-28T14:52:48.301Z,1656427968.301 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-06-28T14:52:48.709Z,1656427968.709 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-06-28T14:52:48.709Z,1656427968.709 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2022-06-28T14:52:49.917Z,1656427969.917 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2022-06-28T14:53:39.615Z,1656428019.615 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2022-06-28T14:54:22.395Z,1656428062.395 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2022-06-28T14:54:33.765Z,1656428073.765 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2022-06-28T14:54:45.132Z,1656428085.132 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2022-06-28T14:54:56.795Z,1656428096.795 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2022-06-28T14:55:07.701Z,1656428107.701 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2022-06-28T14:55:18.684Z,1656428118.684 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2022-06-28T14:55:29.920Z,1656428129.920 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2022-06-28T14:55:39.968Z,1656428139.968 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-06-28T14:50:39.8Z
2022-06-28T14:55:39.968Z,1656428139.968 [Default:CheckIn:Read_GPS] Stopped
2022-06-28T14:55:39.968Z,1656428139.968 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-06-28T14:55:40.374Z,1656428140.374 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-06-28T14:55:40.892Z,1656428140.892 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2022-06-28T14:55:47.537Z,1656428147.537 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20220628T144635/Courier0004.lzma
2022-06-28T14:55:48.540Z,1656428148.540 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Courier0004.lzma.bak
2022-06-28T14:55:48.540Z,1656428148.540 [DataOverHttps](INFO): SBD MOMSN=16932027
2022-06-28T14:55:49.267Z,1656428149.267 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2022-06-28T14:55:49.267Z,1656428149.267 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-06-28T14:55:49.281Z,1656428149.281 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-06-28T14:55:49.712Z,1656428149.712 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-06-28T14:55:49.712Z,1656428149.712 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2022-06-28T14:56:05.029Z,1656428165.029 [DataOverHttps](INFO): Sending 188 bytes from file Logs/20220628T144635/Express0005.lzma
2022-06-28T14:56:06.032Z,1656428166.032 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Express0005.lzma.bak
2022-06-28T14:56:06.032Z,1656428166.032 [DataOverHttps](INFO): SBD MOMSN=16932029
2022-06-28T14:56:07.059Z,1656428167.059 [Default:CheckIn:Read_Iridium] Stopped
2022-06-28T14:56:07.060Z,1656428167.060 [Default:CheckIn:C.Wait] Running Loop=1
2022-06-28T14:56:07.060Z,1656428167.060 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-06-28T14:56:47.027Z,1656428207.027 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2022-06-28T14:56:47.030Z,1656428207.030 [BPC1](INFO): Received data from all battery sticks.
2022-06-28T14:57:14.710Z,1656428234.710 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.239239
2022-06-28T14:57:28.640Z,1656428248.640 [NAL9602](FAULT): GPS failed to acquire within timeout.
2022-06-28T14:57:28.640Z,1656428248.640 [NAL9602] Data Fault, FailCount= 1
2022-06-28T14:57:28.640Z,1656428248.640 [NAL9602](ERROR): Data Fault
2022-06-28T14:57:28.657Z,1656428248.657 [CBIT](ERROR): Data Fault in component: NAL9602
2022-06-28T14:57:29.045Z,1656428249.045 [NAL9602](INFO): Powering down
2022-06-28T14:57:29.865Z,1656428249.865 [CBIT](INFO): Clearing failed state for component NAL9602
2022-06-28T14:57:29.865Z,1656428249.865 [NAL9602] No Fault, FailCount= 1
2022-06-28T14:57:47.870Z,1656428267.870 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T14:57:59.366Z,1656428279.366 [NAL9602](INFO): Powering up NAL9602
2022-06-28T14:58:10.244Z,1656428290.244 [NAL9602](INFO): NAL9602 initialized
2022-06-28T14:58:23.018Z,1656428303.018 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T14:58:50.251Z,1656428330.251 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2022-06-28T14:58:50.251Z,1656428330.251 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-06-28T14:58:50.285Z,1656428330.285 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-06-28T14:58:50.697Z,1656428330.697 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-06-28T14:58:50.697Z,1656428330.697 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2022-06-28T14:58:58.158Z,1656428338.158 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T14:59:33.311Z,1656428373.311 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T15:00:08.450Z,1656428408.450 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T15:00:43.590Z,1656428443.590 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T15:01:07.643Z,1656428467.643 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-06-28T15:01:07.643Z,1656428467.643 [Default:CheckIn:C.Wait] Stopped
2022-06-28T15:01:07.643Z,1656428467.643 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-06-28T15:01:07.643Z,1656428467.643 [Default:CheckIn:D] Running Loop=1
2022-06-28T15:01:08.057Z,1656428468.057 [Default:CheckIn:D] Stopped
2022-06-28T15:01:08.057Z,1656428468.057 [Default:CheckIn:E] Running Loop=1
2022-06-28T15:01:08.423Z,1656428468.423 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.699755 min 
2022-06-28T15:01:08.423Z,1656428468.423 [Default:CheckIn:E] Stopped
2022-06-28T15:01:08.423Z,1656428468.423 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-06-28T15:01:08.423Z,1656428468.423 [Default:CheckIn] Stopped
2022-06-28T15:01:08.423Z,1656428468.423 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-06-28T15:01:08.423Z,1656428468.423 [Default:CheckIn](INFO): Running loop #2
2022-06-28T15:01:08.424Z,1656428468.424 [Default:CheckIn] Running Loop=2
2022-06-28T15:01:08.424Z,1656428468.424 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-06-28T15:01:08.424Z,1656428468.424 [Default:CheckIn:Read_GPS] Running Loop=1
2022-06-28T15:01:18.734Z,1656428478.734 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T15:01:51.277Z,1656428511.277 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2022-06-28T15:01:51.277Z,1656428511.277 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-06-28T15:01:51.290Z,1656428511.290 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-06-28T15:01:51.705Z,1656428511.705 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-06-28T15:01:51.705Z,1656428511.705 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2022-06-28T15:01:53.874Z,1656428513.874 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T15:02:29.014Z,1656428549.014 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T15:03:04.166Z,1656428584.166 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T15:03:24.966Z,1656428604.966 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150323.00,A,3648.16801,N,12147.27992,W,0.039,0.00,280622,,,A*7D
2022-06-28T15:03:24.969Z,1656428604.969 [NAL9602](INFO): GPS fix at 20220628T150323: (36.802800, -121.787999)
2022-06-28T15:03:24.980Z,1656428604.980 [Default:CheckIn:Read_GPS] Stopped
2022-06-28T15:03:24.980Z,1656428604.980 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-06-28T15:03:39.308Z,1656428619.308 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T15:04:14.446Z,1656428654.446 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T15:04:32.113Z,1656428672.113 [NAL9602](INFO): SBD MO Status=2, MOMSN=19348, MT Status=2, MTMSN=0
2022-06-28T15:04:32.113Z,1656428672.113 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-06-28T15:04:49.586Z,1656428689.586 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T15:04:58.060Z,1656428698.060 [NAL9602](INFO): SBD MO Status=2, MOMSN=19348, MT Status=2, MTMSN=0
2022-06-28T15:04:58.061Z,1656428698.061 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-06-28T15:05:22.555Z,1656428722.555 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003220
2022-06-28T15:05:30.102Z,1656428730.102 [DataOverHttps](INFO): Sending 286 bytes from file Logs/20220628T144635/Courier0007.lzma
2022-06-28T15:05:31.104Z,1656428731.104 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Courier0007.lzma.bak
2022-06-28T15:05:31.104Z,1656428731.104 [DataOverHttps](INFO): SBD MOMSN=16932081
2022-06-28T15:05:32.491Z,1656428732.491 [NAL9602](INFO): SBD MO Status=2, MOMSN=19348, MT Status=2, MTMSN=0
2022-06-28T15:05:32.491Z,1656428732.491 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-06-28T15:05:47.394Z,1656428747.394 [DataOverHttps](INFO): Sending 309 bytes from file Logs/20220628T144635/Express0008.lzma
2022-06-28T15:05:48.396Z,1656428748.396 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Express0008.lzma.bak
2022-06-28T15:05:48.396Z,1656428748.396 [DataOverHttps](INFO): SBD MOMSN=16932084
2022-06-28T15:05:49.502Z,1656428749.502 [Default:CheckIn:Read_Iridium] Stopped
2022-06-28T15:05:49.502Z,1656428749.502 [Default:CheckIn:C.Wait] Running Loop=1
2022-06-28T15:05:49.503Z,1656428749.503 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-06-28T15:06:03.199Z,1656428763.199 [NAL9602](INFO): Not Powering down - fast GPS
2022-06-28T15:10:50.098Z,1656429050.098 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-06-28T15:10:50.098Z,1656429050.098 [Default:CheckIn:C.Wait] Stopped
2022-06-28T15:10:50.098Z,1656429050.098 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-06-28T15:10:50.098Z,1656429050.098 [Default:CheckIn:D] Running Loop=1
2022-06-28T15:10:50.493Z,1656429050.493 [Default:CheckIn:D] Stopped
2022-06-28T15:10:50.493Z,1656429050.493 [Default:CheckIn:E] Running Loop=1
2022-06-28T15:10:50.894Z,1656429050.894 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.407017 min 
2022-06-28T15:10:50.894Z,1656429050.894 [Default:CheckIn:E] Stopped
2022-06-28T15:10:50.894Z,1656429050.894 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-06-28T15:10:50.894Z,1656429050.894 [Default:CheckIn] Stopped
2022-06-28T15:10:50.894Z,1656429050.894 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-06-28T15:10:50.894Z,1656429050.894 [Default:CheckIn](INFO): Running loop #3
2022-06-28T15:10:50.894Z,1656429050.894 [Default:CheckIn] Running Loop=3
2022-06-28T15:10:50.895Z,1656429050.895 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-06-28T15:10:50.895Z,1656429050.895 [Default:CheckIn:Read_GPS] Running Loop=1
2022-06-28T15:10:52.900Z,1656429052.900 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151052.00,A,3648.13659,N,12147.23316,W,0.039,184.99,280622,,,A*70
2022-06-28T15:10:52.903Z,1656429052.903 [NAL9602](INFO): GPS fix at 20220628T151052: (36.802276, -121.787219)
2022-06-28T15:10:52.913Z,1656429052.913 [Default:CheckIn:Read_GPS] Stopped
2022-06-28T15:10:52.913Z,1656429052.913 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-06-28T15:11:00.417Z,1656429060.417 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220628T144635/Courier0010.lzma
2022-06-28T15:11:01.421Z,1656429061.421 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Courier0010.lzma.bak
2022-06-28T15:11:01.421Z,1656429061.421 [DataOverHttps](INFO): SBD MOMSN=16932141
2022-06-28T15:11:10.020Z,1656429070.020 [DataOverHttps](IMPORTANT): SBD MTMSN=20220628T151109
2022-06-28T15:11:17.825Z,1656429077.825 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20220628T144635/Express0011.lzma
2022-06-28T15:11:17.828Z,1656429077.828 [DataOverHttps](INFO): Received command: ibit
2022-06-28T15:11:17.863Z,1656429077.863 [CommandExec](IMPORTANT): got command ibit
2022-06-28T15:11:17.968Z,1656429077.968 [IBIT](IMPORTANT): Beginning Initiated BIT
2022-06-28T15:11:17.968Z,1656429077.968 [IBIT](IMPORTANT): Beginning control surface checks.
2022-06-28T15:11:17.972Z,1656429077.972 [CBIT](IMPORTANT): Beginning ground fault scan
2022-06-28T15:11:19.013Z,1656429079.013 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Express0011.lzma.bak
2022-06-28T15:11:19.013Z,1656429079.013 [DataOverHttps](INFO): SBD MOMSN=16932145
2022-06-28T15:11:22.801Z,1656429082.801 [NAL9602](INFO): SBD MO Status=2, MOMSN=19348, MT Status=2, MTMSN=0
2022-06-28T15:11:22.801Z,1656429082.801 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-06-28T15:11:28.919Z,1656429088.919 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.010979
CHAN A1 (24V): 0.000472
CHAN A2 (12V): -0.007164
CHAN A3 (5V): -0.001615
CHAN B0 (3.3V): 0.000190
CHAN B1 (3.15aV): 0.000148
CHAN B2 (3.15bV): 0.000119
CHAN B3 (GND): 0.002197
OPEN: 0.005350
Full Scale: +/- 1 mA
2022-06-28T15:11:35.505Z,1656429095.505 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220628T144635/Courier0013.lzma
2022-06-28T15:11:36.508Z,1656429096.508 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Courier0013.lzma.bak
2022-06-28T15:11:36.508Z,1656429096.508 [DataOverHttps](INFO): SBD MOMSN=16932149
2022-06-28T15:11:52.722Z,1656429112.722 [DataOverHttps](INFO): Sending 246 bytes from file Logs/20220628T144635/Express0014.lzma
2022-06-28T15:11:53.724Z,1656429113.724 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Express0014.lzma.bak
2022-06-28T15:11:53.724Z,1656429113.724 [DataOverHttps](INFO): SBD MOMSN=16932151
2022-06-28T15:12:04.052Z,1656429124.052 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 2
Latitude: 36.802277 Longitude: -121.787216
2022-06-28T15:12:04.468Z,1656429124.468 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.572001
2022-06-28T15:12:04.469Z,1656429124.469 [IBIT](IMPORTANT): batteryCapacityThreshold: 24.000000 Ah
2022-06-28T15:12:04.469Z,1656429124.469 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.000000 V
2022-06-28T15:12:04.863Z,1656429124.863 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2022-06-28T15:12:04.863Z,1656429124.863 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2022-06-28T15:12:04.864Z,1656429124.864 [IBIT](IMPORTANT): Pressure:7.717748 PSI
2022-06-28T15:12:04.864Z,1656429124.864 [IBIT](IMPORTANT): Humidity:22.500305 %
2022-06-28T15:12:05.272Z,1656429125.272 [IBIT](IMPORTANT): Vehicle Pitch:-0.729669 degrees
2022-06-28T15:12:05.273Z,1656429125.273 [IBIT](IMPORTANT): Vehicle  Roll:-0.439353 degrees
2022-06-28T15:12:05.273Z,1656429125.273 [IBIT](IMPORTANT): Vehicle  Heading:298.941193 degrees
2022-06-28T15:12:05.737Z,1656429125.737 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2022-06-28T15:12:05.737Z,1656429125.737 [IBIT](IMPORTANT): buoyancyNeutral: 217.756134 cc
2022-06-28T15:12:05.746Z,1656429125.746 [IBIT](IMPORTANT): massDefault: 0.594198 cm
2022-06-28T15:12:05.746Z,1656429125.746 [IBIT](IMPORTANT): stopDepth: 215.000000 m
2022-06-28T15:12:05.747Z,1656429125.747 [IBIT](IMPORTANT): abortDepth: 255.000000 m
2022-06-28T15:12:05.747Z,1656429125.747 [IBIT](IMPORTANT): IBIT PASSED
2022-06-28T15:12:06.056Z,1656429126.056 [NAL9602](INFO): SBD MO Status=1, MOMSN=19348, MT Status=0, MTMSN=0
2022-06-28T15:12:06.056Z,1656429126.056 [NAL9602](INFO): No messages in MT queue
2022-06-28T15:12:06.074Z,1656429126.074 [Default:CheckIn:Read_Iridium] Stopped
2022-06-28T15:12:06.074Z,1656429126.074 [Default:CheckIn:C.Wait] Running Loop=1
2022-06-28T15:12:06.074Z,1656429126.074 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-06-28T15:12:36.760Z,1656429156.760 [NAL9602](INFO): Not Powering down - fast GPS
2022-06-28T15:17:06.657Z,1656429426.657 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-06-28T15:17:06.657Z,1656429426.657 [Default:CheckIn:C.Wait] Stopped
2022-06-28T15:17:06.657Z,1656429426.657 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-06-28T15:17:06.658Z,1656429426.658 [Default:CheckIn:D] Running Loop=1
2022-06-28T15:17:07.067Z,1656429427.067 [Default:CheckIn:D] Stopped
2022-06-28T15:17:07.067Z,1656429427.067 [Default:CheckIn:E] Running Loop=1
2022-06-28T15:17:07.492Z,1656429427.492 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 26.683246 min 
2022-06-28T15:17:07.492Z,1656429427.492 [Default:CheckIn:E] Stopped
2022-06-28T15:17:07.492Z,1656429427.492 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-06-28T15:17:07.492Z,1656429427.492 [Default:CheckIn] Stopped
2022-06-28T15:17:07.492Z,1656429427.492 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-06-28T15:17:07.493Z,1656429427.493 [Default:CheckIn](INFO): Running loop #4
2022-06-28T15:17:07.493Z,1656429427.493 [Default:CheckIn] Running Loop=4
2022-06-28T15:17:07.493Z,1656429427.493 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-06-28T15:17:07.493Z,1656429427.493 [Default:CheckIn:Read_GPS] Running Loop=1
2022-06-28T15:17:09.477Z,1656429429.477 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151708.00,A,3648.13331,N,12147.23294,W,0.039,184.99,280622,,,A*78
2022-06-28T15:17:09.479Z,1656429429.479 [NAL9602](INFO): GPS fix at 20220628T151708: (36.802222, -121.787216)
2022-06-28T15:17:09.525Z,1656429429.525 [Default:CheckIn:Read_GPS] Stopped
2022-06-28T15:17:09.525Z,1656429429.525 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-06-28T15:17:17.549Z,1656429437.549 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220628T144635/Courier0016.lzma
2022-06-28T15:17:18.552Z,1656429438.552 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Courier0016.lzma.bak
2022-06-28T15:17:18.552Z,1656429438.552 [DataOverHttps](INFO): SBD MOMSN=16932160
2022-06-28T15:17:24.020Z,1656429444.020 [NAL9602](INFO): SBD MO Status=1, MOMSN=19349, MT Status=0, MTMSN=0
2022-06-28T15:17:24.021Z,1656429444.021 [NAL9602](INFO): No messages in MT queue
2022-06-28T15:17:34.875Z,1656429454.875 [DataOverHttps](INFO): Sending 670 bytes from file Logs/20220628T144635/Express0017.lzma
2022-06-28T15:17:35.876Z,1656429455.876 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Express0017.lzma.bak
2022-06-28T15:17:35.876Z,1656429455.876 [DataOverHttps](INFO): SBD MOMSN=16932163
2022-06-28T15:17:36.951Z,1656429456.951 [Default:CheckIn:Read_Iridium] Stopped
2022-06-28T15:17:36.951Z,1656429456.951 [Default:CheckIn:C.Wait] Running Loop=1
2022-06-28T15:17:36.951Z,1656429456.951 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-06-28T15:17:54.723Z,1656429474.723 [NAL9602](INFO): Not Powering down - fast GPS
2022-06-28T15:22:37.596Z,1656429757.596 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-06-28T15:22:37.597Z,1656429757.597 [Default:CheckIn:C.Wait] Stopped
2022-06-28T15:22:37.597Z,1656429757.597 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-06-28T15:22:37.597Z,1656429757.597 [Default:CheckIn:D] Running Loop=1
2022-06-28T15:22:37.957Z,1656429757.957 [Default:CheckIn:D] Stopped
2022-06-28T15:22:37.957Z,1656429757.957 [Default:CheckIn:E] Running Loop=1
2022-06-28T15:22:38.363Z,1656429758.363 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.198083 min 
2022-06-28T15:22:38.363Z,1656429758.363 [Default:CheckIn:E] Stopped
2022-06-28T15:22:38.363Z,1656429758.363 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-06-28T15:22:38.363Z,1656429758.363 [Default:CheckIn] Stopped
2022-06-28T15:22:38.363Z,1656429758.363 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-06-28T15:22:38.363Z,1656429758.363 [Default:CheckIn](INFO): Running loop #5
2022-06-28T15:22:38.363Z,1656429758.363 [Default:CheckIn] Running Loop=5
2022-06-28T15:22:38.364Z,1656429758.364 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-06-28T15:22:38.364Z,1656429758.364 [Default:CheckIn:Read_GPS] Running Loop=1
2022-06-28T15:22:40.368Z,1656429760.368 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,152239.00,A,3648.13290,N,12147.23339,W,0.078,184.99,280622,,,A*75
2022-06-28T15:22:40.371Z,1656429760.371 [NAL9602](INFO): GPS fix at 20220628T152239: (36.802215, -121.787223)
2022-06-28T15:22:40.381Z,1656429760.381 [Default:CheckIn:Read_GPS] Stopped
2022-06-28T15:22:40.381Z,1656429760.381 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-06-28T15:22:48.045Z,1656429768.045 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220628T144635/Courier0019.lzma
2022-06-28T15:22:49.048Z,1656429769.048 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Courier0019.lzma.bak
2022-06-28T15:22:49.048Z,1656429769.048 [DataOverHttps](INFO): SBD MOMSN=16932245
2022-06-28T15:22:51.680Z,1656429771.680 [NAL9602](INFO): SBD MO Status=2, MOMSN=19350, MT Status=2, MTMSN=0
2022-06-28T15:22:51.681Z,1656429771.681 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-06-28T15:23:05.501Z,1656429785.501 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220628T144635/Express0020.lzma
2022-06-28T15:23:06.504Z,1656429786.504 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Express0020.lzma.bak
2022-06-28T15:23:06.504Z,1656429786.504 [DataOverHttps](INFO): SBD MOMSN=16932248
2022-06-28T15:23:07.440Z,1656429787.440 [NAL9602](INFO): SBD MO Status=1, MOMSN=19350, MT Status=0, MTMSN=0
2022-06-28T15:23:07.440Z,1656429787.440 [NAL9602](INFO): No messages in MT queue
2022-06-28T15:23:07.855Z,1656429787.855 [Default:CheckIn:Read_Iridium] Stopped
2022-06-28T15:23:07.855Z,1656429787.855 [Default:CheckIn:C.Wait] Running Loop=1
2022-06-28T15:23:07.855Z,1656429787.855 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-06-28T15:23:38.149Z,1656429818.149 [NAL9602](INFO): Not Powering down - fast GPS
2022-06-28T15:24:51.376Z,1656429891.376 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2022-06-28T15:28:08.495Z,1656430088.495 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-06-28T15:28:08.495Z,1656430088.495 [Default:CheckIn:C.Wait] Stopped
2022-06-28T15:28:08.495Z,1656430088.495 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-06-28T15:28:08.495Z,1656430088.495 [Default:CheckIn:D] Running Loop=1
2022-06-28T15:28:08.906Z,1656430088.906 [Default:CheckIn:D] Stopped
2022-06-28T15:28:08.907Z,1656430088.907 [Default:CheckIn:E] Running Loop=1
2022-06-28T15:28:09.297Z,1656430089.297 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 37.713908 min 
2022-06-28T15:28:09.297Z,1656430089.297 [Default:CheckIn:E] Stopped
2022-06-28T15:28:09.297Z,1656430089.297 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-06-28T15:28:09.297Z,1656430089.297 [Default:CheckIn] Stopped
2022-06-28T15:28:09.297Z,1656430089.297 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-06-28T15:28:09.297Z,1656430089.297 [Default:CheckIn](INFO): Running loop #6
2022-06-28T15:28:09.297Z,1656430089.297 [Default:CheckIn] Running Loop=6
2022-06-28T15:28:09.297Z,1656430089.297 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-06-28T15:28:09.297Z,1656430089.297 [Default:CheckIn:Read_GPS] Running Loop=1
2022-06-28T15:28:11.301Z,1656430091.301 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,152810.00,A,3648.11912,N,12147.23318,W,0.058,103.30,280622,,,A*7A
2022-06-28T15:28:11.308Z,1656430091.308 [NAL9602](INFO): GPS fix at 20220628T152810: (36.801985, -121.787220)
2022-06-28T15:28:11.359Z,1656430091.359 [Default:CheckIn:Read_GPS] Stopped
2022-06-28T15:28:11.359Z,1656430091.359 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-06-28T15:28:19.945Z,1656430099.945 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220628T144635/Courier0022.lzma
2022-06-28T15:28:20.944Z,1656430100.944 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Courier0022.lzma.bak
2022-06-28T15:28:20.944Z,1656430100.944 [DataOverHttps](INFO): SBD MOMSN=16932255
2022-06-28T15:28:22.608Z,1656430102.608 [NAL9602](INFO): SBD MO Status=1, MOMSN=19351, MT Status=0, MTMSN=0
2022-06-28T15:28:22.608Z,1656430102.608 [NAL9602](INFO): No messages in MT queue
2022-06-28T15:28:40.065Z,1656430120.065 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220628T144635/Express0023.lzma
2022-06-28T15:28:41.068Z,1656430121.068 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Express0023.lzma.bak
2022-06-28T15:28:41.068Z,1656430121.068 [DataOverHttps](INFO): SBD MOMSN=16932258
2022-06-28T15:28:42.464Z,1656430122.464 [Default:CheckIn:Read_Iridium] Stopped
2022-06-28T15:28:42.464Z,1656430122.464 [Default:CheckIn:C.Wait] Running Loop=1
2022-06-28T15:28:42.464Z,1656430122.464 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-06-28T15:28:53.371Z,1656430133.371 [NAL9602](INFO): Not Powering down - fast GPS
2022-06-28T15:33:43.106Z,1656430423.106 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-06-28T15:33:43.106Z,1656430423.106 [Default:CheckIn:C.Wait] Stopped
2022-06-28T15:33:43.106Z,1656430423.106 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-06-28T15:33:43.106Z,1656430423.106 [Default:CheckIn:D] Running Loop=1
2022-06-28T15:33:43.532Z,1656430423.532 [Default:CheckIn:D] Stopped
2022-06-28T15:33:43.532Z,1656430423.532 [Default:CheckIn:E] Running Loop=1
2022-06-28T15:33:43.897Z,1656430423.897 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.291007 min 
2022-06-28T15:33:43.897Z,1656430423.897 [Default:CheckIn:E] Stopped
2022-06-28T15:33:43.897Z,1656430423.897 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-06-28T15:33:43.898Z,1656430423.898 [Default:CheckIn] Stopped
2022-06-28T15:33:43.898Z,1656430423.898 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-06-28T15:33:43.898Z,1656430423.898 [Default:CheckIn](INFO): Running loop #7
2022-06-28T15:33:43.898Z,1656430423.898 [Default:CheckIn] Running Loop=7
2022-06-28T15:33:43.898Z,1656430423.898 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-06-28T15:33:43.898Z,1656430423.898 [Default:CheckIn:Read_GPS] Running Loop=1
2022-06-28T15:33:45.909Z,1656430425.909 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153345.00,A,3648.12086,N,12147.23335,W,0.058,103.30,280622,,,A*78
2022-06-28T15:33:45.911Z,1656430425.911 [NAL9602](INFO): GPS fix at 20220628T153345: (36.802014, -121.787222)
2022-06-28T15:33:45.939Z,1656430425.939 [Default:CheckIn:Read_GPS] Stopped
2022-06-28T15:33:45.939Z,1656430425.939 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-06-28T15:33:53.925Z,1656430433.925 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220628T144635/Courier0025.lzma
2022-06-28T15:33:54.928Z,1656430434.928 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Courier0025.lzma.bak
2022-06-28T15:33:54.928Z,1656430434.928 [DataOverHttps](INFO): SBD MOMSN=16932312
2022-06-28T15:33:58.429Z,1656430438.429 [NAL9602](INFO): SBD MO Status=1, MOMSN=19352, MT Status=0, MTMSN=0
2022-06-28T15:33:58.429Z,1656430438.429 [NAL9602](INFO): No messages in MT queue
2022-06-28T15:34:11.352Z,1656430451.352 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220628T144635/Express0026.lzma
2022-06-28T15:34:12.348Z,1656430452.348 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Express0026.lzma.bak
2022-06-28T15:34:12.348Z,1656430452.348 [DataOverHttps](INFO): SBD MOMSN=16932315
2022-06-28T15:34:13.422Z,1656430453.422 [Default:CheckIn:Read_Iridium] Stopped
2022-06-28T15:34:13.422Z,1656430453.422 [Default:CheckIn:C.Wait] Running Loop=1
2022-06-28T15:34:13.423Z,1656430453.423 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-06-28T15:34:29.175Z,1656430469.175 [NAL9602](INFO): Not Powering down - fast GPS
2022-06-28T15:39:14.030Z,1656430754.030 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-06-28T15:39:14.030Z,1656430754.030 [Default:CheckIn:C.Wait] Stopped
2022-06-28T15:39:14.030Z,1656430754.030 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-06-28T15:39:14.030Z,1656430754.030 [Default:CheckIn:D] Running Loop=1
2022-06-28T15:39:14.445Z,1656430754.445 [Default:CheckIn:D] Stopped
2022-06-28T15:39:14.445Z,1656430754.445 [Default:CheckIn:E] Running Loop=1
2022-06-28T15:39:14.835Z,1656430754.835 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.806222 min 
2022-06-28T15:39:14.835Z,1656430754.835 [Default:CheckIn:E] Stopped
2022-06-28T15:39:14.836Z,1656430754.836 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-06-28T15:39:14.836Z,1656430754.836 [Default:CheckIn] Stopped
2022-06-28T15:39:14.836Z,1656430754.836 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-06-28T15:39:14.836Z,1656430754.836 [Default:CheckIn](INFO): Running loop #8
2022-06-28T15:39:14.836Z,1656430754.836 [Default:CheckIn] Running Loop=8
2022-06-28T15:39:14.836Z,1656430754.836 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-06-28T15:39:14.836Z,1656430754.836 [Default:CheckIn:Read_GPS] Running Loop=1
2022-06-28T15:39:16.853Z,1656430756.853 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153916.00,A,3648.12488,N,12147.23272,W,0.097,103.30,280622,,,A*7F
2022-06-28T15:39:16.856Z,1656430756.856 [NAL9602](INFO): GPS fix at 20220628T153916: (36.802081, -121.787212)
2022-06-28T15:39:16.866Z,1656430756.866 [Default:CheckIn:Read_GPS] Stopped
2022-06-28T15:39:16.866Z,1656430756.866 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-06-28T15:39:24.517Z,1656430764.517 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220628T144635/Courier0028.lzma
2022-06-28T15:39:25.520Z,1656430765.520 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Courier0028.lzma.bak
2022-06-28T15:39:25.520Z,1656430765.520 [DataOverHttps](INFO): SBD MOMSN=16932328
2022-06-28T15:39:35.846Z,1656430775.846 [NAL9602](INFO): SBD MO Status=1, MOMSN=19353, MT Status=0, MTMSN=0
2022-06-28T15:39:35.847Z,1656430775.847 [NAL9602](INFO): No messages in MT queue
2022-06-28T15:39:41.816Z,1656430781.816 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220628T144635/Express0029.lzma
2022-06-28T15:39:42.817Z,1656430782.817 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Express0029.lzma.bak
2022-06-28T15:39:42.817Z,1656430782.817 [DataOverHttps](INFO): SBD MOMSN=16932371
2022-06-28T15:39:43.929Z,1656430783.929 [Default:CheckIn:Read_Iridium] Stopped
2022-06-28T15:39:43.929Z,1656430783.929 [Default:CheckIn:C.Wait] Running Loop=1
2022-06-28T15:39:43.930Z,1656430783.930 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-06-28T15:40:06.543Z,1656430806.543 [NAL9602](INFO): Not Powering down - fast GPS
2022-06-28T15:44:44.560Z,1656431084.560 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-06-28T15:44:44.560Z,1656431084.560 [Default:CheckIn:C.Wait] Stopped
2022-06-28T15:44:44.560Z,1656431084.560 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-06-28T15:44:44.561Z,1656431084.561 [Default:CheckIn:D] Running Loop=1
2022-06-28T15:44:44.979Z,1656431084.979 [Default:CheckIn:D] Stopped
2022-06-28T15:44:44.979Z,1656431084.979 [Default:CheckIn:E] Running Loop=1
2022-06-28T15:44:45.409Z,1656431085.409 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 54.315112 min 
2022-06-28T15:44:45.409Z,1656431085.409 [Default:CheckIn:E] Stopped
2022-06-28T15:44:45.409Z,1656431085.409 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-06-28T15:44:45.409Z,1656431085.409 [Default:CheckIn] Stopped
2022-06-28T15:44:45.409Z,1656431085.409 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-06-28T15:44:45.410Z,1656431085.410 [Default:CheckIn](INFO): Running loop #9
2022-06-28T15:44:45.410Z,1656431085.410 [Default:CheckIn] Running Loop=9
2022-06-28T15:44:45.410Z,1656431085.410 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-06-28T15:44:45.410Z,1656431085.410 [Default:CheckIn:Read_GPS] Running Loop=1
2022-06-28T15:44:47.393Z,1656431087.393 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154446.00,A,3648.11401,N,12147.21051,W,0.933,124.93,280622,,,A*78
2022-06-28T15:44:47.395Z,1656431087.395 [NAL9602](INFO): GPS fix at 20220628T154446: (36.801900, -121.786842)
2022-06-28T15:44:47.448Z,1656431087.448 [Default:CheckIn:Read_GPS] Stopped
2022-06-28T15:44:47.448Z,1656431087.448 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-06-28T15:44:55.449Z,1656431095.449 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220628T144635/Courier0031.lzma
2022-06-28T15:44:56.452Z,1656431096.452 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Courier0031.lzma.bak
2022-06-28T15:44:56.452Z,1656431096.452 [DataOverHttps](INFO): SBD MOMSN=16932376
2022-06-28T15:45:03.550Z,1656431103.550 [NAL9602](INFO): SBD MO Status=1, MOMSN=19354, MT Status=0, MTMSN=0
2022-06-28T15:45:03.551Z,1656431103.551 [NAL9602](INFO): No messages in MT queue
2022-06-28T15:45:12.846Z,1656431112.846 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20220628T144635/Express0032.lzma
2022-06-28T15:45:13.848Z,1656431113.848 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Express0032.lzma.bak
2022-06-28T15:45:13.848Z,1656431113.848 [DataOverHttps](INFO): SBD MOMSN=16932379
2022-06-28T15:45:14.881Z,1656431114.881 [Default:CheckIn:Read_Iridium] Stopped
2022-06-28T15:45:14.881Z,1656431114.881 [Default:CheckIn:C.Wait] Running Loop=1
2022-06-28T15:45:14.881Z,1656431114.881 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-06-28T15:45:34.251Z,1656431134.251 [NAL9602](INFO): Not Powering down - fast GPS
2022-06-28T15:50:15.498Z,1656431415.498 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-06-28T15:50:15.498Z,1656431415.498 [Default:CheckIn:C.Wait] Stopped
2022-06-28T15:50:15.498Z,1656431415.498 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-06-28T15:50:15.498Z,1656431415.498 [Default:CheckIn:D] Running Loop=1
2022-06-28T15:50:15.886Z,1656431415.886 [Default:CheckIn:D] Stopped
2022-06-28T15:50:15.886Z,1656431415.886 [Default:CheckIn:E] Running Loop=1
2022-06-28T15:50:16.263Z,1656431416.263 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 59.829960 min 
2022-06-28T15:50:16.264Z,1656431416.264 [Default:CheckIn:E] Stopped
2022-06-28T15:50:16.264Z,1656431416.264 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-06-28T15:50:16.264Z,1656431416.264 [Default:CheckIn] Stopped
2022-06-28T15:50:16.264Z,1656431416.264 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-06-28T15:50:16.264Z,1656431416.264 [Default:CheckIn](INFO): Running loop #10
2022-06-28T15:50:16.264Z,1656431416.264 [Default:CheckIn] Running Loop=10
2022-06-28T15:50:16.264Z,1656431416.264 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-06-28T15:50:16.264Z,1656431416.264 [Default:CheckIn:Read_GPS] Running Loop=1
2022-06-28T15:50:18.287Z,1656431418.287 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155017.00,A,3648.51368,N,12147.13310,W,4.743,331.39,280622,,,D*7C
2022-06-28T15:50:18.289Z,1656431418.289 [NAL9602](INFO): GPS fix at 20220628T155017: (36.808561, -121.785552)
2022-06-28T15:50:18.305Z,1656431418.305 [Default:CheckIn:Read_GPS] Stopped
2022-06-28T15:50:18.305Z,1656431418.305 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-06-28T15:50:29.367Z,1656431429.367 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220628T144635/Courier0034.lzma
2022-06-28T15:50:30.364Z,1656431430.364 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Courier0034.lzma.bak
2022-06-28T15:50:30.364Z,1656431430.364 [DataOverHttps](INFO): SBD MOMSN=16932443
2022-06-28T15:50:46.777Z,1656431446.777 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20220628T144635/Express0035.lzma
2022-06-28T15:50:47.780Z,1656431447.780 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Express0035.lzma.bak
2022-06-28T15:50:47.780Z,1656431447.780 [DataOverHttps](INFO): SBD MOMSN=16932446
2022-06-28T15:50:49.062Z,1656431449.062 [Default:CheckIn:Read_Iridium] Stopped
2022-06-28T15:50:49.062Z,1656431449.062 [Default:CheckIn:C.Wait] Running Loop=1
2022-06-28T15:50:49.062Z,1656431449.062 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-06-28T15:50:59.557Z,1656431459.557 [NAL9602](INFO): SBD MO Status=1, MOMSN=19355, MT Status=0, MTMSN=0
2022-06-28T15:50:59.557Z,1656431459.557 [NAL9602](INFO): No messages in MT queue
2022-06-28T15:51:30.268Z,1656431490.268 [NAL9602](INFO): Not Powering down - fast GPS
2022-06-28T15:55:49.683Z,1656431749.683 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-06-28T15:55:49.683Z,1656431749.683 [Default:CheckIn:C.Wait] Stopped
2022-06-28T15:55:49.683Z,1656431749.683 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-06-28T15:55:49.683Z,1656431749.683 [Default:CheckIn:D] Running Loop=1
2022-06-28T15:55:50.062Z,1656431750.062 [Default:CheckIn:D] Stopped
2022-06-28T15:55:50.062Z,1656431750.062 [Default:CheckIn:E] Running Loop=1
2022-06-28T15:55:50.465Z,1656431750.465 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 65.399837 min 
2022-06-28T15:55:50.465Z,1656431750.465 [Default:CheckIn:E] Stopped
2022-06-28T15:55:50.465Z,1656431750.465 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-06-28T15:55:50.465Z,1656431750.465 [Default:CheckIn] Stopped
2022-06-28T15:55:50.466Z,1656431750.466 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-06-28T15:55:50.466Z,1656431750.466 [Default:CheckIn](INFO): Running loop #11
2022-06-28T15:55:50.466Z,1656431750.466 [Default:CheckIn] Running Loop=11
2022-06-28T15:55:50.466Z,1656431750.466 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-06-28T15:55:50.466Z,1656431750.466 [Default:CheckIn:Read_GPS] Running Loop=1
2022-06-28T15:55:52.477Z,1656431752.477 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155551.00,A,3648.52682,N,12148.36421,W,18.933,308.71,280622,,,D*46
2022-06-28T15:55:52.480Z,1656431752.480 [NAL9602](INFO): GPS fix at 20220628T155551: (36.808780, -121.806070)
2022-06-28T15:55:52.491Z,1656431752.491 [Default:CheckIn:Read_GPS] Stopped
2022-06-28T15:55:52.491Z,1656431752.491 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-06-28T15:56:00.265Z,1656431760.265 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220628T144635/Courier0037.lzma
2022-06-28T15:56:01.268Z,1656431761.268 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Courier0037.lzma.bak
2022-06-28T15:56:01.268Z,1656431761.268 [DataOverHttps](INFO): SBD MOMSN=16932451
2022-06-28T15:56:09.037Z,1656431769.037 [NAL9602](INFO): SBD MO Status=1, MOMSN=19356, MT Status=0, MTMSN=0
2022-06-28T15:56:09.037Z,1656431769.037 [NAL9602](INFO): No messages in MT queue
2022-06-28T15:56:17.659Z,1656431777.659 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20220628T144635/Express0038.lzma
2022-06-28T15:56:18.660Z,1656431778.660 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Express0038.lzma.bak
2022-06-28T15:56:18.660Z,1656431778.660 [DataOverHttps](INFO): SBD MOMSN=16932454
2022-06-28T15:56:19.985Z,1656431779.985 [Default:CheckIn:Read_Iridium] Stopped
2022-06-28T15:56:19.985Z,1656431779.985 [Default:CheckIn:C.Wait] Running Loop=1
2022-06-28T15:56:19.985Z,1656431779.985 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-06-28T15:56:39.787Z,1656431799.787 [NAL9602](INFO): Not Powering down - fast GPS
2022-06-28T16:01:20.577Z,1656432080.577 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-06-28T16:01:20.578Z,1656432080.578 [Default:CheckIn:C.Wait] Stopped
2022-06-28T16:01:20.578Z,1656432080.578 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-06-28T16:01:20.578Z,1656432080.578 [Default:CheckIn:D] Running Loop=1
2022-06-28T16:01:20.993Z,1656432080.993 [Default:CheckIn:D] Stopped
2022-06-28T16:01:20.993Z,1656432080.993 [Default:CheckIn:E] Running Loop=1
2022-06-28T16:01:21.428Z,1656432081.428 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 70.915356 min 
2022-06-28T16:01:21.428Z,1656432081.428 [Default:CheckIn:E] Stopped
2022-06-28T16:01:21.428Z,1656432081.428 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-06-28T16:01:21.428Z,1656432081.428 [Default:CheckIn] Stopped
2022-06-28T16:01:21.428Z,1656432081.428 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-06-28T16:01:21.428Z,1656432081.428 [Default:CheckIn](INFO): Running loop #12
2022-06-28T16:01:21.429Z,1656432081.429 [Default:CheckIn] Running Loop=12
2022-06-28T16:01:21.429Z,1656432081.429 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-06-28T16:01:21.429Z,1656432081.429 [Default:CheckIn:Read_GPS] Running Loop=1
2022-06-28T16:01:23.398Z,1656432083.398 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160122.00,A,3649.50048,N,12150.02924,W,18.583,295.25,280622,,,D*46
2022-06-28T16:01:23.400Z,1656432083.400 [NAL9602](INFO): GPS fix at 20220628T160122: (36.825008, -121.833821)
2022-06-28T16:01:23.430Z,1656432083.430 [Default:CheckIn:Read_GPS] Stopped
2022-06-28T16:01:23.430Z,1656432083.430 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-06-28T16:01:31.093Z,1656432091.093 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220628T144635/Courier0040.lzma
2022-06-28T16:01:32.096Z,1656432092.096 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Courier0040.lzma.bak
2022-06-28T16:01:32.096Z,1656432092.096 [DataOverHttps](INFO): SBD MOMSN=16932507
2022-06-28T16:01:45.633Z,1656432105.633 [NAL9602](INFO): SBD MO Status=2, MOMSN=19357, MT Status=2, MTMSN=0
2022-06-28T16:01:45.633Z,1656432105.633 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-06-28T16:01:48.617Z,1656432108.617 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20220628T144635/Express0041.lzma
2022-06-28T16:01:49.620Z,1656432109.620 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Express0041.lzma.bak
2022-06-28T16:01:49.620Z,1656432109.620 [DataOverHttps](INFO): SBD MOMSN=16932510
2022-06-28T16:01:50.881Z,1656432110.881 [Default:CheckIn:Read_Iridium] Stopped
2022-06-28T16:01:50.881Z,1656432110.881 [Default:CheckIn:C.Wait] Running Loop=1
2022-06-28T16:01:50.881Z,1656432110.881 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-06-28T16:02:18.355Z,1656432138.355 [NAL9602](INFO): SBD MO Status=2, MOMSN=19357, MT Status=2, MTMSN=0
2022-06-28T16:02:18.355Z,1656432138.355 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-06-28T16:02:42.184Z,1656432162.184 [NAL9602](INFO): SBD MO Status=1, MOMSN=19357, MT Status=0, MTMSN=0
2022-06-28T16:02:42.184Z,1656432162.184 [NAL9602](INFO): No messages in MT queue
2022-06-28T16:03:12.883Z,1656432192.883 [NAL9602](INFO): Not Powering down - fast GPS
2022-06-28T16:04:11.464Z,1656432251.464 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6.
2022-06-28T16:04:11.466Z,1656432251.466 [BPC1](INFO): Received data from all battery sticks.
2022-06-28T16:06:51.505Z,1656432411.505 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-06-28T16:06:51.506Z,1656432411.506 [Default:CheckIn:C.Wait] Stopped
2022-06-28T16:06:51.506Z,1656432411.506 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-06-28T16:06:51.506Z,1656432411.506 [Default:CheckIn:D] Running Loop=1
2022-06-28T16:06:51.902Z,1656432411.902 [Default:CheckIn:D] Stopped
2022-06-28T16:06:51.903Z,1656432411.903 [Default:CheckIn:E] Running Loop=1
2022-06-28T16:06:52.293Z,1656432412.293 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 76.430509 min 
2022-06-28T16:06:52.293Z,1656432412.293 [Default:CheckIn:E] Stopped
2022-06-28T16:06:52.293Z,1656432412.293 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-06-28T16:06:52.293Z,1656432412.293 [Default:CheckIn] Stopped
2022-06-28T16:06:52.293Z,1656432412.293 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-06-28T16:06:52.294Z,1656432412.294 [Default:CheckIn](INFO): Running loop #13
2022-06-28T16:06:52.294Z,1656432412.294 [Default:CheckIn] Running Loop=13
2022-06-28T16:06:52.294Z,1656432412.294 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-06-28T16:06:52.294Z,1656432412.294 [Default:CheckIn:Read_GPS] Running Loop=1
2022-06-28T16:06:54.305Z,1656432414.305 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160653.00,A,3650.21936,N,12151.92967,W,17.048,297.05,280622,,,A*4E
2022-06-28T16:06:54.307Z,1656432414.307 [NAL9602](INFO): GPS fix at 20220628T160653: (36.836989, -121.865494)
2022-06-28T16:06:54.318Z,1656432414.318 [Default:CheckIn:Read_GPS] Stopped
2022-06-28T16:06:54.318Z,1656432414.318 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-06-28T16:07:01.745Z,1656432421.745 [DataOverHttps](INFO): Sending 86 bytes from file Logs/20220628T144635/Courier0043.lzma
2022-06-28T16:07:02.748Z,1656432422.748 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Courier0043.lzma.bak
2022-06-28T16:07:02.748Z,1656432422.748 [DataOverHttps](INFO): SBD MOMSN=16932515
2022-06-28T16:07:19.273Z,1656432439.273 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20220628T144635/Express0044.lzma
2022-06-28T16:07:20.276Z,1656432440.276 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Express0044.lzma.bak
2022-06-28T16:07:20.276Z,1656432440.276 [DataOverHttps](INFO): SBD MOMSN=16932518
2022-06-28T16:07:21.424Z,1656432441.424 [Default:CheckIn:Read_Iridium] Stopped
2022-06-28T16:07:21.424Z,1656432441.424 [Default:CheckIn:C.Wait] Running Loop=1
2022-06-28T16:07:21.424Z,1656432441.424 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-06-28T16:07:28.244Z,1656432448.244 [NAL9602](INFO): SBD MO Status=1, MOMSN=19358, MT Status=0, MTMSN=0
2022-06-28T16:07:28.244Z,1656432448.244 [NAL9602](INFO): No messages in MT queue
2022-06-28T16:07:58.943Z,1656432478.943 [NAL9602](INFO): Not Powering down - fast GPS
2022-06-28T16:08:27.174Z,1656432507.174 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:08:29.182Z,1656432509.182 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.271275
2022-06-28T16:09:02.314Z,1656432542.314 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:09:37.454Z,1656432577.454 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:10:12.619Z,1656432612.619 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:10:47.774Z,1656432647.774 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:11:22.914Z,1656432682.914 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:11:58.054Z,1656432718.054 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:12:21.963Z,1656432741.963 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-06-28T16:12:21.964Z,1656432741.964 [Default:CheckIn:C.Wait] Stopped
2022-06-28T16:12:21.964Z,1656432741.964 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-06-28T16:12:21.964Z,1656432741.964 [Default:CheckIn:D] Running Loop=1
2022-06-28T16:12:22.357Z,1656432742.357 [Default:CheckIn:D] Stopped
2022-06-28T16:12:22.357Z,1656432742.357 [Default:CheckIn:E] Running Loop=1
2022-06-28T16:12:22.761Z,1656432742.761 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 81.938086 min 
2022-06-28T16:12:22.761Z,1656432742.761 [Default:CheckIn:E] Stopped
2022-06-28T16:12:22.762Z,1656432742.762 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-06-28T16:12:22.762Z,1656432742.762 [Default:CheckIn] Stopped
2022-06-28T16:12:22.762Z,1656432742.762 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-06-28T16:12:22.762Z,1656432742.762 [Default:CheckIn](INFO): Running loop #14
2022-06-28T16:12:22.762Z,1656432742.762 [Default:CheckIn] Running Loop=14
2022-06-28T16:12:22.762Z,1656432742.762 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-06-28T16:12:22.762Z,1656432742.762 [Default:CheckIn:Read_GPS] Running Loop=1
2022-06-28T16:12:24.773Z,1656432744.773 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161224.00,A,3650.77814,N,12153.48555,W,15.959,285.24,280622,,,A*4A
2022-06-28T16:12:24.775Z,1656432744.775 [NAL9602](INFO): GPS fix at 20220628T161224: (36.846302, -121.891426)
2022-06-28T16:12:24.787Z,1656432744.787 [Default:CheckIn:Read_GPS] Stopped
2022-06-28T16:12:24.788Z,1656432744.788 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-06-28T16:12:33.194Z,1656432753.194 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:12:51.922Z,1656432771.922 [NAL9602](INFO): SBD MO Status=2, MOMSN=19359, MT Status=2, MTMSN=0
2022-06-28T16:12:51.922Z,1656432771.922 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-06-28T16:13:08.346Z,1656432788.346 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:13:12.588Z,1656432792.588 [NAL9602](INFO): SBD MO Status=1, MOMSN=19359, MT Status=0, MTMSN=0
2022-06-28T16:13:12.647Z,1656432792.647 [NAL9602](INFO): Sent 72 bytes from file Logs/20220628T144635/Courier0046.lzma
2022-06-28T16:13:12.647Z,1656432792.647 [NAL9602](INFO): Packets left to send: 0
2022-06-28T16:13:18.752Z,1656432798.752 [NAL9602](INFO): SBD MO Status=1, MOMSN=19360, MT Status=0, MTMSN=0
2022-06-28T16:13:18.802Z,1656432798.802 [NAL9602](INFO): Sent 144 bytes from file Logs/20220628T144635/Express0047.lzma
2022-06-28T16:13:18.802Z,1656432798.802 [NAL9602](INFO): Packets left to send: 0
2022-06-28T16:13:27.630Z,1656432807.630 [NAL9602](INFO): SBD MO Status=0, MOMSN=19361, MT Status=0, MTMSN=0
2022-06-28T16:13:27.725Z,1656432807.725 [Default:CheckIn:Read_Iridium] Stopped
2022-06-28T16:13:27.725Z,1656432807.725 [Default:CheckIn:C.Wait] Running Loop=1
2022-06-28T16:13:27.725Z,1656432807.725 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-06-28T16:13:43.498Z,1656432823.498 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:13:58.326Z,1656432838.326 [NAL9602](INFO): Not Powering down - fast GPS
2022-06-28T16:14:18.638Z,1656432858.638 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:14:53.779Z,1656432893.779 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:15:28.950Z,1656432928.950 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:16:04.095Z,1656432964.095 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:16:39.234Z,1656432999.234 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:17:14.391Z,1656433034.391 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:17:49.570Z,1656433069.570 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:18:24.718Z,1656433104.718 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:18:28.225Z,1656433108.225 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-06-28T16:18:28.225Z,1656433108.225 [Default:CheckIn:C.Wait] Stopped
2022-06-28T16:18:28.225Z,1656433108.225 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-06-28T16:18:28.225Z,1656433108.225 [Default:CheckIn:D] Running Loop=1
2022-06-28T16:18:28.616Z,1656433108.616 [Default:CheckIn:D] Stopped
2022-06-28T16:18:28.617Z,1656433108.617 [Default:CheckIn:E] Running Loop=1
2022-06-28T16:18:29.026Z,1656433109.026 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 88.042407 min 
2022-06-28T16:18:29.026Z,1656433109.026 [Default:CheckIn:E] Stopped
2022-06-28T16:18:29.026Z,1656433109.026 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-06-28T16:18:29.026Z,1656433109.026 [Default:CheckIn] Stopped
2022-06-28T16:18:29.026Z,1656433109.026 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-06-28T16:18:29.027Z,1656433109.027 [Default:CheckIn](INFO): Running loop #15
2022-06-28T16:18:29.027Z,1656433109.027 [Default:CheckIn] Running Loop=15
2022-06-28T16:18:29.027Z,1656433109.027 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-06-28T16:18:29.027Z,1656433109.027 [Default:CheckIn:Read_GPS] Running Loop=1
2022-06-28T16:18:31.037Z,1656433111.037 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161830.00,A,3651.32555,N,12155.29422,W,10.983,309.53,280622,,,A*4A
2022-06-28T16:18:31.039Z,1656433111.039 [NAL9602](INFO): GPS fix at 20220628T161830: (36.855426, -121.921570)
2022-06-28T16:18:31.050Z,1656433111.050 [Default:CheckIn:Read_GPS] Stopped
2022-06-28T16:18:31.050Z,1656433111.050 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-06-28T16:18:59.858Z,1656433139.858 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:19:04.237Z,1656433144.237 [NAL9602](INFO): SBD MO Status=2, MOMSN=19362, MT Status=2, MTMSN=0
2022-06-28T16:19:04.237Z,1656433144.237 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-06-28T16:19:20.065Z,1656433160.065 [NAL9602](INFO): SBD MO Status=1, MOMSN=19362, MT Status=0, MTMSN=0
2022-06-28T16:19:20.126Z,1656433160.126 [NAL9602](INFO): Sent 73 bytes from file Logs/20220628T144635/Courier0049.lzma
2022-06-28T16:19:20.126Z,1656433160.126 [NAL9602](INFO): Packets left to send: 0
2022-06-28T16:19:35.006Z,1656433175.006 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:19:36.293Z,1656433176.293 [NAL9602](INFO): SBD MO Status=2, MOMSN=19363, MT Status=2, MTMSN=0
2022-06-28T16:19:36.293Z,1656433176.293 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-06-28T16:20:01.841Z,1656433201.841 [NAL9602](INFO): SBD MO Status=1, MOMSN=19363, MT Status=0, MTMSN=0
2022-06-28T16:20:01.890Z,1656433201.890 [NAL9602](INFO): Sent 144 bytes from file Logs/20220628T144635/Express0050.lzma
2022-06-28T16:20:01.890Z,1656433201.890 [NAL9602](INFO): Packets left to send: 0
2022-06-28T16:20:10.146Z,1656433210.146 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:20:14.352Z,1656433214.352 [NAL9602](INFO): SBD MO Status=0, MOMSN=19364, MT Status=0, MTMSN=0
2022-06-28T16:20:14.444Z,1656433214.444 [Default:CheckIn:Read_Iridium] Stopped
2022-06-28T16:20:14.444Z,1656433214.444 [Default:CheckIn:C.Wait] Running Loop=1
2022-06-28T16:20:14.444Z,1656433214.444 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-06-28T16:20:42.915Z,1656433242.915 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003285
2022-06-28T16:20:45.049Z,1656433245.049 [NAL9602](INFO): Not Powering down - fast GPS
2022-06-28T16:23:08.350Z,1656433388.350 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:23:10.358Z,1656433390.358 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.239254
2022-06-28T16:23:43.498Z,1656433423.498 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:23:59.075Z,1656433439.075 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003685
2022-06-28T16:24:54.298Z,1656433494.298 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:24:59.321Z,1656433499.321 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.248978
2022-06-28T16:25:14.931Z,1656433514.931 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-06-28T16:25:14.931Z,1656433514.931 [Default:CheckIn:C.Wait] Stopped
2022-06-28T16:25:14.931Z,1656433514.931 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-06-28T16:25:14.931Z,1656433514.931 [Default:CheckIn:D] Running Loop=1
2022-06-28T16:25:15.389Z,1656433515.389 [Default:CheckIn:D] Stopped
2022-06-28T16:25:15.389Z,1656433515.389 [Default:CheckIn:E] Running Loop=1
2022-06-28T16:25:15.770Z,1656433515.770 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 94.821940 min 
2022-06-28T16:25:15.770Z,1656433515.770 [Default:CheckIn:E] Stopped
2022-06-28T16:25:15.770Z,1656433515.770 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-06-28T16:25:15.770Z,1656433515.770 [Default:CheckIn] Stopped
2022-06-28T16:25:15.770Z,1656433515.770 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-06-28T16:25:15.770Z,1656433515.770 [Default:CheckIn](INFO): Running loop #16
2022-06-28T16:25:15.771Z,1656433515.771 [Default:CheckIn] Running Loop=16
2022-06-28T16:25:15.771Z,1656433515.771 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-06-28T16:25:15.771Z,1656433515.771 [Default:CheckIn:Read_GPS] Running Loop=1
2022-06-28T16:25:17.757Z,1656433517.757 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162517.00,A,3652.25644,N,12156.28623,W,10.400,320.33,280622,,,A*4D
2022-06-28T16:25:17.759Z,1656433517.759 [NAL9602](INFO): GPS fix at 20220628T162517: (36.870941, -121.938104)
2022-06-28T16:25:17.787Z,1656433517.787 [Default:CheckIn:Read_GPS] Stopped
2022-06-28T16:25:17.787Z,1656433517.787 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-06-28T16:25:41.654Z,1656433541.654 [NAL9602](INFO): SBD MO Status=1, MOMSN=19365, MT Status=0, MTMSN=0
2022-06-28T16:25:41.704Z,1656433541.704 [NAL9602](INFO): Sent 73 bytes from file Logs/20220628T144635/Courier0052.lzma
2022-06-28T16:25:41.704Z,1656433541.704 [NAL9602](INFO): Packets left to send: 0
2022-06-28T16:25:56.680Z,1656433556.680 [NAL9602](INFO): SBD MO Status=2, MOMSN=19366, MT Status=2, MTMSN=0
2022-06-28T16:25:56.681Z,1656433556.681 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-06-28T16:26:04.602Z,1656433564.602 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:26:31.497Z,1656433591.497 [NAL9602](INFO): SBD MO Status=2, MOMSN=19366, MT Status=2, MTMSN=0
2022-06-28T16:26:31.497Z,1656433591.497 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-06-28T16:26:39.754Z,1656433599.754 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:26:57.416Z,1656433617.416 [NAL9602](INFO): SBD MO Status=2, MOMSN=19366, MT Status=2, MTMSN=0
2022-06-28T16:26:57.417Z,1656433617.417 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-06-28T16:27:14.894Z,1656433634.894 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:27:17.683Z,1656433637.683 [NAL9602](INFO): SBD MO Status=1, MOMSN=19366, MT Status=0, MTMSN=0
2022-06-28T16:27:17.732Z,1656433637.732 [NAL9602](INFO): Sent 144 bytes from file Logs/20220628T144635/Express0053.lzma
2022-06-28T16:27:17.732Z,1656433637.732 [NAL9602](INFO): Packets left to send: 0
2022-06-28T16:27:36.271Z,1656433656.271 [NAL9602](INFO): SBD MO Status=2, MOMSN=19367, MT Status=2, MTMSN=0
2022-06-28T16:27:36.271Z,1656433656.271 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-06-28T16:27:50.034Z,1656433670.034 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:27:54.848Z,1656433674.848 [NAL9602](INFO): SBD MO Status=2, MOMSN=19367, MT Status=2, MTMSN=0
2022-06-28T16:27:54.849Z,1656433674.849 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-06-28T16:28:05.756Z,1656433685.756 [NAL9602](INFO): SBD MO Status=0, MOMSN=19367, MT Status=0, MTMSN=0
2022-06-28T16:28:05.850Z,1656433685.850 [Default:CheckIn:Read_Iridium] Stopped
2022-06-28T16:28:05.850Z,1656433685.850 [Default:CheckIn:C.Wait] Running Loop=1
2022-06-28T16:28:05.850Z,1656433685.850 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-06-28T16:28:25.182Z,1656433705.182 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:28:36.464Z,1656433716.464 [NAL9602](INFO): Not Powering down - fast GPS
2022-06-28T16:29:00.334Z,1656433740.334 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:29:35.490Z,1656433775.490 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:30:10.630Z,1656433810.630 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:30:45.790Z,1656433845.790 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:31:20.938Z,1656433880.938 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:31:33.626Z,1656433893.626 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003208
2022-06-28T16:33:06.350Z,1656433986.350 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-06-28T16:33:06.350Z,1656433986.350 [Default:CheckIn:C.Wait] Stopped
2022-06-28T16:33:06.350Z,1656433986.350 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-06-28T16:33:06.350Z,1656433986.350 [Default:CheckIn:D] Running Loop=1
2022-06-28T16:33:06.765Z,1656433986.765 [Default:CheckIn:D] Stopped
2022-06-28T16:33:06.765Z,1656433986.765 [Default:CheckIn:E] Running Loop=1
2022-06-28T16:33:07.163Z,1656433987.163 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 102.678223 min 
2022-06-28T16:33:07.164Z,1656433987.164 [Default:CheckIn:E] Stopped
2022-06-28T16:33:07.164Z,1656433987.164 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-06-28T16:33:07.164Z,1656433987.164 [Default:CheckIn] Stopped
2022-06-28T16:33:07.164Z,1656433987.164 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-06-28T16:33:07.164Z,1656433987.164 [Default:CheckIn](INFO): Running loop #17
2022-06-28T16:33:07.164Z,1656433987.164 [Default:CheckIn] Running Loop=17
2022-06-28T16:33:07.164Z,1656433987.164 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-06-28T16:33:07.164Z,1656433987.164 [Default:CheckIn:Read_GPS] Running Loop=1
2022-06-28T16:33:09.169Z,1656433989.169 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163308.00,A,3652.47358,N,12158.31716,W,13.199,276.70,280622,,,D*4F
2022-06-28T16:33:09.180Z,1656433989.180 [NAL9602](INFO): GPS fix at 20220628T163308: (36.874560, -121.971953)
2022-06-28T16:33:09.199Z,1656433989.199 [Default:CheckIn:Read_GPS] Stopped
2022-06-28T16:33:09.199Z,1656433989.199 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-06-28T16:33:25.736Z,1656434005.736 [NAL9602](INFO): SBD MO Status=0, MOMSN=19368, MT Status=0, MTMSN=0
2022-06-28T16:33:25.736Z,1656434005.736 [NAL9602](INFO): No messages in MT queue
2022-06-28T16:33:25.833Z,1656434005.833 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220628T144635/Courier0055.lzma
2022-06-28T16:33:26.836Z,1656434006.836 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Courier0055.lzma.bak
2022-06-28T16:33:26.836Z,1656434006.836 [DataOverHttps](INFO): SBD MOMSN=16932713
2022-06-28T16:33:42.913Z,1656434022.913 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20220628T144635/Express0056.lzma
2022-06-28T16:33:44.920Z,1656434024.920 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Express0056.lzma.bak
2022-06-28T16:33:44.920Z,1656434024.920 [DataOverHttps](INFO): SBD MOMSN=16932717
2022-06-28T16:33:45.961Z,1656434025.961 [Default:CheckIn:Read_Iridium] Stopped
2022-06-28T16:33:45.961Z,1656434025.961 [Default:CheckIn:C.Wait] Running Loop=1
2022-06-28T16:33:45.961Z,1656434025.961 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-06-28T16:33:56.439Z,1656434036.439 [NAL9602](INFO): Not Powering down - fast GPS
2022-06-28T16:36:39.182Z,1656434199.182 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:36:41.190Z,1656434201.190 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.266186
2022-06-28T16:36:54.778Z,1656434214.778 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002781
2022-06-28T16:38:46.531Z,1656434326.531 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-06-28T16:38:46.531Z,1656434326.531 [Default:CheckIn:C.Wait] Stopped
2022-06-28T16:38:46.531Z,1656434326.531 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-06-28T16:38:46.531Z,1656434326.531 [Default:CheckIn:D] Running Loop=1
2022-06-28T16:38:46.941Z,1656434326.941 [Default:CheckIn:D] Stopped
2022-06-28T16:38:46.941Z,1656434326.941 [Default:CheckIn:E] Running Loop=1
2022-06-28T16:38:47.393Z,1656434327.393 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 108.347811 min 
2022-06-28T16:38:47.393Z,1656434327.393 [Default:CheckIn:E] Stopped
2022-06-28T16:38:47.393Z,1656434327.393 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-06-28T16:38:47.393Z,1656434327.393 [Default:CheckIn] Stopped
2022-06-28T16:38:47.393Z,1656434327.393 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-06-28T16:38:47.393Z,1656434327.393 [Default:CheckIn](INFO): Running loop #18
2022-06-28T16:38:47.393Z,1656434327.393 [Default:CheckIn] Running Loop=18
2022-06-28T16:38:47.393Z,1656434327.393 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-06-28T16:38:47.394Z,1656434327.394 [Default:CheckIn:Read_GPS] Running Loop=1
2022-06-28T16:38:49.382Z,1656434329.382 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163848.00,A,3652.49086,N,12158.34026,W,0.505,197.86,280622,,,D*79
2022-06-28T16:38:49.384Z,1656434329.384 [NAL9602](INFO): GPS fix at 20220628T163848: (36.874848, -121.972338)
2022-06-28T16:38:49.430Z,1656434329.430 [Default:CheckIn:Read_GPS] Stopped
2022-06-28T16:38:49.430Z,1656434329.430 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-06-28T16:39:02.281Z,1656434342.281 [NAL9602](INFO): SBD MO Status=0, MOMSN=19369, MT Status=0, MTMSN=0
2022-06-28T16:39:02.281Z,1656434342.281 [NAL9602](INFO): No messages in MT queue
2022-06-28T16:39:07.280Z,1656434347.280 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.932850
2022-06-28T16:39:38.402Z,1656434378.402 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:39:51.656Z,1656434391.656 [NAL9602](INFO): SBD MO Status=2, MOMSN=19370, MT Status=2, MTMSN=0
2022-06-28T16:39:51.657Z,1656434391.657 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-06-28T16:40:13.124Z,1656434413.124 [NAL9602](INFO): SBD MO Status=1, MOMSN=19370, MT Status=0, MTMSN=0
2022-06-28T16:40:13.182Z,1656434413.182 [NAL9602](INFO): Sent 72 bytes from file Logs/20220628T144635/Courier0058.lzma
2022-06-28T16:40:13.183Z,1656434413.183 [NAL9602](INFO): Packets left to send: 0
2022-06-28T16:40:13.542Z,1656434413.542 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:40:31.760Z,1656434431.760 [NAL9602](INFO): SBD MO Status=2, MOMSN=19371, MT Status=2, MTMSN=0
2022-06-28T16:40:31.761Z,1656434431.761 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-06-28T16:40:43.250Z,1656434443.250 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002907
2022-06-28T16:41:04.043Z,1656434464.043 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220628T144635/Express0059.lzma
2022-06-28T16:41:05.044Z,1656434465.044 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Express0059.lzma.bak
2022-06-28T16:41:05.044Z,1656434465.044 [DataOverHttps](INFO): SBD MOMSN=16932723
2022-06-28T16:41:06.204Z,1656434466.204 [Default:CheckIn:Read_Iridium] Stopped
2022-06-28T16:41:06.204Z,1656434466.204 [Default:CheckIn:C.Wait] Running Loop=1
2022-06-28T16:41:06.204Z,1656434466.204 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-06-28T16:41:11.024Z,1656434471.024 [NAL9602](INFO): SBD MO Status=1, MOMSN=19371, MT Status=0, MTMSN=0
2022-06-28T16:41:11.078Z,1656434471.078 [NAL9602](INFO): Sent 129 bytes from file Logs/20220628T144635/Express0059.lzma
2022-06-28T16:41:11.078Z,1656434471.078 [NAL9602](INFO): Packets left to send: 0
2022-06-28T16:41:41.726Z,1656434501.726 [NAL9602](INFO): Not Powering down - fast GPS
2022-06-28T16:46:06.844Z,1656434766.844 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-06-28T16:46:06.844Z,1656434766.844 [Default:CheckIn:C.Wait] Stopped
2022-06-28T16:46:06.844Z,1656434766.844 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-06-28T16:46:06.844Z,1656434766.844 [Default:CheckIn:D] Running Loop=1
2022-06-28T16:46:07.253Z,1656434767.253 [Default:CheckIn:D] Stopped
2022-06-28T16:46:07.253Z,1656434767.253 [Default:CheckIn:E] Running Loop=1
2022-06-28T16:46:07.680Z,1656434767.680 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 115.686361 min 
2022-06-28T16:46:07.681Z,1656434767.681 [Default:CheckIn:E] Stopped
2022-06-28T16:46:07.681Z,1656434767.681 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-06-28T16:46:07.681Z,1656434767.681 [Default:CheckIn] Stopped
2022-06-28T16:46:07.681Z,1656434767.681 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-06-28T16:46:07.681Z,1656434767.681 [Default:CheckIn](INFO): Running loop #19
2022-06-28T16:46:07.681Z,1656434767.681 [Default:CheckIn] Running Loop=19
2022-06-28T16:46:07.681Z,1656434767.681 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-06-28T16:46:07.681Z,1656434767.681 [Default:CheckIn:Read_GPS] Running Loop=1
2022-06-28T16:46:09.657Z,1656434769.657 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164608.00,A,3652.48723,N,12158.30180,W,0.505,60.66,280622,,,D*43
2022-06-28T16:46:09.659Z,1656434769.659 [NAL9602](INFO): GPS fix at 20220628T164608: (36.874787, -121.971697)
2022-06-28T16:46:09.689Z,1656434769.689 [Default:CheckIn:Read_GPS] Stopped
2022-06-28T16:46:09.689Z,1656434769.689 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-06-28T16:46:17.553Z,1656434777.553 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220628T144635/Courier0061.lzma
2022-06-28T16:46:18.560Z,1656434778.560 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Courier0061.lzma.bak
2022-06-28T16:46:18.560Z,1656434778.560 [DataOverHttps](INFO): SBD MOMSN=16932780
2022-06-28T16:46:26.706Z,1656434786.706 [NAL9602](INFO): SBD MO Status=0, MOMSN=19372, MT Status=0, MTMSN=0
2022-06-28T16:46:26.706Z,1656434786.706 [NAL9602](INFO): No messages in MT queue
2022-06-28T16:46:37.765Z,1656434797.765 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20220628T144635/Express0062.lzma
2022-06-28T16:46:38.768Z,1656434798.768 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Express0062.lzma.bak
2022-06-28T16:46:38.768Z,1656434798.768 [DataOverHttps](INFO): SBD MOMSN=16932783
2022-06-28T16:46:40.043Z,1656434800.043 [Default:CheckIn:Read_Iridium] Stopped
2022-06-28T16:46:40.043Z,1656434800.043 [Default:CheckIn:C.Wait] Running Loop=1
2022-06-28T16:46:40.043Z,1656434800.043 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-06-28T16:46:57.403Z,1656434817.403 [NAL9602](INFO): Not Powering down - fast GPS
2022-06-28T16:47:13.569Z,1656434833.569 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2022-06-28T16:48:59.262Z,1656434939.262 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.247166
2022-06-28T16:50:08.090Z,1656435008.090 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:50:43.230Z,1656435043.230 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:51:18.382Z,1656435078.382 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:51:40.625Z,1656435100.625 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-06-28T16:51:40.625Z,1656435100.625 [Default:CheckIn:C.Wait] Stopped
2022-06-28T16:51:40.625Z,1656435100.625 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-06-28T16:51:40.625Z,1656435100.625 [Default:CheckIn:D] Running Loop=1
2022-06-28T16:51:41.022Z,1656435101.022 [Default:CheckIn:D] Stopped
2022-06-28T16:51:41.022Z,1656435101.022 [Default:CheckIn:E] Running Loop=1
2022-06-28T16:51:41.461Z,1656435101.461 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 121.249162 min 
2022-06-28T16:51:41.461Z,1656435101.461 [Default:CheckIn:E] Stopped
2022-06-28T16:51:41.461Z,1656435101.461 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-06-28T16:51:41.462Z,1656435101.462 [Default:CheckIn] Stopped
2022-06-28T16:51:41.462Z,1656435101.462 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-06-28T16:51:41.463Z,1656435101.463 [Default:CheckIn](INFO): Running loop #20
2022-06-28T16:51:41.463Z,1656435101.463 [Default:CheckIn] Running Loop=20
2022-06-28T16:51:41.463Z,1656435101.463 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-06-28T16:51:41.463Z,1656435101.463 [Default:CheckIn:Read_GPS] Running Loop=1
2022-06-28T16:51:43.443Z,1656435103.443 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165142.00,A,3652.49413,N,12158.27297,W,0.039,95.71,280622,,,D*4F
2022-06-28T16:51:43.445Z,1656435103.445 [NAL9602](INFO): GPS fix at 20220628T165142: (36.874902, -121.971216)
2022-06-28T16:51:43.475Z,1656435103.475 [Default:CheckIn:Read_GPS] Stopped
2022-06-28T16:51:43.475Z,1656435103.475 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-06-28T16:51:53.538Z,1656435113.538 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-06-28T16:52:04.924Z,1656435124.924 [NAL9602](INFO): SBD MO Status=1, MOMSN=19373, MT Status=0, MTMSN=0
2022-06-28T16:52:04.986Z,1656435124.986 [NAL9602](INFO): Sent 73 bytes from file Logs/20220628T144635/Courier0064.lzma
2022-06-28T16:52:04.986Z,1656435124.986 [NAL9602](INFO): Packets left to send: 0
2022-06-28T16:52:23.832Z,1656435143.832 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003913
2022-06-28T16:52:24.376Z,1656435144.376 [NAL9602](INFO): SBD MO Status=1, MOMSN=19374, MT Status=0, MTMSN=0
2022-06-28T16:52:24.426Z,1656435144.426 [NAL9602](INFO): Sent 130 bytes from file Logs/20220628T144635/Express0065.lzma
2022-06-28T16:52:24.426Z,1656435144.426 [NAL9602](INFO): Packets left to send: 0
2022-06-28T16:52:25.206Z,1656435145.206 [Default:CheckIn:Read_Iridium] Stopped
2022-06-28T16:52:25.206Z,1656435145.206 [Default:CheckIn:C.Wait] Running Loop=1
2022-06-28T16:52:25.206Z,1656435145.206 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-06-28T16:52:55.127Z,1656435175.127 [NAL9602](INFO): Not Powering down - fast GPS
2022-06-28T16:57:25.817Z,1656435445.817 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-06-28T16:57:25.817Z,1656435445.817 [Default:CheckIn:C.Wait] Stopped
2022-06-28T16:57:25.817Z,1656435445.817 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-06-28T16:57:25.817Z,1656435445.817 [Default:CheckIn:D] Running Loop=1
2022-06-28T16:57:26.231Z,1656435446.231 [Default:CheckIn:D] Stopped
2022-06-28T16:57:26.231Z,1656435446.231 [Default:CheckIn:E] Running Loop=1
2022-06-28T16:57:26.643Z,1656435446.643 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 127.002645 min 
2022-06-28T16:57:26.644Z,1656435446.644 [Default:CheckIn:E] Stopped
2022-06-28T16:57:26.644Z,1656435446.644 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-06-28T16:57:26.644Z,1656435446.644 [Default:CheckIn] Stopped
2022-06-28T16:57:26.644Z,1656435446.644 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-06-28T16:57:26.644Z,1656435446.644 [Default:CheckIn](INFO): Running loop #21
2022-06-28T16:57:26.644Z,1656435446.644 [Default:CheckIn] Running Loop=21
2022-06-28T16:57:26.644Z,1656435446.644 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-06-28T16:57:26.644Z,1656435446.644 [Default:CheckIn:Read_GPS] Running Loop=1
2022-06-28T16:57:28.635Z,1656435448.635 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165727.00,A,3652.49923,N,12158.21457,W,0.369,149.12,280622,,,D*7B
2022-06-28T16:57:28.637Z,1656435448.637 [NAL9602](INFO): GPS fix at 20220628T165727: (36.874987, -121.970243)
2022-06-28T16:57:28.648Z,1656435448.648 [Default:CheckIn:Read_GPS] Stopped
2022-06-28T16:57:28.648Z,1656435448.648 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-06-28T16:57:36.289Z,1656435456.289 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220628T144635/Courier0067.lzma
2022-06-28T16:57:37.292Z,1656435457.292 [DataOverHttps](INFO): Moved sent file to Logs/20220628T144635/Courier0067.lzma.bak
2022-06-28T16:57:37.292Z,1656435457.292 [DataOverHttps](IMPORTANT): SBD MOMSN=16932854, MTMSN=20220628T165736
2022-06-28T16:57:45.154Z,1656435465.154 [DataOverHttps](INFO): Received command: restart logs