2021-03-31T15:02:38.560Z,1617202958.560 [Supervisor](DEBUG): Initializing supervisor.
2021-03-31T15:02:38.564Z,1617202958.564 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2021-03-31T15:02:38.565Z,1617202958.565 [SyncHandler](INFO): Protected caller Thread ID is 4042
2021-03-31T15:02:38.565Z,1617202958.565 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2021-03-31T15:02:38.566Z,1617202958.566 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2021-03-31T15:02:38.567Z,1617202958.567 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 4043
2021-03-31T15:02:38.571Z,1617202958.571 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2021-03-31T15:02:38.589Z,1617202958.589 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2021-03-31T15:02:38.590Z,1617202958.590 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2021-03-31T15:02:38.590Z,1617202958.590 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 4044
2021-03-31T15:02:38.592Z,1617202958.592 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2021-03-31T15:02:38.593Z,1617202958.593 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2021-03-31T15:02:38.594Z,1617202958.594 [logger ThreadHandler](INFO): Protected caller Thread ID is 4045
2021-03-31T15:02:38.597Z,1617202958.597 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2021-03-31T15:02:38.597Z,1617202958.597 [Supervisor](INFO): Looking for Config files in directory: Config/
2021-03-31T15:02:38.599Z,1617202958.599 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2021-03-31T15:02:39.023Z,1617202959.023 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2021-03-31T15:02:39.023Z,1617202959.023 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2021-03-31T15:02:39.105Z,1617202959.105 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2021-03-31T15:02:39.434Z,1617202959.434 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2021-03-31T15:02:39.435Z,1617202959.435 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2021-03-31T15:02:39.537Z,1617202959.537 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2021-03-31T15:02:39.538Z,1617202959.538 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2021-03-31T15:02:39.736Z,1617202959.736 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2021-03-31T15:02:39.737Z,1617202959.737 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2021-03-31T15:02:40.242Z,1617202960.242 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2021-03-31T15:02:40.243Z,1617202960.243 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2021-03-31T15:02:40.482Z,1617202960.482 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2021-03-31T15:02:40.482Z,1617202960.482 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2021-03-31T15:02:40.634Z,1617202960.634 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2021-03-31T15:02:40.634Z,1617202960.634 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2021-03-31T15:02:40.828Z,1617202960.828 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2021-03-31T15:02:40.828Z,1617202960.828 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2021-03-31T15:02:40.927Z,1617202960.927 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2021-03-31T15:02:40.927Z,1617202960.927 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2021-03-31T15:02:41.152Z,1617202961.152 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2021-03-31T15:02:41.153Z,1617202961.153 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2021-03-31T15:02:41.512Z,1617202961.512 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2021-03-31T15:02:41.513Z,1617202961.513 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2021-03-31T15:02:41.597Z,1617202961.597 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2021-03-31T15:02:41.725Z,1617202961.725 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2021-03-31T15:02:41.725Z,1617202961.725 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2021-03-31T15:02:42.377Z,1617202962.377 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2021-03-31T15:02:42.378Z,1617202962.378 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2021-03-31T15:02:42.738Z,1617202962.739 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2021-03-31T15:02:42.741Z,1617202962.741 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2021-03-31T15:02:42.741Z,1617202962.741 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2021-03-31T15:02:42.943Z,1617202962.943 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2021-03-31T15:02:43.048Z,1617202963.048 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2021-03-31T15:02:43.149Z,1617202963.149 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2021-03-31T15:02:43.405Z,1617202963.405 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2021-03-31T15:02:43.405Z,1617202963.405 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2021-03-31T15:02:43.494Z,1617202963.494 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2021-03-31T15:02:43.593Z,1617202963.593 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2021-03-31T15:02:43.708Z,1617202963.708 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2021-03-31T15:02:43.796Z,1617202963.796 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Dock.cfg
2021-03-31T15:02:43.885Z,1617202963.885 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2021-03-31T15:02:43.998Z,1617202963.998 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/workSite.cfg
2021-03-31T15:02:44.239Z,1617202964.239 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2021-03-31T15:02:44.844Z,1617202964.844 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2021-03-31T15:02:45.291Z,1617202965.291 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2021-03-31T15:02:45.297Z,1617202965.297 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2021-03-31T15:02:45.640Z,1617202965.640 [AHRS_M2] Loaded
2021-03-31T15:02:45.640Z,1617202965.640 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2021-03-31T15:02:45.668Z,1617202965.668 [BackseatComponent] Loaded
2021-03-31T15:02:45.668Z,1617202965.668 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2021-03-31T15:02:45.669Z,1617202965.669 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 407934E0
2021-03-31T15:02:45.670Z,1617202965.670 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 4133
2021-03-31T15:02:45.672Z,1617202965.672 [LcmUniversalReporter] Loaded
2021-03-31T15:02:45.672Z,1617202965.672 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2021-03-31T15:02:46.401Z,1617202966.401 [BPC1] Loaded
2021-03-31T15:02:46.401Z,1617202966.401 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2021-03-31T15:02:46.471Z,1617202966.471 [DataOverHttps] Loaded
2021-03-31T15:02:46.471Z,1617202966.471 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2021-03-31T15:02:46.472Z,1617202966.472 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407C34E0
2021-03-31T15:02:46.472Z,1617202966.472 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 4134
2021-03-31T15:02:46.490Z,1617202966.490 [Depth_Keller] Loaded
2021-03-31T15:02:46.491Z,1617202966.491 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2021-03-31T15:02:46.495Z,1617202966.495 [DropWeight] Loaded
2021-03-31T15:02:46.495Z,1617202966.495 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2021-03-31T15:02:46.531Z,1617202966.531 [Micromodem] Loaded
2021-03-31T15:02:46.532Z,1617202966.532 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2021-03-31T15:02:46.587Z,1617202966.587 [NAL9602] Loaded
2021-03-31T15:02:46.587Z,1617202966.587 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2021-03-31T15:02:46.614Z,1617202966.614 [Onboard] Loaded
2021-03-31T15:02:46.614Z,1617202966.614 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2021-03-31T15:02:46.615Z,1617202966.615 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 407F34E0
2021-03-31T15:02:46.616Z,1617202966.616 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 4135
2021-03-31T15:02:46.621Z,1617202966.621 [PowerOnly](INFO): Adding load control power supply at /dev/loadC1
2021-03-31T15:02:46.631Z,1617202966.631 [PowerOnly] Loaded
2021-03-31T15:02:46.631Z,1617202966.631 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2021-03-31T15:02:46.644Z,1617202966.644 [Radio_Surface] Loaded
2021-03-31T15:02:46.644Z,1617202966.644 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2021-03-31T15:02:46.645Z,1617202966.645 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408234E0
2021-03-31T15:02:46.645Z,1617202966.645 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 4136
2021-03-31T15:02:46.674Z,1617202966.674 [RDI_Pathfinder] Loaded
2021-03-31T15:02:46.674Z,1617202966.674 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2021-03-31T15:02:46.699Z,1617202966.699 [RDI_PathfinderUp] Loaded
2021-03-31T15:02:46.699Z,1617202966.699 [ComponentRegistry](DEBUG): SyncComponent "RDI_PathfinderUp" handled in the control thread.
2021-03-31T15:02:46.700Z,1617202966.700 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2021-03-31T15:02:46.700Z,1617202966.700 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2021-03-31T15:02:46.711Z,1617202966.711 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2021-03-31T15:02:46.711Z,1617202966.711 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2021-03-31T15:02:46.786Z,1617202966.786 [DeadReckonUsingMultipleVelocitySources] Loaded
2021-03-31T15:02:46.786Z,1617202966.786 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2021-03-31T15:02:46.799Z,1617202966.799 [NavChart] Loaded
2021-03-31T15:02:46.799Z,1617202966.799 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2021-03-31T15:02:46.804Z,1617202966.804 [UniversalFixResidualReporter] Loaded
2021-03-31T15:02:46.805Z,1617202966.805 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2021-03-31T15:02:46.814Z,1617202966.814 [WorkSite] Loaded
2021-03-31T15:02:46.815Z,1617202966.815 [ComponentRegistry](DEBUG): SyncComponent "WorkSite" handled in the control thread.
2021-03-31T15:02:46.815Z,1617202966.815 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2021-03-31T15:02:46.816Z,1617202966.816 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2021-03-31T15:02:46.899Z,1617202966.899 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2021-03-31T15:02:46.900Z,1617202966.900 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2021-03-31T15:02:47.005Z,1617202967.005 [BuoyancyServo] Loaded
2021-03-31T15:02:47.005Z,1617202967.005 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2021-03-31T15:02:47.025Z,1617202967.025 [ElevatorServo] Loaded
2021-03-31T15:02:47.025Z,1617202967.025 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2021-03-31T15:02:47.045Z,1617202967.045 [MassServo] Loaded
2021-03-31T15:02:47.045Z,1617202967.045 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2021-03-31T15:02:47.064Z,1617202967.064 [RudderServo] Loaded
2021-03-31T15:02:47.064Z,1617202967.064 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2021-03-31T15:02:47.082Z,1617202967.082 [ThrusterServo] Loaded
2021-03-31T15:02:47.082Z,1617202967.082 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2021-03-31T15:02:47.083Z,1617202967.083 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2021-03-31T15:02:47.083Z,1617202967.083 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2021-03-31T15:02:47.245Z,1617202967.245 [CTD_Seabird] Loaded
2021-03-31T15:02:47.246Z,1617202967.246 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2021-03-31T15:02:47.247Z,1617202967.247 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409414E0
2021-03-31T15:02:47.247Z,1617202967.247 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 4137
2021-03-31T15:02:47.266Z,1617202967.266 [PAR_Licor] Loaded
2021-03-31T15:02:47.266Z,1617202967.266 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2021-03-31T15:02:47.297Z,1617202967.297 [WetLabsSeaOWL_UV_A] Loaded
2021-03-31T15:02:47.297Z,1617202967.297 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2021-03-31T15:02:47.298Z,1617202967.298 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409714E0
2021-03-31T15:02:47.298Z,1617202967.298 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 4138
2021-03-31T15:02:47.299Z,1617202967.299 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2021-03-31T15:02:47.300Z,1617202967.300 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2021-03-31T15:02:47.591Z,1617202967.591 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2021-03-31T15:02:47.592Z,1617202967.592 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2021-03-31T15:02:47.631Z,1617202967.631 [DepthRateCalculator] Loaded
2021-03-31T15:02:47.631Z,1617202967.631 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2021-03-31T15:02:47.636Z,1617202967.636 [PitchRateCalculator] Loaded
2021-03-31T15:02:47.636Z,1617202967.636 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2021-03-31T15:02:47.645Z,1617202967.645 [SpeedCalculator] Loaded
2021-03-31T15:02:47.646Z,1617202967.646 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2021-03-31T15:02:47.658Z,1617202967.658 [TempGradientCalculator] Loaded
2021-03-31T15:02:47.658Z,1617202967.658 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2021-03-31T15:02:47.663Z,1617202967.663 [YawRateCalculator] Loaded
2021-03-31T15:02:47.663Z,1617202967.663 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2021-03-31T15:02:47.684Z,1617202967.684 [ElevatorOffsetCalculator] Loaded
2021-03-31T15:02:47.684Z,1617202967.684 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2021-03-31T15:02:47.684Z,1617202967.684 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2021-03-31T15:02:47.685Z,1617202967.685 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2021-03-31T15:02:47.822Z,1617202967.822 [SBIT](DEBUG): Construct Startup Built In Test.
2021-03-31T15:02:47.833Z,1617202967.833 [SBIT] Loaded
2021-03-31T15:02:47.833Z,1617202967.833 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2021-03-31T15:02:47.836Z,1617202967.836 [IBIT](DEBUG): Construct Initiated Built In Test.
2021-03-31T15:02:47.849Z,1617202967.849 [IBIT] Loaded
2021-03-31T15:02:47.849Z,1617202967.849 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2021-03-31T15:02:47.854Z,1617202967.854 [CBIT](DEBUG): Construct Continuous Built In Test.
2021-03-31T15:02:47.950Z,1617202967.950 [CBIT] Loaded
2021-03-31T15:02:47.950Z,1617202967.950 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2021-03-31T15:02:47.951Z,1617202967.951 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2021-03-31T15:02:47.951Z,1617202967.951 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2021-03-31T15:02:48.003Z,1617202968.003 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2021-03-31T15:02:48.004Z,1617202968.004 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2021-03-31T15:02:48.100Z,1617202968.100 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2021-03-31T15:02:48.101Z,1617202968.101 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2021-03-31T15:02:48.149Z,1617202968.149 [VerticalControl](DEBUG): Construct VerticalControl.
2021-03-31T15:02:48.199Z,1617202968.199 [VerticalControl] Loaded
2021-03-31T15:02:48.199Z,1617202968.199 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2021-03-31T15:02:48.202Z,1617202968.202 [HorizontalControl](DEBUG): Construct HorizontalControl.
2021-03-31T15:02:48.236Z,1617202968.236 [HorizontalControl] Loaded
2021-03-31T15:02:48.236Z,1617202968.236 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2021-03-31T15:02:48.238Z,1617202968.238 [SpeedControl](DEBUG): Construct SpeedControl.
2021-03-31T15:02:48.240Z,1617202968.240 [SpeedControl] Loaded
2021-03-31T15:02:48.240Z,1617202968.240 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2021-03-31T15:02:48.243Z,1617202968.243 [LoopControl](DEBUG): Construct LoopControl.
2021-03-31T15:02:48.243Z,1617202968.243 [LoopControl] Loaded
2021-03-31T15:02:48.244Z,1617202968.244 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2021-03-31T15:02:48.244Z,1617202968.244 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2021-03-31T15:02:48.245Z,1617202968.245 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2021-03-31T15:02:48.272Z,1617202968.272 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2021-03-31T15:02:48.278Z,1617202968.278 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2021-03-31T15:02:48.280Z,1617202968.280 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2021-03-31T15:02:48.290Z,1617202968.290 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2021-03-31T15:02:48.292Z,1617202968.292 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B1B4E0
2021-03-31T15:02:48.292Z,1617202968.292 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 4139
2021-03-31T15:02:48.296Z,1617202968.296 [Supervisor](INFO): Main Thread ID is 3313
2021-03-31T15:02:48.296Z,1617202968.296 [Supervisor](DEBUG): Running supervisor.
2021-03-31T15:02:48.297Z,1617202968.297 [CommandLine ThreadHandler](INFO): Handler Thread ID is 4140
2021-03-31T15:02:48.299Z,1617202968.299 [controlThread ThreadHandler](INFO): Handler Thread ID is 4141
2021-03-31T15:02:48.300Z,1617202968.300 [controlThread](DEBUG): Initializing ControlThread
2021-03-31T15:02:48.306Z,1617202968.306 [NavChart](DEBUG): Initialize NavChart Navigation.
2021-03-31T15:02:48.307Z,1617202968.307 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2021-03-31T15:02:48.307Z,1617202968.307 [WorkSite](DEBUG): Initializing WorkSite component.
2021-03-31T15:02:48.312Z,1617202968.312 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2021-03-31T15:02:48.312Z,1617202968.312 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2021-03-31T15:02:48.313Z,1617202968.313 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2021-03-31T15:02:48.313Z,1617202968.313 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2021-03-31T15:02:48.314Z,1617202968.314 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2021-03-31T15:02:48.314Z,1617202968.314 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2021-03-31T15:02:48.315Z,1617202968.315 [SBIT](INFO): Initialize SBIT Component.
2021-03-31T15:02:48.315Z,1617202968.315 [SBIT](IMPORTANT): git: 2021-03-30_A
2021-03-31T15:02:48.316Z,1617202968.316 [SBIT](INFO): git hash: cd879fcb970100e74ebf57bcee2c6db5cbfff587
2021-03-31T15:02:48.316Z,1617202968.316 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2021-03-31T15:02:48.318Z,1617202968.318 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Thu Aug 6 12:04:53 PDT 2020
2021-03-31T15:02:48.319Z,1617202968.319 [SBIT](INFO): Beginning SBIT in 29.000000 seconds.
2021-03-31T15:02:48.319Z,1617202968.319 [IBIT](INFO): Initialize IBIT Component.
2021-03-31T15:02:48.320Z,1617202968.320 [logger ThreadHandler](INFO): Handler Thread ID is 4142
2021-03-31T15:02:48.336Z,1617202968.336 [CBIT](DEBUG): Initialize CBIT Component.
2021-03-31T15:02:48.344Z,1617202968.344 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 4143
2021-03-31T15:02:48.348Z,1617202968.348 [CBIT](DEBUG): Initialized mux pins.
2021-03-31T15:02:48.348Z,1617202968.348 [CBIT](DEBUG): Initializing the watchdog timer.
2021-03-31T15:02:48.356Z,1617202968.356 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 4144
2021-03-31T15:02:48.357Z,1617202968.357 [DataOverHttps](DEBUG): dashIP=128.128.181.155 starts with a digit so assuming it is a numeric IP
2021-03-31T15:02:48.368Z,1617202968.368 [Onboard ThreadHandler](INFO): Handler Thread ID is 4145
2021-03-31T15:02:48.372Z,1617202968.372 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2021-03-31T15:02:48.373Z,1617202968.373 [CBIT](DEBUG): Initializing heartbeat.
2021-03-31T15:02:48.400Z,1617202968.400 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 4146
2021-03-31T15:02:48.408Z,1617202968.408 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 4147
2021-03-31T15:02:48.409Z,1617202968.409 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2021-03-31T15:02:48.413Z,1617202968.413 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 4149
2021-03-31T15:02:48.414Z,1617202968.414 [WetLabsSeaOWL_UV_A](INFO): Powering down
2021-03-31T15:02:48.424Z,1617202968.424 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 4150
2021-03-31T15:02:48.428Z,1617202968.428 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2021-03-31T15:02:48.428Z,1617202968.428 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2021-03-31T15:02:48.428Z,1617202968.428 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2021-03-31T15:02:48.428Z,1617202968.428 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2021-03-31T15:02:48.428Z,1617202968.428 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2021-03-31T15:02:48.428Z,1617202968.428 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2021-03-31T15:02:48.429Z,1617202968.429 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2021-03-31T15:02:48.429Z,1617202968.429 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2021-03-31T15:02:48.429Z,1617202968.429 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2021-03-31T15:02:48.429Z,1617202968.429 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2021-03-31T15:02:48.429Z,1617202968.429 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2021-03-31T15:02:48.429Z,1617202968.429 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2021-03-31T15:02:48.430Z,1617202968.430 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2021-03-31T15:02:48.430Z,1617202968.430 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2021-03-31T15:02:48.430Z,1617202968.430 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2021-03-31T15:02:48.430Z,1617202968.430 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2021-03-31T15:02:48.444Z,1617202968.444 [CBIT](DEBUG): Deactivating GF circuits.
2021-03-31T15:02:48.444Z,1617202968.444 [CBIT](DEBUG): Deactivating emergency mode.
2021-03-31T15:02:48.480Z,1617202968.480 [CBIT](DEBUG): Backplane powered.
2021-03-31T15:02:48.480Z,1617202968.480 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2021-03-31T15:02:48.482Z,1617202968.482 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2021-03-31T15:02:48.482Z,1617202968.482 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2021-03-31T15:02:48.483Z,1617202968.483 [LoopControl](DEBUG): Initialize LoopControlComponent.
2021-03-31T15:02:48.484Z,1617202968.484 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2021-03-31T15:02:48.496Z,1617202968.496 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2021-03-31T15:02:48.523Z,1617202968.523 [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>
2021-03-31T15:02:48.524Z,1617202968.524 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2021-03-31T15:02:48.587Z,1617202968.587 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2021-03-31T15:02:48.604Z,1617202968.604 [Default:A.Wait](DEBUG): Construct Wait.
2021-03-31T15:02:48.606Z,1617202968.606 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-03-31T15:02:48.626Z,1617202968.626 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-03-31T15:02:48.656Z,1617202968.656 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-03-31T15:02:48.670Z,1617202968.670 [Default:E.Execute](DEBUG): Construct Execute.
2021-03-31T15:02:48.673Z,1617202968.673 [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>
2021-03-31T15:02:48.684Z,1617202968.684 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,Micromodem,NAL9602,PowerOnly,RDI_Pathfinder,RDI_PathfinderUp,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,WorkSite,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2021-03-31T15:02:48.696Z,1617202968.696 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2021-03-31T15:02:48.757Z,1617202968.757 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2021-03-31T15:02:48.804Z,1617202968.804 [Radio_Surface](INFO): Powering up
2021-03-31T15:02:48.824Z,1617202968.824 [DepthRateCalculator](ERROR): Depth measurement is not active
2021-03-31T15:02:48.847Z,1617202968.847 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2021-03-31T15:02:48.860Z,1617202968.860 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2021-03-31T15:02:48.861Z,1617202968.861 [ElevatorServo](DEBUG): Initializing EZServoServo.
2021-03-31T15:02:48.868Z,1617202968.868 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2021-03-31T15:02:48.869Z,1617202968.869 [MassServo](DEBUG): Initializing EZServoServo.
2021-03-31T15:02:48.876Z,1617202968.876 [MassServo](DEBUG): Initializing MassServo.
2021-03-31T15:02:48.877Z,1617202968.877 [RudderServo](DEBUG): Initializing EZServoServo.
2021-03-31T15:02:48.884Z,1617202968.884 [RudderServo](DEBUG): Initializing RudderServo.
2021-03-31T15:02:48.885Z,1617202968.885 [ThrusterServo](DEBUG): Initializing EZServoServo.
2021-03-31T15:02:48.892Z,1617202968.892 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2021-03-31T15:02:49.111Z,1617202969.111 [Micromodem](INFO): Powering up
2021-03-31T15:02:49.112Z,1617202969.112 [Micromodem](DEBUG): Initializing Micromodem.
2021-03-31T15:02:49.832Z,1617202969.832 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2021-03-31T15:02:49.832Z,1617202969.832 [RudderServo](FAULT): Rudder failed to initialize
2021-03-31T15:02:49.832Z,1617202969.832 [RudderServo] Communications Fault, FailCount= 1
2021-03-31T15:02:49.832Z,1617202969.832 [RudderServo](ERROR): Communications Fault
2021-03-31T15:02:49.932Z,1617202969.932 [CBIT](ERROR): Communications Fault in component: RudderServo
2021-03-31T15:02:50.117Z,1617202970.117 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-03-31T15:02:50.117Z,1617202970.117 [RudderServo](INFO): Powering down
2021-03-31T15:02:50.364Z,1617202970.364 [RudderServo](FAULT): LCB fault: Current Limiter Activated.
2021-03-31T15:02:50.365Z,1617202970.365 [RudderServo] Hardware Fault, FailCount= 1
2021-03-31T15:02:50.365Z,1617202970.365 [RudderServo](ERROR): Hardware Fault
2021-03-31T15:02:50.763Z,1617202970.763 [RudderServo](DEBUG): Initializing EZServoServo.
2021-03-31T15:02:50.881Z,1617202970.881 [RudderServo](DEBUG): Initializing RudderServo.
2021-03-31T15:02:50.885Z,1617202970.885 [CBIT](INFO): Clearing failed state for component RudderServo
2021-03-31T15:02:50.885Z,1617202970.885 [RudderServo] No Fault, FailCount= 1
2021-03-31T15:02:54.018Z,1617202974.018 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33
2021-03-31T15:02:56.039Z,1617202976.039 [Micromodem](INFO): Nmea in: $CATMG,2021-03-31T15:02:54.699391Z,RTC,RTC*5A
2021-03-31T15:02:56.039Z,1617202976.039 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2021-03-31T15:02:54.699391Z,RTC,RTC*5A
2021-03-31T15:03:05.293Z,1617202985.293 [Micromodem](ERROR): Nmea resend: $CCCFG,ALL,0*33
2021-03-31T15:03:05.698Z,1617202985.698 [Micromodem](INFO): Nmea in: $CAERR,150305,NI ,12,Unknown command*4E
2021-03-31T15:03:05.698Z,1617202985.698 [Micromodem](ERROR): Got error from modem: $CAERR,150305,NI ,12,Unknown command*4E
2021-03-31T15:03:16.605Z,1617202996.605 [Micromodem](ERROR): Nmea resend: $CCCFG,ALL,0*33
2021-03-31T15:03:16.606Z,1617202996.606 [NAL9602](INFO): Powering up NAL9602
2021-03-31T15:03:17.009Z,1617202997.009 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31
2021-03-31T15:03:17.010Z,1617202997.010 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31
2021-03-31T15:03:17.413Z,1617202997.413 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33
2021-03-31T15:03:17.414Z,1617202997.414 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64
2021-03-31T15:03:17.822Z,1617202997.822 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66
2021-03-31T15:03:17.822Z,1617202997.822 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F
2021-03-31T15:03:17.890Z,1617202997.890 [SBIT](IMPORTANT): Beginning Startup BIT
2021-03-31T15:03:17.894Z,1617202997.894 [CBIT](IMPORTANT): Beginning ground fault scan
2021-03-31T15:03:18.222Z,1617202998.222 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D
2021-03-31T15:03:18.222Z,1617202998.222 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E
2021-03-31T15:03:18.638Z,1617202998.638 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C
2021-03-31T15:03:18.638Z,1617202998.638 [Micromodem](INFO): Nmea out: $CCCFG,FC0,14500*47
2021-03-31T15:03:19.030Z,1617202999.030 [Micromodem](INFO): Nmea in: $CACFG,FC0,14500*45
2021-03-31T15:03:19.030Z,1617202999.030 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63
2021-03-31T15:03:19.433Z,1617202999.433 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61
2021-03-31T15:03:19.434Z,1617202999.434 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A
2021-03-31T15:03:19.837Z,1617202999.837 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38
2021-03-31T15:03:19.838Z,1617202999.838 [Micromodem](INFO): Nmea out: $CCCLK,2021,03,31,15,03,20*41
2021-03-31T15:03:20.242Z,1617203000.242 [Micromodem](INFO): Nmea in: $CACLK,2021,3,31,15,3,20*43
2021-03-31T15:03:20.646Z,1617203000.646 [Micromodem](INFO): Nmea in: $CATMS,0,2021-03-31T15:03:21Z*72
2021-03-31T15:03:20.647Z,1617203000.647 [Micromodem](INFO): Nmea in: $CATMG,2021-03-31T15:03:21.027382Z,USER_CMD,RTC*19
2021-03-31T15:03:27.514Z,1617203007.514 [NAL9602](INFO): NAL9602 initialized
2021-03-31T15:03:28.876Z,1617203008.876 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.010385
CHAN A1 (24V): -0.028732
CHAN A2 (12V): -0.007345
CHAN A3 (5V): -0.002209
CHAN B0 (3.3V): 0.000210
CHAN B1 (3.15aV): 0.000180
CHAN B2 (3.15bV): -0.000329
CHAN B3 (GND): 0.002397
OPEN: 0.005374
Full Scale Calc: 4.765 mA, -1.589 mA
2021-03-31T15:03:42.090Z,1617203022.090 [NAL9602](INFO): SBD MO Status=0, MOMSN=14204, MT Status=0, MTMSN=0
2021-03-31T15:03:42.090Z,1617203022.090 [NAL9602](INFO): No messages in MT queue
2021-03-31T15:04:11.976Z,1617203051.976 [SBIT](IMPORTANT): SBIT PASSED
2021-03-31T15:04:11.976Z,1617203051.976 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2021-03-31T15:04:11.977Z,1617203051.977 [SBIT](IMPORTANT): Express linearApproximation mass_concentration_of_chlorophyll_in_sea_water 1.000000 microgram_per_liter;
2021-03-31T15:04:11.977Z,1617203051.977 [SBIT](IMPORTANT): Express linearApproximation mass_concentration_of_petroleum_hydrocarbons_in_sea_water 1.000000 microgram_per_liter;
2021-03-31T15:04:11.978Z,1617203051.978 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=318.938742 cubic_centimeter;
2021-03-31T15:04:11.978Z,1617203051.978 [SBIT](IMPORTANT): VerticalControl.massDefault=2.262471 millimeter;
2021-03-31T15:04:12.394Z,1617203052.394 [WorkSite](IMPORTANT): Reading workSite position from Data/workSite.cfg
2021-03-31T15:04:12.397Z,1617203052.397 [WorkSite](IMPORTANT): WorkSite fix at 20210331T150138: (41.524226, -70.671792)
2021-03-31T15:04:12.399Z,1617203052.399 [MissionManager](IMPORTANT): Started mission Startup
2021-03-31T15:04:12.399Z,1617203052.399 [Startup] Running Loop=1
2021-03-31T15:04:12.399Z,1617203052.399 [Startup](DEBUG): Aggregate::initialize Startup
2021-03-31T15:04:12.399Z,1617203052.399 [Startup:A.GoToSurface] Running Loop=1
2021-03-31T15:04:12.400Z,1617203052.400 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-03-31T15:04:12.400Z,1617203052.400 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-03-31T15:04:12.401Z,1617203052.401 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-03-31T15:04:12.401Z,1617203052.401 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-03-31T15:04:12.401Z,1617203052.401 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-03-31T15:04:12.402Z,1617203052.402 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-03-31T15:04:12.403Z,1617203052.403 [Startup:StartupSatComms] Running Loop=1
2021-03-31T15:04:12.403Z,1617203052.403 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2021-03-31T15:04:12.403Z,1617203052.403 [Startup:StartupSatComms:A] Running Loop=1
2021-03-31T15:04:12.820Z,1617203052.820 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2021-03-31T15:04:24.892Z,1617203064.892 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150423.00,A,4131.46061,N,07040.27489,W,0.486,0.00,310321,,,A*74
2021-03-31T15:04:24.895Z,1617203064.895 [NAL9602](INFO): GPS fix at 20210331T150423: (41.524344, -70.671248)
2021-03-31T15:04:24.932Z,1617203064.932 [Startup:StartupSatComms:A] Stopped
2021-03-31T15:04:24.932Z,1617203064.932 [Startup:StartupSatComms:B] Running Loop=1
2021-03-31T15:04:25.350Z,1617203065.350 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-03-31T15:04:44.426Z,1617203084.426 [NAL9602](INFO): SBD MO Status=1, MOMSN=14205, MT Status=0, MTMSN=0
2021-03-31T15:04:44.480Z,1617203084.480 [NAL9602](INFO): Sent 51 bytes from file Logs/20210331T145201/Courier0010.lzma
2021-03-31T15:04:44.480Z,1617203084.480 [NAL9602](INFO): Packets left to send: 0
2021-03-31T15:04:54.277Z,1617203094.277 [NAL9602](INFO): SBD MO Status=1, MOMSN=14206, MT Status=0, MTMSN=0
2021-03-31T15:04:54.332Z,1617203094.332 [NAL9602](INFO): Sent 184 bytes from file Logs/20210331T150238/Courier0000.lzma
2021-03-31T15:04:54.332Z,1617203094.332 [NAL9602](INFO): Packets left to send: 1
2021-03-31T15:05:02.901Z,1617203102.901 [NAL9602](INFO): SBD MO Status=1, MOMSN=14207, MT Status=0, MTMSN=0
2021-03-31T15:05:02.948Z,1617203102.948 [NAL9602](INFO): Sent 69 bytes from file Logs/20210331T150238/Courier0000.lzma
2021-03-31T15:05:02.948Z,1617203102.948 [NAL9602](INFO): Packets left to send: 0
2021-03-31T15:05:13.164Z,1617203113.164 [NAL9602](INFO): SBD MO Status=1, MOMSN=14208, MT Status=0, MTMSN=0
2021-03-31T15:05:13.232Z,1617203113.232 [NAL9602](INFO): Sent 125 bytes from file Logs/20210331T145201/Express0011.lzma
2021-03-31T15:05:13.232Z,1617203113.232 [NAL9602](INFO): Packets left to send: 0
2021-03-31T15:05:18.521Z,1617203118.521 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-03-31T15:05:19.359Z,1617203119.359 [NAL9602](INFO): SBD MO Status=1, MOMSN=14209, MT Status=0, MTMSN=0
2021-03-31T15:05:19.424Z,1617203119.424 [NAL9602](INFO): Sent 184 bytes from file Logs/20210331T150238/Express0001.lzma
2021-03-31T15:05:19.424Z,1617203119.424 [NAL9602](INFO): Packets left to send: 5
2021-03-31T15:05:25.142Z,1617203125.142 [Startup:StartupSatComms:B](INFO): Timed out from 2021-03-31T15:04:24.9Z
2021-03-31T15:05:25.142Z,1617203125.142 [Startup:StartupSatComms:B] Stopped
2021-03-31T15:05:25.142Z,1617203125.142 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2021-03-31T15:05:25.142Z,1617203125.142 [Startup:StartupSatComms] Stopped
2021-03-31T15:05:25.142Z,1617203125.142 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2021-03-31T15:05:25.143Z,1617203125.143 [Startup](INFO): Completed Startup
2021-03-31T15:05:25.143Z,1617203125.143 [MissionManager](INFO): Startup is completed.
2021-03-31T15:05:25.144Z,1617203125.144 [MissionManager](INFO): Uninitializing Mission Startup
2021-03-31T15:05:25.144Z,1617203125.144 [Startup] Stopped
2021-03-31T15:05:25.144Z,1617203125.144 [Startup](DEBUG): Aggregate::uninitialize Startup
2021-03-31T15:05:25.144Z,1617203125.144 [Startup:A.GoToSurface] Stopped
2021-03-31T15:05:25.144Z,1617203125.144 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-03-31T15:05:25.547Z,1617203125.547 [MissionManager](IMPORTANT): Started mission Default
2021-03-31T15:05:25.548Z,1617203125.548 [Default] Running Loop=1
2021-03-31T15:05:25.548Z,1617203125.548 [Default](DEBUG): Aggregate::initialize Default
2021-03-31T15:05:25.548Z,1617203125.548 [Default:B.GoToSurface] Running Loop=1
2021-03-31T15:05:25.548Z,1617203125.548 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-03-31T15:05:25.548Z,1617203125.548 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-03-31T15:05:25.549Z,1617203125.549 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-03-31T15:05:25.549Z,1617203125.549 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-03-31T15:05:25.549Z,1617203125.549 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-03-31T15:05:25.549Z,1617203125.549 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-03-31T15:05:25.550Z,1617203125.550 [Default:A.Wait] Running Loop=1
2021-03-31T15:05:25.550Z,1617203125.550 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-03-31T15:05:38.883Z,1617203138.883 [Default:A.Wait](INFO): Done Waiting.
2021-03-31T15:05:38.883Z,1617203138.883 [Default:A.Wait] Stopped
2021-03-31T15:05:38.883Z,1617203138.883 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T15:05:39.290Z,1617203139.290 [Default:CheckIn] Running Loop=1
2021-03-31T15:05:39.290Z,1617203139.290 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T15:05:39.290Z,1617203139.290 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T15:05:39.702Z,1617203139.702 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2021-03-31T15:05:40.073Z,1617203140.073 [NAL9602](INFO): SBD MO Status=2, MOMSN=14210, MT Status=2, MTMSN=0
2021-03-31T15:05:40.073Z,1617203140.073 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T15:05:41.324Z,1617203141.324 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150539.00,A,4131.46468,N,07040.28208,W,0.156,0.00,310321,,,A*7B
2021-03-31T15:05:41.326Z,1617203141.326 [NAL9602](INFO): GPS fix at 20210331T150539: (41.524411, -70.671368)
2021-03-31T15:05:41.349Z,1617203141.349 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T15:05:41.349Z,1617203141.349 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T15:05:41.733Z,1617203141.733 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-03-31T15:05:51.959Z,1617203151.959 [NAL9602](INFO): SBD MO Status=1, MOMSN=14210, MT Status=0, MTMSN=0
2021-03-31T15:05:52.008Z,1617203152.008 [NAL9602](INFO): Sent 72 bytes from file Logs/20210331T150238/Courier0004.lzma
2021-03-31T15:05:52.008Z,1617203152.008 [NAL9602](INFO): Packets left to send: 0
2021-03-31T15:06:02.563Z,1617203162.563 [NAL9602](INFO): SBD MO Status=1, MOMSN=14211, MT Status=0, MTMSN=0
2021-03-31T15:06:02.616Z,1617203162.616 [NAL9602](INFO): Sent 184 bytes from file Logs/20210331T150238/Express0001.lzma
2021-03-31T15:06:02.616Z,1617203162.616 [NAL9602](INFO): Packets left to send: 4
2021-03-31T15:06:08.185Z,1617203168.185 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004356
2021-03-31T15:06:11.548Z,1617203171.548 [NAL9602](INFO): SBD MO Status=1, MOMSN=14212, MT Status=0, MTMSN=0
2021-03-31T15:06:11.596Z,1617203171.596 [NAL9602](INFO): Sent 184 bytes from file Logs/20210331T150238/Express0001.lzma
2021-03-31T15:06:11.596Z,1617203171.596 [NAL9602](INFO): Packets left to send: 3
2021-03-31T15:06:11.628Z,1617203171.628 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T15:06:11.628Z,1617203171.628 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T15:06:11.628Z,1617203171.628 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T15:06:12.213Z,1617203172.213 [DataOverHttps](INFO): Sending 941 bytes from file Logs/20210331T150238/Express0001.lzma
2021-03-31T15:06:13.229Z,1617203173.229 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0001.lzma.bak
2021-03-31T15:06:13.230Z,1617203173.230 [DataOverHttps](INFO): SBD MOMSN=101796
2021-03-31T15:06:18.837Z,1617203178.837 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2021-03-31T15:06:42.263Z,1617203202.263 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T15:07:05.284Z,1617203225.284 [RDI_Pathfinder](ERROR): only read 0 of 4 data items
2021-03-31T15:10:08.303Z,1617203408.303 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2021-03-31T15:10:08.306Z,1617203408.306 [BPC1](INFO): Received data from all battery sticks.
2021-03-31T15:11:03.261Z,1617203463.261 [RDI_PathfinderUp](ERROR): only read 0 of 4 data items
2021-03-31T15:11:12.157Z,1617203472.157 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T15:11:12.157Z,1617203472.157 [Default:CheckIn:C.Wait] Stopped
2021-03-31T15:11:12.157Z,1617203472.157 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T15:11:12.157Z,1617203472.157 [Default:CheckIn:D] Running Loop=1
2021-03-31T15:11:12.556Z,1617203472.556 [Default:CheckIn:D] Stopped
2021-03-31T15:11:12.556Z,1617203472.556 [Default:CheckIn:E] Running Loop=1
2021-03-31T15:11:12.987Z,1617203472.987 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.783472 min
2021-03-31T15:11:12.987Z,1617203472.987 [Default:CheckIn:E] Stopped
2021-03-31T15:11:12.987Z,1617203472.987 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T15:11:12.987Z,1617203472.987 [Default:CheckIn] Stopped
2021-03-31T15:11:12.987Z,1617203472.987 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T15:11:12.987Z,1617203472.987 [Default:CheckIn](INFO): Running loop #2
2021-03-31T15:11:12.987Z,1617203472.987 [Default:CheckIn] Running Loop=2
2021-03-31T15:11:12.992Z,1617203472.992 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T15:11:12.992Z,1617203472.992 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T15:11:14.961Z,1617203474.961 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151113.00,A,4131.46437,N,07040.27906,W,0.175,0.00,310321,,,A*77
2021-03-31T15:11:14.963Z,1617203474.963 [NAL9602](INFO): GPS fix at 20210331T151113: (41.524406, -70.671318)
2021-03-31T15:11:14.978Z,1617203474.978 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T15:11:14.978Z,1617203474.978 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T15:11:18.475Z,1617203478.475 [DataOverHttps](INFO): Sending 200 bytes from file Logs/20210331T150238/Courier0007.lzma
2021-03-31T15:11:19.486Z,1617203479.486 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Courier0007.lzma.bak
2021-03-31T15:11:19.486Z,1617203479.486 [DataOverHttps](IMPORTANT): SBD MOMSN=101821, MTMSN=20210331T151118
2021-03-31T15:11:23.504Z,1617203483.504 [DataOverHttps](INFO): Received command:ibit
2021-03-31T15:11:23.560Z,1617203483.560 [CommandLine](IMPORTANT): got command ibit
2021-03-31T15:11:23.881Z,1617203483.881 [IBIT](IMPORTANT): Beginning Initiated BIT
2021-03-31T15:11:23.882Z,1617203483.882 [IBIT](IMPORTANT): Beginning control surface checks.
2021-03-31T15:11:23.885Z,1617203483.885 [CBIT](IMPORTANT): Beginning ground fault scan
2021-03-31T15:11:28.523Z,1617203488.523 [DataOverHttps](INFO): Sending 93 bytes from file Logs/20210331T150238/Express0005.lzma
2021-03-31T15:11:29.526Z,1617203489.526 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0005.lzma.bak
2021-03-31T15:11:29.526Z,1617203489.526 [DataOverHttps](INFO): SBD MOMSN=101825
2021-03-31T15:11:30.319Z,1617203490.319 [NAL9602](INFO): SBD MO Status=0, MOMSN=14213, MT Status=0, MTMSN=0
2021-03-31T15:11:30.319Z,1617203490.319 [NAL9602](INFO): No messages in MT queue
2021-03-31T15:11:31.527Z,1617203491.527 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151129.00,A,4131.46404,N,07040.27906,W,0.233,0.00,310321,,,A*7F
2021-03-31T15:11:31.553Z,1617203491.553 [NAL9602](INFO): GPS fix at 20210331T151129: (41.524401, -70.671318)
2021-03-31T15:11:33.949Z,1617203493.949 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151132.00,A,4131.46405,N,07040.27880,W,0.136,0.00,310321,,,A*7D
2021-03-31T15:11:33.951Z,1617203493.951 [NAL9602](INFO): GPS fix at 20210331T151132: (41.524401, -70.671313)
2021-03-31T15:11:34.843Z,1617203494.843 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.009898
CHAN A1 (24V): -0.028778
CHAN A2 (12V): -0.007233
CHAN A3 (5V): -0.001933
CHAN B0 (3.3V): 0.000238
CHAN B1 (3.15aV): 0.000255
CHAN B2 (3.15bV): 0.000075
CHAN B3 (GND): 0.002410
OPEN: 0.005083
Full Scale Calc: 4.765 mA, -1.589 mA
2021-03-31T15:11:36.780Z,1617203496.780 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151135.00,A,4131.46402,N,07040.27870,W,0.136,0.00,310321,,,A*72
2021-03-31T15:11:36.782Z,1617203496.782 [NAL9602](INFO): GPS fix at 20210331T151135: (41.524400, -70.671312)
2021-03-31T15:11:38.563Z,1617203498.563 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20210331T150238/Courier0010.lzma
2021-03-31T15:11:39.566Z,1617203499.566 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Courier0010.lzma.bak
2021-03-31T15:11:39.566Z,1617203499.566 [DataOverHttps](INFO): SBD MOMSN=101828
2021-03-31T15:11:40.015Z,1617203500.015 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151138.00,A,4131.46402,N,07040.27888,W,0.233,0.00,310321,,,A*7E
2021-03-31T15:11:40.022Z,1617203500.022 [NAL9602](INFO): GPS fix at 20210331T151138: (41.524400, -70.671315)
2021-03-31T15:11:42.848Z,1617203502.848 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151141.00,A,4131.46404,N,07040.27883,W,0.058,0.00,310321,,,A*72
2021-03-31T15:11:42.850Z,1617203502.850 [NAL9602](INFO): GPS fix at 20210331T151141: (41.524401, -70.671314)
2021-03-31T15:11:46.099Z,1617203506.099 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151144.00,A,4131.46417,N,07040.27887,W,0.292,0.00,310321,,,A*75
2021-03-31T15:11:46.106Z,1617203506.106 [NAL9602](INFO): GPS fix at 20210331T151144: (41.524403, -70.671314)
2021-03-31T15:11:48.608Z,1617203508.608 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20210331T150238/Express0008.lzma
2021-03-31T15:11:48.899Z,1617203508.899 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151147.00,A,4131.46443,N,07040.27874,W,0.194,0.00,310321,,,A*7E
2021-03-31T15:11:48.901Z,1617203508.901 [NAL9602](INFO): GPS fix at 20210331T151147: (41.524407, -70.671312)
2021-03-31T15:11:49.610Z,1617203509.610 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0008.lzma.bak
2021-03-31T15:11:49.610Z,1617203509.610 [DataOverHttps](INFO): SBD MOMSN=101830
2021-03-31T15:11:52.139Z,1617203512.139 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151150.00,A,4131.46474,N,07040.27858,W,0.117,0.00,310321,,,A*79
2021-03-31T15:11:52.141Z,1617203512.141 [NAL9602](INFO): GPS fix at 20210331T151150: (41.524412, -70.671310)
2021-03-31T15:11:54.964Z,1617203514.964 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151153.00,A,4131.46503,N,07040.27838,W,0.097,0.00,310321,,,A*74
2021-03-31T15:11:54.966Z,1617203514.966 [NAL9602](INFO): GPS fix at 20210331T151153: (41.524417, -70.671306)
2021-03-31T15:11:57.787Z,1617203517.787 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151156.00,A,4131.46540,N,07040.27813,W,0.136,0.00,310321,,,A*75
2021-03-31T15:11:57.789Z,1617203517.789 [NAL9602](INFO): GPS fix at 20210331T151156: (41.524423, -70.671302)
2021-03-31T15:11:58.656Z,1617203518.656 [DataOverHttps](INFO): Sending 260 bytes from file Logs/20210331T150238/Express0011.lzma
2021-03-31T15:11:59.649Z,1617203519.649 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0011.lzma.bak
2021-03-31T15:11:59.650Z,1617203519.650 [DataOverHttps](INFO): SBD MOMSN=101834
2021-03-31T15:12:01.017Z,1617203521.017 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151159.00,A,4131.46555,N,07040.27804,W,0.097,0.00,310321,,,A*72
2021-03-31T15:12:01.020Z,1617203521.020 [NAL9602](INFO): GPS fix at 20210331T151159: (41.524426, -70.671301)
2021-03-31T15:12:03.867Z,1617203523.867 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151202.00,A,4131.46492,N,07040.27966,W,0.175,0.00,310321,,,A*7D
2021-03-31T15:12:03.877Z,1617203523.877 [NAL9602](INFO): GPS fix at 20210331T151202: (41.524415, -70.671328)
2021-03-31T15:12:07.081Z,1617203527.081 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151205.00,A,4131.46456,N,07040.28062,W,0.078,0.00,310321,,,A*7C
2021-03-31T15:12:07.083Z,1617203527.083 [NAL9602](INFO): GPS fix at 20210331T151205: (41.524409, -70.671344)
2021-03-31T15:12:09.911Z,1617203529.911 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151208.00,A,4131.46427,N,07040.28146,W,0.058,0.00,310321,,,A*72
2021-03-31T15:12:09.913Z,1617203529.913 [NAL9602](INFO): GPS fix at 20210331T151208: (41.524405, -70.671358)
2021-03-31T15:12:09.958Z,1617203529.958 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 5
Latitude: 41.524403 Longitude: -70.671356
2021-03-31T15:12:10.362Z,1617203530.362 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.532000
2021-03-31T15:12:10.362Z,1617203530.362 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2021-03-31T15:12:10.362Z,1617203530.362 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2021-03-31T15:12:10.757Z,1617203530.757 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2021-03-31T15:12:10.757Z,1617203530.757 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2021-03-31T15:12:10.758Z,1617203530.758 [IBIT](IMPORTANT): Pressure:6.492056 PSI
2021-03-31T15:12:10.758Z,1617203530.758 [IBIT](IMPORTANT): Humidity:4.419485 %
2021-03-31T15:12:11.173Z,1617203531.173 [IBIT](IMPORTANT): Vehicle Pitch:-3.040923 degrees
2021-03-31T15:12:11.174Z,1617203531.174 [IBIT](IMPORTANT): Vehicle Roll:0.679077 degrees
2021-03-31T15:12:11.174Z,1617203531.174 [IBIT](IMPORTANT): Vehicle Heading:58.131618 degrees
2021-03-31T15:12:11.541Z,1617203531.541 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2021-03-31T15:12:11.542Z,1617203531.542 [IBIT](IMPORTANT): buoyancyNeutral: 318.938751 cc
2021-03-31T15:12:11.542Z,1617203531.542 [IBIT](IMPORTANT): massDefault: 0.226247 cm
2021-03-31T15:12:11.542Z,1617203531.542 [IBIT](IMPORTANT): stopDepth: 105.000000 m
2021-03-31T15:12:11.542Z,1617203531.542 [IBIT](IMPORTANT): abortDepth: 150.000000 m
2021-03-31T15:12:11.543Z,1617203531.543 [IBIT](IMPORTANT): IBIT PASSED
2021-03-31T15:12:11.962Z,1617203531.962 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T15:12:11.962Z,1617203531.962 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T15:12:11.962Z,1617203531.962 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T15:12:42.630Z,1617203562.630 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T15:15:54.135Z,1617203754.135 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2021-03-31T15:16:14.344Z,1617203774.344 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-03-31T15:16:19.181Z,1617203779.181 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-03-31T15:16:39.385Z,1617203799.385 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-03-31T15:16:39.393Z,1617203799.393 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude
2021-03-31T15:17:04.448Z,1617203824.448 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-03-31T15:17:12.540Z,1617203832.540 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T15:17:12.540Z,1617203832.540 [Default:CheckIn:C.Wait] Stopped
2021-03-31T15:17:12.540Z,1617203832.540 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T15:17:12.540Z,1617203832.540 [Default:CheckIn:D] Running Loop=1
2021-03-31T15:17:12.958Z,1617203832.958 [Default:CheckIn:D] Stopped
2021-03-31T15:17:12.958Z,1617203832.958 [Default:CheckIn:E] Running Loop=1
2021-03-31T15:17:13.347Z,1617203833.347 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.790168 min
2021-03-31T15:17:13.347Z,1617203833.347 [Default:CheckIn:E] Stopped
2021-03-31T15:17:13.347Z,1617203833.347 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T15:17:13.348Z,1617203833.348 [Default:CheckIn] Stopped
2021-03-31T15:17:13.348Z,1617203833.348 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T15:17:13.348Z,1617203833.348 [Default:CheckIn](INFO): Running loop #3
2021-03-31T15:17:13.348Z,1617203833.348 [Default:CheckIn] Running Loop=3
2021-03-31T15:17:13.348Z,1617203833.348 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T15:17:13.348Z,1617203833.348 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T15:17:15.337Z,1617203835.337 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151714.00,A,4131.46141,N,07040.28420,W,0.078,217.66,310321,,,A*7C
2021-03-31T15:17:15.353Z,1617203835.353 [NAL9602](INFO): GPS fix at 20210331T151714: (41.524357, -70.671403)
2021-03-31T15:17:15.383Z,1617203835.383 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T15:17:15.383Z,1617203835.383 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T15:17:19.003Z,1617203839.003 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210331T150238/Courier0013.lzma
2021-03-31T15:17:20.005Z,1617203840.005 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Courier0013.lzma.bak
2021-03-31T15:17:20.005Z,1617203840.005 [DataOverHttps](INFO): SBD MOMSN=101841
2021-03-31T15:17:29.045Z,1617203849.045 [DataOverHttps](INFO): Sending 668 bytes from file Logs/20210331T150238/Express0014.lzma
2021-03-31T15:17:30.045Z,1617203850.045 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0014.lzma.bak
2021-03-31T15:17:30.046Z,1617203850.046 [DataOverHttps](INFO): SBD MOMSN=101844
2021-03-31T15:17:31.170Z,1617203851.170 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T15:17:31.170Z,1617203851.170 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T15:17:31.170Z,1617203851.170 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T15:17:31.907Z,1617203851.907 [NAL9602](INFO): SBD MO Status=0, MOMSN=14214, MT Status=0, MTMSN=0
2021-03-31T15:17:31.907Z,1617203851.907 [NAL9602](INFO): No messages in MT queue
2021-03-31T15:17:54.197Z,1617203874.197 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-03-31T15:17:54.206Z,1617203874.206 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude
2021-03-31T15:18:02.605Z,1617203882.605 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T15:18:39.390Z,1617203919.390 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2021-03-31T15:18:41.801Z,1617203921.801 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-03-31T15:20:15.156Z,1617204015.156 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2021-03-31T15:20:19.593Z,1617204019.593 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude
2021-03-31T15:21:04.421Z,1617204064.421 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-03-31T15:22:30.109Z,1617204150.109 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-03-31T15:22:31.691Z,1617204151.691 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T15:22:31.708Z,1617204151.708 [Default:CheckIn:C.Wait] Stopped
2021-03-31T15:22:31.708Z,1617204151.708 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T15:22:31.708Z,1617204151.708 [Default:CheckIn:D] Running Loop=1
2021-03-31T15:22:32.141Z,1617204152.141 [Default:CheckIn:D] Stopped
2021-03-31T15:22:32.141Z,1617204152.141 [Default:CheckIn:E] Running Loop=1
2021-03-31T15:22:32.500Z,1617204152.500 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.109882 min
2021-03-31T15:22:32.500Z,1617204152.500 [Default:CheckIn:E] Stopped
2021-03-31T15:22:32.500Z,1617204152.500 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T15:22:32.500Z,1617204152.500 [Default:CheckIn] Stopped
2021-03-31T15:22:32.500Z,1617204152.500 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T15:22:32.501Z,1617204152.501 [Default:CheckIn](INFO): Running loop #4
2021-03-31T15:22:32.501Z,1617204152.501 [Default:CheckIn] Running Loop=4
2021-03-31T15:22:32.501Z,1617204152.501 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T15:22:32.501Z,1617204152.501 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T15:22:34.505Z,1617204154.505 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,152233.00,A,4131.46056,N,07040.28445,W,0.058,217.66,310321,,,A*79
2021-03-31T15:22:34.507Z,1617204154.507 [NAL9602](INFO): GPS fix at 20210331T152233: (41.524343, -70.671408)
2021-03-31T15:22:34.554Z,1617204154.554 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T15:22:34.554Z,1617204154.554 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T15:22:38.320Z,1617204158.320 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210331T150238/Courier0016.lzma
2021-03-31T15:22:39.321Z,1617204159.321 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Courier0016.lzma.bak
2021-03-31T15:22:39.322Z,1617204159.322 [DataOverHttps](INFO): SBD MOMSN=101866
2021-03-31T15:22:43.811Z,1617204163.811 [NAL9602](INFO): SBD MO Status=0, MOMSN=14215, MT Status=0, MTMSN=0
2021-03-31T15:22:43.811Z,1617204163.811 [NAL9602](INFO): No messages in MT queue
2021-03-31T15:22:48.359Z,1617204168.359 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20210331T150238/Express0017.lzma
2021-03-31T15:22:49.361Z,1617204169.361 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0017.lzma.bak
2021-03-31T15:22:49.362Z,1617204169.362 [DataOverHttps](INFO): SBD MOMSN=101869
2021-03-31T15:22:50.691Z,1617204170.691 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T15:22:50.692Z,1617204170.692 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T15:22:50.692Z,1617204170.692 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T15:23:14.531Z,1617204194.531 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T15:25:46.025Z,1617204346.025 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2021-03-31T15:26:29.649Z,1617204389.649 [RDI_Pathfinder](ERROR): only read -1 of 1 data item for BIT error
2021-03-31T15:27:51.303Z,1617204471.303 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T15:27:51.303Z,1617204471.303 [Default:CheckIn:C.Wait] Stopped
2021-03-31T15:27:51.303Z,1617204471.303 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T15:27:51.303Z,1617204471.303 [Default:CheckIn:D] Running Loop=1
2021-03-31T15:27:51.719Z,1617204471.719 [Default:CheckIn:D] Stopped
2021-03-31T15:27:51.719Z,1617204471.719 [Default:CheckIn:E] Running Loop=1
2021-03-31T15:27:52.145Z,1617204472.145 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 22.436188 min
2021-03-31T15:27:52.145Z,1617204472.145 [Default:CheckIn:E] Stopped
2021-03-31T15:27:52.145Z,1617204472.145 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T15:27:52.145Z,1617204472.145 [Default:CheckIn] Stopped
2021-03-31T15:27:52.146Z,1617204472.146 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T15:27:52.146Z,1617204472.146 [Default:CheckIn](INFO): Running loop #5
2021-03-31T15:27:52.146Z,1617204472.146 [Default:CheckIn] Running Loop=5
2021-03-31T15:27:52.146Z,1617204472.146 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T15:27:52.146Z,1617204472.146 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T15:27:54.100Z,1617204474.100 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,152753.00,A,4131.46215,N,07040.28438,W,0.253,217.66,310321,,,A*7C
2021-03-31T15:27:54.102Z,1617204474.102 [NAL9602](INFO): GPS fix at 20210331T152753: (41.524369, -70.671406)
2021-03-31T15:27:54.123Z,1617204474.123 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T15:27:54.123Z,1617204474.123 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T15:27:57.667Z,1617204477.667 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210331T150238/Courier0019.lzma
2021-03-31T15:27:58.669Z,1617204478.669 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Courier0019.lzma.bak
2021-03-31T15:27:58.670Z,1617204478.670 [DataOverHttps](INFO): SBD MOMSN=101873
2021-03-31T15:28:07.707Z,1617204487.707 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20210331T150238/Express0020.lzma
2021-03-31T15:28:08.709Z,1617204488.709 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0020.lzma.bak
2021-03-31T15:28:08.710Z,1617204488.710 [DataOverHttps](INFO): SBD MOMSN=101876
2021-03-31T15:28:09.874Z,1617204489.874 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T15:28:09.874Z,1617204489.874 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T15:28:09.874Z,1617204489.874 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T15:28:59.971Z,1617204539.971 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2021-03-31T15:29:29.448Z,1617204569.448 [NAL9602](INFO): SBD MO Status=0, MOMSN=14216, MT Status=0, MTMSN=0
2021-03-31T15:29:29.448Z,1617204569.448 [NAL9602](INFO): No messages in MT queue
2021-03-31T15:30:00.153Z,1617204600.153 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T15:33:10.465Z,1617204790.465 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T15:33:10.465Z,1617204790.465 [Default:CheckIn:C.Wait] Stopped
2021-03-31T15:33:10.465Z,1617204790.465 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T15:33:10.466Z,1617204790.466 [Default:CheckIn:D] Running Loop=1
2021-03-31T15:33:10.873Z,1617204790.873 [Default:CheckIn:D] Stopped
2021-03-31T15:33:10.873Z,1617204790.873 [Default:CheckIn:E] Running Loop=1
2021-03-31T15:33:11.286Z,1617204791.286 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 27.755418 min
2021-03-31T15:33:11.286Z,1617204791.286 [Default:CheckIn:E] Stopped
2021-03-31T15:33:11.286Z,1617204791.286 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T15:33:11.286Z,1617204791.286 [Default:CheckIn] Stopped
2021-03-31T15:33:11.287Z,1617204791.287 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T15:33:11.287Z,1617204791.287 [Default:CheckIn](INFO): Running loop #6
2021-03-31T15:33:11.287Z,1617204791.287 [Default:CheckIn] Running Loop=6
2021-03-31T15:33:11.287Z,1617204791.287 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T15:33:11.287Z,1617204791.287 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T15:33:13.293Z,1617204793.293 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153312.00,A,4131.46167,N,07040.28322,W,0.097,0.00,310321,,,D*7D
2021-03-31T15:33:13.295Z,1617204793.295 [NAL9602](INFO): GPS fix at 20210331T153312: (41.524361, -70.671387)
2021-03-31T15:33:13.337Z,1617204793.337 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T15:33:13.337Z,1617204793.337 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T15:33:17.077Z,1617204797.077 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210331T150238/Courier0022.lzma
2021-03-31T15:33:18.074Z,1617204798.074 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Courier0022.lzma.bak
2021-03-31T15:33:18.074Z,1617204798.074 [DataOverHttps](INFO): SBD MOMSN=101880
2021-03-31T15:33:27.107Z,1617204807.107 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20210331T150238/Express0023.lzma
2021-03-31T15:33:28.109Z,1617204808.109 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0023.lzma.bak
2021-03-31T15:33:28.110Z,1617204808.110 [DataOverHttps](INFO): SBD MOMSN=101884
2021-03-31T15:33:29.459Z,1617204809.459 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T15:33:29.459Z,1617204809.459 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T15:33:29.459Z,1617204809.459 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T15:33:37.919Z,1617204817.919 [NAL9602](INFO): SBD MO Status=0, MOMSN=14217, MT Status=0, MTMSN=0
2021-03-31T15:33:37.919Z,1617204817.919 [NAL9602](INFO): No messages in MT queue
2021-03-31T15:34:08.622Z,1617204848.622 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T15:34:37.340Z,1617204877.340 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items
2021-03-31T15:36:35.300Z,1617204995.300 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items
2021-03-31T15:37:10.456Z,1617205030.456 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout
2021-03-31T15:37:10.456Z,1617205030.456 [RDI_Pathfinder] Communications Fault, FailCount= 1
2021-03-31T15:37:10.456Z,1617205030.456 [RDI_Pathfinder](ERROR): Communications Fault
2021-03-31T15:37:10.520Z,1617205030.520 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-03-31T15:37:10.900Z,1617205030.900 [RDI_Pathfinder](INFO): Powering down
2021-03-31T15:37:11.660Z,1617205031.660 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-03-31T15:37:11.660Z,1617205031.660 [RDI_Pathfinder] No Fault, FailCount= 1
2021-03-31T15:38:30.024Z,1617205110.024 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T15:38:30.024Z,1617205110.024 [Default:CheckIn:C.Wait] Stopped
2021-03-31T15:38:30.024Z,1617205110.024 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T15:38:30.024Z,1617205110.024 [Default:CheckIn:D] Running Loop=1
2021-03-31T15:38:30.442Z,1617205110.442 [Default:CheckIn:D] Stopped
2021-03-31T15:38:30.442Z,1617205110.442 [Default:CheckIn:E] Running Loop=1
2021-03-31T15:38:30.861Z,1617205110.861 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 33.081571 min
2021-03-31T15:38:30.862Z,1617205110.862 [Default:CheckIn:E] Stopped
2021-03-31T15:38:30.862Z,1617205110.862 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T15:38:30.862Z,1617205110.862 [Default:CheckIn] Stopped
2021-03-31T15:38:30.862Z,1617205110.862 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T15:38:30.862Z,1617205110.862 [Default:CheckIn](INFO): Running loop #7
2021-03-31T15:38:30.862Z,1617205110.862 [Default:CheckIn] Running Loop=7
2021-03-31T15:38:30.862Z,1617205110.862 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T15:38:30.862Z,1617205110.862 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T15:38:32.841Z,1617205112.841 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153832.00,A,4131.46276,N,07040.28206,W,0.214,0.00,310321,,,D*79
2021-03-31T15:38:32.844Z,1617205112.844 [NAL9602](INFO): GPS fix at 20210331T153832: (41.524379, -70.671368)
2021-03-31T15:38:32.854Z,1617205112.854 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T15:38:32.854Z,1617205112.854 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T15:38:36.371Z,1617205116.371 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210331T150238/Courier0025.lzma
2021-03-31T15:38:37.373Z,1617205117.373 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Courier0025.lzma.bak
2021-03-31T15:38:37.374Z,1617205117.374 [DataOverHttps](INFO): SBD MOMSN=101888
2021-03-31T15:38:46.411Z,1617205126.411 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20210331T150238/Express0026.lzma
2021-03-31T15:38:47.414Z,1617205127.414 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0026.lzma.bak
2021-03-31T15:38:47.414Z,1617205127.414 [DataOverHttps](INFO): SBD MOMSN=101891
2021-03-31T15:38:48.195Z,1617205128.195 [NAL9602](INFO): SBD MO Status=0, MOMSN=14218, MT Status=0, MTMSN=0
2021-03-31T15:38:48.195Z,1617205128.195 [NAL9602](INFO): No messages in MT queue
2021-03-31T15:38:48.616Z,1617205128.616 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T15:38:48.616Z,1617205128.616 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T15:38:48.616Z,1617205128.616 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T15:39:18.894Z,1617205158.894 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T15:39:43.139Z,1617205183.139 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2021-03-31T15:40:25.558Z,1617205225.558 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2021-03-31T15:40:37.897Z,1617205237.897 [DataOverHttps](IMPORTANT): SBD MTMSN=20210331T154036
2021-03-31T15:40:40.528Z,1617205240.528 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout
2021-03-31T15:40:40.528Z,1617205240.528 [RDI_Pathfinder] Communications Fault, FailCount= 1
2021-03-31T15:40:40.528Z,1617205240.528 [RDI_Pathfinder](ERROR): Communications Fault
2021-03-31T15:40:40.573Z,1617205240.573 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-03-31T15:40:41.016Z,1617205241.016 [RDI_Pathfinder](INFO): Powering down
2021-03-31T15:40:41.741Z,1617205241.741 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-03-31T15:40:41.741Z,1617205241.741 [RDI_Pathfinder] No Fault, FailCount= 1
2021-03-31T15:40:41.915Z,1617205241.915 [DataOverHttps](INFO): Received command:get platform_battery_charge
2021-03-31T15:40:42.741Z,1617205242.741 [CommandLine](IMPORTANT): got command get platform_battery_charge
2021-03-31T15:40:42.741Z,1617205242.741 [CommandLine](FAULT): Element has no value
2021-03-31T15:43:49.331Z,1617205429.331 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T15:43:49.331Z,1617205429.331 [Default:CheckIn:C.Wait] Stopped
2021-03-31T15:43:49.331Z,1617205429.331 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T15:43:49.331Z,1617205429.331 [Default:CheckIn:D] Running Loop=1
2021-03-31T15:43:49.649Z,1617205429.649 [Default:CheckIn:D] Stopped
2021-03-31T15:43:49.649Z,1617205429.649 [Default:CheckIn:E] Running Loop=1
2021-03-31T15:43:50.003Z,1617205430.003 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 38.401681 min
2021-03-31T15:43:50.003Z,1617205430.003 [Default:CheckIn:E] Stopped
2021-03-31T15:43:50.003Z,1617205430.003 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T15:43:50.003Z,1617205430.003 [Default:CheckIn] Stopped
2021-03-31T15:43:50.012Z,1617205430.012 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T15:43:50.012Z,1617205430.012 [Default:CheckIn](INFO): Running loop #8
2021-03-31T15:43:50.012Z,1617205430.012 [Default:CheckIn] Running Loop=8
2021-03-31T15:43:50.012Z,1617205430.012 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T15:43:50.012Z,1617205430.012 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T15:43:52.007Z,1617205432.007 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154351.00,A,4131.46373,N,07040.27973,W,0.039,0.00,310321,,,D*7F
2021-03-31T15:43:52.019Z,1617205432.019 [NAL9602](INFO): GPS fix at 20210331T154351: (41.524395, -70.671329)
2021-03-31T15:43:52.039Z,1617205432.039 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T15:43:52.039Z,1617205432.039 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T15:43:55.727Z,1617205435.727 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210331T150238/Courier0028.lzma
2021-03-31T15:43:56.731Z,1617205436.731 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Courier0028.lzma.bak
2021-03-31T15:43:56.731Z,1617205436.731 [DataOverHttps](INFO): SBD MOMSN=101897
2021-03-31T15:44:05.767Z,1617205445.767 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20210331T150238/Courier0031.lzma
2021-03-31T15:44:06.769Z,1617205446.769 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Courier0031.lzma.bak
2021-03-31T15:44:06.770Z,1617205446.770 [DataOverHttps](INFO): SBD MOMSN=101900
2021-03-31T15:44:15.812Z,1617205455.812 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20210331T150238/Express0029.lzma
2021-03-31T15:44:16.813Z,1617205456.813 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0029.lzma.bak
2021-03-31T15:44:16.814Z,1617205456.814 [DataOverHttps](INFO): SBD MOMSN=101902
2021-03-31T15:44:20.753Z,1617205460.753 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2021-03-31T15:44:23.537Z,1617205463.537 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2021-03-31T15:44:25.851Z,1617205465.851 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20210331T150238/Express0032.lzma
2021-03-31T15:44:26.854Z,1617205466.854 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0032.lzma.bak
2021-03-31T15:44:26.854Z,1617205466.854 [DataOverHttps](INFO): SBD MOMSN=101908
2021-03-31T15:44:27.984Z,1617205467.984 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T15:44:27.984Z,1617205467.984 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T15:44:27.984Z,1617205467.984 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T15:45:24.528Z,1617205524.528 [NAL9602](INFO): SBD MO Status=2, MOMSN=14219, MT Status=2, MTMSN=0
2021-03-31T15:45:24.528Z,1617205524.528 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T15:46:03.311Z,1617205563.311 [NAL9602](INFO): SBD MO Status=0, MOMSN=14219, MT Status=0, MTMSN=0
2021-03-31T15:46:03.311Z,1617205563.311 [NAL9602](INFO): No messages in MT queue
2021-03-31T15:46:34.016Z,1617205594.016 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T15:49:28.562Z,1617205768.562 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T15:49:28.562Z,1617205768.562 [Default:CheckIn:C.Wait] Stopped
2021-03-31T15:49:28.562Z,1617205768.562 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T15:49:28.563Z,1617205768.563 [Default:CheckIn:D] Running Loop=1
2021-03-31T15:49:28.954Z,1617205768.954 [Default:CheckIn:D] Stopped
2021-03-31T15:49:28.954Z,1617205768.954 [Default:CheckIn:E] Running Loop=1
2021-03-31T15:49:29.386Z,1617205769.386 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 44.056767 min
2021-03-31T15:49:29.386Z,1617205769.386 [Default:CheckIn:E] Stopped
2021-03-31T15:49:29.386Z,1617205769.386 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T15:49:29.386Z,1617205769.386 [Default:CheckIn] Stopped
2021-03-31T15:49:29.386Z,1617205769.386 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T15:49:29.386Z,1617205769.386 [Default:CheckIn](INFO): Running loop #9
2021-03-31T15:49:29.386Z,1617205769.386 [Default:CheckIn] Running Loop=9
2021-03-31T15:49:29.387Z,1617205769.387 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T15:49:29.387Z,1617205769.387 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T15:49:31.378Z,1617205771.378 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154930.00,A,4131.46375,N,07040.28342,W,0.136,0.00,310321,,,D*7D
2021-03-31T15:49:31.401Z,1617205771.401 [NAL9602](INFO): GPS fix at 20210331T154930: (41.524396, -70.671390)
2021-03-31T15:49:31.472Z,1617205771.472 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T15:49:31.472Z,1617205771.472 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T15:49:35.127Z,1617205775.127 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210331T150238/Courier0034.lzma
2021-03-31T15:49:36.130Z,1617205776.130 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Courier0034.lzma.bak
2021-03-31T15:49:36.130Z,1617205776.130 [DataOverHttps](INFO): SBD MOMSN=101911
2021-03-31T15:49:45.179Z,1617205785.179 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20210331T150238/Express0035.lzma
2021-03-31T15:49:46.179Z,1617205786.179 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0035.lzma.bak
2021-03-31T15:49:46.185Z,1617205786.185 [DataOverHttps](INFO): SBD MOMSN=101914
2021-03-31T15:49:47.338Z,1617205787.338 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T15:49:47.338Z,1617205787.338 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T15:49:47.338Z,1617205787.338 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T15:49:50.497Z,1617205790.497 [NAL9602](INFO): SBD MO Status=0, MOMSN=14220, MT Status=0, MTMSN=0
2021-03-31T15:49:50.497Z,1617205790.497 [NAL9602](INFO): No messages in MT queue
2021-03-31T15:50:21.207Z,1617205821.207 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T15:50:32.507Z,1617205832.507 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2021-03-31T15:50:51.432Z,1617205851.432 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.239468
2021-03-31T15:51:27.584Z,1617205887.584 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T15:52:02.744Z,1617205922.744 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T15:52:37.892Z,1617205957.892 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T15:53:13.052Z,1617205993.052 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T15:53:48.208Z,1617206028.208 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T15:54:23.348Z,1617206063.348 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T15:54:47.864Z,1617206087.864 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T15:54:47.864Z,1617206087.864 [Default:CheckIn:C.Wait] Stopped
2021-03-31T15:54:47.864Z,1617206087.864 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T15:54:47.864Z,1617206087.864 [Default:CheckIn:D] Running Loop=1
2021-03-31T15:54:48.255Z,1617206088.255 [Default:CheckIn:D] Stopped
2021-03-31T15:54:48.256Z,1617206088.256 [Default:CheckIn:E] Running Loop=1
2021-03-31T15:54:48.668Z,1617206088.668 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 49.378455 min
2021-03-31T15:54:48.668Z,1617206088.668 [Default:CheckIn:E] Stopped
2021-03-31T15:54:48.668Z,1617206088.668 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T15:54:48.668Z,1617206088.668 [Default:CheckIn] Stopped
2021-03-31T15:54:48.668Z,1617206088.668 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T15:54:48.668Z,1617206088.668 [Default:CheckIn](INFO): Running loop #10
2021-03-31T15:54:48.668Z,1617206088.668 [Default:CheckIn] Running Loop=10
2021-03-31T15:54:48.668Z,1617206088.668 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T15:54:48.668Z,1617206088.668 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T15:54:50.676Z,1617206090.676 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155449.00,A,4131.46064,N,07040.27876,W,0.000,0.00,310321,,,D*7B
2021-03-31T15:54:50.683Z,1617206090.683 [NAL9602](INFO): GPS fix at 20210331T155449: (41.524344, -70.671313)
2021-03-31T15:54:50.713Z,1617206090.713 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T15:54:50.713Z,1617206090.713 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T15:54:58.500Z,1617206098.500 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T15:55:05.296Z,1617206105.296 [NAL9602](INFO): SBD MO Status=2, MOMSN=14221, MT Status=2, MTMSN=0
2021-03-31T15:55:05.296Z,1617206105.296 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T15:55:16.765Z,1617206116.765 [NAL9602](INFO): SBD MO Status=1, MOMSN=14221, MT Status=0, MTMSN=0
2021-03-31T15:55:16.820Z,1617206116.820 [NAL9602](INFO): Sent 72 bytes from file Logs/20210331T150238/Courier0037.lzma
2021-03-31T15:55:16.820Z,1617206116.820 [NAL9602](INFO): Packets left to send: 0
2021-03-31T15:55:25.748Z,1617206125.748 [NAL9602](INFO): SBD MO Status=2, MOMSN=14222, MT Status=2, MTMSN=0
2021-03-31T15:55:25.748Z,1617206125.748 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T15:55:33.653Z,1617206133.653 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T15:55:42.692Z,1617206142.692 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003072
2021-03-31T15:55:46.708Z,1617206146.708 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20210331T150238/Express0038.lzma
2021-03-31T15:55:47.710Z,1617206147.710 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0038.lzma.bak
2021-03-31T15:55:47.710Z,1617206147.710 [DataOverHttps](INFO): SBD MOMSN=101920
2021-03-31T15:55:48.807Z,1617206148.807 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T15:55:48.807Z,1617206148.807 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T15:55:48.807Z,1617206148.807 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T15:56:14.234Z,1617206174.234 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T15:57:41.518Z,1617206261.518 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2021-03-31T15:58:01.309Z,1617206281.309 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-03-31T15:58:16.255Z,1617206296.255 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2021-03-31T15:58:26.368Z,1617206306.368 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items
2021-03-31T15:58:36.447Z,1617206316.447 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-03-31T15:58:36.453Z,1617206316.453 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items
2021-03-31T15:58:46.564Z,1617206326.564 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude
2021-03-31T15:59:02.310Z,1617206342.310 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2021-03-31T16:00:49.402Z,1617206449.402 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T16:00:49.402Z,1617206449.402 [Default:CheckIn:C.Wait] Stopped
2021-03-31T16:00:49.402Z,1617206449.402 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T16:00:49.402Z,1617206449.402 [Default:CheckIn:D] Running Loop=1
2021-03-31T16:00:49.768Z,1617206449.768 [Default:CheckIn:D] Stopped
2021-03-31T16:00:49.768Z,1617206449.768 [Default:CheckIn:E] Running Loop=1
2021-03-31T16:00:50.252Z,1617206450.252 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 55.403670 min
2021-03-31T16:00:50.252Z,1617206450.252 [Default:CheckIn:E] Stopped
2021-03-31T16:00:50.253Z,1617206450.253 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T16:00:50.253Z,1617206450.253 [Default:CheckIn] Stopped
2021-03-31T16:00:50.253Z,1617206450.253 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T16:00:50.253Z,1617206450.253 [Default:CheckIn](INFO): Running loop #11
2021-03-31T16:00:50.253Z,1617206450.253 [Default:CheckIn] Running Loop=11
2021-03-31T16:00:50.253Z,1617206450.253 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T16:00:50.253Z,1617206450.253 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T16:00:52.210Z,1617206452.210 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160051.00,A,4131.46701,N,07040.28213,W,0.039,0.00,310321,,,D*78
2021-03-31T16:00:52.212Z,1617206452.212 [NAL9602](INFO): GPS fix at 20210331T160051: (41.524450, -70.671369)
2021-03-31T16:00:52.243Z,1617206452.243 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T16:00:52.243Z,1617206452.243 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T16:00:55.987Z,1617206455.987 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210331T150238/Courier0040.lzma
2021-03-31T16:00:56.990Z,1617206456.990 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Courier0040.lzma.bak
2021-03-31T16:00:56.990Z,1617206456.990 [DataOverHttps](INFO): SBD MOMSN=101927
2021-03-31T16:01:06.027Z,1617206466.027 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20210331T150238/Express0041.lzma
2021-03-31T16:01:07.030Z,1617206467.030 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0041.lzma.bak
2021-03-31T16:01:07.030Z,1617206467.030 [DataOverHttps](INFO): SBD MOMSN=101930
2021-03-31T16:01:08.373Z,1617206468.373 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T16:01:08.373Z,1617206468.373 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T16:01:08.373Z,1617206468.373 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T16:01:15.236Z,1617206475.236 [NAL9602](INFO): SBD MO Status=2, MOMSN=14222, MT Status=2, MTMSN=0
2021-03-31T16:01:15.236Z,1617206475.236 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T16:01:41.471Z,1617206501.471 [NAL9602](INFO): SBD MO Status=2, MOMSN=14222, MT Status=2, MTMSN=0
2021-03-31T16:01:41.471Z,1617206501.471 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T16:01:58.849Z,1617206518.849 [NAL9602](INFO): SBD MO Status=2, MOMSN=14222, MT Status=2, MTMSN=0
2021-03-31T16:01:58.849Z,1617206518.849 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T16:02:12.987Z,1617206532.987 [NAL9602](INFO): SBD MO Status=2, MOMSN=14222, MT Status=2, MTMSN=0
2021-03-31T16:02:12.987Z,1617206532.987 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T16:02:38.840Z,1617206558.840 [NAL9602](INFO): SBD MO Status=2, MOMSN=14222, MT Status=2, MTMSN=0
2021-03-31T16:02:38.840Z,1617206558.840 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T16:04:05.710Z,1617206645.710 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=14222, MT Status=1, MTMSN=548
2021-03-31T16:04:05.710Z,1617206645.710 [NAL9602](INFO): Data available in MT queue
2021-03-31T16:04:06.221Z,1617206646.221 [NAL9602](INFO): Received command:failc
2021-03-31T16:04:06.288Z,1617206646.288 [CommandLine](IMPORTANT): got command failComponent
2021-03-31T16:04:06.289Z,1617206646.289 [CommandLine](IMPORTANT): Failed components:
2021-03-31T16:04:06.289Z,1617206646.289 [CommandLine](IMPORTANT): No failed Components.
2021-03-31T16:04:36.833Z,1617206676.833 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T16:05:22.510Z,1617206722.510 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2021-03-31T16:06:08.976Z,1617206768.976 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T16:06:08.976Z,1617206768.976 [Default:CheckIn:C.Wait] Stopped
2021-03-31T16:06:08.976Z,1617206768.976 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T16:06:08.976Z,1617206768.976 [Default:CheckIn:D] Running Loop=1
2021-03-31T16:06:09.416Z,1617206769.416 [Default:CheckIn:D] Stopped
2021-03-31T16:06:09.416Z,1617206769.416 [Default:CheckIn:E] Running Loop=1
2021-03-31T16:06:09.781Z,1617206769.781 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 60.731136 min
2021-03-31T16:06:09.781Z,1617206769.781 [Default:CheckIn:E] Stopped
2021-03-31T16:06:09.781Z,1617206769.781 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T16:06:09.781Z,1617206769.781 [Default:CheckIn] Stopped
2021-03-31T16:06:09.781Z,1617206769.781 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T16:06:09.782Z,1617206769.782 [Default:CheckIn](INFO): Running loop #12
2021-03-31T16:06:09.782Z,1617206769.782 [Default:CheckIn] Running Loop=12
2021-03-31T16:06:09.782Z,1617206769.782 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T16:06:09.782Z,1617206769.782 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T16:06:11.777Z,1617206771.777 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160611.00,A,4131.46306,N,07040.28058,W,0.097,0.00,310321,,,D*70
2021-03-31T16:06:11.779Z,1617206771.779 [NAL9602](INFO): GPS fix at 20210331T160611: (41.524384, -70.671343)
2021-03-31T16:06:11.851Z,1617206771.851 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T16:06:11.851Z,1617206771.851 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T16:06:15.315Z,1617206775.315 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210331T150238/Courier0043.lzma
2021-03-31T16:06:16.318Z,1617206776.318 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Courier0043.lzma.bak
2021-03-31T16:06:16.318Z,1617206776.318 [DataOverHttps](INFO): SBD MOMSN=101935
2021-03-31T16:06:25.356Z,1617206785.356 [DataOverHttps](INFO): Sending 243 bytes from file Logs/20210331T150238/Express0044.lzma
2021-03-31T16:06:26.358Z,1617206786.358 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0044.lzma.bak
2021-03-31T16:06:26.358Z,1617206786.358 [DataOverHttps](INFO): SBD MOMSN=101938
2021-03-31T16:06:27.581Z,1617206787.581 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T16:06:27.581Z,1617206787.581 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T16:06:27.581Z,1617206787.581 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T16:07:35.454Z,1617206855.454 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items
2021-03-31T16:08:02.489Z,1617206882.489 [NAL9602](INFO): SBD MO Status=2, MOMSN=14223, MT Status=2, MTMSN=0
2021-03-31T16:08:02.489Z,1617206882.489 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T16:08:19.864Z,1617206899.864 [NAL9602](INFO): SBD MO Status=2, MOMSN=14223, MT Status=2, MTMSN=0
2021-03-31T16:08:19.864Z,1617206899.864 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T16:08:51.789Z,1617206931.789 [NAL9602](INFO): SBD MO Status=1, MOMSN=14223, MT Status=0, MTMSN=0
2021-03-31T16:08:51.789Z,1617206931.789 [NAL9602](INFO): No messages in MT queue
2021-03-31T16:09:22.485Z,1617206962.485 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T16:11:28.281Z,1617207088.281 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T16:11:28.281Z,1617207088.281 [Default:CheckIn:C.Wait] Stopped
2021-03-31T16:11:28.281Z,1617207088.281 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T16:11:28.281Z,1617207088.281 [Default:CheckIn:D] Running Loop=1
2021-03-31T16:11:28.649Z,1617207088.649 [Default:CheckIn:D] Stopped
2021-03-31T16:11:28.649Z,1617207088.649 [Default:CheckIn:E] Running Loop=1
2021-03-31T16:11:29.056Z,1617207089.056 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 66.051689 min
2021-03-31T16:11:29.057Z,1617207089.057 [Default:CheckIn:E] Stopped
2021-03-31T16:11:29.057Z,1617207089.057 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T16:11:29.057Z,1617207089.057 [Default:CheckIn] Stopped
2021-03-31T16:11:29.057Z,1617207089.057 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T16:11:29.057Z,1617207089.057 [Default:CheckIn](INFO): Running loop #13
2021-03-31T16:11:29.057Z,1617207089.057 [Default:CheckIn] Running Loop=13
2021-03-31T16:11:29.057Z,1617207089.057 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T16:11:29.057Z,1617207089.057 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T16:11:31.078Z,1617207091.078 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161130.00,A,4131.46669,N,07040.27971,W,0.019,0.00,310321,,,D*72
2021-03-31T16:11:31.080Z,1617207091.080 [NAL9602](INFO): GPS fix at 20210331T161130: (41.524445, -70.671329)
2021-03-31T16:11:31.091Z,1617207091.091 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T16:11:31.091Z,1617207091.091 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T16:11:34.676Z,1617207094.676 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210331T150238/Courier0046.lzma
2021-03-31T16:11:35.678Z,1617207095.678 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Courier0046.lzma.bak
2021-03-31T16:11:35.679Z,1617207095.679 [DataOverHttps](INFO): SBD MOMSN=101947
2021-03-31T16:11:44.716Z,1617207104.716 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20210331T150238/Express0047.lzma
2021-03-31T16:11:45.718Z,1617207105.718 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0047.lzma.bak
2021-03-31T16:11:45.718Z,1617207105.718 [DataOverHttps](INFO): SBD MOMSN=101950
2021-03-31T16:11:46.844Z,1617207106.844 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T16:11:46.845Z,1617207106.845 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T16:11:46.845Z,1617207106.845 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T16:12:15.513Z,1617207135.513 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2021-03-31T16:12:23.255Z,1617207143.255 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2021-03-31T16:12:37.325Z,1617207157.325 [NAL9602](INFO): SBD MO Status=1, MOMSN=14224, MT Status=0, MTMSN=0
2021-03-31T16:12:37.325Z,1617207157.325 [NAL9602](INFO): No messages in MT queue
2021-03-31T16:13:08.017Z,1617207188.017 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T16:15:57.700Z,1617207357.700 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file).
2021-03-31T16:16:47.426Z,1617207407.426 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T16:16:47.426Z,1617207407.426 [Default:CheckIn:C.Wait] Stopped
2021-03-31T16:16:47.427Z,1617207407.427 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T16:16:47.427Z,1617207407.427 [Default:CheckIn:D] Running Loop=1
2021-03-31T16:16:47.820Z,1617207407.820 [Default:CheckIn:D] Stopped
2021-03-31T16:16:47.820Z,1617207407.820 [Default:CheckIn:E] Running Loop=1
2021-03-31T16:16:48.290Z,1617207408.290 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 71.371208 min
2021-03-31T16:16:48.290Z,1617207408.290 [Default:CheckIn:E] Stopped
2021-03-31T16:16:48.290Z,1617207408.290 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T16:16:48.290Z,1617207408.290 [Default:CheckIn] Stopped
2021-03-31T16:16:48.290Z,1617207408.290 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T16:16:48.290Z,1617207408.290 [Default:CheckIn](INFO): Running loop #14
2021-03-31T16:16:48.291Z,1617207408.291 [Default:CheckIn] Running Loop=14
2021-03-31T16:16:48.291Z,1617207408.291 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T16:16:48.291Z,1617207408.291 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T16:16:50.225Z,1617207410.225 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161649.00,A,4131.46522,N,07040.28120,W,0.039,0.00,310321,,,A*73
2021-03-31T16:16:50.227Z,1617207410.227 [NAL9602](INFO): GPS fix at 20210331T161649: (41.524420, -70.671353)
2021-03-31T16:16:50.264Z,1617207410.264 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T16:16:50.264Z,1617207410.264 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T16:16:54.031Z,1617207414.031 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210331T150238/Courier0049.lzma
2021-03-31T16:16:55.033Z,1617207415.033 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Courier0049.lzma.bak
2021-03-31T16:16:55.034Z,1617207415.034 [DataOverHttps](INFO): SBD MOMSN=101955
2021-03-31T16:17:04.071Z,1617207424.071 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20210331T150238/Express0050.lzma
2021-03-31T16:17:05.074Z,1617207425.074 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0050.lzma.bak
2021-03-31T16:17:05.074Z,1617207425.074 [DataOverHttps](INFO): SBD MOMSN=101958
2021-03-31T16:17:06.417Z,1617207426.417 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T16:17:06.418Z,1617207426.418 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T16:17:06.418Z,1617207426.418 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T16:17:15.290Z,1617207435.290 [NAL9602](INFO): SBD MO Status=2, MOMSN=14225, MT Status=2, MTMSN=0
2021-03-31T16:17:15.291Z,1617207435.291 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T16:17:31.036Z,1617207451.036 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2021-03-31T16:17:31.038Z,1617207451.038 [BPC1](INFO): Received data from all battery sticks.
2021-03-31T16:17:39.103Z,1617207459.103 [NAL9602](INFO): SBD MO Status=2, MOMSN=14225, MT Status=2, MTMSN=0
2021-03-31T16:17:39.104Z,1617207459.104 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T16:17:58.496Z,1617207478.496 [NAL9602](INFO): SBD MO Status=2, MOMSN=14225, MT Status=2, MTMSN=0
2021-03-31T16:17:58.496Z,1617207478.496 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T16:18:17.485Z,1617207497.485 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-03-31T16:18:21.931Z,1617207501.931 [NAL9602](INFO): SBD MO Status=2, MOMSN=14225, MT Status=2, MTMSN=0
2021-03-31T16:18:21.931Z,1617207501.931 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T16:18:27.232Z,1617207507.232 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2021-03-31T16:18:29.255Z,1617207509.255 [RDI_Pathfinder](ERROR): only read -1 of 1 data item for altitude
2021-03-31T16:18:32.448Z,1617207512.448 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2021-03-31T16:18:45.360Z,1617207525.360 [NAL9602](INFO): SBD MO Status=2, MOMSN=14225, MT Status=2, MTMSN=0
2021-03-31T16:18:45.360Z,1617207525.360 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T16:18:53.039Z,1617207533.039 [NAL9602](INFO): SBD MO Status=1, MOMSN=14225, MT Status=0, MTMSN=0
2021-03-31T16:18:53.039Z,1617207533.039 [NAL9602](INFO): No messages in MT queue
2021-03-31T16:19:23.735Z,1617207563.735 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T16:19:52.436Z,1617207592.436 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2021-03-31T16:22:06.967Z,1617207726.967 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T16:22:06.968Z,1617207726.968 [Default:CheckIn:C.Wait] Stopped
2021-03-31T16:22:06.968Z,1617207726.968 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T16:22:06.968Z,1617207726.968 [Default:CheckIn:D] Running Loop=1
2021-03-31T16:22:07.421Z,1617207727.421 [Default:CheckIn:D] Stopped
2021-03-31T16:22:07.421Z,1617207727.421 [Default:CheckIn:E] Running Loop=1
2021-03-31T16:22:07.779Z,1617207727.779 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 76.697884 min
2021-03-31T16:22:07.780Z,1617207727.780 [Default:CheckIn:E] Stopped
2021-03-31T16:22:07.780Z,1617207727.780 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T16:22:07.780Z,1617207727.780 [Default:CheckIn] Stopped
2021-03-31T16:22:07.780Z,1617207727.780 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T16:22:07.780Z,1617207727.780 [Default:CheckIn](INFO): Running loop #15
2021-03-31T16:22:07.780Z,1617207727.780 [Default:CheckIn] Running Loop=15
2021-03-31T16:22:07.780Z,1617207727.780 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T16:22:07.780Z,1617207727.780 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T16:22:09.781Z,1617207729.781 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162209.00,A,4131.46309,N,07040.28345,W,0.175,0.00,310321,,,A*77
2021-03-31T16:22:09.783Z,1617207729.783 [NAL9602](INFO): GPS fix at 20210331T162209: (41.524385, -70.671391)
2021-03-31T16:22:09.821Z,1617207729.821 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T16:22:09.821Z,1617207729.821 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T16:22:13.375Z,1617207733.375 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20210331T150238/Courier0052.lzma
2021-03-31T16:22:14.377Z,1617207734.377 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Courier0052.lzma.bak
2021-03-31T16:22:14.378Z,1617207734.378 [DataOverHttps](INFO): SBD MOMSN=101963
2021-03-31T16:22:17.465Z,1617207737.465 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-03-31T16:22:23.415Z,1617207743.415 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20210331T150238/Express0053.lzma
2021-03-31T16:22:24.418Z,1617207744.418 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0053.lzma.bak
2021-03-31T16:22:24.418Z,1617207744.418 [DataOverHttps](INFO): SBD MOMSN=101966
2021-03-31T16:22:25.581Z,1617207745.581 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T16:22:25.581Z,1617207745.581 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T16:22:25.581Z,1617207745.581 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T16:22:35.249Z,1617207755.249 [NAL9602](INFO): SBD MO Status=2, MOMSN=14226, MT Status=2, MTMSN=0
2021-03-31T16:22:35.250Z,1617207755.250 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T16:22:46.147Z,1617207766.147 [NAL9602](INFO): SBD MO Status=1, MOMSN=14226, MT Status=0, MTMSN=0
2021-03-31T16:22:46.147Z,1617207766.147 [NAL9602](INFO): No messages in MT queue
2021-03-31T16:23:16.849Z,1617207796.849 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T16:24:28.376Z,1617207868.376 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2021-03-31T16:27:26.121Z,1617208046.121 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T16:27:26.121Z,1617208046.121 [Default:CheckIn:C.Wait] Stopped
2021-03-31T16:27:26.121Z,1617208046.121 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T16:27:26.121Z,1617208046.121 [Default:CheckIn:D] Running Loop=1
2021-03-31T16:27:26.544Z,1617208046.544 [Default:CheckIn:D] Stopped
2021-03-31T16:27:26.544Z,1617208046.544 [Default:CheckIn:E] Running Loop=1
2021-03-31T16:27:26.950Z,1617208046.950 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 82.016593 min
2021-03-31T16:27:26.950Z,1617208046.950 [Default:CheckIn:E] Stopped
2021-03-31T16:27:26.950Z,1617208046.950 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T16:27:26.950Z,1617208046.950 [Default:CheckIn] Stopped
2021-03-31T16:27:26.950Z,1617208046.950 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T16:27:26.950Z,1617208046.950 [Default:CheckIn](INFO): Running loop #16
2021-03-31T16:27:26.951Z,1617208046.951 [Default:CheckIn] Running Loop=16
2021-03-31T16:27:26.951Z,1617208046.951 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T16:27:26.951Z,1617208046.951 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T16:27:28.943Z,1617208048.943 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162728.00,A,4131.46273,N,07040.28537,W,0.058,0.00,310321,,,A*70
2021-03-31T16:27:28.946Z,1617208048.946 [NAL9602](INFO): GPS fix at 20210331T162728: (41.524379, -70.671423)
2021-03-31T16:27:28.956Z,1617208048.956 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T16:27:28.956Z,1617208048.956 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T16:27:32.718Z,1617208052.718 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210331T150238/Courier0055.lzma
2021-03-31T16:27:33.718Z,1617208053.718 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Courier0055.lzma.bak
2021-03-31T16:27:33.718Z,1617208053.718 [DataOverHttps](INFO): SBD MOMSN=101971
2021-03-31T16:27:42.767Z,1617208062.767 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20210331T150238/Express0056.lzma
2021-03-31T16:27:43.083Z,1617208063.083 [NAL9602](INFO): SBD MO Status=1, MOMSN=14227, MT Status=0, MTMSN=0
2021-03-31T16:27:43.083Z,1617208063.083 [NAL9602](INFO): No messages in MT queue
2021-03-31T16:27:43.770Z,1617208063.770 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0056.lzma.bak
2021-03-31T16:27:43.770Z,1617208063.770 [DataOverHttps](INFO): SBD MOMSN=101974
2021-03-31T16:27:45.166Z,1617208065.166 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T16:27:45.166Z,1617208065.166 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T16:27:45.166Z,1617208065.166 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T16:28:13.793Z,1617208093.793 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T16:30:17.827Z,1617208217.827 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2021-03-31T16:32:45.712Z,1617208365.712 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T16:32:45.712Z,1617208365.712 [Default:CheckIn:C.Wait] Stopped
2021-03-31T16:32:45.712Z,1617208365.712 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T16:32:45.712Z,1617208365.712 [Default:CheckIn:D] Running Loop=1
2021-03-31T16:32:46.106Z,1617208366.106 [Default:CheckIn:D] Stopped
2021-03-31T16:32:46.106Z,1617208366.106 [Default:CheckIn:E] Running Loop=1
2021-03-31T16:32:46.523Z,1617208366.523 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 87.342643 min
2021-03-31T16:32:46.523Z,1617208366.523 [Default:CheckIn:E] Stopped
2021-03-31T16:32:46.523Z,1617208366.523 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T16:32:46.524Z,1617208366.524 [Default:CheckIn] Stopped
2021-03-31T16:32:46.524Z,1617208366.524 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T16:32:46.524Z,1617208366.524 [Default:CheckIn](INFO): Running loop #17
2021-03-31T16:32:46.524Z,1617208366.524 [Default:CheckIn] Running Loop=17
2021-03-31T16:32:46.525Z,1617208366.525 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T16:32:46.525Z,1617208366.525 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T16:32:48.508Z,1617208368.508 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163247.00,A,4131.46133,N,07040.28472,W,0.058,0.00,310321,,,A*7A
2021-03-31T16:32:48.510Z,1617208368.510 [NAL9602](INFO): GPS fix at 20210331T163247: (41.524355, -70.671412)
2021-03-31T16:32:48.559Z,1617208368.559 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T16:32:48.560Z,1617208368.560 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T16:32:52.116Z,1617208372.116 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210331T150238/Courier0058.lzma
2021-03-31T16:32:53.117Z,1617208373.117 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Courier0058.lzma.bak
2021-03-31T16:32:53.118Z,1617208373.118 [DataOverHttps](INFO): SBD MOMSN=101979
2021-03-31T16:33:02.157Z,1617208382.157 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20210331T150238/Express0059.lzma
2021-03-31T16:33:03.162Z,1617208383.162 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0059.lzma.bak
2021-03-31T16:33:03.163Z,1617208383.163 [DataOverHttps](INFO): SBD MOMSN=101982
2021-03-31T16:33:04.301Z,1617208384.301 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T16:33:04.301Z,1617208384.301 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T16:33:04.301Z,1617208384.301 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T16:33:24.871Z,1617208404.871 [NAL9602](INFO): SBD MO Status=1, MOMSN=14228, MT Status=0, MTMSN=0
2021-03-31T16:33:24.871Z,1617208404.871 [NAL9602](INFO): No messages in MT queue
2021-03-31T16:33:55.575Z,1617208435.575 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T16:33:58.423Z,1617208438.423 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2021-03-31T16:38:04.894Z,1617208684.894 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T16:38:04.894Z,1617208684.894 [Default:CheckIn:C.Wait] Stopped
2021-03-31T16:38:04.894Z,1617208684.894 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T16:38:04.894Z,1617208684.894 [Default:CheckIn:D] Running Loop=1
2021-03-31T16:38:05.287Z,1617208685.287 [Default:CheckIn:D] Stopped
2021-03-31T16:38:05.287Z,1617208685.287 [Default:CheckIn:E] Running Loop=1
2021-03-31T16:38:05.680Z,1617208685.680 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 92.662321 min
2021-03-31T16:38:05.680Z,1617208685.680 [Default:CheckIn:E] Stopped
2021-03-31T16:38:05.681Z,1617208685.681 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T16:38:05.681Z,1617208685.681 [Default:CheckIn] Stopped
2021-03-31T16:38:05.681Z,1617208685.681 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T16:38:05.681Z,1617208685.681 [Default:CheckIn](INFO): Running loop #18
2021-03-31T16:38:05.681Z,1617208685.681 [Default:CheckIn] Running Loop=18
2021-03-31T16:38:05.681Z,1617208685.681 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T16:38:05.681Z,1617208685.681 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T16:38:07.691Z,1617208687.691 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163806.00,A,4131.46985,N,07040.28203,W,0.194,0.00,310321,,,A*71
2021-03-31T16:38:07.701Z,1617208687.701 [NAL9602](INFO): GPS fix at 20210331T163806: (41.524498, -70.671367)
2021-03-31T16:38:07.723Z,1617208687.723 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T16:38:07.723Z,1617208687.723 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T16:38:11.483Z,1617208691.483 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20210331T150238/Courier0061.lzma
2021-03-31T16:38:12.485Z,1617208692.485 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Courier0061.lzma.bak
2021-03-31T16:38:12.486Z,1617208692.486 [DataOverHttps](INFO): SBD MOMSN=101987
2021-03-31T16:38:21.523Z,1617208701.523 [DataOverHttps](INFO): Sending 122 bytes from file Logs/20210331T150238/Express0062.lzma
2021-03-31T16:38:22.526Z,1617208702.526 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0062.lzma.bak
2021-03-31T16:38:22.526Z,1617208702.526 [DataOverHttps](INFO): SBD MOMSN=101990
2021-03-31T16:38:23.864Z,1617208703.864 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T16:38:23.864Z,1617208703.864 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T16:38:23.864Z,1617208703.864 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T16:38:28.294Z,1617208708.294 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2021-03-31T16:38:45.667Z,1617208725.667 [NAL9602](INFO): SBD MO Status=2, MOMSN=14229, MT Status=2, MTMSN=0
2021-03-31T16:38:45.668Z,1617208725.668 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T16:39:13.244Z,1617208753.244 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude
2021-03-31T16:39:30.508Z,1617208770.508 [NAL9602](INFO): SBD MO Status=1, MOMSN=14229, MT Status=0, MTMSN=0
2021-03-31T16:39:30.508Z,1617208770.508 [NAL9602](INFO): No messages in MT queue
2021-03-31T16:40:01.214Z,1617208801.214 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T16:43:13.536Z,1617208993.536 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2021-03-31T16:43:24.456Z,1617209004.456 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T16:43:24.456Z,1617209004.456 [Default:CheckIn:C.Wait] Stopped
2021-03-31T16:43:24.456Z,1617209004.456 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T16:43:24.456Z,1617209004.456 [Default:CheckIn:D] Running Loop=1
2021-03-31T16:43:24.866Z,1617209004.866 [Default:CheckIn:D] Stopped
2021-03-31T16:43:24.866Z,1617209004.866 [Default:CheckIn:E] Running Loop=1
2021-03-31T16:43:25.302Z,1617209005.302 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 97.988639 min
2021-03-31T16:43:25.302Z,1617209005.302 [Default:CheckIn:E] Stopped
2021-03-31T16:43:25.302Z,1617209005.302 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T16:43:25.302Z,1617209005.302 [Default:CheckIn] Stopped
2021-03-31T16:43:25.302Z,1617209005.302 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T16:43:25.302Z,1617209005.302 [Default:CheckIn](INFO): Running loop #19
2021-03-31T16:43:25.302Z,1617209005.302 [Default:CheckIn] Running Loop=19
2021-03-31T16:43:25.302Z,1617209005.302 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T16:43:25.303Z,1617209005.303 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T16:43:27.259Z,1617209007.259 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164326.00,A,4131.46440,N,07040.28216,W,0.194,196.61,310321,,,A*76
2021-03-31T16:43:27.262Z,1617209007.262 [NAL9602](INFO): GPS fix at 20210331T164326: (41.524407, -70.671369)
2021-03-31T16:43:27.283Z,1617209007.283 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T16:43:27.283Z,1617209007.283 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T16:43:30.771Z,1617209010.771 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210331T150238/Courier0064.lzma
2021-03-31T16:43:31.774Z,1617209011.774 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Courier0064.lzma.bak
2021-03-31T16:43:31.774Z,1617209011.774 [DataOverHttps](INFO): SBD MOMSN=101995
2021-03-31T16:43:40.820Z,1617209020.820 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20210331T150238/Express0065.lzma
2021-03-31T16:43:41.822Z,1617209021.822 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0065.lzma.bak
2021-03-31T16:43:41.822Z,1617209021.822 [DataOverHttps](INFO): SBD MOMSN=101998
2021-03-31T16:43:43.049Z,1617209023.049 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T16:43:43.049Z,1617209023.049 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T16:43:43.049Z,1617209023.049 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T16:43:56.357Z,1617209036.357 [NAL9602](INFO): SBD MO Status=2, MOMSN=14230, MT Status=2, MTMSN=0
2021-03-31T16:43:56.357Z,1617209036.357 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T16:46:33.913Z,1617209193.913 [NAL9602](INFO): SBD MO Status=1, MOMSN=14230, MT Status=0, MTMSN=0
2021-03-31T16:46:33.913Z,1617209193.913 [NAL9602](INFO): No messages in MT queue
2021-03-31T16:47:04.621Z,1617209224.621 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T16:48:16.536Z,1617209296.536 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2021-03-31T16:48:17.348Z,1617209297.348 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-03-31T16:48:43.617Z,1617209323.617 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T16:48:43.617Z,1617209323.617 [Default:CheckIn:C.Wait] Stopped
2021-03-31T16:48:43.617Z,1617209323.617 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T16:48:43.617Z,1617209323.617 [Default:CheckIn:D] Running Loop=1
2021-03-31T16:48:44.035Z,1617209324.035 [Default:CheckIn:D] Stopped
2021-03-31T16:48:44.035Z,1617209324.035 [Default:CheckIn:E] Running Loop=1
2021-03-31T16:48:44.461Z,1617209324.461 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 103.308114 min
2021-03-31T16:48:44.461Z,1617209324.461 [Default:CheckIn:E] Stopped
2021-03-31T16:48:44.461Z,1617209324.461 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T16:48:44.462Z,1617209324.462 [Default:CheckIn] Stopped
2021-03-31T16:48:44.462Z,1617209324.462 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T16:48:44.462Z,1617209324.462 [Default:CheckIn](INFO): Running loop #20
2021-03-31T16:48:44.462Z,1617209324.462 [Default:CheckIn] Running Loop=20
2021-03-31T16:48:44.462Z,1617209324.462 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T16:48:44.462Z,1617209324.462 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T16:48:46.429Z,1617209326.429 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164845.00,A,4131.47244,N,07040.27889,W,0.350,196.61,310321,,,A*72
2021-03-31T16:48:46.431Z,1617209326.431 [NAL9602](INFO): GPS fix at 20210331T164845: (41.524541, -70.671315)
2021-03-31T16:48:46.462Z,1617209326.462 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T16:48:46.462Z,1617209326.462 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T16:48:50.083Z,1617209330.083 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210331T150238/Courier0067.lzma
2021-03-31T16:48:51.085Z,1617209331.085 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Courier0067.lzma.bak
2021-03-31T16:48:51.086Z,1617209331.086 [DataOverHttps](INFO): SBD MOMSN=102019
2021-03-31T16:49:00.123Z,1617209340.123 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20210331T150238/Express0068.lzma
2021-03-31T16:49:01.126Z,1617209341.126 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0068.lzma.bak
2021-03-31T16:49:01.126Z,1617209341.126 [DataOverHttps](INFO): SBD MOMSN=102022
2021-03-31T16:49:02.248Z,1617209342.248 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T16:49:02.248Z,1617209342.248 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T16:49:02.248Z,1617209342.248 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T16:49:11.887Z,1617209351.887 [NAL9602](INFO): SBD MO Status=2, MOMSN=14231, MT Status=2, MTMSN=0
2021-03-31T16:49:11.887Z,1617209351.887 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T16:50:18.969Z,1617209418.969 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2021-03-31T16:50:33.913Z,1617209433.913 [NAL9602](INFO): SBD MO Status=2, MOMSN=14231, MT Status=2, MTMSN=0
2021-03-31T16:50:33.913Z,1617209433.913 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T16:52:06.021Z,1617209526.021 [NAL9602](INFO): SBD MO Status=2, MOMSN=14231, MT Status=2, MTMSN=0
2021-03-31T16:52:06.021Z,1617209526.021 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T16:53:08.637Z,1617209588.637 [NAL9602](INFO): SBD MO Status=2, MOMSN=14231, MT Status=0, MTMSN=0
2021-03-31T16:53:08.637Z,1617209588.637 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T16:53:22.779Z,1617209602.779 [NAL9602](INFO): SBD MO Status=1, MOMSN=14231, MT Status=0, MTMSN=0
2021-03-31T16:53:22.779Z,1617209602.779 [NAL9602](INFO): No messages in MT queue
2021-03-31T16:53:53.482Z,1617209633.482 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T16:54:02.793Z,1617209642.793 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T16:54:02.793Z,1617209642.793 [Default:CheckIn:C.Wait] Stopped
2021-03-31T16:54:02.793Z,1617209642.793 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T16:54:02.794Z,1617209642.794 [Default:CheckIn:D] Running Loop=1
2021-03-31T16:54:03.221Z,1617209643.221 [Default:CheckIn:D] Stopped
2021-03-31T16:54:03.221Z,1617209643.221 [Default:CheckIn:E] Running Loop=1
2021-03-31T16:54:03.612Z,1617209643.612 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 108.627889 min
2021-03-31T16:54:03.612Z,1617209643.612 [Default:CheckIn:E] Stopped
2021-03-31T16:54:03.612Z,1617209643.612 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T16:54:03.612Z,1617209643.612 [Default:CheckIn] Stopped
2021-03-31T16:54:03.612Z,1617209643.612 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T16:54:03.612Z,1617209643.612 [Default:CheckIn](INFO): Running loop #21
2021-03-31T16:54:03.612Z,1617209643.612 [Default:CheckIn] Running Loop=21
2021-03-31T16:54:03.613Z,1617209643.613 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T16:54:03.613Z,1617209643.613 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T16:54:05.609Z,1617209645.609 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165404.00,A,4131.45957,N,07040.31029,W,0.019,219.85,310321,,,A*74
2021-03-31T16:54:05.611Z,1617209645.611 [NAL9602](INFO): GPS fix at 20210331T165404: (41.524326, -70.671838)
2021-03-31T16:54:05.622Z,1617209645.622 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T16:54:05.622Z,1617209645.622 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T16:54:09.427Z,1617209649.427 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210331T150238/Courier0070.lzma
2021-03-31T16:54:10.430Z,1617209650.430 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Courier0070.lzma.bak
2021-03-31T16:54:10.430Z,1617209650.430 [DataOverHttps](INFO): SBD MOMSN=102028
2021-03-31T16:54:19.468Z,1617209659.468 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20210331T150238/Express0071.lzma
2021-03-31T16:54:20.470Z,1617209660.470 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0071.lzma.bak
2021-03-31T16:54:20.470Z,1617209660.470 [DataOverHttps](INFO): SBD MOMSN=102031
2021-03-31T16:54:21.798Z,1617209661.798 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T16:54:21.799Z,1617209661.799 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T16:54:21.799Z,1617209661.799 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T16:54:28.235Z,1617209668.235 [NAL9602](INFO): SBD MO Status=1, MOMSN=14232, MT Status=0, MTMSN=0
2021-03-31T16:54:28.235Z,1617209668.235 [NAL9602](INFO): No messages in MT queue
2021-03-31T16:54:58.938Z,1617209698.938 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T16:57:59.542Z,1617209879.542 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2021-03-31T16:58:24.211Z,1617209904.211 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2021-03-31T16:58:29.424Z,1617209909.424 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2021-03-31T16:58:34.284Z,1617209914.284 [RDI_Pathfinder](ERROR): only read 0 of 4 data items
2021-03-31T16:58:34.288Z,1617209914.288 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2021-03-31T16:58:44.382Z,1617209924.382 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2021-03-31T16:58:44.387Z,1617209924.387 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2021-03-31T16:59:22.397Z,1617209962.397 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T16:59:22.398Z,1617209962.398 [Default:CheckIn:C.Wait] Stopped
2021-03-31T16:59:22.398Z,1617209962.398 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T16:59:22.398Z,1617209962.398 [Default:CheckIn:D] Running Loop=1
2021-03-31T16:59:22.759Z,1617209962.759 [Default:CheckIn:D] Stopped
2021-03-31T16:59:22.759Z,1617209962.759 [Default:CheckIn:E] Running Loop=1
2021-03-31T16:59:23.183Z,1617209963.183 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 113.953516 min
2021-03-31T16:59:23.183Z,1617209963.183 [Default:CheckIn:E] Stopped
2021-03-31T16:59:23.183Z,1617209963.183 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T16:59:23.183Z,1617209963.183 [Default:CheckIn] Stopped
2021-03-31T16:59:23.184Z,1617209963.184 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T16:59:23.184Z,1617209963.184 [Default:CheckIn](INFO): Running loop #22
2021-03-31T16:59:23.184Z,1617209963.184 [Default:CheckIn] Running Loop=22
2021-03-31T16:59:23.184Z,1617209963.184 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T16:59:23.184Z,1617209963.184 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T16:59:25.177Z,1617209965.177 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165924.00,A,4131.45648,N,07040.31050,W,0.019,219.85,310321,,,D*71
2021-03-31T16:59:25.181Z,1617209965.181 [NAL9602](INFO): GPS fix at 20210331T165924: (41.524275, -70.671842)
2021-03-31T16:59:25.242Z,1617209965.242 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T16:59:25.242Z,1617209965.242 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T16:59:28.743Z,1617209968.743 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210331T150238/Courier0073.lzma
2021-03-31T16:59:29.746Z,1617209969.746 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Courier0073.lzma.bak
2021-03-31T16:59:29.746Z,1617209969.746 [DataOverHttps](INFO): SBD MOMSN=102036
2021-03-31T16:59:38.784Z,1617209978.784 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20210331T150238/Express0074.lzma
2021-03-31T16:59:39.790Z,1617209979.790 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0074.lzma.bak
2021-03-31T16:59:39.790Z,1617209979.790 [DataOverHttps](INFO): SBD MOMSN=102039
2021-03-31T16:59:40.957Z,1617209980.957 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T16:59:40.957Z,1617209980.957 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T16:59:40.958Z,1617209980.958 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T16:59:50.215Z,1617209990.215 [NAL9602](INFO): SBD MO Status=1, MOMSN=14233, MT Status=0, MTMSN=0
2021-03-31T16:59:50.215Z,1617209990.215 [NAL9602](INFO): No messages in MT queue
2021-03-31T17:00:20.921Z,1617210020.921 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T17:00:41.532Z,1617210041.532 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2021-03-31T17:04:41.535Z,1617210281.535 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T17:04:41.535Z,1617210281.535 [Default:CheckIn:C.Wait] Stopped
2021-03-31T17:04:41.535Z,1617210281.535 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T17:04:41.535Z,1617210281.535 [Default:CheckIn:D] Running Loop=1
2021-03-31T17:04:41.931Z,1617210281.931 [Default:CheckIn:D] Stopped
2021-03-31T17:04:41.931Z,1617210281.931 [Default:CheckIn:E] Running Loop=1
2021-03-31T17:04:42.345Z,1617210282.345 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 119.273055 min
2021-03-31T17:04:42.346Z,1617210282.346 [Default:CheckIn:E] Stopped
2021-03-31T17:04:42.346Z,1617210282.346 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T17:04:42.346Z,1617210282.346 [Default:CheckIn] Stopped
2021-03-31T17:04:42.346Z,1617210282.346 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T17:04:42.346Z,1617210282.346 [Default:CheckIn](INFO): Running loop #23
2021-03-31T17:04:42.346Z,1617210282.346 [Default:CheckIn] Running Loop=23
2021-03-31T17:04:42.346Z,1617210282.346 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T17:04:42.346Z,1617210282.346 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T17:04:44.335Z,1617210284.335 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170443.00,A,4131.45853,N,07040.31420,W,0.136,219.85,310321,,,D*72
2021-03-31T17:04:44.338Z,1617210284.338 [NAL9602](INFO): GPS fix at 20210331T170443: (41.524309, -70.671903)
2021-03-31T17:04:44.364Z,1617210284.364 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T17:04:44.364Z,1617210284.364 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T17:04:48.063Z,1617210288.063 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210331T150238/Courier0076.lzma
2021-03-31T17:04:49.066Z,1617210289.066 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Courier0076.lzma.bak
2021-03-31T17:04:49.066Z,1617210289.066 [DataOverHttps](INFO): SBD MOMSN=102044
2021-03-31T17:04:58.103Z,1617210298.103 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20210331T150238/Express0077.lzma
2021-03-31T17:04:59.106Z,1617210299.106 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0077.lzma.bak
2021-03-31T17:04:59.106Z,1617210299.106 [DataOverHttps](INFO): SBD MOMSN=102047
2021-03-31T17:05:00.519Z,1617210300.519 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T17:05:00.520Z,1617210300.520 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T17:05:00.520Z,1617210300.520 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T17:05:00.899Z,1617210300.899 [NAL9602](INFO): SBD MO Status=1, MOMSN=14234, MT Status=0, MTMSN=0
2021-03-31T17:05:00.899Z,1617210300.899 [NAL9602](INFO): No messages in MT queue
2021-03-31T17:05:19.521Z,1617210319.521 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2021-03-31T17:05:31.602Z,1617210331.602 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T17:08:44.737Z,1617210524.737 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-03-31T17:09:28.406Z,1617210568.406 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2021-03-31T17:10:01.103Z,1617210601.103 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T17:10:01.103Z,1617210601.103 [Default:CheckIn:C.Wait] Stopped
2021-03-31T17:10:01.104Z,1617210601.104 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T17:10:01.104Z,1617210601.104 [Default:CheckIn:D] Running Loop=1
2021-03-31T17:10:01.524Z,1617210601.524 [Default:CheckIn:D] Stopped
2021-03-31T17:10:01.524Z,1617210601.524 [Default:CheckIn:E] Running Loop=1
2021-03-31T17:10:01.920Z,1617210601.920 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 124.599601 min
2021-03-31T17:10:01.920Z,1617210601.920 [Default:CheckIn:E] Stopped
2021-03-31T17:10:01.920Z,1617210601.920 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T17:10:01.920Z,1617210601.920 [Default:CheckIn] Stopped
2021-03-31T17:10:01.921Z,1617210601.921 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T17:10:01.921Z,1617210601.921 [Default:CheckIn](INFO): Running loop #24
2021-03-31T17:10:01.921Z,1617210601.921 [Default:CheckIn] Running Loop=24
2021-03-31T17:10:01.921Z,1617210601.921 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T17:10:01.921Z,1617210601.921 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T17:10:03.919Z,1617210603.919 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171003.00,A,4131.42291,N,07040.35584,W,5.423,206.65,310321,,,A*7A
2021-03-31T17:10:03.922Z,1617210603.922 [NAL9602](INFO): GPS fix at 20210331T171003: (41.523715, -70.672597)
2021-03-31T17:10:03.952Z,1617210603.952 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T17:10:03.952Z,1617210603.952 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T17:10:04.781Z,1617210604.781 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T17:10:04.781Z,1617210604.781 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T17:10:04.781Z,1617210604.781 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T17:10:40.684Z,1617210640.684 [NAL9602](INFO): SBD MO Status=2, MOMSN=14235, MT Status=2, MTMSN=0
2021-03-31T17:10:40.684Z,1617210640.684 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T17:11:02.907Z,1617210662.907 [NAL9602](INFO): SBD MO Status=1, MOMSN=14235, MT Status=0, MTMSN=0
2021-03-31T17:11:02.907Z,1617210662.907 [NAL9602](INFO): No messages in MT queue
2021-03-31T17:11:33.605Z,1617210693.605 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T17:15:05.326Z,1617210905.326 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T17:15:05.326Z,1617210905.326 [Default:CheckIn:C.Wait] Stopped
2021-03-31T17:15:05.326Z,1617210905.326 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T17:15:05.326Z,1617210905.326 [Default:CheckIn:D] Running Loop=1
2021-03-31T17:15:05.729Z,1617210905.729 [Default:CheckIn:D] Stopped
2021-03-31T17:15:05.729Z,1617210905.729 [Default:CheckIn:E] Running Loop=1
2021-03-31T17:15:06.203Z,1617210906.203 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 129.669694 min
2021-03-31T17:15:06.203Z,1617210906.203 [Default:CheckIn:E] Stopped
2021-03-31T17:15:06.208Z,1617210906.208 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T17:15:06.208Z,1617210906.208 [Default:CheckIn] Stopped
2021-03-31T17:15:06.208Z,1617210906.208 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T17:15:06.209Z,1617210906.209 [Default:CheckIn](INFO): Running loop #25
2021-03-31T17:15:06.209Z,1617210906.209 [Default:CheckIn] Running Loop=25
2021-03-31T17:15:06.209Z,1617210906.209 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T17:15:06.210Z,1617210906.210 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T17:15:08.141Z,1617210908.141 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171507.00,A,4131.46731,N,07042.39788,W,19.536,249.79,310321,,,D*4B
2021-03-31T17:15:08.148Z,1617210908.148 [NAL9602](INFO): GPS fix at 20210331T171507: (41.524455, -70.706631)
2021-03-31T17:15:08.206Z,1617210908.206 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T17:15:08.206Z,1617210908.206 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T17:15:11.687Z,1617210911.687 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210331T150238/Courier0079.lzma
2021-03-31T17:15:12.689Z,1617210912.689 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Courier0079.lzma.bak
2021-03-31T17:15:12.690Z,1617210912.690 [DataOverHttps](INFO): SBD MOMSN=102055
2021-03-31T17:15:21.736Z,1617210921.736 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210331T150238/Courier0082.lzma
2021-03-31T17:15:22.738Z,1617210922.738 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Courier0082.lzma.bak
2021-03-31T17:15:22.738Z,1617210922.738 [DataOverHttps](INFO): SBD MOMSN=102058
2021-03-31T17:15:31.184Z,1617210931.184 [NAL9602](INFO): SBD MO Status=2, MOMSN=14236, MT Status=2, MTMSN=0
2021-03-31T17:15:31.184Z,1617210931.184 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T17:15:31.776Z,1617210931.776 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20210331T150238/Express0080.lzma
2021-03-31T17:15:32.781Z,1617210932.781 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0080.lzma.bak
2021-03-31T17:15:32.782Z,1617210932.782 [DataOverHttps](INFO): SBD MOMSN=102061
2021-03-31T17:15:41.820Z,1617210941.820 [DataOverHttps](INFO): Sending 134 bytes from file Logs/20210331T150238/Express0083.lzma
2021-03-31T17:15:42.822Z,1617210942.822 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0083.lzma.bak
2021-03-31T17:15:42.822Z,1617210942.822 [DataOverHttps](INFO): SBD MOMSN=102064
2021-03-31T17:15:44.113Z,1617210944.113 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T17:15:44.113Z,1617210944.113 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T17:15:44.113Z,1617210944.113 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T17:15:48.543Z,1617210948.543 [NAL9602](INFO): SBD MO Status=1, MOMSN=14236, MT Status=0, MTMSN=0
2021-03-31T17:15:48.543Z,1617210948.543 [NAL9602](INFO): No messages in MT queue
2021-03-31T17:16:19.255Z,1617210979.255 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T17:20:44.709Z,1617211244.709 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T17:20:44.709Z,1617211244.709 [Default:CheckIn:C.Wait] Stopped
2021-03-31T17:20:44.709Z,1617211244.709 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T17:20:44.709Z,1617211244.709 [Default:CheckIn:D] Running Loop=1
2021-03-31T17:20:45.097Z,1617211245.097 [Default:CheckIn:D] Stopped
2021-03-31T17:20:45.097Z,1617211245.097 [Default:CheckIn:E] Running Loop=1
2021-03-31T17:20:45.515Z,1617211245.515 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 135.325814 min
2021-03-31T17:20:45.515Z,1617211245.515 [Default:CheckIn:E] Stopped
2021-03-31T17:20:45.516Z,1617211245.516 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T17:20:45.516Z,1617211245.516 [Default:CheckIn] Stopped
2021-03-31T17:20:45.516Z,1617211245.516 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T17:20:45.516Z,1617211245.516 [Default:CheckIn](INFO): Running loop #26
2021-03-31T17:20:45.516Z,1617211245.516 [Default:CheckIn] Running Loop=26
2021-03-31T17:20:45.516Z,1617211245.516 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T17:20:45.516Z,1617211245.516 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T17:20:47.501Z,1617211247.501 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172046.00,A,4130.36749,N,07044.37592,W,17.300,231.61,310321,,,D*4B
2021-03-31T17:20:47.504Z,1617211247.504 [NAL9602](INFO): GPS fix at 20210331T172046: (41.506125, -70.739599)
2021-03-31T17:20:47.530Z,1617211247.530 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T17:20:47.530Z,1617211247.530 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T17:20:51.079Z,1617211251.079 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210331T150238/Courier0085.lzma
2021-03-31T17:20:52.082Z,1617211252.082 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Courier0085.lzma.bak
2021-03-31T17:20:52.082Z,1617211252.082 [DataOverHttps](INFO): SBD MOMSN=102069
2021-03-31T17:21:01.119Z,1617211261.119 [DataOverHttps](INFO): Sending 137 bytes from file Logs/20210331T150238/Express0086.lzma
2021-03-31T17:21:02.122Z,1617211262.122 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0086.lzma.bak
2021-03-31T17:21:02.122Z,1617211262.122 [DataOverHttps](INFO): SBD MOMSN=102072
2021-03-31T17:21:03.324Z,1617211263.324 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T17:21:03.324Z,1617211263.324 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T17:21:03.324Z,1617211263.324 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T17:21:04.927Z,1617211264.927 [NAL9602](INFO): SBD MO Status=1, MOMSN=14237, MT Status=0, MTMSN=0
2021-03-31T17:21:04.928Z,1617211264.928 [NAL9602](INFO): No messages in MT queue
2021-03-31T17:21:35.657Z,1617211295.657 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T17:24:55.738Z,1617211495.738 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2021-03-31T17:24:55.742Z,1617211495.742 [BPC1](INFO): Received data from all battery sticks.
2021-03-31T17:26:04.048Z,1617211564.048 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T17:26:04.048Z,1617211564.048 [Default:CheckIn:C.Wait] Stopped
2021-03-31T17:26:04.048Z,1617211564.048 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T17:26:04.048Z,1617211564.048 [Default:CheckIn:D] Running Loop=1
2021-03-31T17:26:04.475Z,1617211564.475 [Default:CheckIn:D] Stopped
2021-03-31T17:26:04.475Z,1617211564.475 [Default:CheckIn:E] Running Loop=1
2021-03-31T17:26:04.872Z,1617211564.872 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 140.648779 min
2021-03-31T17:26:04.872Z,1617211564.872 [Default:CheckIn:E] Stopped
2021-03-31T17:26:04.872Z,1617211564.872 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T17:26:04.872Z,1617211564.872 [Default:CheckIn] Stopped
2021-03-31T17:26:04.872Z,1617211564.872 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T17:26:04.873Z,1617211564.873 [Default:CheckIn](INFO): Running loop #27
2021-03-31T17:26:04.873Z,1617211564.873 [Default:CheckIn] Running Loop=27
2021-03-31T17:26:04.873Z,1617211564.873 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T17:26:04.873Z,1617211564.873 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T17:26:06.864Z,1617211566.864 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172606.00,A,4129.63053,N,07045.63550,W,19.788,240.66,310321,,,A*4D
2021-03-31T17:26:06.866Z,1617211566.866 [NAL9602](INFO): GPS fix at 20210331T172606: (41.493842, -70.760592)
2021-03-31T17:26:06.877Z,1617211566.877 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T17:26:06.877Z,1617211566.877 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T17:26:19.395Z,1617211579.395 [NAL9602](INFO): SBD MO Status=1, MOMSN=14238, MT Status=0, MTMSN=0
2021-03-31T17:26:19.395Z,1617211579.395 [NAL9602](INFO): No messages in MT queue
2021-03-31T17:26:38.516Z,1617211598.516 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:26:48.556Z,1617211608.556 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.247391
2021-03-31T17:27:11.605Z,1617211631.605 [NAL9602](INFO): SBD MO Status=1, MOMSN=14239, MT Status=0, MTMSN=0
2021-03-31T17:27:11.661Z,1617211631.661 [NAL9602](INFO): Sent 84 bytes from file Logs/20210331T150238/Courier0088.lzma
2021-03-31T17:27:11.662Z,1617211631.662 [NAL9602](INFO): Packets left to send: 0
2021-03-31T17:27:19.684Z,1617211639.684 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:27:21.003Z,1617211641.003 [NAL9602](INFO): SBD MO Status=1, MOMSN=14240, MT Status=0, MTMSN=0
2021-03-31T17:27:21.052Z,1617211641.052 [NAL9602](INFO): Sent 136 bytes from file Logs/20210331T150238/Express0089.lzma
2021-03-31T17:27:21.052Z,1617211641.052 [NAL9602](INFO): Packets left to send: 0
2021-03-31T17:27:33.509Z,1617211653.509 [NAL9602](INFO): SBD MO Status=0, MOMSN=14241, MT Status=0, MTMSN=0
2021-03-31T17:27:33.614Z,1617211653.614 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T17:27:33.614Z,1617211653.614 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T17:27:33.614Z,1617211653.614 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T17:27:54.856Z,1617211674.856 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:28:04.214Z,1617211684.214 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T17:28:29.996Z,1617211709.996 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:29:05.138Z,1617211745.138 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:29:40.276Z,1617211780.276 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:29:58.353Z,1617211798.353 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003486
2021-03-31T17:31:16.129Z,1617211876.129 [RDI_Pathfinder](ERROR): only read 1 of 4 data items
2021-03-31T17:32:34.105Z,1617211954.105 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T17:32:34.105Z,1617211954.105 [Default:CheckIn:C.Wait] Stopped
2021-03-31T17:32:34.106Z,1617211954.106 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T17:32:34.106Z,1617211954.106 [Default:CheckIn:D] Running Loop=1
2021-03-31T17:32:34.540Z,1617211954.540 [Default:CheckIn:D] Stopped
2021-03-31T17:32:34.540Z,1617211954.540 [Default:CheckIn:E] Running Loop=1
2021-03-31T17:32:34.907Z,1617211954.907 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 147.149870 min
2021-03-31T17:32:34.908Z,1617211954.908 [Default:CheckIn:E] Stopped
2021-03-31T17:32:34.908Z,1617211954.908 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T17:32:34.908Z,1617211954.908 [Default:CheckIn] Stopped
2021-03-31T17:32:34.908Z,1617211954.908 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T17:32:34.908Z,1617211954.908 [Default:CheckIn](INFO): Running loop #28
2021-03-31T17:32:34.908Z,1617211954.908 [Default:CheckIn] Running Loop=28
2021-03-31T17:32:34.908Z,1617211954.908 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T17:32:34.908Z,1617211954.908 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T17:32:36.916Z,1617211956.916 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173236.00,A,4128.41432,N,07047.86773,W,18.952,245.24,310321,,,A*48
2021-03-31T17:32:36.918Z,1617211956.918 [NAL9602](INFO): GPS fix at 20210331T173236: (41.473572, -70.797796)
2021-03-31T17:32:36.939Z,1617211956.939 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T17:32:36.939Z,1617211956.939 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T17:32:59.543Z,1617211979.543 [NAL9602](INFO): SBD MO Status=2, MOMSN=14242, MT Status=2, MTMSN=0
2021-03-31T17:32:59.544Z,1617211979.544 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T17:33:08.158Z,1617211988.158 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:33:10.166Z,1617211990.166 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.248486
2021-03-31T17:33:19.349Z,1617211999.349 [NAL9602](INFO): SBD MO Status=0, MOMSN=14242, MT Status=0, MTMSN=0
2021-03-31T17:33:19.349Z,1617211999.349 [NAL9602](INFO): No messages in MT queue
2021-03-31T17:33:41.288Z,1617212021.288 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:33:48.919Z,1617212028.919 [NAL9602](INFO): SBD MO Status=2, MOMSN=14243, MT Status=2, MTMSN=0
2021-03-31T17:33:48.919Z,1617212028.919 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T17:34:06.444Z,1617212046.444 [NAL9602](INFO): SBD MO Status=1, MOMSN=14243, MT Status=0, MTMSN=0
2021-03-31T17:34:06.492Z,1617212046.492 [NAL9602](INFO): Sent 71 bytes from file Logs/20210331T150238/Courier0091.lzma
2021-03-31T17:34:06.492Z,1617212046.492 [NAL9602](INFO): Packets left to send: 0
2021-03-31T17:34:16.440Z,1617212056.440 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:34:18.284Z,1617212058.284 [NAL9602](INFO): SBD MO Status=1, MOMSN=14244, MT Status=0, MTMSN=0
2021-03-31T17:34:18.332Z,1617212058.332 [NAL9602](INFO): Sent 136 bytes from file Logs/20210331T150238/Express0092.lzma
2021-03-31T17:34:18.332Z,1617212058.332 [NAL9602](INFO): Packets left to send: 0
2021-03-31T17:34:28.387Z,1617212068.387 [NAL9602](INFO): SBD MO Status=0, MOMSN=14245, MT Status=0, MTMSN=0
2021-03-31T17:34:28.504Z,1617212068.504 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T17:34:28.504Z,1617212068.504 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T17:34:28.504Z,1617212068.504 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T17:34:51.581Z,1617212091.581 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:34:59.087Z,1617212099.087 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T17:35:26.720Z,1617212126.720 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:36:01.864Z,1617212161.864 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:36:37.004Z,1617212197.004 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:37:12.162Z,1617212232.162 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:37:47.308Z,1617212267.308 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:38:22.464Z,1617212302.464 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:38:41.306Z,1617212321.306 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2021-03-31T17:38:56.260Z,1617212336.260 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2021-03-31T17:38:57.612Z,1617212337.612 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:39:15.701Z,1617212355.701 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003475
2021-03-31T17:39:26.218Z,1617212366.218 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2021-03-31T17:39:28.980Z,1617212368.980 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T17:39:28.980Z,1617212368.980 [Default:CheckIn:C.Wait] Stopped
2021-03-31T17:39:28.980Z,1617212368.980 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T17:39:28.980Z,1617212368.980 [Default:CheckIn:D] Running Loop=1
2021-03-31T17:39:29.390Z,1617212369.390 [Default:CheckIn:D] Stopped
2021-03-31T17:39:29.390Z,1617212369.390 [Default:CheckIn:E] Running Loop=1
2021-03-31T17:39:29.806Z,1617212369.806 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 154.064046 min
2021-03-31T17:39:29.806Z,1617212369.806 [Default:CheckIn:E] Stopped
2021-03-31T17:39:29.806Z,1617212369.806 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T17:39:29.806Z,1617212369.806 [Default:CheckIn] Stopped
2021-03-31T17:39:29.807Z,1617212369.807 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T17:39:29.807Z,1617212369.807 [Default:CheckIn](INFO): Running loop #29
2021-03-31T17:39:29.807Z,1617212369.807 [Default:CheckIn] Running Loop=29
2021-03-31T17:39:29.807Z,1617212369.807 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T17:39:29.807Z,1617212369.807 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T17:39:31.799Z,1617212371.799 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173931.00,A,4127.28049,N,07050.56128,W,20.896,203.28,310321,,,A*43
2021-03-31T17:39:31.802Z,1617212371.802 [NAL9602](INFO): GPS fix at 20210331T173931: (41.454675, -70.842688)
2021-03-31T17:39:31.839Z,1617212371.839 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T17:39:31.839Z,1617212371.839 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T17:39:46.385Z,1617212386.385 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude
2021-03-31T17:39:50.384Z,1617212390.384 [NAL9602](INFO): SBD MO Status=0, MOMSN=14246, MT Status=0, MTMSN=0
2021-03-31T17:39:50.384Z,1617212390.384 [NAL9602](INFO): No messages in MT queue
2021-03-31T17:40:02.892Z,1617212402.892 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:40:06.911Z,1617212406.911 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210331T150238/Courier0094.lzma
2021-03-31T17:40:08.918Z,1617212408.918 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Courier0094.lzma.bak
2021-03-31T17:40:08.918Z,1617212408.918 [DataOverHttps](INFO): SBD MOMSN=102098
2021-03-31T17:40:21.082Z,1617212421.082 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T17:40:40.052Z,1617212440.052 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:40:46.561Z,1617212446.561 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2021-03-31T17:41:51.339Z,1617212511.339 [DataOverHttps](INFO): Sending 136 bytes from file Logs/20210331T150238/Express0095.lzma
2021-03-31T17:41:52.342Z,1617212512.342 [DataOverHttps](INFO): Moved sent file to Logs/20210331T150238/Express0095.lzma.bak
2021-03-31T17:41:52.342Z,1617212512.342 [DataOverHttps](INFO): SBD MOMSN=102101
2021-03-31T17:41:53.612Z,1617212513.612 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T17:41:53.612Z,1617212513.612 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T17:41:53.612Z,1617212513.612 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T17:42:23.480Z,1617212543.480 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:42:52.596Z,1617212572.596 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.255226
2021-03-31T17:43:33.761Z,1617212613.761 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:44:08.909Z,1617212648.909 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:44:44.048Z,1617212684.048 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:45:19.188Z,1617212719.188 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:45:54.344Z,1617212754.344 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:46:29.484Z,1617212789.484 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:46:54.230Z,1617212814.230 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T17:46:54.230Z,1617212814.230 [Default:CheckIn:C.Wait] Stopped
2021-03-31T17:46:54.230Z,1617212814.230 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T17:46:54.230Z,1617212814.230 [Default:CheckIn:D] Running Loop=1
2021-03-31T17:46:54.608Z,1617212814.608 [Default:CheckIn:D] Stopped
2021-03-31T17:46:54.608Z,1617212814.608 [Default:CheckIn:E] Running Loop=1
2021-03-31T17:46:55.001Z,1617212815.001 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 161.484342 min
2021-03-31T17:46:55.001Z,1617212815.001 [Default:CheckIn:E] Stopped
2021-03-31T17:46:55.001Z,1617212815.001 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T17:46:55.001Z,1617212815.001 [Default:CheckIn] Stopped
2021-03-31T17:46:55.001Z,1617212815.001 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T17:46:55.001Z,1617212815.001 [Default:CheckIn](INFO): Running loop #30
2021-03-31T17:46:55.001Z,1617212815.001 [Default:CheckIn] Running Loop=30
2021-03-31T17:46:55.001Z,1617212815.001 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T17:46:55.002Z,1617212815.002 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T17:46:57.005Z,1617212817.005 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174656.00,A,4126.51585,N,07050.83474,W,4.801,195.16,310321,,,D*78
2021-03-31T17:46:57.008Z,1617212817.008 [NAL9602](INFO): GPS fix at 20210331T174656: (41.441931, -70.847246)
2021-03-31T17:46:57.018Z,1617212817.018 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T17:46:57.018Z,1617212817.018 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T17:47:04.624Z,1617212824.624 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:47:20.199Z,1617212840.199 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-03-31T17:47:23.797Z,1617212843.797 [NAL9602](INFO): SBD MO Status=1, MOMSN=14247, MT Status=0, MTMSN=0
2021-03-31T17:47:23.844Z,1617212843.844 [NAL9602](INFO): Sent 71 bytes from file Logs/20210331T150238/Courier0097.lzma
2021-03-31T17:47:23.844Z,1617212843.844 [NAL9602](INFO): Packets left to send: 0
2021-03-31T17:47:44.900Z,1617212864.900 [NAL9602](INFO): SBD MO Status=2, MOMSN=14248, MT Status=2, MTMSN=0
2021-03-31T17:47:44.901Z,1617212864.901 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T17:48:08.867Z,1617212888.867 [NAL9602](INFO): SBD MO Status=2, MOMSN=14248, MT Status=2, MTMSN=0
2021-03-31T17:48:08.867Z,1617212888.867 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T17:48:14.904Z,1617212894.904 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:48:26.720Z,1617212906.720 [NAL9602](INFO): SBD MO Status=2, MOMSN=14248, MT Status=2, MTMSN=0
2021-03-31T17:48:26.720Z,1617212906.720 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T17:48:50.064Z,1617212930.064 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:48:51.051Z,1617212931.051 [NAL9602](INFO): SBD MO Status=1, MOMSN=14248, MT Status=0, MTMSN=0
2021-03-31T17:48:51.109Z,1617212931.109 [NAL9602](INFO): Sent 129 bytes from file Logs/20210331T150238/Express0098.lzma
2021-03-31T17:48:51.109Z,1617212931.109 [NAL9602](INFO): Packets left to send: 0
2021-03-31T17:49:06.397Z,1617212946.397 [NAL9602](INFO): SBD MO Status=2, MOMSN=14249, MT Status=2, MTMSN=0
2021-03-31T17:49:06.398Z,1617212946.398 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T17:49:16.504Z,1617212956.504 [NAL9602](INFO): SBD MO Status=0, MOMSN=14249, MT Status=0, MTMSN=0
2021-03-31T17:49:16.597Z,1617212956.597 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T17:49:16.597Z,1617212956.597 [Default:CheckIn:C.Wait] Running Loop=1
2021-03-31T17:49:16.597Z,1617212956.597 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-03-31T17:49:25.204Z,1617212965.204 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:49:47.205Z,1617212987.205 [NAL9602](INFO): Not Powering down - fast GPS
2021-03-31T17:50:00.344Z,1617213000.344 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:50:35.485Z,1617213035.485 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:51:10.624Z,1617213070.624 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:51:45.772Z,1617213105.772 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:52:20.912Z,1617213140.912 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:52:56.052Z,1617213176.052 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:53:05.092Z,1617213185.092 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003416
2021-03-31T17:54:01.313Z,1617213241.313 [DataOverHttps](IMPORTANT): SBD MTMSN=20210331T175400
2021-03-31T17:54:17.081Z,1617213257.081 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-03-31T17:54:17.081Z,1617213257.081 [Default:CheckIn:C.Wait] Stopped
2021-03-31T17:54:17.081Z,1617213257.081 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-03-31T17:54:17.081Z,1617213257.081 [Default:CheckIn:D] Running Loop=1
2021-03-31T17:54:17.508Z,1617213257.508 [Default:CheckIn:D] Stopped
2021-03-31T17:54:17.509Z,1617213257.509 [Default:CheckIn:E] Running Loop=1
2021-03-31T17:54:17.898Z,1617213257.898 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 168.866016 min
2021-03-31T17:54:17.898Z,1617213257.898 [Default:CheckIn:E] Stopped
2021-03-31T17:54:17.898Z,1617213257.898 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-03-31T17:54:17.898Z,1617213257.898 [Default:CheckIn] Stopped
2021-03-31T17:54:17.898Z,1617213257.898 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T17:54:17.898Z,1617213257.898 [Default:CheckIn](INFO): Running loop #31
2021-03-31T17:54:17.898Z,1617213257.898 [Default:CheckIn] Running Loop=31
2021-03-31T17:54:17.898Z,1617213257.898 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-03-31T17:54:17.898Z,1617213257.898 [Default:CheckIn:Read_GPS] Running Loop=1
2021-03-31T17:54:19.916Z,1617213259.916 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175419.00,A,4125.77856,N,07050.85305,W,7.775,207.13,310321,,,D*71
2021-03-31T17:54:19.918Z,1617213259.918 [NAL9602](INFO): GPS fix at 20210331T175419: (41.429643, -70.847551)
2021-03-31T17:54:19.939Z,1617213259.939 [Default:CheckIn:Read_GPS] Stopped
2021-03-31T17:54:19.939Z,1617213259.939 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-03-31T17:54:32.436Z,1617213272.436 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-03-31T17:54:33.263Z,1617213273.263 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2021-03-31T17:54:59.501Z,1617213299.501 [NAL9602](INFO): SBD MO Status=2, MOMSN=14250, MT Status=2, MTMSN=0
2021-03-31T17:54:59.502Z,1617213299.502 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-03-31T17:55:01.555Z,1617213301.555 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.241577
2021-03-31T17:55:05.571Z,1617213305.571 [DataOverHttps](INFO): Received command:restart app
2021-03-31T17:55:05.644Z,1617213305.644 [CommandLine](IMPORTANT): got command restart application
2021-03-31T17:55:06.577Z,1617213306.577 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004016
2021-03-31T17:55:06.648Z,1617213306.648 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2021-03-31T17:55:06.649Z,1617213306.649 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2021-03-31T17:55:06.650Z,1617213306.650 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-03-31T17:55:06.764Z,1617213306.764 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2021-03-31T17:55:06.764Z,1617213306.764 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-03-31T17:55:06.764Z,1617213306.764 [CommandLine](INFO): Join timeout helper Thread ID is 4603
2021-03-31T17:55:06.768Z,1617213306.768 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2021-03-31T17:55:06.768Z,1617213306.768 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-03-31T17:55:06.768Z,1617213306.768 [NavChartDb](INFO): Join timeout helper Thread ID is 4604
2021-03-31T17:55:06.856Z,1617213306.856 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2021-03-31T17:55:06.856Z,1617213306.856 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-03-31T17:55:06.876Z,1617213306.876 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2021-03-31T17:55:06.876Z,1617213306.876 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2021-03-31T17:55:06.876Z,1617213306.876 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 4605
2021-03-31T17:55:06.900Z,1617213306.900 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2021-03-31T17:55:06.900Z,1617213306.900 [WetLabsSeaOWL_UV_A](INFO): Powering down
2021-03-31T17:55:06.901Z,1617213306.901 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2021-03-31T17:55:06.916Z,1617213306.916 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2021-03-31T17:55:06.916Z,1617213306.916 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-03-31T17:55:06.916Z,1617213306.916 [CTD_Seabird](INFO): Join timeout helper Thread ID is 4606
2021-03-31T17:55:07.160Z,1617213307.160 [CTD_Seabird](INFO): Powering down
2021-03-31T17:55:07.176Z,1617213307.176 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2021-03-31T17:55:07.177Z,1617213307.177 [CTD_Seabird](INFO): Powering down
2021-03-31T17:55:07.192Z,1617213307.192 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-03-31T17:55:07.204Z,1617213307.204 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2021-03-31T17:55:07.204Z,1617213307.204 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-03-31T17:55:07.204Z,1617213307.204 [Radio_Surface](INFO): Join timeout helper Thread ID is 4607
2021-03-31T17:55:07.436Z,1617213307.436 [Radio_Surface](INFO): Powering down
2021-03-31T17:55:07.437Z,1617213307.437 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2021-03-31T17:55:07.437Z,1617213307.437 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-03-31T17:55:07.444Z,1617213307.444 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2021-03-31T17:55:07.445Z,1617213307.445 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-03-31T17:55:07.445Z,1617213307.445 [Onboard](INFO): Join timeout helper Thread ID is 4608
2021-03-31T17:55:07.838Z,1617213307.838 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2021-03-31T17:55:11.936Z,1617213311.936 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2021-03-31T17:55:11.936Z,1617213311.936 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-03-31T17:55:11.956Z,1617213311.956 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2021-03-31T17:55:11.956Z,1617213311.956 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-03-31T17:55:11.957Z,1617213311.957 [DataOverHttps](INFO): Join timeout helper Thread ID is 4609
2021-03-31T17:55:12.596Z,1617213312.596 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2021-03-31T17:55:12.596Z,1617213312.596 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-03-31T17:55:12.600Z,1617213312.600 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2021-03-31T17:55:12.600Z,1617213312.600 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2021-03-31T17:55:12.601Z,1617213312.601 [BackseatComponent](INFO): Join timeout helper Thread ID is 4610
2021-03-31T17:55:12.728Z,1617213312.728 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2021-03-31T17:55:12.728Z,1617213312.728 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2021-03-31T17:55:12.740Z,1617213312.740 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2021-03-31T17:55:12.740Z,1617213312.740 [logger ThreadHandler](INFO): Thread cancelled.
2021-03-31T17:55:12.741Z,1617213312.741 [logger](INFO): Join timeout helper Thread ID is 4611
2021-03-31T17:55:12.780Z,1617213312.780 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2021-03-31T17:55:12.780Z,1617213312.780 [logger ThreadHandler](INFO): Thread cancelled.
2021-03-31T17:55:12.800Z,1617213312.800 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2021-03-31T17:55:12.800Z,1617213312.800 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-03-31T17:55:12.801Z,1617213312.801 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2021-03-31T17:55:12.801Z,1617213312.801 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-03-31T17:55:12.801Z,1617213312.801 [controlThread](INFO): Join timeout helper Thread ID is 4612
2021-03-31T17:55:12.808Z,1617213312.808 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2021-03-31T17:55:12.808Z,1617213312.808 [controlThread](DEBUG): Uninitializing ControlThread
2021-03-31T17:55:12.809Z,1617213312.809 [AHRS_M2](INFO): Powering down
2021-03-31T17:55:12.881Z,1617213312.881 [Micromodem](INFO): Powering down
2021-03-31T17:55:12.976Z,1617213312.976 [NAL9602](INFO): Powering down
2021-03-31T17:55:13.048Z,1617213313.048 [RDI_Pathfinder](INFO): Powering down
2021-03-31T17:55:13.120Z,1617213313.120 [RDI_PathfinderUp](INFO): Powering down
2021-03-31T17:55:13.121Z,1617213313.121 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2021-03-31T17:55:13.122Z,1617213313.122 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2021-03-31T17:55:13.123Z,1617213313.123 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2021-03-31T17:55:13.123Z,1617213313.123 [MissionManager](INFO): Uninitializing Mission Default
2021-03-31T17:55:13.123Z,1617213313.123 [Default] Stopped
2021-03-31T17:55:13.123Z,1617213313.123 [Default](DEBUG): Aggregate::uninitialize Default
2021-03-31T17:55:13.124Z,1617213313.124 [Default:B.GoToSurface] Stopped
2021-03-31T17:55:13.124Z,1617213313.124 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-03-31T17:55:13.124Z,1617213313.124 [Default:CheckIn] Stopped
2021-03-31T17:55:13.124Z,1617213313.124 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-03-31T17:55:13.124Z,1617213313.124 [Default:CheckIn:Read_Iridium] Stopped
2021-03-31T17:55:13.127Z,1617213313.127 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2021-03-31T17:55:13.127Z,1617213313.127 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2021-03-31T17:55:13.127Z,1617213313.127 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2021-03-31T17:55:13.127Z,1617213313.127 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2021-03-31T17:55:13.128Z,1617213313.128 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2021-03-31T17:55:13.128Z,1617213313.128 [BuoyancyServo](INFO): Powering down
2021-03-31T17:55:13.140Z,1617213313.140 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2021-03-31T17:55:13.140Z,1617213313.140 [ElevatorServo](INFO): Powering down
2021-03-31T17:55:13.141Z,1617213313.141 [MassServo](DEBUG): Uninitialize Mass Servo.
2021-03-31T17:55:13.141Z,1617213313.141 [MassServo](INFO): Powering down
2021-03-31T17:55:13.142Z,1617213313.142 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-03-31T17:55:13.142Z,1617213313.142 [RudderServo](INFO): Powering down
2021-03-31T17:55:13.142Z,1617213313.142 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2021-03-31T17:55:13.143Z,1617213313.143 [ThrusterServo](INFO): Powering down
2021-03-31T17:55:13.143Z,1617213313.143 [SBIT](DEBUG): Uninitialize SBIT Component.
2021-03-31T17:55:13.144Z,1617213313.144 [IBIT](DEBUG): Uninitialize IBIT Component.
2021-03-31T17:55:13.144Z,1617213313.144 [CBIT](DEBUG): Uninitialize CBIT Component.
2021-03-31T17:55:13.144Z,1617213313.144 [CBIT](DEBUG): Powering off loads.
2021-03-31T17:55:13.155Z,1617213313.155 [CBIT](DEBUG): Disabling WDT.
2021-03-31T17:55:13.167Z,1617213313.167 [CBIT](DEBUG): Opening all GF detection circuits.
2021-03-31T17:55:13.169Z,1617213313.169 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-03-31T17:55:13.184Z,1617213313.184 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-03-31T17:55:13.187Z,1617213313.187 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-03-31T17:55:13.195Z,1617213313.195 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-03-31T17:55:13.237Z,1617213313.237 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2021-03-31T17:55:13.331Z,1617213313.331 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2021-03-31T17:55:13.334Z,1617213313.334 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-03-31T17:55:13.605Z,1617213313.605 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-03-31T17:55:13.678Z,1617213313.678 [logger ThreadHandler](INFO): Thread cancelled.