2021-04-15T10:44:05.567Z,1618483445.567 [Supervisor](DEBUG): Initializing supervisor.
2021-04-15T10:44:05.571Z,1618483445.571 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2021-04-15T10:44:05.572Z,1618483445.572 [SyncHandler](INFO): Protected caller Thread ID is 1223
2021-04-15T10:44:05.572Z,1618483445.572 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2021-04-15T10:44:05.573Z,1618483445.573 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2021-04-15T10:44:05.574Z,1618483445.574 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1224
2021-04-15T10:44:05.578Z,1618483445.578 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2021-04-15T10:44:05.596Z,1618483445.596 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2021-04-15T10:44:05.597Z,1618483445.597 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2021-04-15T10:44:05.597Z,1618483445.597 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1225
2021-04-15T10:44:05.599Z,1618483445.599 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2021-04-15T10:44:05.600Z,1618483445.600 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2021-04-15T10:44:05.600Z,1618483445.600 [logger ThreadHandler](INFO): Protected caller Thread ID is 1226
2021-04-15T10:44:05.604Z,1618483445.604 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2021-04-15T10:44:05.604Z,1618483445.604 [Supervisor](INFO): Looking for Config files in directory: Config/
2021-04-15T10:44:05.606Z,1618483445.606 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2021-04-15T10:44:06.013Z,1618483446.013 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2021-04-15T10:44:06.013Z,1618483446.013 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2021-04-15T10:44:06.093Z,1618483446.093 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2021-04-15T10:44:06.422Z,1618483446.422 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2021-04-15T10:44:06.423Z,1618483446.423 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2021-04-15T10:44:06.524Z,1618483446.524 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2021-04-15T10:44:06.525Z,1618483446.525 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2021-04-15T10:44:06.722Z,1618483446.722 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2021-04-15T10:44:06.723Z,1618483446.723 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2021-04-15T10:44:07.228Z,1618483447.228 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2021-04-15T10:44:07.229Z,1618483447.229 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2021-04-15T10:44:07.465Z,1618483447.465 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2021-04-15T10:44:07.466Z,1618483447.466 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2021-04-15T10:44:07.616Z,1618483447.616 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2021-04-15T10:44:07.616Z,1618483447.616 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2021-04-15T10:44:07.809Z,1618483447.809 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2021-04-15T10:44:07.809Z,1618483447.809 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2021-04-15T10:44:07.907Z,1618483447.907 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2021-04-15T10:44:07.907Z,1618483447.907 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2021-04-15T10:44:08.131Z,1618483448.131 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2021-04-15T10:44:08.131Z,1618483448.131 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2021-04-15T10:44:08.491Z,1618483448.491 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2021-04-15T10:44:08.491Z,1618483448.491 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2021-04-15T10:44:08.574Z,1618483448.574 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2021-04-15T10:44:08.701Z,1618483448.701 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2021-04-15T10:44:08.702Z,1618483448.702 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2021-04-15T10:44:09.361Z,1618483449.361 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2021-04-15T10:44:09.362Z,1618483449.362 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2021-04-15T10:44:10.741Z,1618483450.741 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2021-04-15T10:44:10.744Z,1618483450.744 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2021-04-15T10:44:10.744Z,1618483450.744 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2021-04-15T10:44:10.946Z,1618483450.946 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2021-04-15T10:44:11.049Z,1618483451.049 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2021-04-15T10:44:11.150Z,1618483451.150 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2021-04-15T10:44:11.404Z,1618483451.404 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2021-04-15T10:44:11.405Z,1618483451.405 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2021-04-15T10:44:11.492Z,1618483451.492 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2021-04-15T10:44:11.589Z,1618483451.589 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2021-04-15T10:44:11.704Z,1618483451.704 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2021-04-15T10:44:11.790Z,1618483451.790 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Dock.cfg
2021-04-15T10:44:11.878Z,1618483451.878 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2021-04-15T10:44:11.989Z,1618483451.989 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/workSite.cfg
2021-04-15T10:44:12.089Z,1618483452.089 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2021-04-15T10:44:12.284Z,1618483452.284 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2021-04-15T10:44:12.448Z,1618483452.448 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2021-04-15T10:44:12.457Z,1618483452.457 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2021-04-15T10:44:12.799Z,1618483452.799 [AHRS_M2] Loaded
2021-04-15T10:44:12.799Z,1618483452.799 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2021-04-15T10:44:13.525Z,1618483453.525 [BPC1] Loaded
2021-04-15T10:44:13.525Z,1618483453.525 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2021-04-15T10:44:13.597Z,1618483453.597 [DataOverHttps] Loaded
2021-04-15T10:44:13.598Z,1618483453.598 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2021-04-15T10:44:13.599Z,1618483453.599 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407934E0
2021-04-15T10:44:13.599Z,1618483453.599 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1314
2021-04-15T10:44:13.617Z,1618483453.617 [Depth_Keller] Loaded
2021-04-15T10:44:13.618Z,1618483453.618 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2021-04-15T10:44:13.622Z,1618483453.622 [DropWeight] Loaded
2021-04-15T10:44:13.622Z,1618483453.622 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2021-04-15T10:44:13.658Z,1618483453.658 [Micromodem] Loaded
2021-04-15T10:44:13.658Z,1618483453.658 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2021-04-15T10:44:13.713Z,1618483453.713 [NAL9602] Loaded
2021-04-15T10:44:13.713Z,1618483453.713 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2021-04-15T10:44:13.740Z,1618483453.740 [Onboard] Loaded
2021-04-15T10:44:13.741Z,1618483453.741 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2021-04-15T10:44:13.742Z,1618483453.742 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 407C34E0
2021-04-15T10:44:13.742Z,1618483453.742 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1315
2021-04-15T10:44:13.747Z,1618483453.747 [PowerOnly](INFO): Adding load control power supply at /dev/loadC1
2021-04-15T10:44:13.757Z,1618483453.757 [PowerOnly] Loaded
2021-04-15T10:44:13.757Z,1618483453.757 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2021-04-15T10:44:13.771Z,1618483453.771 [Radio_Surface] Loaded
2021-04-15T10:44:13.771Z,1618483453.771 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2021-04-15T10:44:13.772Z,1618483453.772 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407F34E0
2021-04-15T10:44:13.772Z,1618483453.772 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1316
2021-04-15T10:44:13.874Z,1618483453.874 [RDI_Pathfinder] Loaded
2021-04-15T10:44:13.875Z,1618483453.875 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2021-04-15T10:44:13.899Z,1618483453.899 [RDI_PathfinderUp] Loaded
2021-04-15T10:44:13.899Z,1618483453.899 [ComponentRegistry](DEBUG): SyncComponent "RDI_PathfinderUp" handled in the control thread.
2021-04-15T10:44:13.900Z,1618483453.900 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2021-04-15T10:44:13.900Z,1618483453.900 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2021-04-15T10:44:13.911Z,1618483453.911 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2021-04-15T10:44:13.911Z,1618483453.911 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2021-04-15T10:44:13.987Z,1618483453.987 [DeadReckonUsingMultipleVelocitySources] Loaded
2021-04-15T10:44:13.988Z,1618483453.988 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2021-04-15T10:44:14.000Z,1618483454.000 [NavChart] Loaded
2021-04-15T10:44:14.000Z,1618483454.000 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2021-04-15T10:44:14.006Z,1618483454.006 [UniversalFixResidualReporter] Loaded
2021-04-15T10:44:14.006Z,1618483454.006 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2021-04-15T10:44:14.016Z,1618483454.016 [WorkSite] Loaded
2021-04-15T10:44:14.016Z,1618483454.016 [ComponentRegistry](DEBUG): SyncComponent "WorkSite" handled in the control thread.
2021-04-15T10:44:14.016Z,1618483454.016 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2021-04-15T10:44:14.017Z,1618483454.017 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2021-04-15T10:44:14.099Z,1618483454.099 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2021-04-15T10:44:14.100Z,1618483454.099 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2021-04-15T10:44:14.205Z,1618483454.205 [BuoyancyServo] Loaded
2021-04-15T10:44:14.205Z,1618483454.205 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2021-04-15T10:44:14.226Z,1618483454.226 [ElevatorServo] Loaded
2021-04-15T10:44:14.226Z,1618483454.226 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2021-04-15T10:44:14.245Z,1618483454.245 [MassServo] Loaded
2021-04-15T10:44:14.245Z,1618483454.245 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2021-04-15T10:44:14.264Z,1618483454.264 [RudderServo] Loaded
2021-04-15T10:44:14.264Z,1618483454.264 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2021-04-15T10:44:14.282Z,1618483454.282 [ThrusterServo] Loaded
2021-04-15T10:44:14.282Z,1618483454.282 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2021-04-15T10:44:14.283Z,1618483454.283 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2021-04-15T10:44:14.283Z,1618483454.283 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2021-04-15T10:44:14.565Z,1618483454.565 [CTD_Seabird] Loaded
2021-04-15T10:44:14.565Z,1618483454.565 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2021-04-15T10:44:14.587Z,1618483454.587 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409114E0
2021-04-15T10:44:14.587Z,1618483454.587 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1317
2021-04-15T10:44:14.673Z,1618483454.673 [PAR_Licor] Loaded
2021-04-15T10:44:14.674Z,1618483454.674 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2021-04-15T10:44:14.875Z,1618483454.875 [WetLabsSeaOWL_UV_A] Loaded
2021-04-15T10:44:14.875Z,1618483454.875 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2021-04-15T10:44:14.895Z,1618483454.895 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409414E0
2021-04-15T10:44:14.895Z,1618483454.895 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 1318
2021-04-15T10:44:14.896Z,1618483454.896 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2021-04-15T10:44:14.896Z,1618483454.896 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2021-04-15T10:44:15.523Z,1618483455.523 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2021-04-15T10:44:15.524Z,1618483455.524 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2021-04-15T10:44:15.563Z,1618483455.563 [DepthRateCalculator] Loaded
2021-04-15T10:44:15.563Z,1618483455.563 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2021-04-15T10:44:15.568Z,1618483455.568 [PitchRateCalculator] Loaded
2021-04-15T10:44:15.568Z,1618483455.568 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2021-04-15T10:44:15.577Z,1618483455.577 [SpeedCalculator] Loaded
2021-04-15T10:44:15.577Z,1618483455.577 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2021-04-15T10:44:15.590Z,1618483455.590 [TempGradientCalculator] Loaded
2021-04-15T10:44:15.590Z,1618483455.590 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2021-04-15T10:44:15.595Z,1618483455.595 [YawRateCalculator] Loaded
2021-04-15T10:44:15.595Z,1618483455.595 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2021-04-15T10:44:15.616Z,1618483455.616 [ElevatorOffsetCalculator] Loaded
2021-04-15T10:44:15.616Z,1618483455.616 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2021-04-15T10:44:15.616Z,1618483455.616 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2021-04-15T10:44:15.617Z,1618483455.617 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2021-04-15T10:44:15.750Z,1618483455.750 [SBIT](DEBUG): Construct Startup Built In Test.
2021-04-15T10:44:15.762Z,1618483455.762 [SBIT] Loaded
2021-04-15T10:44:15.762Z,1618483455.762 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2021-04-15T10:44:15.765Z,1618483455.765 [IBIT](DEBUG): Construct Initiated Built In Test.
2021-04-15T10:44:15.778Z,1618483455.778 [IBIT] Loaded
2021-04-15T10:44:15.778Z,1618483455.778 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2021-04-15T10:44:15.784Z,1618483455.784 [CBIT](DEBUG): Construct Continuous Built In Test.
2021-04-15T10:44:15.879Z,1618483455.879 [CBIT] Loaded
2021-04-15T10:44:15.879Z,1618483455.879 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2021-04-15T10:44:15.880Z,1618483455.880 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2021-04-15T10:44:15.880Z,1618483455.880 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2021-04-15T10:44:15.933Z,1618483455.933 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2021-04-15T10:44:15.933Z,1618483455.933 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2021-04-15T10:44:16.031Z,1618483456.031 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2021-04-15T10:44:16.031Z,1618483456.031 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2021-04-15T10:44:16.080Z,1618483456.080 [VerticalControl](DEBUG): Construct VerticalControl.
2021-04-15T10:44:16.130Z,1618483456.130 [VerticalControl] Loaded
2021-04-15T10:44:16.130Z,1618483456.130 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2021-04-15T10:44:16.133Z,1618483456.133 [HorizontalControl](DEBUG): Construct HorizontalControl.
2021-04-15T10:44:16.168Z,1618483456.168 [HorizontalControl] Loaded
2021-04-15T10:44:16.168Z,1618483456.168 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2021-04-15T10:44:16.170Z,1618483456.170 [SpeedControl](DEBUG): Construct SpeedControl.
2021-04-15T10:44:16.172Z,1618483456.172 [SpeedControl] Loaded
2021-04-15T10:44:16.172Z,1618483456.172 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2021-04-15T10:44:16.175Z,1618483456.175 [LoopControl](DEBUG): Construct LoopControl.
2021-04-15T10:44:16.175Z,1618483456.175 [LoopControl] Loaded
2021-04-15T10:44:16.176Z,1618483456.176 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2021-04-15T10:44:16.176Z,1618483456.176 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2021-04-15T10:44:16.177Z,1618483456.177 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2021-04-15T10:44:16.203Z,1618483456.203 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2021-04-15T10:44:16.209Z,1618483456.209 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2021-04-15T10:44:16.212Z,1618483456.212 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2021-04-15T10:44:16.222Z,1618483456.222 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2021-04-15T10:44:16.223Z,1618483456.223 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AEB4E0
2021-04-15T10:44:16.223Z,1618483456.223 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1319
2021-04-15T10:44:16.227Z,1618483456.227 [Supervisor](INFO): Main Thread ID is 446
2021-04-15T10:44:16.228Z,1618483456.228 [Supervisor](DEBUG): Running supervisor.
2021-04-15T10:44:16.228Z,1618483456.228 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1320
2021-04-15T10:44:16.230Z,1618483456.230 [controlThread ThreadHandler](INFO): Handler Thread ID is 1321
2021-04-15T10:44:16.231Z,1618483456.231 [controlThread](DEBUG): Initializing ControlThread
2021-04-15T10:44:16.238Z,1618483456.238 [NavChart](DEBUG): Initialize NavChart Navigation.
2021-04-15T10:44:16.238Z,1618483456.238 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2021-04-15T10:44:16.238Z,1618483456.238 [WorkSite](DEBUG): Initializing WorkSite component.
2021-04-15T10:44:16.243Z,1618483456.243 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2021-04-15T10:44:16.244Z,1618483456.244 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2021-04-15T10:44:16.244Z,1618483456.244 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2021-04-15T10:44:16.244Z,1618483456.244 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2021-04-15T10:44:16.245Z,1618483456.245 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2021-04-15T10:44:16.245Z,1618483456.245 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2021-04-15T10:44:16.246Z,1618483456.246 [SBIT](INFO): Initialize SBIT Component.
2021-04-15T10:44:16.246Z,1618483456.246 [SBIT](IMPORTANT): git: 2021-03-30_A
2021-04-15T10:44:16.246Z,1618483456.246 [SBIT](INFO): git hash: cd879fcb970100e74ebf57bcee2c6db5cbfff587
2021-04-15T10:44:16.247Z,1618483456.247 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2021-04-15T10:44:16.248Z,1618483456.248 [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-04-15T10:44:16.249Z,1618483456.249 [SBIT](INFO): Beginning SBIT in 68.000000 seconds.
2021-04-15T10:44:16.250Z,1618483456.250 [IBIT](INFO): Initialize IBIT Component.
2021-04-15T10:44:16.251Z,1618483456.251 [CBIT](DEBUG): Initialize CBIT Component.
2021-04-15T10:44:16.252Z,1618483456.252 [logger ThreadHandler](INFO): Handler Thread ID is 1322
2021-04-15T10:44:16.263Z,1618483456.263 [CBIT](DEBUG): Initialized mux pins.
2021-04-15T10:44:16.263Z,1618483456.263 [CBIT](DEBUG): Initializing the watchdog timer.
2021-04-15T10:44:16.271Z,1618483456.271 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1323
2021-04-15T10:44:16.272Z,1618483456.272 [DataOverHttps](DEBUG): dashIP=128.128.181.155 starts with a digit so assuming it is a numeric IP
2021-04-15T10:44:16.283Z,1618483456.283 [Onboard ThreadHandler](INFO): Handler Thread ID is 1324
2021-04-15T10:44:16.287Z,1618483456.287 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2021-04-15T10:44:16.288Z,1618483456.288 [CBIT](DEBUG): Initializing heartbeat.
2021-04-15T10:44:16.304Z,1618483456.304 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1325
2021-04-15T10:44:16.319Z,1618483456.319 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1326
2021-04-15T10:44:16.320Z,1618483456.320 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2021-04-15T10:44:16.324Z,1618483456.324 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 1328
2021-04-15T10:44:16.325Z,1618483456.325 [WetLabsSeaOWL_UV_A](INFO): Powering down
2021-04-15T10:44:16.336Z,1618483456.336 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1329
2021-04-15T10:44:16.339Z,1618483456.339 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2021-04-15T10:44:16.339Z,1618483456.339 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2021-04-15T10:44:16.339Z,1618483456.339 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2021-04-15T10:44:16.339Z,1618483456.339 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2021-04-15T10:44:16.340Z,1618483456.340 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2021-04-15T10:44:16.340Z,1618483456.340 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2021-04-15T10:44:16.340Z,1618483456.340 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2021-04-15T10:44:16.340Z,1618483456.340 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2021-04-15T10:44:16.340Z,1618483456.340 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2021-04-15T10:44:16.340Z,1618483456.340 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2021-04-15T10:44:16.341Z,1618483456.341 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2021-04-15T10:44:16.341Z,1618483456.341 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2021-04-15T10:44:16.341Z,1618483456.341 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2021-04-15T10:44:16.341Z,1618483456.341 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2021-04-15T10:44:16.341Z,1618483456.341 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2021-04-15T10:44:16.341Z,1618483456.341 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2021-04-15T10:44:16.359Z,1618483456.359 [CBIT](DEBUG): Deactivating GF circuits.
2021-04-15T10:44:16.359Z,1618483456.359 [CBIT](DEBUG): Deactivating emergency mode.
2021-04-15T10:44:16.395Z,1618483456.395 [CBIT](DEBUG): Backplane powered.
2021-04-15T10:44:16.395Z,1618483456.395 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2021-04-15T10:44:16.397Z,1618483456.397 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2021-04-15T10:44:16.398Z,1618483456.398 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2021-04-15T10:44:16.398Z,1618483456.398 [LoopControl](DEBUG): Initialize LoopControlComponent.
2021-04-15T10:44:16.399Z,1618483456.399 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2021-04-15T10:44:16.411Z,1618483456.411 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2021-04-15T10:44:16.438Z,1618483456.438 [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-04-15T10:44:16.439Z,1618483456.439 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2021-04-15T10:44:16.506Z,1618483456.506 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2021-04-15T10:44:16.507Z,1618483456.507 [Default:A.Wait](DEBUG): Construct Wait.
2021-04-15T10:44:16.510Z,1618483456.510 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-04-15T10:44:16.553Z,1618483456.553 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-04-15T10:44:16.555Z,1618483456.555 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-04-15T10:44:16.577Z,1618483456.577 [Default:E.Execute](DEBUG): Construct Execute.
2021-04-15T10:44:16.580Z,1618483456.580 [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-04-15T10:44:16.599Z,1618483456.599 [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,Reporter,LogSplitter,
2021-04-15T10:44:16.605Z,1618483456.605 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2021-04-15T10:44:16.711Z,1618483456.711 [Radio_Surface](INFO): Powering up
2021-04-15T10:44:16.821Z,1618483456.821 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2021-04-15T10:44:16.827Z,1618483456.827 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2021-04-15T10:44:16.828Z,1618483456.828 [ElevatorServo](DEBUG): Initializing EZServoServo.
2021-04-15T10:44:16.835Z,1618483456.835 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2021-04-15T10:44:16.836Z,1618483456.836 [MassServo](DEBUG): Initializing EZServoServo.
2021-04-15T10:44:16.843Z,1618483456.843 [MassServo](DEBUG): Initializing MassServo.
2021-04-15T10:44:16.844Z,1618483456.844 [RudderServo](DEBUG): Initializing EZServoServo.
2021-04-15T10:44:16.851Z,1618483456.851 [RudderServo](DEBUG): Initializing RudderServo.
2021-04-15T10:44:16.852Z,1618483456.852 [ThrusterServo](DEBUG): Initializing EZServoServo.
2021-04-15T10:44:16.859Z,1618483456.859 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2021-04-15T10:44:17.029Z,1618483457.029 [Micromodem](INFO): Powering up
2021-04-15T10:44:17.029Z,1618483457.029 [Micromodem](DEBUG): Initializing Micromodem.
2021-04-15T10:44:17.743Z,1618483457.743 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2021-04-15T10:44:17.743Z,1618483457.743 [RudderServo](FAULT): Rudder failed to initialize
2021-04-15T10:44:17.743Z,1618483457.743 [RudderServo] Communications Fault, FailCount= 1
2021-04-15T10:44:17.743Z,1618483457.743 [RudderServo](ERROR): Communications Fault
2021-04-15T10:44:17.843Z,1618483457.843 [CBIT](ERROR): Communications Fault in component: RudderServo
2021-04-15T10:44:18.036Z,1618483458.036 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-04-15T10:44:18.036Z,1618483458.036 [RudderServo](INFO): Powering down
2021-04-15T10:44:18.687Z,1618483458.687 [RudderServo](DEBUG): Initializing EZServoServo.
2021-04-15T10:44:18.808Z,1618483458.808 [RudderServo](DEBUG): Initializing RudderServo.
2021-04-15T10:44:18.812Z,1618483458.812 [CBIT](INFO): Clearing failed state for component RudderServo
2021-04-15T10:44:18.812Z,1618483458.812 [RudderServo] No Fault, FailCount= 1
2021-04-15T10:44:21.930Z,1618483461.930 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2021-04-15T10:44:22.337Z,1618483462.337 [Micromodem](INFO): Nmea in: $CATMG,2021-04-15T10:44:21.577681Z,RTC,RTC*59

2021-04-15T10:44:22.338Z,1618483462.338 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2021-04-15T10:44:21.577681Z,RTC,RTC*59

2021-04-15T10:44:22.745Z,1618483462.745 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31

2021-04-15T10:44:22.745Z,1618483462.745 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31

2021-04-15T10:44:23.141Z,1618483463.141 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33

2021-04-15T10:44:23.141Z,1618483463.141 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64

2021-04-15T10:44:23.549Z,1618483463.549 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66

2021-04-15T10:44:23.549Z,1618483463.549 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F

2021-04-15T10:44:23.949Z,1618483463.949 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D

2021-04-15T10:44:23.949Z,1618483463.949 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E

2021-04-15T10:44:24.357Z,1618483464.357 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C

2021-04-15T10:44:24.357Z,1618483464.357 [Micromodem](INFO): Nmea out: $CCCFG,FC0,14500*47

2021-04-15T10:44:24.745Z,1618483464.745 [Micromodem](INFO): Nmea in: $CACFG,FC0,14500*45

2021-04-15T10:44:24.745Z,1618483464.745 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63

2021-04-15T10:44:25.161Z,1618483465.161 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61

2021-04-15T10:44:25.161Z,1618483465.161 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A

2021-04-15T10:44:25.543Z,1618483465.543 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38

2021-04-15T10:44:25.544Z,1618483465.544 [Micromodem](INFO): Nmea out: $CCCLK,2021,04,15,10,44,26*40

2021-04-15T10:44:25.941Z,1618483465.941 [Micromodem](INFO): Nmea in: $CACLK,2021,4,15,10,44,26*72

2021-04-15T10:44:26.749Z,1618483466.749 [Micromodem](INFO): Nmea in: $CATMS,0,2021-04-15T10:44:27Z*73

2021-04-15T10:44:26.751Z,1618483466.751 [Micromodem](INFO): Nmea in: $CATMG,2021-04-15T10:44:27.026044Z,USER_CMD,RTC*10

2021-04-15T10:44:44.117Z,1618483484.117 [NAL9602](INFO): Powering up NAL9602
2021-04-15T10:44:55.021Z,1618483495.021 [NAL9602](INFO): NAL9602 initialized
2021-04-15T10:45:24.956Z,1618483524.956 [SBIT](IMPORTANT): Beginning Startup BIT
2021-04-15T10:45:24.964Z,1618483524.964 [CBIT](IMPORTANT): Beginning ground fault scan
2021-04-15T10:45:27.379Z,1618483527.379 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout
2021-04-15T10:45:27.379Z,1618483527.379 [RDI_Pathfinder] Communications Fault, FailCount= 1
2021-04-15T10:45:27.379Z,1618483527.379 [RDI_Pathfinder](ERROR): Communications Fault
2021-04-15T10:45:27.523Z,1618483527.523 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-04-15T10:45:27.819Z,1618483527.819 [RDI_Pathfinder](INFO): Powering down
2021-04-15T10:45:28.783Z,1618483528.783 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-04-15T10:45:28.783Z,1618483528.783 [RDI_Pathfinder] No Fault, FailCount= 1
2021-04-15T10:45:36.047Z,1618483536.047 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.009562
CHAN A1 (24V): -0.028791
CHAN A2 (12V): -0.006970
CHAN A3 (5V): -0.002039
CHAN B0 (3.3V): 0.000167
CHAN B1 (3.15aV): 0.000695
CHAN B2 (3.15bV): 0.000220
CHAN B3 (GND): 0.002151
OPEN: 0.005129
Full Scale Calc: 4.765 mA, -1.589 mA
2021-04-15T10:46:19.236Z,1618483579.236 [SBIT](IMPORTANT): SBIT PASSED
2021-04-15T10:46:19.236Z,1618483579.236 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2021-04-15T10:46:19.237Z,1618483579.237 [SBIT](IMPORTANT): BackseatComponent.loadAtStartup=0 bool;

2021-04-15T10:46:19.237Z,1618483579.237 [SBIT](IMPORTANT): CBIT.gfScanTimeout=2 hour;

2021-04-15T10:46:19.237Z,1618483579.237 [SBIT](IMPORTANT): Express none CurrentEstimator.current_direction_navigation_frame;

2021-04-15T10:46:19.237Z,1618483579.237 [SBIT](IMPORTANT): Express none CurrentEstimator.current_speed_navigation_frame;

2021-04-15T10:46:19.237Z,1618483579.237 [SBIT](IMPORTANT): Express linearApproximation mass_concentration_of_chlorophyll_in_sea_water 2.000000 microgram_per_liter;

2021-04-15T10:46:19.237Z,1618483579.237 [SBIT](IMPORTANT): Express none mass_concentration_of_petroleum_hydrocarbons_in_sea_water;

2021-04-15T10:46:19.238Z,1618483579.238 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=375 cubic_centimeter;

2021-04-15T10:46:19.238Z,1618483579.238 [SBIT](IMPORTANT): VerticalControl.massDefault=12 millimeter;

2021-04-15T10:46:19.490Z,1618483579.490 [WorkSite](IMPORTANT): Reading workSite position from Data/workSite.cfg
2021-04-15T10:46:19.493Z,1618483579.493 [WorkSite](IMPORTANT): WorkSite fix at 20210415T104306: (41.522943, -70.672836)
2021-04-15T10:46:19.494Z,1618483579.494 [MissionManager](IMPORTANT): Started mission Startup
2021-04-15T10:46:19.494Z,1618483579.494 [Startup] Running Loop=1
2021-04-15T10:46:19.507Z,1618483579.507 [Startup](DEBUG): Aggregate::initialize Startup
2021-04-15T10:46:19.507Z,1618483579.507 [Startup:A.GoToSurface] Running Loop=1
2021-04-15T10:46:19.507Z,1618483579.507 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-04-15T10:46:19.508Z,1618483579.508 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-04-15T10:46:19.508Z,1618483579.508 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-04-15T10:46:19.508Z,1618483579.508 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-04-15T10:46:19.509Z,1618483579.509 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-04-15T10:46:19.509Z,1618483579.509 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-04-15T10:46:19.510Z,1618483579.510 [Startup:StartupSatComms] Running Loop=1
2021-04-15T10:46:19.515Z,1618483579.515 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2021-04-15T10:46:19.515Z,1618483579.515 [Startup:StartupSatComms:A] Running Loop=1
2021-04-15T10:46:19.892Z,1618483579.892 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2021-04-15T10:46:54.613Z,1618483614.613 [NAL9602](INFO): SBD MO Status=2, MOMSN=15509, MT Status=2, MTMSN=0
2021-04-15T10:46:54.613Z,1618483614.613 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-15T10:47:19.690Z,1618483639.690 [Startup:StartupSatComms:A](INFO): Timed out from 2021-04-15T10:46:19.5Z
2021-04-15T10:47:19.690Z,1618483639.690 [Startup:StartupSatComms:A] Stopped
2021-04-15T10:47:19.690Z,1618483639.690 [Startup:StartupSatComms:B] Running Loop=1
2021-04-15T10:47:20.079Z,1618483640.079 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-04-15T10:47:38.278Z,1618483658.278 [NAL9602](INFO): SBD MO Status=2, MOMSN=15509, MT Status=2, MTMSN=0
2021-04-15T10:47:38.279Z,1618483658.279 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-15T10:47:51.193Z,1618483671.193 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004552
2021-04-15T10:47:55.206Z,1618483675.206 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20210414T215859/Courier0229.lzma
2021-04-15T10:47:56.209Z,1618483676.209 [DataOverHttps](INFO): Moved sent file to Logs/20210414T215859/Courier0229.lzma.bak
2021-04-15T10:47:56.210Z,1618483676.210 [DataOverHttps](INFO): SBD MOMSN=105830
2021-04-15T10:48:05.247Z,1618483685.247 [DataOverHttps](INFO): Sending 255 bytes from file Logs/20210415T104405/Courier0000.lzma
2021-04-15T10:48:06.249Z,1618483686.249 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0000.lzma.bak
2021-04-15T10:48:06.249Z,1618483686.249 [DataOverHttps](INFO): SBD MOMSN=105832
2021-04-15T10:48:15.286Z,1618483695.286 [DataOverHttps](INFO): Sending 178 bytes from file Logs/20210414T215859/Express0230.lzma
2021-04-15T10:48:16.289Z,1618483696.289 [DataOverHttps](INFO): Moved sent file to Logs/20210414T215859/Express0230.lzma.bak
2021-04-15T10:48:16.289Z,1618483696.289 [DataOverHttps](INFO): SBD MOMSN=105836
2021-04-15T10:48:19.870Z,1618483699.870 [Startup:StartupSatComms:B](INFO): Timed out from 2021-04-15T10:47:19.7Z
2021-04-15T10:48:19.870Z,1618483699.870 [Startup:StartupSatComms:B] Stopped
2021-04-15T10:48:19.870Z,1618483699.870 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2021-04-15T10:48:19.870Z,1618483699.870 [Startup:StartupSatComms] Stopped
2021-04-15T10:48:19.870Z,1618483699.870 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2021-04-15T10:48:19.871Z,1618483699.871 [Startup](INFO): Completed Startup
2021-04-15T10:48:19.871Z,1618483699.871 [MissionManager](INFO): Startup is completed.
2021-04-15T10:48:19.871Z,1618483699.871 [MissionManager](INFO): Uninitializing Mission Startup
2021-04-15T10:48:19.871Z,1618483699.871 [Startup] Stopped
2021-04-15T10:48:19.872Z,1618483699.872 [Startup](DEBUG): Aggregate::uninitialize Startup
2021-04-15T10:48:19.872Z,1618483699.872 [Startup:A.GoToSurface] Stopped
2021-04-15T10:48:19.872Z,1618483699.872 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-04-15T10:48:20.343Z,1618483700.343 [MissionManager](IMPORTANT): Started mission Default
2021-04-15T10:48:20.343Z,1618483700.343 [Default] Running Loop=1
2021-04-15T10:48:20.343Z,1618483700.343 [Default](DEBUG): Aggregate::initialize Default
2021-04-15T10:48:20.343Z,1618483700.343 [Default:B.GoToSurface] Running Loop=1
2021-04-15T10:48:20.343Z,1618483700.343 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-04-15T10:48:20.344Z,1618483700.344 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-04-15T10:48:20.344Z,1618483700.344 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-04-15T10:48:20.344Z,1618483700.344 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-04-15T10:48:20.345Z,1618483700.345 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-04-15T10:48:20.345Z,1618483700.345 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-04-15T10:48:20.345Z,1618483700.345 [Default:A.Wait] Running Loop=1
2021-04-15T10:48:20.345Z,1618483700.345 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-04-15T10:48:25.330Z,1618483705.330 [DataOverHttps](INFO): Sending 993 bytes from file Logs/20210415T104405/Express0001.lzma
2021-04-15T10:48:26.328Z,1618483706.328 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0001.lzma.bak
2021-04-15T10:48:26.329Z,1618483706.329 [DataOverHttps](INFO): SBD MOMSN=105840
2021-04-15T10:48:33.638Z,1618483713.638 [Default:A.Wait](INFO): Done Waiting.
2021-04-15T10:48:33.638Z,1618483713.638 [Default:A.Wait] Stopped
2021-04-15T10:48:33.639Z,1618483713.639 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T10:48:34.059Z,1618483714.059 [Default:CheckIn] Running Loop=1
2021-04-15T10:48:34.059Z,1618483714.059 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T10:48:34.059Z,1618483714.059 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T10:48:34.463Z,1618483714.463 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2021-04-15T10:48:38.457Z,1618483718.457 [CommandLine](IMPORTANT): got command burn on
2021-04-15T10:48:38.457Z,1618483718.457 [CommandLine](IMPORTANT): Activating dropweight wire
2021-04-15T10:48:48.002Z,1618483728.002 [CommandLine](IMPORTANT): got command burn off
2021-04-15T10:48:48.002Z,1618483728.002 [CommandLine](IMPORTANT): Deactivating dropweight wire
2021-04-15T10:49:57.649Z,1618483797.649 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-04-15T10:51:25.333Z,1618483885.333 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2021-04-15T10:52:04.495Z,1618483924.495 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2021-04-15T10:52:04.498Z,1618483924.498 [BPC1](INFO): Received data from all battery sticks.
2021-04-15T10:52:39.914Z,1618483959.914 [CommandLine](IMPORTANT): got command ibit
2021-04-15T10:52:40.126Z,1618483960.126 [IBIT](IMPORTANT): Beginning Initiated BIT
2021-04-15T10:52:40.126Z,1618483960.126 [IBIT](IMPORTANT): Beginning control surface checks.
2021-04-15T10:52:40.133Z,1618483960.133 [CBIT](IMPORTANT): Beginning ground fault scan
2021-04-15T10:52:51.050Z,1618483971.050 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.009084
CHAN A1 (24V): -0.028819
CHAN A2 (12V): -0.007168
CHAN A3 (5V): -0.001789
CHAN B0 (3.3V): 0.000213
CHAN B1 (3.15aV): 0.000174
CHAN B2 (3.15bV): 0.000214
CHAN B3 (GND): 0.002057
OPEN: 0.005394
Full Scale Calc: 4.765 mA, -1.589 mA
2021-04-15T10:52:55.509Z,1618483975.509 [IBIT](FAULT): Rudder: EXPECTED:15.000000 ACTUAL:14.619523
2021-04-15T10:52:55.509Z,1618483975.509 [IBIT](FAULT): Control surface position failure.
2021-04-15T10:53:02.256Z,1618483982.256 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105300.00,A,4131.46316,N,07040.27558,W,0.389,0.00,150421,,,A*75
2021-04-15T10:53:02.259Z,1618483982.259 [NAL9602](INFO): GPS fix at 20210415T105300: (41.524386, -70.671260)
2021-04-15T10:53:05.109Z,1618483985.109 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105303.00,A,4131.46335,N,07040.27583,W,0.136,0.00,150421,,,A*77
2021-04-15T10:53:05.111Z,1618483985.111 [NAL9602](INFO): GPS fix at 20210415T105303: (41.524389, -70.671264)
2021-04-15T10:53:07.913Z,1618483987.913 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105306.00,A,4131.46367,N,07040.27643,W,0.097,0.00,150421,,,A*70
2021-04-15T10:53:07.916Z,1618483987.916 [NAL9602](INFO): GPS fix at 20210415T105306: (41.524394, -70.671274)
2021-04-15T10:53:10.740Z,1618483990.740 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105309.00,A,4131.46401,N,07040.27703,W,0.078,0.00,150421,,,A*7C
2021-04-15T10:53:10.742Z,1618483990.742 [NAL9602](INFO): GPS fix at 20210415T105309: (41.524400, -70.671284)
2021-04-15T10:53:13.974Z,1618483993.974 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105312.00,A,4131.46408,N,07040.27716,W,0.253,0.00,150421,,,A*70
2021-04-15T10:53:13.978Z,1618483993.978 [NAL9602](INFO): GPS fix at 20210415T105312: (41.524401, -70.671286)
2021-04-15T10:53:16.802Z,1618483996.802 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105315.00,A,4131.46442,N,07040.27811,W,0.739,0.00,150421,,,A*78
2021-04-15T10:53:16.805Z,1618483996.805 [NAL9602](INFO): GPS fix at 20210415T105315: (41.524407, -70.671302)
2021-04-15T10:53:20.032Z,1618484000.032 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105318.00,A,4131.46464,N,07040.27870,W,0.583,0.00,150421,,,A*75
2021-04-15T10:53:20.034Z,1618484000.034 [NAL9602](INFO): GPS fix at 20210415T105318: (41.524411, -70.671312)
2021-04-15T10:53:22.860Z,1618484002.860 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105321.00,A,4131.46497,N,07040.27898,W,0.719,0.00,150421,,,A*74
2021-04-15T10:53:22.862Z,1618484002.862 [NAL9602](INFO): GPS fix at 20210415T105321: (41.524416, -70.671316)
2021-04-15T10:53:26.116Z,1618484006.116 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105324.00,A,4131.46524,N,07040.27931,W,0.564,0.00,150421,,,A*72
2021-04-15T10:53:26.118Z,1618484006.118 [NAL9602](INFO): GPS fix at 20210415T105324: (41.524421, -70.671322)
2021-04-15T10:53:28.922Z,1618484008.922 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105327.00,A,4131.46516,N,07040.27952,W,0.019,0.00,150421,,,A*7A
2021-04-15T10:53:28.925Z,1618484008.925 [NAL9602](INFO): GPS fix at 20210415T105327: (41.524419, -70.671325)
2021-04-15T10:53:31.770Z,1618484011.770 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105330.00,A,4131.46516,N,07040.27957,W,0.641,0.00,150421,,,A*72
2021-04-15T10:53:31.773Z,1618484011.773 [NAL9602](INFO): GPS fix at 20210415T105330: (41.524419, -70.671326)
2021-04-15T10:53:34.995Z,1618484014.995 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105333.00,A,4131.46504,N,07040.28047,W,0.350,0.00,150421,,,A*70
2021-04-15T10:53:34.997Z,1618484014.997 [NAL9602](INFO): GPS fix at 20210415T105333: (41.524417, -70.671341)
2021-04-15T10:53:37.820Z,1618484017.820 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105336.00,A,4131.46507,N,07040.28060,W,0.272,262.63,150421,,,A*71
2021-04-15T10:53:37.822Z,1618484017.822 [NAL9602](INFO): GPS fix at 20210415T105336: (41.524418, -70.671343)
2021-04-15T10:53:41.078Z,1618484021.078 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105339.00,A,4131.46513,N,07040.28063,W,0.272,262.63,150421,,,A*78
2021-04-15T10:53:41.089Z,1618484021.089 [NAL9602](INFO): GPS fix at 20210415T105339: (41.524419, -70.671344)
2021-04-15T10:53:43.892Z,1618484023.892 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105342.00,A,4131.46516,N,07040.28075,W,0.058,262.63,150421,,,A*7C
2021-04-15T10:53:43.894Z,1618484023.894 [NAL9602](INFO): GPS fix at 20210415T105342: (41.524419, -70.671346)
2021-04-15T10:53:47.114Z,1618484027.114 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105345.00,A,4131.46511,N,07040.28104,W,0.253,262.63,150421,,,A*72
2021-04-15T10:53:47.117Z,1618484027.117 [NAL9602](INFO): GPS fix at 20210415T105345: (41.524419, -70.671351)
2021-04-15T10:53:49.943Z,1618484029.943 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105348.00,A,4131.46503,N,07040.28128,W,0.058,262.63,150421,,,A*7B
2021-04-15T10:53:49.945Z,1618484029.945 [NAL9602](INFO): GPS fix at 20210415T105348: (41.524417, -70.671355)
2021-04-15T10:53:52.774Z,1618484032.774 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105351.00,A,4131.46498,N,07040.28131,W,0.233,262.63,150421,,,A*77
2021-04-15T10:53:52.777Z,1618484032.777 [NAL9602](INFO): GPS fix at 20210415T105351: (41.524416, -70.671355)
2021-04-15T10:53:56.000Z,1618484036.000 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105354.00,A,4131.46492,N,07040.28137,W,0.194,262.63,150421,,,A*70
2021-04-15T10:53:56.002Z,1618484036.002 [NAL9602](INFO): GPS fix at 20210415T105354: (41.524415, -70.671356)
2021-04-15T10:53:58.828Z,1618484038.828 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105357.00,A,4131.46486,N,07040.28128,W,0.097,262.63,150421,,,A*7A
2021-04-15T10:53:58.830Z,1618484038.830 [NAL9602](INFO): GPS fix at 20210415T105357: (41.524414, -70.671355)
2021-04-15T10:54:02.065Z,1618484042.065 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105400.00,A,4131.46477,N,07040.28126,W,0.272,262.63,150421,,,A*76
2021-04-15T10:54:02.067Z,1618484042.067 [NAL9602](INFO): GPS fix at 20210415T105400: (41.524413, -70.671354)
2021-04-15T10:54:04.888Z,1618484044.888 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105403.00,A,4131.46476,N,07040.28109,W,0.214,262.63,150421,,,A*79
2021-04-15T10:54:04.890Z,1618484044.890 [NAL9602](INFO): GPS fix at 20210415T105403: (41.524413, -70.671352)
2021-04-15T10:54:08.121Z,1618484048.121 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105406.00,A,4131.46470,N,07040.28101,W,0.175,262.63,150421,,,A*76
2021-04-15T10:54:08.123Z,1618484048.123 [NAL9602](INFO): GPS fix at 20210415T105406: (41.524412, -70.671350)
2021-04-15T10:54:10.948Z,1618484050.948 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105409.00,A,4131.46464,N,07040.28099,W,0.214,262.63,150421,,,A*78
2021-04-15T10:54:10.950Z,1618484050.950 [NAL9602](INFO): GPS fix at 20210415T105409: (41.524411, -70.671350)
2021-04-15T10:54:13.780Z,1618484053.780 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105412.00,A,4131.46459,N,07040.28089,W,0.039,262.63,150421,,,A*70
2021-04-15T10:54:13.782Z,1618484053.782 [NAL9602](INFO): GPS fix at 20210415T105412: (41.524410, -70.671348)
2021-04-15T10:54:17.035Z,1618484057.035 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105415.00,A,4131.46447,N,07040.28093,W,0.194,262.63,150421,,,A*75
2021-04-15T10:54:17.037Z,1618484057.037 [NAL9602](INFO): GPS fix at 20210415T105415: (41.524408, -70.671349)
2021-04-15T10:54:19.836Z,1618484059.836 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105418.00,A,4131.46434,N,07040.28090,W,0.039,262.63,150421,,,A*79
2021-04-15T10:54:19.838Z,1618484059.838 [NAL9602](INFO): GPS fix at 20210415T105418: (41.524406, -70.671348)
2021-04-15T10:54:23.074Z,1618484063.074 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105421.00,A,4131.46423,N,07040.28086,W,0.156,262.63,150421,,,A*7A
2021-04-15T10:54:23.077Z,1618484063.077 [NAL9602](INFO): GPS fix at 20210415T105421: (41.524404, -70.671348)
2021-04-15T10:54:25.896Z,1618484065.896 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105424.00,A,4131.46397,N,07040.28079,W,0.272,262.63,150421,,,A*72
2021-04-15T10:54:25.898Z,1618484065.898 [NAL9602](INFO): GPS fix at 20210415T105424: (41.524400, -70.671346)
2021-04-15T10:54:29.131Z,1618484069.131 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105427.00,A,4131.46366,N,07040.28066,W,0.330,262.63,150421,,,A*76
2021-04-15T10:54:29.134Z,1618484069.134 [NAL9602](INFO): GPS fix at 20210415T105427: (41.524394, -70.671344)
2021-04-15T10:54:31.724Z,1618484071.724 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2021-04-15T10:54:31.959Z,1618484071.959 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105430.00,A,4131.46345,N,07040.28056,W,0.311,262.63,150421,,,A*71
2021-04-15T10:54:31.961Z,1618484071.961 [NAL9602](INFO): GPS fix at 20210415T105430: (41.524391, -70.671343)
2021-04-15T10:54:32.076Z,1618484072.076 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 15.660000
2021-04-15T10:54:32.077Z,1618484072.077 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2021-04-15T10:54:32.077Z,1618484072.077 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2021-04-15T10:54:32.480Z,1618484072.480 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2021-04-15T10:54:32.481Z,1618484072.481 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2021-04-15T10:54:32.481Z,1618484072.481 [IBIT](IMPORTANT): Pressure:6.554482 PSI
2021-04-15T10:54:32.481Z,1618484072.481 [IBIT](IMPORTANT): Humidity:5.341228 %
2021-04-15T10:54:32.888Z,1618484072.888 [IBIT](IMPORTANT): Vehicle Pitch:-0.235443 degrees
2021-04-15T10:54:32.889Z,1618484072.889 [IBIT](IMPORTANT): Vehicle  Roll:-0.932124 degrees
2021-04-15T10:54:32.889Z,1618484072.889 [IBIT](IMPORTANT): Vehicle  Heading:50.631165 degrees
2021-04-15T10:54:33.300Z,1618484073.300 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2021-04-15T10:54:33.300Z,1618484073.300 [IBIT](IMPORTANT): buoyancyNeutral: 375.000000 cc
2021-04-15T10:54:33.301Z,1618484073.301 [IBIT](IMPORTANT): massDefault: 1.200000 cm
2021-04-15T10:54:33.301Z,1618484073.301 [IBIT](IMPORTANT): stopDepth: 105.000000 m
2021-04-15T10:54:33.301Z,1618484073.301 [IBIT](IMPORTANT): abortDepth: 150.000000 m
2021-04-15T10:54:33.301Z,1618484073.301 [IBIT](IMPORTANT): IBIT FAILED
2021-04-15T10:54:33.608Z,1618484073.608 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-15T10:48:34.1Z
2021-04-15T10:54:33.608Z,1618484073.608 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T10:54:33.608Z,1618484073.608 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T10:54:33.988Z,1618484073.988 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-04-15T10:54:37.866Z,1618484077.866 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20210415T104405/Courier0004.lzma
2021-04-15T10:54:38.869Z,1618484078.869 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0004.lzma.bak
2021-04-15T10:54:38.869Z,1618484078.869 [DataOverHttps](INFO): SBD MOMSN=105862
2021-04-15T10:54:47.909Z,1618484087.909 [DataOverHttps](INFO): Sending 898 bytes from file Logs/20210415T104405/Express0005.lzma
2021-04-15T10:54:48.908Z,1618484088.908 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0005.lzma.bak
2021-04-15T10:54:48.909Z,1618484088.909 [DataOverHttps](INFO): SBD MOMSN=105865
2021-04-15T10:54:50.159Z,1618484090.159 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T10:54:50.159Z,1618484090.159 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T10:54:50.159Z,1618484090.159 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T10:55:04.297Z,1618484104.297 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T10:56:20.265Z,1618484180.265 [CommandLine](IMPORTANT): got command ibit
2021-04-15T10:56:20.738Z,1618484180.738 [IBIT](IMPORTANT): Beginning Initiated BIT
2021-04-15T10:56:20.738Z,1618484180.738 [IBIT](IMPORTANT): Beginning control surface checks.
2021-04-15T10:56:20.745Z,1618484180.745 [CBIT](IMPORTANT): Beginning ground fault scan
2021-04-15T10:56:22.266Z,1618484182.266 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,105620.00,A,4131.46326,N,07040.28012,W,0.330,262.63,150421,,,D*71
2021-04-15T10:56:22.270Z,1618484182.270 [NAL9602](INFO): GPS fix at 20210415T105620: (41.524388, -70.671335)
2021-04-15T10:56:31.592Z,1618484191.592 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.009552
CHAN A1 (24V): -0.028302
CHAN A2 (12V): -0.007030
CHAN A3 (5V): -0.002358
CHAN B0 (3.3V): 0.000211
CHAN B1 (3.15aV): -0.000316
CHAN B2 (3.15bV): 0.000378
CHAN B3 (GND): 0.002147
OPEN: 0.005079
Full Scale Calc: 4.765 mA, -1.589 mA
2021-04-15T10:56:52.974Z,1618484212.974 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-04-15T10:56:53.047Z,1618484213.047 [NAL9602](FAULT): received: 
+CSQ:0

OK509, 2, 0, 0, 0

OK
2021-04-15T10:56:53.047Z,1618484213.047 [NAL9602] Data Fault, FailCount= 1
2021-04-15T10:56:53.047Z,1618484213.047 [NAL9602](ERROR): Data Fault
2021-04-15T10:56:53.123Z,1618484213.123 [CBIT](ERROR): Data Fault in component: NAL9602
2021-04-15T10:56:53.369Z,1618484213.369 [NAL9602](INFO): Powering down
2021-04-15T10:56:54.272Z,1618484214.272 [CBIT](INFO): Clearing failed state for component NAL9602
2021-04-15T10:56:54.272Z,1618484214.272 [NAL9602] No Fault, FailCount= 1
2021-04-15T10:57:23.681Z,1618484243.681 [NAL9602](INFO): Powering up NAL9602
2021-04-15T10:57:34.577Z,1618484254.577 [NAL9602](INFO): NAL9602 initialized
2021-04-15T10:57:50.799Z,1618484270.799 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 2
Latitude: 41.524387 Longitude: -70.671333
2021-04-15T10:57:51.203Z,1618484271.203 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 15.660000
2021-04-15T10:57:51.204Z,1618484271.204 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2021-04-15T10:57:51.204Z,1618484271.204 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2021-04-15T10:57:51.564Z,1618484271.564 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2021-04-15T10:57:51.565Z,1618484271.565 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2021-04-15T10:57:51.565Z,1618484271.565 [IBIT](IMPORTANT): Pressure:6.616351 PSI
2021-04-15T10:57:51.565Z,1618484271.565 [IBIT](IMPORTANT): Humidity:5.292394 %
2021-04-15T10:57:52.031Z,1618484272.031 [IBIT](IMPORTANT): Vehicle Pitch:-0.221735 degrees
2021-04-15T10:57:52.032Z,1618484272.032 [IBIT](IMPORTANT): Vehicle  Roll:-0.929798 degrees
2021-04-15T10:57:52.033Z,1618484272.033 [IBIT](IMPORTANT): Vehicle  Heading:50.653564 degrees
2021-04-15T10:57:52.422Z,1618484272.422 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2021-04-15T10:57:52.422Z,1618484272.422 [IBIT](IMPORTANT): buoyancyNeutral: 375.000000 cc
2021-04-15T10:57:52.422Z,1618484272.422 [IBIT](IMPORTANT): massDefault: 1.200000 cm
2021-04-15T10:57:52.422Z,1618484272.422 [IBIT](IMPORTANT): stopDepth: 105.000000 m
2021-04-15T10:57:52.427Z,1618484272.427 [IBIT](IMPORTANT): abortDepth: 150.000000 m
2021-04-15T10:57:52.427Z,1618484272.427 [IBIT](IMPORTANT): IBIT PASSED
2021-04-15T10:58:04.482Z,1618484284.482 [NAL9602](INFO): SBD MO Status=2, MOMSN=15509, MT Status=2, MTMSN=0
2021-04-15T10:58:04.483Z,1618484284.483 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-15T10:58:12.170Z,1618484292.170 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-04-15T10:59:06.694Z,1618484346.694 [NAL9602](INFO): SBD MO Status=2, MOMSN=15509, MT Status=2, MTMSN=0
2021-04-15T10:59:06.694Z,1618484346.694 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-15T10:59:18.691Z,1618484358.691 [CommandLine](IMPORTANT): got command failComponent
2021-04-15T10:59:18.691Z,1618484358.691 [CommandLine](IMPORTANT): Failed components:
2021-04-15T10:59:18.691Z,1618484358.691 [CommandLine](IMPORTANT): No failed Components.
2021-04-15T10:59:32.175Z,1618484372.175 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2021-04-15T10:59:36.990Z,1618484376.990 [NAL9602](INFO): SBD MO Status=2, MOMSN=15509, MT Status=2, MTMSN=0
2021-04-15T10:59:36.990Z,1618484376.990 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-15T10:59:50.752Z,1618484390.752 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T10:59:50.752Z,1618484390.752 [Default:CheckIn:C.Wait] Stopped
2021-04-15T10:59:50.752Z,1618484390.752 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T10:59:50.752Z,1618484390.752 [Default:CheckIn:D] Running Loop=1
2021-04-15T10:59:51.192Z,1618484391.192 [Default:CheckIn:D] Stopped
2021-04-15T10:59:51.192Z,1618484391.192 [Default:CheckIn:E] Running Loop=1
2021-04-15T10:59:51.547Z,1618484391.547 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.514139 min 
2021-04-15T10:59:51.547Z,1618484391.547 [Default:CheckIn:E] Stopped
2021-04-15T10:59:51.547Z,1618484391.547 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T10:59:51.547Z,1618484391.547 [Default:CheckIn] Stopped
2021-04-15T10:59:51.548Z,1618484391.548 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T10:59:51.548Z,1618484391.548 [Default:CheckIn](INFO): Running loop #2
2021-04-15T10:59:51.548Z,1618484391.548 [Default:CheckIn] Running Loop=2
2021-04-15T10:59:51.548Z,1618484391.548 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T10:59:51.548Z,1618484391.548 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T10:59:52.375Z,1618484392.375 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2021-04-15T11:00:30.726Z,1618484430.726 [NAL9602](INFO): SBD MO Status=2, MOMSN=15509, MT Status=2, MTMSN=0
2021-04-15T11:00:30.726Z,1618484430.726 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-15T11:01:30.918Z,1618484490.918 [NAL9602](INFO): SBD MO Status=2, MOMSN=15509, MT Status=2, MTMSN=0
2021-04-15T11:01:30.918Z,1618484490.918 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-15T11:01:31.322Z,1618484491.322 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-04-15T11:01:32.534Z,1618484492.534 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,110131.00,A,4131.46406,N,07040.28640,W,0.097,316.64,150421,,,A*78
2021-04-15T11:01:32.536Z,1618484492.536 [NAL9602](INFO): GPS fix at 20210415T110131: (41.524401, -70.671440)
2021-04-15T11:01:32.587Z,1618484492.587 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T11:01:32.588Z,1618484492.588 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T11:01:36.610Z,1618484496.610 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210415T104405/Courier0007.lzma
2021-04-15T11:01:37.613Z,1618484497.613 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0007.lzma.bak
2021-04-15T11:01:37.613Z,1618484497.613 [DataOverHttps](INFO): SBD MOMSN=105897
2021-04-15T11:01:46.652Z,1618484506.652 [DataOverHttps](INFO): Sending 910 bytes from file Logs/20210415T104405/Express0008.lzma
2021-04-15T11:01:47.653Z,1618484507.653 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0008.lzma.bak
2021-04-15T11:01:47.653Z,1618484507.653 [DataOverHttps](INFO): SBD MOMSN=105900
2021-04-15T11:01:48.964Z,1618484508.964 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T11:01:48.964Z,1618484508.964 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T11:01:48.964Z,1618484508.964 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T11:02:05.497Z,1618484525.497 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T11:06:49.580Z,1618484809.580 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T11:06:49.580Z,1618484809.580 [Default:CheckIn:C.Wait] Stopped
2021-04-15T11:06:49.580Z,1618484809.580 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T11:06:49.580Z,1618484809.580 [Default:CheckIn:D] Running Loop=1
2021-04-15T11:06:49.946Z,1618484809.946 [Default:CheckIn:D] Stopped
2021-04-15T11:06:49.947Z,1618484809.947 [Default:CheckIn:E] Running Loop=1
2021-04-15T11:06:50.350Z,1618484810.350 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.493386 min 
2021-04-15T11:06:50.350Z,1618484810.350 [Default:CheckIn:E] Stopped
2021-04-15T11:06:50.351Z,1618484810.351 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T11:06:50.351Z,1618484810.351 [Default:CheckIn] Stopped
2021-04-15T11:06:50.351Z,1618484810.351 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T11:06:50.351Z,1618484810.351 [Default:CheckIn](INFO): Running loop #3
2021-04-15T11:06:50.351Z,1618484810.351 [Default:CheckIn] Running Loop=3
2021-04-15T11:06:50.351Z,1618484810.351 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T11:06:50.351Z,1618484810.351 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T11:06:52.365Z,1618484812.365 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,110651.00,A,4131.46603,N,07040.28540,W,0.078,271.26,150421,,,A*7A
2021-04-15T11:06:52.367Z,1618484812.367 [NAL9602](INFO): GPS fix at 20210415T110651: (41.524434, -70.671423)
2021-04-15T11:06:52.398Z,1618484812.398 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T11:06:52.398Z,1618484812.398 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T11:06:55.960Z,1618484815.960 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210415T104405/Courier0010.lzma
2021-04-15T11:06:56.961Z,1618484816.961 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0010.lzma.bak
2021-04-15T11:06:56.961Z,1618484816.961 [DataOverHttps](INFO): SBD MOMSN=105930
2021-04-15T11:07:05.998Z,1618484825.998 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20210415T104405/Express0011.lzma
2021-04-15T11:07:07.001Z,1618484827.001 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0011.lzma.bak
2021-04-15T11:07:07.001Z,1618484827.001 [DataOverHttps](INFO): SBD MOMSN=105933
2021-04-15T11:07:08.143Z,1618484828.143 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T11:07:08.143Z,1618484828.143 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T11:07:08.143Z,1618484828.143 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T11:08:10.338Z,1618484890.338 [NAL9602](INFO): SBD MO Status=0, MOMSN=15509, MT Status=0, MTMSN=0
2021-04-15T11:08:10.338Z,1618484890.338 [NAL9602](INFO): No messages in MT queue
2021-04-15T11:08:41.033Z,1618484921.033 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T11:10:06.309Z,1618485006.309 [RDI_PathfinderUp](ERROR): only read 1 of 4 data items
2021-04-15T11:10:16.379Z,1618485016.379 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-04-15T11:11:57.387Z,1618485117.387 [RDI_Pathfinder](ERROR): only read 1 of 4 data items
2021-04-15T11:12:08.711Z,1618485128.711 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T11:12:08.711Z,1618485128.711 [Default:CheckIn:C.Wait] Stopped
2021-04-15T11:12:08.711Z,1618485128.711 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T11:12:08.711Z,1618485128.711 [Default:CheckIn:D] Running Loop=1
2021-04-15T11:12:09.141Z,1618485129.141 [Default:CheckIn:D] Stopped
2021-04-15T11:12:09.141Z,1618485129.141 [Default:CheckIn:E] Running Loop=1
2021-04-15T11:12:09.554Z,1618485129.554 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.813300 min 
2021-04-15T11:12:09.554Z,1618485129.554 [Default:CheckIn:E] Stopped
2021-04-15T11:12:09.554Z,1618485129.554 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T11:12:09.554Z,1618485129.554 [Default:CheckIn] Stopped
2021-04-15T11:12:09.554Z,1618485129.554 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T11:12:09.554Z,1618485129.554 [Default:CheckIn](INFO): Running loop #4
2021-04-15T11:12:09.555Z,1618485129.555 [Default:CheckIn] Running Loop=4
2021-04-15T11:12:09.555Z,1618485129.555 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T11:12:09.555Z,1618485129.555 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T11:12:11.530Z,1618485131.530 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,111210.00,A,4131.46492,N,07040.28746,W,0.039,264.73,150421,,,A*75
2021-04-15T11:12:11.532Z,1618485131.532 [NAL9602](INFO): GPS fix at 20210415T111210: (41.524415, -70.671458)
2021-04-15T11:12:11.542Z,1618485131.542 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T11:12:11.542Z,1618485131.542 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T11:12:15.310Z,1618485135.310 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210415T104405/Courier0013.lzma
2021-04-15T11:12:16.313Z,1618485136.313 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0013.lzma.bak
2021-04-15T11:12:16.313Z,1618485136.313 [DataOverHttps](INFO): SBD MOMSN=105937
2021-04-15T11:12:24.856Z,1618485144.856 [NAL9602](INFO): SBD MO Status=0, MOMSN=15510, MT Status=0, MTMSN=0
2021-04-15T11:12:24.856Z,1618485144.856 [NAL9602](INFO): No messages in MT queue
2021-04-15T11:12:25.350Z,1618485145.350 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20210415T104405/Express0014.lzma
2021-04-15T11:12:26.353Z,1618485146.353 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0014.lzma.bak
2021-04-15T11:12:26.353Z,1618485146.353 [DataOverHttps](INFO): SBD MOMSN=105940
2021-04-15T11:12:27.746Z,1618485147.746 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T11:12:27.746Z,1618485147.746 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T11:12:27.746Z,1618485147.746 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T11:12:55.565Z,1618485175.565 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T11:14:40.208Z,1618485280.208 [RDI_Pathfinder](ERROR): only read 1 of 4 data items
2021-04-15T11:14:46.321Z,1618485286.321 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2021-04-15T11:17:28.329Z,1618485448.329 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T11:17:28.330Z,1618485448.330 [Default:CheckIn:C.Wait] Stopped
2021-04-15T11:17:28.330Z,1618485448.330 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T11:17:28.330Z,1618485448.330 [Default:CheckIn:D] Running Loop=1
2021-04-15T11:17:28.685Z,1618485448.685 [Default:CheckIn:D] Stopped
2021-04-15T11:17:28.685Z,1618485448.685 [Default:CheckIn:E] Running Loop=1
2021-04-15T11:17:29.093Z,1618485449.093 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.139020 min 
2021-04-15T11:17:29.093Z,1618485449.093 [Default:CheckIn:E] Stopped
2021-04-15T11:17:29.093Z,1618485449.093 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T11:17:29.094Z,1618485449.094 [Default:CheckIn] Stopped
2021-04-15T11:17:29.094Z,1618485449.094 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T11:17:29.094Z,1618485449.094 [Default:CheckIn](INFO): Running loop #5
2021-04-15T11:17:29.094Z,1618485449.094 [Default:CheckIn] Running Loop=5
2021-04-15T11:17:29.094Z,1618485449.094 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T11:17:29.094Z,1618485449.094 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T11:17:31.141Z,1618485451.141 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,111730.00,A,4131.46589,N,07040.28552,W,0.272,264.73,150421,,,A*73
2021-04-15T11:17:31.144Z,1618485451.144 [NAL9602](INFO): GPS fix at 20210415T111730: (41.524431, -70.671425)
2021-04-15T11:17:31.182Z,1618485451.182 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T11:17:31.182Z,1618485451.182 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T11:17:34.651Z,1618485454.651 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20210415T104405/Courier0016.lzma
2021-04-15T11:17:35.653Z,1618485455.653 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0016.lzma.bak
2021-04-15T11:17:35.653Z,1618485455.653 [DataOverHttps](INFO): SBD MOMSN=105944
2021-04-15T11:17:44.694Z,1618485464.694 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20210415T104405/Express0017.lzma
2021-04-15T11:17:45.693Z,1618485465.693 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0017.lzma.bak
2021-04-15T11:17:45.693Z,1618485465.693 [DataOverHttps](INFO): SBD MOMSN=105947
2021-04-15T11:17:46.880Z,1618485466.880 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T11:17:46.880Z,1618485466.880 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T11:17:46.880Z,1618485466.880 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T11:19:40.774Z,1618485580.774 [NAL9602](INFO): SBD MO Status=0, MOMSN=15511, MT Status=0, MTMSN=0
2021-04-15T11:19:40.774Z,1618485580.774 [NAL9602](INFO): No messages in MT queue
2021-04-15T11:20:11.476Z,1618485611.476 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T11:21:53.327Z,1618485713.327 [RDI_PathfinderUp](ERROR): DVL uart error: serial timeout
2021-04-15T11:21:53.327Z,1618485713.327 [RDI_PathfinderUp] Communications Fault, FailCount= 1
2021-04-15T11:21:53.327Z,1618485713.327 [RDI_PathfinderUp](ERROR): Communications Fault
2021-04-15T11:21:53.352Z,1618485713.352 [CBIT](ERROR): Communications Fault in component: RDI_PathfinderUp
2021-04-15T11:21:53.767Z,1618485713.767 [RDI_PathfinderUp](INFO): Powering down
2021-04-15T11:21:54.578Z,1618485714.578 [CBIT](INFO): Clearing failed state for component RDI_PathfinderUp
2021-04-15T11:21:54.578Z,1618485714.578 [RDI_PathfinderUp] No Fault, FailCount= 1
2021-04-15T11:22:47.452Z,1618485767.452 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T11:22:47.452Z,1618485767.452 [Default:CheckIn:C.Wait] Stopped
2021-04-15T11:22:47.452Z,1618485767.452 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T11:22:47.452Z,1618485767.452 [Default:CheckIn:D] Running Loop=1
2021-04-15T11:22:47.855Z,1618485767.855 [Default:CheckIn:D] Stopped
2021-04-15T11:22:47.855Z,1618485767.855 [Default:CheckIn:E] Running Loop=1
2021-04-15T11:22:48.286Z,1618485768.286 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.458529 min 
2021-04-15T11:22:48.286Z,1618485768.286 [Default:CheckIn:E] Stopped
2021-04-15T11:22:48.286Z,1618485768.286 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T11:22:48.286Z,1618485768.286 [Default:CheckIn] Stopped
2021-04-15T11:22:48.286Z,1618485768.286 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T11:22:48.286Z,1618485768.286 [Default:CheckIn](INFO): Running loop #6
2021-04-15T11:22:48.286Z,1618485768.286 [Default:CheckIn] Running Loop=6
2021-04-15T11:22:48.287Z,1618485768.287 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T11:22:48.287Z,1618485768.287 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T11:22:50.258Z,1618485770.258 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,112249.00,A,4131.46764,N,07040.29358,W,0.408,264.73,150421,,,A*7C
2021-04-15T11:22:50.261Z,1618485770.261 [NAL9602](INFO): GPS fix at 20210415T112249: (41.524461, -70.671560)
2021-04-15T11:22:50.320Z,1618485770.320 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T11:22:50.320Z,1618485770.320 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T11:22:53.968Z,1618485773.968 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20210415T104405/Courier0019.lzma
2021-04-15T11:22:54.964Z,1618485774.964 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0019.lzma.bak
2021-04-15T11:22:54.964Z,1618485774.964 [DataOverHttps](INFO): SBD MOMSN=105951
2021-04-15T11:23:03.586Z,1618485783.586 [NAL9602](INFO): SBD MO Status=0, MOMSN=15512, MT Status=0, MTMSN=0
2021-04-15T11:23:03.586Z,1618485783.586 [NAL9602](INFO): No messages in MT queue
2021-04-15T11:23:04.014Z,1618485784.014 [DataOverHttps](INFO): Sending 118 bytes from file Logs/20210415T104405/Express0020.lzma
2021-04-15T11:23:05.017Z,1618485785.017 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0020.lzma.bak
2021-04-15T11:23:05.017Z,1618485785.017 [DataOverHttps](INFO): SBD MOMSN=105954
2021-04-15T11:23:06.074Z,1618485786.074 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T11:23:06.074Z,1618485786.074 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T11:23:06.074Z,1618485786.074 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T11:23:34.289Z,1618485814.289 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T11:24:23.180Z,1618485863.180 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-04-15T11:28:03.782Z,1618486083.782 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2021-04-15T11:28:06.612Z,1618486086.612 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T11:28:06.612Z,1618486086.612 [Default:CheckIn:C.Wait] Stopped
2021-04-15T11:28:06.612Z,1618486086.612 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T11:28:06.612Z,1618486086.612 [Default:CheckIn:D] Running Loop=1
2021-04-15T11:28:07.031Z,1618486087.031 [Default:CheckIn:D] Stopped
2021-04-15T11:28:07.031Z,1618486087.031 [Default:CheckIn:E] Running Loop=1
2021-04-15T11:28:07.430Z,1618486087.430 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.778121 min 
2021-04-15T11:28:07.430Z,1618486087.430 [Default:CheckIn:E] Stopped
2021-04-15T11:28:07.430Z,1618486087.430 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T11:28:07.430Z,1618486087.430 [Default:CheckIn] Stopped
2021-04-15T11:28:07.430Z,1618486087.430 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T11:28:07.430Z,1618486087.430 [Default:CheckIn](INFO): Running loop #7
2021-04-15T11:28:07.430Z,1618486087.430 [Default:CheckIn] Running Loop=7
2021-04-15T11:28:07.430Z,1618486087.430 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T11:28:07.430Z,1618486087.430 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T11:28:09.423Z,1618486089.423 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,112808.00,A,4131.47161,N,07040.28660,W,0.019,298.89,150421,,,A*7C
2021-04-15T11:28:09.425Z,1618486089.425 [NAL9602](INFO): GPS fix at 20210415T112808: (41.524527, -70.671443)
2021-04-15T11:28:09.436Z,1618486089.436 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T11:28:09.436Z,1618486089.436 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T11:28:13.282Z,1618486093.282 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210415T104405/Courier0022.lzma
2021-04-15T11:28:14.293Z,1618486094.293 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0022.lzma.bak
2021-04-15T11:28:14.293Z,1618486094.293 [DataOverHttps](INFO): SBD MOMSN=105958
2021-04-15T11:28:24.334Z,1618486104.334 [DataOverHttps](INFO): Sending 118 bytes from file Logs/20210415T104405/Express0023.lzma
2021-04-15T11:28:25.337Z,1618486105.337 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0023.lzma.bak
2021-04-15T11:28:25.337Z,1618486105.337 [DataOverHttps](INFO): SBD MOMSN=105961
2021-04-15T11:28:26.823Z,1618486106.823 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T11:28:26.823Z,1618486106.823 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T11:28:26.823Z,1618486106.823 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T11:28:40.534Z,1618486120.534 [NAL9602](INFO): SBD MO Status=0, MOMSN=15513, MT Status=0, MTMSN=0
2021-04-15T11:28:40.534Z,1618486120.534 [NAL9602](INFO): No messages in MT queue
2021-04-15T11:29:11.245Z,1618486151.245 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T11:33:27.401Z,1618486407.401 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T11:33:27.401Z,1618486407.401 [Default:CheckIn:C.Wait] Stopped
2021-04-15T11:33:27.402Z,1618486407.402 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T11:33:27.402Z,1618486407.402 [Default:CheckIn:D] Running Loop=1
2021-04-15T11:33:27.798Z,1618486407.798 [Default:CheckIn:D] Stopped
2021-04-15T11:33:27.798Z,1618486407.798 [Default:CheckIn:E] Running Loop=1
2021-04-15T11:33:28.217Z,1618486408.217 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.124247 min 
2021-04-15T11:33:28.218Z,1618486408.218 [Default:CheckIn:E] Stopped
2021-04-15T11:33:28.218Z,1618486408.218 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T11:33:28.218Z,1618486408.218 [Default:CheckIn] Stopped
2021-04-15T11:33:28.218Z,1618486408.218 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T11:33:28.218Z,1618486408.218 [Default:CheckIn](INFO): Running loop #8
2021-04-15T11:33:28.218Z,1618486408.218 [Default:CheckIn] Running Loop=8
2021-04-15T11:33:28.218Z,1618486408.218 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T11:33:28.218Z,1618486408.218 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T11:33:30.206Z,1618486410.206 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,113329.00,A,4131.47101,N,07040.27535,W,1.808,297.09,150421,,,A*71
2021-04-15T11:33:30.209Z,1618486410.209 [NAL9602](INFO): GPS fix at 20210415T113329: (41.524517, -70.671256)
2021-04-15T11:33:30.230Z,1618486410.230 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T11:33:30.230Z,1618486410.230 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T11:33:34.602Z,1618486414.602 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210415T104405/Courier0025.lzma
2021-04-15T11:33:35.605Z,1618486415.605 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0025.lzma.bak
2021-04-15T11:33:35.605Z,1618486415.605 [DataOverHttps](INFO): SBD MOMSN=105965
2021-04-15T11:33:44.643Z,1618486424.643 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20210415T104405/Express0026.lzma
2021-04-15T11:33:45.645Z,1618486425.645 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0026.lzma.bak
2021-04-15T11:33:45.645Z,1618486425.645 [DataOverHttps](INFO): SBD MOMSN=105968
2021-04-15T11:33:46.804Z,1618486426.804 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T11:33:46.805Z,1618486426.805 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T11:33:46.805Z,1618486426.805 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T11:35:56.458Z,1618486556.458 [NAL9602](INFO): SBD MO Status=2, MOMSN=15514, MT Status=2, MTMSN=0
2021-04-15T11:35:56.458Z,1618486556.458 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-15T11:36:04.126Z,1618486564.126 [NAL9602](INFO): SBD MO Status=0, MOMSN=15514, MT Status=0, MTMSN=0
2021-04-15T11:36:04.126Z,1618486564.126 [NAL9602](INFO): No messages in MT queue
2021-04-15T11:36:34.833Z,1618486594.833 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T11:38:47.390Z,1618486727.390 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T11:38:47.390Z,1618486727.390 [Default:CheckIn:C.Wait] Stopped
2021-04-15T11:38:47.390Z,1618486727.390 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T11:38:47.390Z,1618486727.390 [Default:CheckIn:D] Running Loop=1
2021-04-15T11:38:47.767Z,1618486727.767 [Default:CheckIn:D] Stopped
2021-04-15T11:38:47.767Z,1618486727.767 [Default:CheckIn:E] Running Loop=1
2021-04-15T11:38:48.173Z,1618486728.173 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 50.457056 min 
2021-04-15T11:38:48.174Z,1618486728.174 [Default:CheckIn:E] Stopped
2021-04-15T11:38:48.174Z,1618486728.174 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T11:38:48.174Z,1618486728.174 [Default:CheckIn] Stopped
2021-04-15T11:38:48.174Z,1618486728.174 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T11:38:48.174Z,1618486728.174 [Default:CheckIn](INFO): Running loop #9
2021-04-15T11:38:48.174Z,1618486728.174 [Default:CheckIn] Running Loop=9
2021-04-15T11:38:48.174Z,1618486728.174 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T11:38:48.174Z,1618486728.174 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T11:38:50.185Z,1618486730.185 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,113849.00,A,4131.58110,N,07040.33237,W,0.505,34.77,150421,,,A*41
2021-04-15T11:38:50.188Z,1618486730.188 [NAL9602](INFO): GPS fix at 20210415T113849: (41.526352, -70.672206)
2021-04-15T11:38:50.219Z,1618486730.219 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T11:38:50.219Z,1618486730.219 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T11:38:53.918Z,1618486733.918 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210415T104405/Courier0028.lzma
2021-04-15T11:38:54.921Z,1618486734.921 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0028.lzma.bak
2021-04-15T11:38:54.921Z,1618486734.921 [DataOverHttps](INFO): SBD MOMSN=105972
2021-04-15T11:39:04.040Z,1618486744.040 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20210415T104405/Express0029.lzma
2021-04-15T11:39:04.964Z,1618486744.964 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0029.lzma.bak
2021-04-15T11:39:04.964Z,1618486744.964 [DataOverHttps](INFO): SBD MOMSN=105975
2021-04-15T11:39:06.357Z,1618486746.357 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T11:39:06.357Z,1618486746.357 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T11:39:06.357Z,1618486746.357 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T11:39:15.236Z,1618486755.236 [NAL9602](INFO): SBD MO Status=0, MOMSN=15515, MT Status=0, MTMSN=0
2021-04-15T11:39:15.236Z,1618486755.236 [NAL9602](INFO): No messages in MT queue
2021-04-15T11:39:45.928Z,1618486785.928 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T11:44:06.977Z,1618487046.977 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T11:44:06.977Z,1618487046.977 [Default:CheckIn:C.Wait] Stopped
2021-04-15T11:44:06.977Z,1618487046.977 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T11:44:06.977Z,1618487046.977 [Default:CheckIn:D] Running Loop=1
2021-04-15T11:44:07.411Z,1618487047.411 [Default:CheckIn:D] Stopped
2021-04-15T11:44:07.412Z,1618487047.412 [Default:CheckIn:E] Running Loop=1
2021-04-15T11:44:07.784Z,1618487047.784 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 55.784469 min 
2021-04-15T11:44:07.784Z,1618487047.784 [Default:CheckIn:E] Stopped
2021-04-15T11:44:07.785Z,1618487047.785 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T11:44:07.785Z,1618487047.785 [Default:CheckIn] Stopped
2021-04-15T11:44:07.785Z,1618487047.785 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T11:44:07.785Z,1618487047.785 [Default:CheckIn](INFO): Running loop #10
2021-04-15T11:44:07.785Z,1618487047.785 [Default:CheckIn] Running Loop=10
2021-04-15T11:44:07.785Z,1618487047.785 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T11:44:07.785Z,1618487047.785 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T11:44:09.804Z,1618487049.804 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,114409.00,A,4131.67659,N,07040.20860,W,2.391,8.71,150421,,,A*72
2021-04-15T11:44:09.806Z,1618487049.806 [NAL9602](INFO): GPS fix at 20210415T114409: (41.527943, -70.670143)
2021-04-15T11:44:09.831Z,1618487049.831 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T11:44:09.831Z,1618487049.831 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T11:44:14.254Z,1618487054.254 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210415T104405/Courier0031.lzma
2021-04-15T11:44:15.257Z,1618487055.257 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0031.lzma.bak
2021-04-15T11:44:15.257Z,1618487055.257 [DataOverHttps](INFO): SBD MOMSN=105980
2021-04-15T11:44:24.294Z,1618487064.294 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20210415T104405/Express0032.lzma
2021-04-15T11:44:25.145Z,1618487065.145 [NAL9602](INFO): SBD MO Status=0, MOMSN=15516, MT Status=0, MTMSN=0
2021-04-15T11:44:25.145Z,1618487065.145 [NAL9602](INFO): No messages in MT queue
2021-04-15T11:44:25.297Z,1618487065.297 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0032.lzma.bak
2021-04-15T11:44:25.297Z,1618487065.297 [DataOverHttps](INFO): SBD MOMSN=105983
2021-04-15T11:44:26.413Z,1618487066.413 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T11:44:26.414Z,1618487066.414 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T11:44:26.414Z,1618487066.414 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T11:44:55.849Z,1618487095.849 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T11:48:49.769Z,1618487329.769 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2021-04-15T11:49:26.968Z,1618487366.968 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T11:49:26.968Z,1618487366.968 [Default:CheckIn:C.Wait] Stopped
2021-04-15T11:49:26.968Z,1618487366.968 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T11:49:26.969Z,1618487366.969 [Default:CheckIn:D] Running Loop=1
2021-04-15T11:49:27.360Z,1618487367.360 [Default:CheckIn:D] Stopped
2021-04-15T11:49:27.360Z,1618487367.360 [Default:CheckIn:E] Running Loop=1
2021-04-15T11:49:27.766Z,1618487367.766 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 61.116947 min 
2021-04-15T11:49:27.766Z,1618487367.766 [Default:CheckIn:E] Stopped
2021-04-15T11:49:27.766Z,1618487367.766 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T11:49:27.766Z,1618487367.766 [Default:CheckIn] Stopped
2021-04-15T11:49:27.766Z,1618487367.766 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T11:49:27.766Z,1618487367.766 [Default:CheckIn](INFO): Running loop #11
2021-04-15T11:49:27.766Z,1618487367.766 [Default:CheckIn] Running Loop=11
2021-04-15T11:49:27.766Z,1618487367.766 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T11:49:27.766Z,1618487367.766 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T11:49:29.772Z,1618487369.772 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,114929.00,A,4131.70096,N,07040.21895,W,0.272,351.70,150421,,,A*75
2021-04-15T11:49:29.774Z,1618487369.774 [NAL9602](INFO): GPS fix at 20210415T114929: (41.528349, -70.670316)
2021-04-15T11:49:29.789Z,1618487369.789 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T11:49:29.789Z,1618487369.789 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T11:49:33.558Z,1618487373.558 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210415T104405/Courier0034.lzma
2021-04-15T11:49:34.562Z,1618487374.562 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0034.lzma.bak
2021-04-15T11:49:34.563Z,1618487374.563 [DataOverHttps](INFO): SBD MOMSN=105987
2021-04-15T11:49:43.606Z,1618487383.606 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20210415T104405/Express0035.lzma
2021-04-15T11:49:44.602Z,1618487384.602 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0035.lzma.bak
2021-04-15T11:49:44.602Z,1618487384.602 [DataOverHttps](INFO): SBD MOMSN=105990
2021-04-15T11:49:45.541Z,1618487385.541 [NAL9602](INFO): SBD MO Status=0, MOMSN=15517, MT Status=0, MTMSN=0
2021-04-15T11:49:45.542Z,1618487385.542 [NAL9602](INFO): No messages in MT queue
2021-04-15T11:49:45.937Z,1618487385.937 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T11:49:45.938Z,1618487385.938 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T11:49:45.938Z,1618487385.938 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T11:50:04.922Z,1618487404.922 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2021-04-15T11:50:16.225Z,1618487416.225 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T11:54:46.516Z,1618487686.516 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T11:54:46.516Z,1618487686.516 [Default:CheckIn:C.Wait] Stopped
2021-04-15T11:54:46.516Z,1618487686.516 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T11:54:46.516Z,1618487686.516 [Default:CheckIn:D] Running Loop=1
2021-04-15T11:54:46.992Z,1618487686.992 [Default:CheckIn:D] Stopped
2021-04-15T11:54:46.992Z,1618487686.992 [Default:CheckIn:E] Running Loop=1
2021-04-15T11:54:47.372Z,1618487687.372 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 66.444141 min 
2021-04-15T11:54:47.373Z,1618487687.373 [Default:CheckIn:E] Stopped
2021-04-15T11:54:47.373Z,1618487687.373 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T11:54:47.373Z,1618487687.373 [Default:CheckIn] Stopped
2021-04-15T11:54:47.373Z,1618487687.373 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T11:54:47.373Z,1618487687.373 [Default:CheckIn](INFO): Running loop #12
2021-04-15T11:54:47.373Z,1618487687.373 [Default:CheckIn] Running Loop=12
2021-04-15T11:54:47.373Z,1618487687.373 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T11:54:47.373Z,1618487687.373 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T11:54:49.351Z,1618487689.351 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,115448.00,A,4131.71328,N,07040.23008,W,0.039,331.31,150421,,,A*79
2021-04-15T11:54:49.353Z,1618487689.353 [NAL9602](INFO): GPS fix at 20210415T115448: (41.528555, -70.670501)
2021-04-15T11:54:49.390Z,1618487689.390 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T11:54:49.390Z,1618487689.390 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T11:54:52.906Z,1618487692.906 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210415T104405/Courier0037.lzma
2021-04-15T11:54:53.909Z,1618487693.909 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0037.lzma.bak
2021-04-15T11:54:53.909Z,1618487693.909 [DataOverHttps](INFO): SBD MOMSN=105994
2021-04-15T11:54:58.230Z,1618487698.230 [NAL9602](INFO): SBD MO Status=0, MOMSN=15518, MT Status=0, MTMSN=0
2021-04-15T11:54:58.230Z,1618487698.230 [NAL9602](INFO): No messages in MT queue
2021-04-15T11:55:02.947Z,1618487702.947 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20210415T104405/Express0038.lzma
2021-04-15T11:55:03.949Z,1618487703.949 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0038.lzma.bak
2021-04-15T11:55:03.949Z,1618487703.949 [DataOverHttps](INFO): SBD MOMSN=105997
2021-04-15T11:55:05.130Z,1618487705.130 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T11:55:05.130Z,1618487705.130 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T11:55:05.130Z,1618487705.130 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T11:55:28.961Z,1618487728.961 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T11:57:20.062Z,1618487840.062 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2021-04-15T11:57:30.178Z,1618487850.178 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2021-04-15T11:57:55.243Z,1618487875.243 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout
2021-04-15T11:57:55.243Z,1618487875.243 [RDI_Pathfinder] Communications Fault, FailCount= 1
2021-04-15T11:57:55.243Z,1618487875.243 [RDI_Pathfinder](ERROR): Communications Fault
2021-04-15T11:57:55.304Z,1618487875.304 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-04-15T11:57:55.703Z,1618487875.703 [RDI_Pathfinder](INFO): Powering down
2021-04-15T11:57:56.537Z,1618487876.537 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-04-15T11:57:56.537Z,1618487876.537 [RDI_Pathfinder] No Fault, FailCount= 1
2021-04-15T11:59:29.358Z,1618487969.358 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2021-04-15T11:59:29.365Z,1618487969.365 [BPC1](INFO): Received data from all battery sticks.
2021-04-15T12:00:05.737Z,1618488005.737 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T12:00:05.737Z,1618488005.737 [Default:CheckIn:C.Wait] Stopped
2021-04-15T12:00:05.737Z,1618488005.737 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T12:00:05.738Z,1618488005.738 [Default:CheckIn:D] Running Loop=1
2021-04-15T12:00:06.153Z,1618488006.153 [Default:CheckIn:D] Stopped
2021-04-15T12:00:06.153Z,1618488006.153 [Default:CheckIn:E] Running Loop=1
2021-04-15T12:00:06.558Z,1618488006.558 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 71.763501 min 
2021-04-15T12:00:06.559Z,1618488006.559 [Default:CheckIn:E] Stopped
2021-04-15T12:00:06.559Z,1618488006.559 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T12:00:06.559Z,1618488006.559 [Default:CheckIn] Stopped
2021-04-15T12:00:06.559Z,1618488006.559 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T12:00:06.559Z,1618488006.559 [Default:CheckIn](INFO): Running loop #13
2021-04-15T12:00:06.559Z,1618488006.559 [Default:CheckIn] Running Loop=13
2021-04-15T12:00:06.559Z,1618488006.559 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T12:00:06.560Z,1618488006.560 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T12:00:08.546Z,1618488008.546 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,120008.00,A,4131.71240,N,07040.23235,W,0.097,331.31,150421,,,A*78
2021-04-15T12:00:08.549Z,1618488008.549 [NAL9602](INFO): GPS fix at 20210415T120008: (41.528540, -70.670539)
2021-04-15T12:00:08.569Z,1618488008.569 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T12:00:08.569Z,1618488008.569 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T12:00:12.294Z,1618488012.294 [DataOverHttps](INFO): Sending 83 bytes from file Logs/20210415T104405/Courier0040.lzma
2021-04-15T12:00:13.297Z,1618488013.297 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0040.lzma.bak
2021-04-15T12:00:13.297Z,1618488013.297 [DataOverHttps](INFO): SBD MOMSN=106001
2021-04-15T12:00:22.334Z,1618488022.334 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20210415T104405/Express0041.lzma
2021-04-15T12:00:23.337Z,1618488023.337 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0041.lzma.bak
2021-04-15T12:00:23.337Z,1618488023.337 [DataOverHttps](INFO): SBD MOMSN=106004
2021-04-15T12:00:24.753Z,1618488024.753 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T12:00:24.753Z,1618488024.753 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T12:00:24.754Z,1618488024.754 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T12:01:04.718Z,1618488064.718 [NAL9602](INFO): SBD MO Status=2, MOMSN=15519, MT Status=2, MTMSN=0
2021-04-15T12:01:04.718Z,1618488064.718 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-15T12:01:17.248Z,1618488077.248 [NAL9602](INFO): SBD MO Status=0, MOMSN=15519, MT Status=0, MTMSN=0
2021-04-15T12:01:17.248Z,1618488077.248 [NAL9602](INFO): No messages in MT queue
2021-04-15T12:01:47.941Z,1618488107.941 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T12:05:25.324Z,1618488325.324 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T12:05:25.324Z,1618488325.324 [Default:CheckIn:C.Wait] Stopped
2021-04-15T12:05:25.324Z,1618488325.324 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T12:05:25.324Z,1618488325.324 [Default:CheckIn:D] Running Loop=1
2021-04-15T12:05:25.711Z,1618488325.711 [Default:CheckIn:D] Stopped
2021-04-15T12:05:25.711Z,1618488325.711 [Default:CheckIn:E] Running Loop=1
2021-04-15T12:05:26.135Z,1618488326.135 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 77.089461 min 
2021-04-15T12:05:26.135Z,1618488326.135 [Default:CheckIn:E] Stopped
2021-04-15T12:05:26.136Z,1618488326.136 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T12:05:26.136Z,1618488326.136 [Default:CheckIn] Stopped
2021-04-15T12:05:26.136Z,1618488326.136 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T12:05:26.136Z,1618488326.136 [Default:CheckIn](INFO): Running loop #14
2021-04-15T12:05:26.136Z,1618488326.136 [Default:CheckIn] Running Loop=14
2021-04-15T12:05:26.136Z,1618488326.136 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T12:05:26.136Z,1618488326.136 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T12:05:28.137Z,1618488328.137 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,120527.00,A,4131.71159,N,07040.22955,W,0.019,331.31,150421,,,A*71
2021-04-15T12:05:28.139Z,1618488328.139 [NAL9602](INFO): GPS fix at 20210415T120527: (41.528526, -70.670492)
2021-04-15T12:05:28.170Z,1618488328.170 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T12:05:28.170Z,1618488328.170 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T12:05:31.631Z,1618488331.631 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210415T104405/Courier0043.lzma
2021-04-15T12:05:32.633Z,1618488332.633 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0043.lzma.bak
2021-04-15T12:05:32.633Z,1618488332.633 [DataOverHttps](INFO): SBD MOMSN=106008
2021-04-15T12:05:41.458Z,1618488341.458 [NAL9602](INFO): SBD MO Status=0, MOMSN=15520, MT Status=0, MTMSN=0
2021-04-15T12:05:41.458Z,1618488341.458 [NAL9602](INFO): No messages in MT queue
2021-04-15T12:05:41.675Z,1618488341.675 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20210415T104405/Express0044.lzma
2021-04-15T12:05:42.677Z,1618488342.677 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0044.lzma.bak
2021-04-15T12:05:42.677Z,1618488342.677 [DataOverHttps](INFO): SBD MOMSN=106011
2021-04-15T12:05:43.940Z,1618488343.940 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T12:05:43.940Z,1618488343.940 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T12:05:43.940Z,1618488343.940 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T12:06:12.158Z,1618488372.158 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T12:10:44.488Z,1618488644.488 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T12:10:44.488Z,1618488644.488 [Default:CheckIn:C.Wait] Stopped
2021-04-15T12:10:44.488Z,1618488644.488 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T12:10:44.488Z,1618488644.488 [Default:CheckIn:D] Running Loop=1
2021-04-15T12:10:44.891Z,1618488644.891 [Default:CheckIn:D] Stopped
2021-04-15T12:10:44.891Z,1618488644.891 [Default:CheckIn:E] Running Loop=1
2021-04-15T12:10:45.282Z,1618488645.282 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 82.409131 min 
2021-04-15T12:10:45.282Z,1618488645.282 [Default:CheckIn:E] Stopped
2021-04-15T12:10:45.282Z,1618488645.282 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T12:10:45.282Z,1618488645.282 [Default:CheckIn] Stopped
2021-04-15T12:10:45.282Z,1618488645.282 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T12:10:45.282Z,1618488645.282 [Default:CheckIn](INFO): Running loop #15
2021-04-15T12:10:45.283Z,1618488645.283 [Default:CheckIn] Running Loop=15
2021-04-15T12:10:45.283Z,1618488645.283 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T12:10:45.283Z,1618488645.283 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T12:10:47.294Z,1618488647.294 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,121046.00,A,4131.71227,N,07040.23012,W,0.019,331.31,150421,,,A*73
2021-04-15T12:10:47.297Z,1618488647.297 [NAL9602](INFO): GPS fix at 20210415T121046: (41.528538, -70.670502)
2021-04-15T12:10:47.307Z,1618488647.307 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T12:10:47.307Z,1618488647.307 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T12:10:50.934Z,1618488650.934 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210415T104405/Courier0046.lzma
2021-04-15T12:10:51.934Z,1618488651.934 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0046.lzma.bak
2021-04-15T12:10:51.934Z,1618488651.934 [DataOverHttps](INFO): SBD MOMSN=106015
2021-04-15T12:11:04.041Z,1618488664.041 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20210415T104405/Express0047.lzma
2021-04-15T12:11:04.985Z,1618488664.985 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0047.lzma.bak
2021-04-15T12:11:04.985Z,1618488664.985 [DataOverHttps](INFO): SBD MOMSN=106018
2021-04-15T12:11:06.311Z,1618488666.311 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T12:11:06.311Z,1618488666.311 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T12:11:06.311Z,1618488666.311 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T12:11:38.210Z,1618488698.210 [NAL9602](INFO): SBD MO Status=2, MOMSN=15521, MT Status=2, MTMSN=0
2021-04-15T12:11:38.210Z,1618488698.210 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-15T12:11:56.414Z,1618488716.414 [NAL9602](INFO): SBD MO Status=0, MOMSN=15521, MT Status=0, MTMSN=0
2021-04-15T12:11:56.414Z,1618488716.414 [NAL9602](INFO): No messages in MT queue
2021-04-15T12:12:27.094Z,1618488747.094 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T12:15:45.933Z,1618488945.933 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2021-04-15T12:16:06.877Z,1618488966.877 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T12:16:06.877Z,1618488966.877 [Default:CheckIn:C.Wait] Stopped
2021-04-15T12:16:06.877Z,1618488966.877 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T12:16:06.877Z,1618488966.877 [Default:CheckIn:D] Running Loop=1
2021-04-15T12:16:07.309Z,1618488967.309 [Default:CheckIn:D] Stopped
2021-04-15T12:16:07.309Z,1618488967.309 [Default:CheckIn:E] Running Loop=1
2021-04-15T12:16:07.703Z,1618488967.703 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 87.782764 min 
2021-04-15T12:16:07.703Z,1618488967.703 [Default:CheckIn:E] Stopped
2021-04-15T12:16:07.703Z,1618488967.703 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T12:16:07.703Z,1618488967.703 [Default:CheckIn] Stopped
2021-04-15T12:16:07.703Z,1618488967.703 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T12:16:07.704Z,1618488967.704 [Default:CheckIn](INFO): Running loop #16
2021-04-15T12:16:07.704Z,1618488967.704 [Default:CheckIn] Running Loop=16
2021-04-15T12:16:07.704Z,1618488967.704 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T12:16:07.704Z,1618488967.704 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T12:16:09.702Z,1618488969.702 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,121609.00,A,4131.71320,N,07040.23044,W,0.039,331.31,150421,,,A*79
2021-04-15T12:16:09.705Z,1618488969.705 [NAL9602](INFO): GPS fix at 20210415T121609: (41.528553, -70.670507)
2021-04-15T12:16:09.744Z,1618488969.744 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T12:16:09.744Z,1618488969.744 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T12:16:13.286Z,1618488973.286 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20210415T104405/Courier0049.lzma
2021-04-15T12:16:14.289Z,1618488974.289 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0049.lzma.bak
2021-04-15T12:16:14.289Z,1618488974.289 [DataOverHttps](INFO): SBD MOMSN=106022
2021-04-15T12:16:23.326Z,1618488983.326 [DataOverHttps](INFO): Sending 118 bytes from file Logs/20210415T104405/Express0050.lzma
2021-04-15T12:16:24.329Z,1618488984.329 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0050.lzma.bak
2021-04-15T12:16:24.329Z,1618488984.329 [DataOverHttps](INFO): SBD MOMSN=106025
2021-04-15T12:16:25.488Z,1618488985.488 [NAL9602](INFO): SBD MO Status=0, MOMSN=15522, MT Status=0, MTMSN=0
2021-04-15T12:16:25.488Z,1618488985.488 [NAL9602](INFO): No messages in MT queue
2021-04-15T12:16:25.509Z,1618488985.509 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T12:16:25.509Z,1618488985.509 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T12:16:25.509Z,1618488985.509 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T12:16:46.100Z,1618489006.100 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2021-04-15T12:16:56.185Z,1618489016.185 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T12:17:36.218Z,1618489056.218 [RDI_PathfinderUp](ERROR): DVL uart error: serial timeout
2021-04-15T12:17:36.218Z,1618489056.218 [RDI_PathfinderUp] Communications Fault, FailCount= 1
2021-04-15T12:17:36.218Z,1618489056.218 [RDI_PathfinderUp](ERROR): Communications Fault
2021-04-15T12:17:36.249Z,1618489056.249 [CBIT](ERROR): Communications Fault in component: RDI_PathfinderUp
2021-04-15T12:17:36.667Z,1618489056.667 [RDI_PathfinderUp](INFO): Powering down
2021-04-15T12:17:37.458Z,1618489057.458 [CBIT](INFO): Clearing failed state for component RDI_PathfinderUp
2021-04-15T12:17:37.458Z,1618489057.458 [RDI_PathfinderUp] No Fault, FailCount= 1
2021-04-15T12:19:41.045Z,1618489181.045 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2021-04-15T12:21:26.092Z,1618489286.092 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T12:21:26.093Z,1618489286.093 [Default:CheckIn:C.Wait] Stopped
2021-04-15T12:21:26.093Z,1618489286.093 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T12:21:26.093Z,1618489286.093 [Default:CheckIn:D] Running Loop=1
2021-04-15T12:21:26.516Z,1618489286.516 [Default:CheckIn:D] Stopped
2021-04-15T12:21:26.516Z,1618489286.516 [Default:CheckIn:E] Running Loop=1
2021-04-15T12:21:26.977Z,1618489286.977 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 93.102881 min 
2021-04-15T12:21:26.977Z,1618489286.977 [Default:CheckIn:E] Stopped
2021-04-15T12:21:26.978Z,1618489286.978 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T12:21:26.978Z,1618489286.978 [Default:CheckIn] Stopped
2021-04-15T12:21:26.978Z,1618489286.978 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T12:21:26.978Z,1618489286.978 [Default:CheckIn](INFO): Running loop #17
2021-04-15T12:21:26.978Z,1618489286.978 [Default:CheckIn] Running Loop=17
2021-04-15T12:21:26.978Z,1618489286.978 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T12:21:26.978Z,1618489286.978 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T12:21:28.912Z,1618489288.912 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,122128.00,A,4131.71335,N,07040.23086,W,0.019,331.31,150421,,,A*76
2021-04-15T12:21:28.914Z,1618489288.914 [NAL9602](INFO): GPS fix at 20210415T122128: (41.528556, -70.670514)
2021-04-15T12:21:28.965Z,1618489288.965 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T12:21:28.965Z,1618489288.965 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T12:21:32.622Z,1618489292.622 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210415T104405/Courier0052.lzma
2021-04-15T12:21:33.625Z,1618489293.625 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0052.lzma.bak
2021-04-15T12:21:33.625Z,1618489293.625 [DataOverHttps](INFO): SBD MOMSN=106029
2021-04-15T12:21:42.670Z,1618489302.670 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20210415T104405/Express0053.lzma
2021-04-15T12:21:43.673Z,1618489303.673 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0053.lzma.bak
2021-04-15T12:21:43.673Z,1618489303.673 [DataOverHttps](INFO): SBD MOMSN=106032
2021-04-15T12:21:45.135Z,1618489305.135 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T12:21:45.135Z,1618489305.135 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T12:21:45.136Z,1618489305.136 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T12:21:52.344Z,1618489312.344 [NAL9602](INFO): SBD MO Status=0, MOMSN=15523, MT Status=0, MTMSN=0
2021-04-15T12:21:52.345Z,1618489312.345 [NAL9602](INFO): No messages in MT queue
2021-04-15T12:22:23.035Z,1618489343.035 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T12:26:24.234Z,1618489584.234 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2021-04-15T12:26:45.647Z,1618489605.647 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T12:26:45.647Z,1618489605.647 [Default:CheckIn:C.Wait] Stopped
2021-04-15T12:26:45.647Z,1618489605.647 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T12:26:45.647Z,1618489605.647 [Default:CheckIn:D] Running Loop=1
2021-04-15T12:26:46.068Z,1618489606.068 [Default:CheckIn:D] Stopped
2021-04-15T12:26:46.068Z,1618489606.068 [Default:CheckIn:E] Running Loop=1
2021-04-15T12:26:46.478Z,1618489606.478 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 98.428735 min 
2021-04-15T12:26:46.478Z,1618489606.478 [Default:CheckIn:E] Stopped
2021-04-15T12:26:46.478Z,1618489606.478 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T12:26:46.478Z,1618489606.478 [Default:CheckIn] Stopped
2021-04-15T12:26:46.478Z,1618489606.478 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T12:26:46.479Z,1618489606.479 [Default:CheckIn](INFO): Running loop #18
2021-04-15T12:26:46.479Z,1618489606.479 [Default:CheckIn] Running Loop=18
2021-04-15T12:26:46.479Z,1618489606.479 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T12:26:46.479Z,1618489606.479 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T12:26:48.460Z,1618489608.460 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,122647.00,A,4131.71258,N,07040.23260,W,0.039,0.00,150421,,,A*79
2021-04-15T12:26:48.462Z,1618489608.462 [NAL9602](INFO): GPS fix at 20210415T122647: (41.528543, -70.670543)
2021-04-15T12:26:48.497Z,1618489608.497 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T12:26:48.497Z,1618489608.497 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T12:26:52.018Z,1618489612.018 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210415T104405/Courier0055.lzma
2021-04-15T12:26:53.021Z,1618489613.021 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0055.lzma.bak
2021-04-15T12:26:53.021Z,1618489613.021 [DataOverHttps](INFO): SBD MOMSN=106036
2021-04-15T12:27:02.058Z,1618489622.058 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20210415T104405/Express0056.lzma
2021-04-15T12:27:03.061Z,1618489623.061 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0056.lzma.bak
2021-04-15T12:27:03.061Z,1618489623.061 [DataOverHttps](INFO): SBD MOMSN=106039
2021-04-15T12:27:03.847Z,1618489623.847 [NAL9602](INFO): SBD MO Status=0, MOMSN=15524, MT Status=0, MTMSN=0
2021-04-15T12:27:03.847Z,1618489623.847 [NAL9602](INFO): No messages in MT queue
2021-04-15T12:27:04.287Z,1618489624.287 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T12:27:04.287Z,1618489624.287 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T12:27:04.288Z,1618489624.288 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T12:27:34.543Z,1618489654.543 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T12:28:58.998Z,1618489738.998 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2021-04-15T12:30:54.143Z,1618489854.143 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items
2021-04-15T12:32:04.838Z,1618489924.838 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T12:32:04.838Z,1618489924.838 [Default:CheckIn:C.Wait] Stopped
2021-04-15T12:32:04.838Z,1618489924.838 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T12:32:04.839Z,1618489924.839 [Default:CheckIn:D] Running Loop=1
2021-04-15T12:32:05.253Z,1618489925.253 [Default:CheckIn:D] Stopped
2021-04-15T12:32:05.253Z,1618489925.253 [Default:CheckIn:E] Running Loop=1
2021-04-15T12:32:05.667Z,1618489925.667 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 103.748503 min 
2021-04-15T12:32:05.667Z,1618489925.667 [Default:CheckIn:E] Stopped
2021-04-15T12:32:05.667Z,1618489925.667 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T12:32:05.667Z,1618489925.667 [Default:CheckIn] Stopped
2021-04-15T12:32:05.667Z,1618489925.667 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T12:32:05.668Z,1618489925.668 [Default:CheckIn](INFO): Running loop #19
2021-04-15T12:32:05.668Z,1618489925.668 [Default:CheckIn] Running Loop=19
2021-04-15T12:32:05.668Z,1618489925.668 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T12:32:05.668Z,1618489925.668 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T12:32:07.652Z,1618489927.652 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,123206.00,A,4131.71520,N,07040.23136,W,0.058,0.00,150421,,,A*76
2021-04-15T12:32:07.654Z,1618489927.654 [NAL9602](INFO): GPS fix at 20210415T123206: (41.528587, -70.670523)
2021-04-15T12:32:07.665Z,1618489927.665 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T12:32:07.665Z,1618489927.665 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T12:32:11.330Z,1618489931.330 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210415T104405/Courier0058.lzma
2021-04-15T12:32:12.333Z,1618489932.333 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0058.lzma.bak
2021-04-15T12:32:12.333Z,1618489932.333 [DataOverHttps](INFO): SBD MOMSN=106043
2021-04-15T12:32:21.378Z,1618489941.378 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20210415T104405/Express0059.lzma
2021-04-15T12:32:21.400Z,1618489941.400 [NAL9602](INFO): SBD MO Status=0, MOMSN=15525, MT Status=0, MTMSN=0
2021-04-15T12:32:21.400Z,1618489941.400 [NAL9602](INFO): No messages in MT queue
2021-04-15T12:32:22.378Z,1618489942.378 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0059.lzma.bak
2021-04-15T12:32:22.378Z,1618489942.378 [DataOverHttps](INFO): SBD MOMSN=106046
2021-04-15T12:32:23.850Z,1618489943.850 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T12:32:23.850Z,1618489943.850 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T12:32:23.850Z,1618489943.850 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T12:32:52.098Z,1618489972.098 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T12:34:46.937Z,1618490086.937 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2021-04-15T12:34:56.967Z,1618490096.967 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2021-04-15T12:35:22.033Z,1618490122.033 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude
2021-04-15T12:35:32.110Z,1618490132.110 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2021-04-15T12:35:51.978Z,1618490151.978 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2021-04-15T12:37:24.441Z,1618490244.441 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T12:37:24.441Z,1618490244.441 [Default:CheckIn:C.Wait] Stopped
2021-04-15T12:37:24.441Z,1618490244.441 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T12:37:24.441Z,1618490244.441 [Default:CheckIn:D] Running Loop=1
2021-04-15T12:37:24.838Z,1618490244.838 [Default:CheckIn:D] Stopped
2021-04-15T12:37:24.838Z,1618490244.838 [Default:CheckIn:E] Running Loop=1
2021-04-15T12:37:25.256Z,1618490245.256 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 109.074919 min 
2021-04-15T12:37:25.256Z,1618490245.256 [Default:CheckIn:E] Stopped
2021-04-15T12:37:25.256Z,1618490245.256 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T12:37:25.257Z,1618490245.257 [Default:CheckIn] Stopped
2021-04-15T12:37:25.257Z,1618490245.257 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T12:37:25.257Z,1618490245.257 [Default:CheckIn](INFO): Running loop #20
2021-04-15T12:37:25.257Z,1618490245.257 [Default:CheckIn] Running Loop=20
2021-04-15T12:37:25.257Z,1618490245.257 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T12:37:25.257Z,1618490245.257 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T12:37:27.244Z,1618490247.244 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,123726.00,A,4131.71369,N,07040.23058,W,0.019,0.00,150421,,,A*76
2021-04-15T12:37:27.246Z,1618490247.246 [NAL9602](INFO): GPS fix at 20210415T123726: (41.528562, -70.670510)
2021-04-15T12:37:27.283Z,1618490247.283 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T12:37:27.283Z,1618490247.283 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T12:37:31.642Z,1618490251.642 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20210415T104405/Courier0061.lzma
2021-04-15T12:37:32.645Z,1618490252.645 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0061.lzma.bak
2021-04-15T12:37:32.645Z,1618490252.645 [DataOverHttps](INFO): SBD MOMSN=106050
2021-04-15T12:37:41.683Z,1618490261.683 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20210415T104405/Express0062.lzma
2021-04-15T12:37:42.685Z,1618490262.685 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0062.lzma.bak
2021-04-15T12:37:42.685Z,1618490262.685 [DataOverHttps](INFO): SBD MOMSN=106053
2021-04-15T12:37:43.849Z,1618490263.849 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T12:37:43.849Z,1618490263.849 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T12:37:43.849Z,1618490263.849 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T12:37:49.096Z,1618490269.096 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2021-04-15T12:37:51.888Z,1618490271.888 [NAL9602](INFO): SBD MO Status=2, MOMSN=15526, MT Status=2, MTMSN=0
2021-04-15T12:37:51.888Z,1618490271.888 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-15T12:38:01.186Z,1618490281.186 [NAL9602](INFO): SBD MO Status=0, MOMSN=15526, MT Status=0, MTMSN=0
2021-04-15T12:38:01.186Z,1618490281.186 [NAL9602](INFO): No messages in MT queue
2021-04-15T12:38:31.914Z,1618490311.914 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T12:39:22.390Z,1618490362.390 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-04-15T12:42:44.457Z,1618490564.457 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T12:42:44.457Z,1618490564.457 [Default:CheckIn:C.Wait] Stopped
2021-04-15T12:42:44.457Z,1618490564.457 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T12:42:44.457Z,1618490564.457 [Default:CheckIn:D] Running Loop=1
2021-04-15T12:42:44.906Z,1618490564.906 [Default:CheckIn:D] Stopped
2021-04-15T12:42:44.906Z,1618490564.906 [Default:CheckIn:E] Running Loop=1
2021-04-15T12:42:45.304Z,1618490565.304 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 114.409383 min 
2021-04-15T12:42:45.304Z,1618490565.304 [Default:CheckIn:E] Stopped
2021-04-15T12:42:45.304Z,1618490565.304 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T12:42:45.304Z,1618490565.304 [Default:CheckIn] Stopped
2021-04-15T12:42:45.304Z,1618490565.304 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T12:42:45.304Z,1618490565.304 [Default:CheckIn](INFO): Running loop #21
2021-04-15T12:42:45.304Z,1618490565.304 [Default:CheckIn] Running Loop=21
2021-04-15T12:42:45.305Z,1618490565.305 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T12:42:45.305Z,1618490565.305 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T12:42:47.283Z,1618490567.283 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,124246.00,A,4131.71395,N,07040.23187,W,0.156,313.57,150421,,,A*7B
2021-04-15T12:42:47.285Z,1618490567.285 [NAL9602](INFO): GPS fix at 20210415T124246: (41.528566, -70.670531)
2021-04-15T12:42:47.362Z,1618490567.362 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T12:42:47.362Z,1618490567.362 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T12:42:50.942Z,1618490570.942 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210415T104405/Courier0064.lzma
2021-04-15T12:42:51.945Z,1618490571.945 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0064.lzma.bak
2021-04-15T12:42:51.945Z,1618490571.945 [DataOverHttps](INFO): SBD MOMSN=106058
2021-04-15T12:43:00.982Z,1618490580.982 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20210415T104405/Express0065.lzma
2021-04-15T12:43:01.985Z,1618490581.985 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0065.lzma.bak
2021-04-15T12:43:01.985Z,1618490581.985 [DataOverHttps](INFO): SBD MOMSN=106061
2021-04-15T12:43:03.102Z,1618490583.102 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T12:43:03.107Z,1618490583.107 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T12:43:03.107Z,1618490583.107 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T12:43:16.364Z,1618490596.364 [NAL9602](INFO): SBD MO Status=2, MOMSN=15527, MT Status=2, MTMSN=0
2021-04-15T12:43:16.364Z,1618490596.364 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-15T12:43:26.050Z,1618490606.050 [NAL9602](INFO): SBD MO Status=0, MOMSN=15527, MT Status=0, MTMSN=0
2021-04-15T12:43:26.050Z,1618490606.050 [NAL9602](INFO): No messages in MT queue
2021-04-15T12:43:56.756Z,1618490636.756 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T12:47:21.282Z,1618490841.282 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2021-04-15T12:47:45.965Z,1618490865.965 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2021-04-15T12:48:03.708Z,1618490883.708 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T12:48:03.708Z,1618490883.708 [Default:CheckIn:C.Wait] Stopped
2021-04-15T12:48:03.708Z,1618490883.708 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T12:48:03.708Z,1618490883.708 [Default:CheckIn:D] Running Loop=1
2021-04-15T12:48:04.116Z,1618490884.116 [Default:CheckIn:D] Stopped
2021-04-15T12:48:04.116Z,1618490884.116 [Default:CheckIn:E] Running Loop=1
2021-04-15T12:48:04.538Z,1618490884.538 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 119.729549 min 
2021-04-15T12:48:04.538Z,1618490884.538 [Default:CheckIn:E] Stopped
2021-04-15T12:48:04.539Z,1618490884.539 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T12:48:04.539Z,1618490884.539 [Default:CheckIn] Stopped
2021-04-15T12:48:04.539Z,1618490884.539 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T12:48:04.539Z,1618490884.539 [Default:CheckIn](INFO): Running loop #22
2021-04-15T12:48:04.539Z,1618490884.539 [Default:CheckIn] Running Loop=22
2021-04-15T12:48:04.539Z,1618490884.539 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T12:48:04.539Z,1618490884.539 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T12:48:06.511Z,1618490886.511 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,124806.00,A,4131.72785,N,07040.24421,W,0.039,297.36,150421,,,A*7F
2021-04-15T12:48:06.513Z,1618490886.513 [NAL9602](INFO): GPS fix at 20210415T124806: (41.528798, -70.670737)
2021-04-15T12:48:06.531Z,1618490886.531 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T12:48:06.531Z,1618490886.531 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T12:48:10.310Z,1618490890.310 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20210415T104405/Courier0067.lzma
2021-04-15T12:48:11.333Z,1618490891.333 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0067.lzma.bak
2021-04-15T12:48:11.333Z,1618490891.333 [DataOverHttps](INFO): SBD MOMSN=106067
2021-04-15T12:48:20.370Z,1618490900.370 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20210415T104405/Express0068.lzma
2021-04-15T12:48:21.376Z,1618490901.376 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0068.lzma.bak
2021-04-15T12:48:21.377Z,1618490901.377 [DataOverHttps](INFO): SBD MOMSN=106070
2021-04-15T12:48:21.880Z,1618490901.880 [NAL9602](INFO): SBD MO Status=0, MOMSN=15528, MT Status=0, MTMSN=0
2021-04-15T12:48:21.881Z,1618490901.881 [NAL9602](INFO): No messages in MT queue
2021-04-15T12:48:22.690Z,1618490902.690 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T12:48:22.690Z,1618490902.690 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T12:48:22.690Z,1618490902.690 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T12:48:52.583Z,1618490932.583 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T12:49:43.932Z,1618490983.932 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-04-15T12:50:08.977Z,1618491008.977 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2021-04-15T12:53:23.305Z,1618491203.305 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T12:53:23.305Z,1618491203.305 [Default:CheckIn:C.Wait] Stopped
2021-04-15T12:53:23.306Z,1618491203.306 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T12:53:23.306Z,1618491203.306 [Default:CheckIn:D] Running Loop=1
2021-04-15T12:53:23.670Z,1618491203.670 [Default:CheckIn:D] Stopped
2021-04-15T12:53:23.670Z,1618491203.670 [Default:CheckIn:E] Running Loop=1
2021-04-15T12:53:24.125Z,1618491204.125 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 125.055452 min 
2021-04-15T12:53:24.125Z,1618491204.125 [Default:CheckIn:E] Stopped
2021-04-15T12:53:24.125Z,1618491204.125 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T12:53:24.126Z,1618491204.126 [Default:CheckIn] Stopped
2021-04-15T12:53:24.126Z,1618491204.126 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T12:53:24.126Z,1618491204.126 [Default:CheckIn](INFO): Running loop #23
2021-04-15T12:53:24.126Z,1618491204.126 [Default:CheckIn] Running Loop=23
2021-04-15T12:53:24.126Z,1618491204.126 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T12:53:24.126Z,1618491204.126 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T12:53:26.109Z,1618491206.109 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,125325.00,A,4131.72805,N,07040.24417,W,0.058,297.36,150421,,,A*71
2021-04-15T12:53:26.111Z,1618491206.111 [NAL9602](INFO): GPS fix at 20210415T125325: (41.528801, -70.670736)
2021-04-15T12:53:26.131Z,1618491206.131 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T12:53:26.132Z,1618491206.132 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T12:53:29.635Z,1618491209.635 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210415T104405/Courier0070.lzma
2021-04-15T12:53:30.637Z,1618491210.637 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0070.lzma.bak
2021-04-15T12:53:30.637Z,1618491210.637 [DataOverHttps](INFO): SBD MOMSN=106075
2021-04-15T12:53:40.682Z,1618491220.682 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20210415T104405/Express0071.lzma
2021-04-15T12:53:41.685Z,1618491221.685 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0071.lzma.bak
2021-04-15T12:53:41.685Z,1618491221.685 [DataOverHttps](INFO): SBD MOMSN=106078
2021-04-15T12:53:43.106Z,1618491223.106 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T12:53:43.106Z,1618491223.106 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T12:53:43.106Z,1618491223.106 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T12:54:16.206Z,1618491256.206 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2021-04-15T12:54:31.550Z,1618491271.550 [NAL9602](INFO): SBD MO Status=2, MOMSN=15529, MT Status=2, MTMSN=0
2021-04-15T12:54:31.551Z,1618491271.551 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-15T12:55:06.302Z,1618491306.302 [NAL9602](INFO): SBD MO Status=0, MOMSN=15529, MT Status=0, MTMSN=0
2021-04-15T12:55:06.303Z,1618491306.303 [NAL9602](INFO): No messages in MT queue
2021-04-15T12:55:07.939Z,1618491307.939 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-04-15T12:55:18.024Z,1618491318.024 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-04-15T12:55:18.029Z,1618491318.029 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2021-04-15T12:55:37.003Z,1618491337.003 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T12:56:32.037Z,1618491392.037 [CBIT](IMPORTANT): Beginning ground fault scan
2021-04-15T12:56:42.891Z,1618491402.891 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.009239
CHAN A1 (24V): -0.028966
CHAN A2 (12V): -0.007254
CHAN A3 (5V): -0.002157
CHAN B0 (3.3V): 0.000447
CHAN B1 (3.15aV): 0.000152
CHAN B2 (3.15bV): 0.000305
CHAN B3 (GND): 0.002268
OPEN: 0.005138
Full Scale Calc: 4.765 mA, -1.589 mA
2021-04-15T12:58:43.696Z,1618491523.696 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T12:58:43.696Z,1618491523.696 [Default:CheckIn:C.Wait] Stopped
2021-04-15T12:58:43.696Z,1618491523.696 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T12:58:43.696Z,1618491523.696 [Default:CheckIn:D] Running Loop=1
2021-04-15T12:58:44.111Z,1618491524.111 [Default:CheckIn:D] Stopped
2021-04-15T12:58:44.111Z,1618491524.111 [Default:CheckIn:E] Running Loop=1
2021-04-15T12:58:44.501Z,1618491524.501 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 130.396126 min 
2021-04-15T12:58:44.501Z,1618491524.501 [Default:CheckIn:E] Stopped
2021-04-15T12:58:44.501Z,1618491524.501 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T12:58:44.501Z,1618491524.501 [Default:CheckIn] Stopped
2021-04-15T12:58:44.501Z,1618491524.501 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T12:58:44.502Z,1618491524.501 [Default:CheckIn](INFO): Running loop #24
2021-04-15T12:58:44.502Z,1618491524.502 [Default:CheckIn] Running Loop=24
2021-04-15T12:58:44.502Z,1618491524.502 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T12:58:44.502Z,1618491524.502 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T12:58:46.127Z,1618491526.127 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2021-04-15T12:58:46.506Z,1618491526.506 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,125845.00,A,4131.72760,N,07040.24367,W,0.000,39.23,150421,,,A*4F
2021-04-15T12:58:46.509Z,1618491526.509 [NAL9602](INFO): GPS fix at 20210415T125845: (41.528793, -70.670728)
2021-04-15T12:58:46.539Z,1618491526.539 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T12:58:46.539Z,1618491526.539 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T12:58:50.974Z,1618491530.974 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210415T104405/Courier0073.lzma
2021-04-15T12:58:51.977Z,1618491531.977 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0073.lzma.bak
2021-04-15T12:58:51.977Z,1618491531.977 [DataOverHttps](INFO): SBD MOMSN=106083
2021-04-15T12:59:01.015Z,1618491541.015 [DataOverHttps](INFO): Sending 305 bytes from file Logs/20210415T104405/Express0074.lzma
2021-04-15T12:59:02.017Z,1618491542.017 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0074.lzma.bak
2021-04-15T12:59:02.017Z,1618491542.017 [DataOverHttps](INFO): SBD MOMSN=106086
2021-04-15T12:59:03.147Z,1618491543.147 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T12:59:03.147Z,1618491543.147 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T12:59:03.147Z,1618491543.147 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T12:59:09.130Z,1618491549.130 [NAL9602](INFO): SBD MO Status=2, MOMSN=15530, MT Status=2, MTMSN=0
2021-04-15T12:59:09.130Z,1618491549.130 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-15T12:59:25.284Z,1618491565.284 [NAL9602](INFO): SBD MO Status=2, MOMSN=15530, MT Status=2, MTMSN=0
2021-04-15T12:59:25.284Z,1618491565.284 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-15T12:59:41.892Z,1618491581.892 [NAL9602](INFO): SBD MO Status=0, MOMSN=15530, MT Status=0, MTMSN=0
2021-04-15T12:59:41.892Z,1618491581.892 [NAL9602](INFO): No messages in MT queue
2021-04-15T13:00:12.570Z,1618491612.570 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T13:04:03.683Z,1618491843.683 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T13:04:03.683Z,1618491843.683 [Default:CheckIn:C.Wait] Stopped
2021-04-15T13:04:03.683Z,1618491843.683 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T13:04:03.683Z,1618491843.683 [Default:CheckIn:D] Running Loop=1
2021-04-15T13:04:04.080Z,1618491844.080 [Default:CheckIn:D] Stopped
2021-04-15T13:04:04.080Z,1618491844.080 [Default:CheckIn:E] Running Loop=1
2021-04-15T13:04:04.486Z,1618491844.486 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 135.728947 min 
2021-04-15T13:04:04.486Z,1618491844.486 [Default:CheckIn:E] Stopped
2021-04-15T13:04:04.486Z,1618491844.486 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T13:04:04.487Z,1618491844.487 [Default:CheckIn] Stopped
2021-04-15T13:04:04.487Z,1618491844.487 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T13:04:04.487Z,1618491844.487 [Default:CheckIn](INFO): Running loop #25
2021-04-15T13:04:04.487Z,1618491844.487 [Default:CheckIn] Running Loop=25
2021-04-15T13:04:04.487Z,1618491844.487 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T13:04:04.487Z,1618491844.487 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T13:04:06.486Z,1618491846.486 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,130405.00,A,4131.72720,N,07040.24300,W,0.058,39.23,150421,,,A*4B
2021-04-15T13:04:06.497Z,1618491846.497 [NAL9602](INFO): GPS fix at 20210415T130405: (41.528787, -70.670717)
2021-04-15T13:04:06.517Z,1618491846.517 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T13:04:06.517Z,1618491846.517 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T13:04:10.274Z,1618491850.274 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210415T104405/Courier0076.lzma
2021-04-15T13:04:11.277Z,1618491851.277 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0076.lzma.bak
2021-04-15T13:04:11.277Z,1618491851.277 [DataOverHttps](INFO): SBD MOMSN=106092
2021-04-15T13:04:20.314Z,1618491860.314 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20210415T104405/Express0077.lzma
2021-04-15T13:04:21.317Z,1618491861.317 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0077.lzma.bak
2021-04-15T13:04:21.317Z,1618491861.317 [DataOverHttps](INFO): SBD MOMSN=106095
2021-04-15T13:04:22.664Z,1618491862.664 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T13:04:22.664Z,1618491862.664 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T13:04:22.664Z,1618491862.664 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T13:04:23.057Z,1618491863.057 [NAL9602](INFO): SBD MO Status=0, MOMSN=15531, MT Status=0, MTMSN=0
2021-04-15T13:04:23.057Z,1618491863.057 [NAL9602](INFO): No messages in MT queue
2021-04-15T13:04:53.768Z,1618491893.768 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T13:05:19.273Z,1618491919.273 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2021-04-15T13:06:54.963Z,1618492014.963 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2021-04-15T13:06:54.966Z,1618492014.966 [BPC1](INFO): Received data from all battery sticks.
2021-04-15T13:07:23.650Z,1618492043.650 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2021-04-15T13:09:23.261Z,1618492163.261 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T13:09:23.261Z,1618492163.261 [Default:CheckIn:C.Wait] Stopped
2021-04-15T13:09:23.261Z,1618492163.261 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T13:09:23.261Z,1618492163.261 [Default:CheckIn:D] Running Loop=1
2021-04-15T13:09:23.651Z,1618492163.651 [Default:CheckIn:D] Stopped
2021-04-15T13:09:23.652Z,1618492163.652 [Default:CheckIn:E] Running Loop=1
2021-04-15T13:09:24.099Z,1618492164.099 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 141.055143 min 
2021-04-15T13:09:24.099Z,1618492164.099 [Default:CheckIn:E] Stopped
2021-04-15T13:09:24.100Z,1618492164.100 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T13:09:24.100Z,1618492164.100 [Default:CheckIn] Stopped
2021-04-15T13:09:24.100Z,1618492164.100 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T13:09:24.100Z,1618492164.100 [Default:CheckIn](INFO): Running loop #26
2021-04-15T13:09:24.100Z,1618492164.100 [Default:CheckIn] Running Loop=26
2021-04-15T13:09:24.100Z,1618492164.100 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T13:09:24.100Z,1618492164.100 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T13:09:26.062Z,1618492166.062 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,130925.00,A,4131.72755,N,07040.24298,W,0.097,39.23,150421,,,A*45
2021-04-15T13:09:26.065Z,1618492166.065 [NAL9602](INFO): GPS fix at 20210415T130925: (41.528793, -70.670716)
2021-04-15T13:09:26.086Z,1618492166.086 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T13:09:26.086Z,1618492166.086 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T13:09:29.574Z,1618492169.574 [DataOverHttps](INFO): Sending 86 bytes from file Logs/20210415T104405/Courier0079.lzma
2021-04-15T13:09:30.577Z,1618492170.577 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0079.lzma.bak
2021-04-15T13:09:30.577Z,1618492170.577 [DataOverHttps](INFO): SBD MOMSN=106099
2021-04-15T13:09:39.614Z,1618492179.614 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20210415T104405/Express0080.lzma
2021-04-15T13:09:40.617Z,1618492180.617 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0080.lzma.bak
2021-04-15T13:09:40.617Z,1618492180.617 [DataOverHttps](INFO): SBD MOMSN=106103
2021-04-15T13:09:41.851Z,1618492181.851 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T13:09:41.851Z,1618492181.851 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T13:09:41.851Z,1618492181.851 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T13:09:43.843Z,1618492183.843 [NAL9602](INFO): SBD MO Status=0, MOMSN=15532, MT Status=0, MTMSN=0
2021-04-15T13:09:43.843Z,1618492183.843 [NAL9602](INFO): No messages in MT queue
2021-04-15T13:10:14.537Z,1618492214.537 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T13:10:16.984Z,1618492216.984 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2021-04-15T13:14:18.981Z,1618492458.981 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-04-15T13:14:29.094Z,1618492469.094 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2021-04-15T13:14:29.097Z,1618492469.097 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2021-04-15T13:14:39.176Z,1618492479.176 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-04-15T13:14:42.432Z,1618492482.432 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T13:14:42.432Z,1618492482.432 [Default:CheckIn:C.Wait] Stopped
2021-04-15T13:14:42.432Z,1618492482.432 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T13:14:42.432Z,1618492482.432 [Default:CheckIn:D] Running Loop=1
2021-04-15T13:14:42.842Z,1618492482.842 [Default:CheckIn:D] Stopped
2021-04-15T13:14:42.842Z,1618492482.842 [Default:CheckIn:E] Running Loop=1
2021-04-15T13:14:43.233Z,1618492483.233 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 146.374967 min 
2021-04-15T13:14:43.234Z,1618492483.234 [Default:CheckIn:E] Stopped
2021-04-15T13:14:43.234Z,1618492483.234 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T13:14:43.234Z,1618492483.234 [Default:CheckIn] Stopped
2021-04-15T13:14:43.234Z,1618492483.234 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T13:14:43.234Z,1618492483.234 [Default:CheckIn](INFO): Running loop #27
2021-04-15T13:14:43.234Z,1618492483.234 [Default:CheckIn] Running Loop=27
2021-04-15T13:14:43.234Z,1618492483.234 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T13:14:43.234Z,1618492483.234 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T13:14:45.238Z,1618492485.238 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,131444.00,A,4131.72723,N,07040.24320,W,0.039,39.23,150421,,,A*49
2021-04-15T13:14:45.241Z,1618492485.241 [NAL9602](INFO): GPS fix at 20210415T131444: (41.528787, -70.670720)
2021-04-15T13:14:45.292Z,1618492485.292 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T13:14:45.292Z,1618492485.292 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T13:14:48.891Z,1618492488.891 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210415T104405/Courier0082.lzma
2021-04-15T13:14:49.889Z,1618492489.889 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0082.lzma.bak
2021-04-15T13:14:49.889Z,1618492489.889 [DataOverHttps](INFO): SBD MOMSN=106107
2021-04-15T13:14:52.958Z,1618492492.958 [NAL9602](INFO): SBD MO Status=0, MOMSN=15533, MT Status=0, MTMSN=0
2021-04-15T13:14:52.958Z,1618492492.958 [NAL9602](INFO): No messages in MT queue
2021-04-15T13:14:54.134Z,1618492494.134 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2021-04-15T13:14:58.930Z,1618492498.930 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20210415T104405/Express0083.lzma
2021-04-15T13:14:59.929Z,1618492499.929 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0083.lzma.bak
2021-04-15T13:14:59.929Z,1618492499.929 [DataOverHttps](INFO): SBD MOMSN=106110
2021-04-15T13:15:01.029Z,1618492501.029 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T13:15:01.029Z,1618492501.029 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T13:15:01.029Z,1618492501.029 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T13:15:04.225Z,1618492504.225 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-04-15T13:15:10.694Z,1618492510.694 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2021-04-15T13:15:23.621Z,1618492523.621 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T13:15:51.922Z,1618492551.922 [RDI_Pathfinder](ERROR): only read -1 of 1 data item for altitude
2021-04-15T13:20:01.581Z,1618492801.581 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T13:20:01.581Z,1618492801.581 [Default:CheckIn:C.Wait] Stopped
2021-04-15T13:20:01.581Z,1618492801.581 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T13:20:01.581Z,1618492801.581 [Default:CheckIn:D] Running Loop=1
2021-04-15T13:20:02.011Z,1618492802.011 [Default:CheckIn:D] Stopped
2021-04-15T13:20:02.011Z,1618492802.011 [Default:CheckIn:E] Running Loop=1
2021-04-15T13:20:02.387Z,1618492802.387 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 151.694466 min 
2021-04-15T13:20:02.387Z,1618492802.387 [Default:CheckIn:E] Stopped
2021-04-15T13:20:02.388Z,1618492802.388 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T13:20:02.388Z,1618492802.388 [Default:CheckIn] Stopped
2021-04-15T13:20:02.388Z,1618492802.388 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T13:20:02.388Z,1618492802.388 [Default:CheckIn](INFO): Running loop #28
2021-04-15T13:20:02.388Z,1618492802.388 [Default:CheckIn] Running Loop=28
2021-04-15T13:20:02.388Z,1618492802.388 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T13:20:02.388Z,1618492802.388 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T13:20:04.398Z,1618492804.398 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,132003.00,A,4131.72842,N,07040.24376,W,0.019,39.23,150421,,,A*44
2021-04-15T13:20:04.401Z,1618492804.401 [NAL9602](INFO): GPS fix at 20210415T132003: (41.528807, -70.670729)
2021-04-15T13:20:04.421Z,1618492804.421 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T13:20:04.421Z,1618492804.421 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T13:20:08.194Z,1618492808.194 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210415T104405/Courier0085.lzma
2021-04-15T13:20:09.201Z,1618492809.201 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0085.lzma.bak
2021-04-15T13:20:09.201Z,1618492809.201 [DataOverHttps](INFO): SBD MOMSN=106114
2021-04-15T13:20:18.239Z,1618492818.239 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20210415T104405/Express0086.lzma
2021-04-15T13:20:18.937Z,1618492818.937 [NAL9602](INFO): SBD MO Status=0, MOMSN=15534, MT Status=0, MTMSN=0
2021-04-15T13:20:18.937Z,1618492818.937 [NAL9602](INFO): No messages in MT queue
2021-04-15T13:20:19.241Z,1618492819.241 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0086.lzma.bak
2021-04-15T13:20:19.241Z,1618492819.241 [DataOverHttps](INFO): SBD MOMSN=106118
2021-04-15T13:20:20.567Z,1618492820.567 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T13:20:20.567Z,1618492820.567 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T13:20:20.567Z,1618492820.567 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T13:20:49.645Z,1618492849.645 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T13:23:47.005Z,1618493027.005 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2021-04-15T13:25:21.163Z,1618493121.163 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T13:25:21.163Z,1618493121.163 [Default:CheckIn:C.Wait] Stopped
2021-04-15T13:25:21.163Z,1618493121.163 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T13:25:21.163Z,1618493121.163 [Default:CheckIn:D] Running Loop=1
2021-04-15T13:25:21.573Z,1618493121.573 [Default:CheckIn:D] Stopped
2021-04-15T13:25:21.573Z,1618493121.573 [Default:CheckIn:E] Running Loop=1
2021-04-15T13:25:21.985Z,1618493121.985 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 157.020492 min 
2021-04-15T13:25:21.985Z,1618493121.985 [Default:CheckIn:E] Stopped
2021-04-15T13:25:21.986Z,1618493121.986 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T13:25:21.986Z,1618493121.986 [Default:CheckIn] Stopped
2021-04-15T13:25:21.986Z,1618493121.986 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T13:25:21.986Z,1618493121.986 [Default:CheckIn](INFO): Running loop #29
2021-04-15T13:25:21.986Z,1618493121.986 [Default:CheckIn] Running Loop=29
2021-04-15T13:25:21.986Z,1618493121.986 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T13:25:21.986Z,1618493121.986 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T13:25:23.966Z,1618493123.966 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,132523.00,A,4131.73954,N,07040.24068,W,0.058,286.70,150421,,,A*7D
2021-04-15T13:25:23.969Z,1618493123.969 [NAL9602](INFO): GPS fix at 20210415T132523: (41.528992, -70.670678)
2021-04-15T13:25:23.999Z,1618493123.999 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T13:25:23.000Z,1618493124.000 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T13:25:27.518Z,1618493127.518 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210415T104405/Courier0088.lzma
2021-04-15T13:25:28.517Z,1618493128.517 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0088.lzma.bak
2021-04-15T13:25:28.517Z,1618493128.517 [DataOverHttps](INFO): SBD MOMSN=106123
2021-04-15T13:25:37.563Z,1618493137.563 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20210415T104405/Express0089.lzma
2021-04-15T13:25:38.565Z,1618493138.565 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0089.lzma.bak
2021-04-15T13:25:38.565Z,1618493138.565 [DataOverHttps](INFO): SBD MOMSN=106126
2021-04-15T13:25:39.324Z,1618493139.324 [NAL9602](INFO): SBD MO Status=0, MOMSN=15535, MT Status=0, MTMSN=0
2021-04-15T13:25:39.324Z,1618493139.324 [NAL9602](INFO): No messages in MT queue
2021-04-15T13:25:39.764Z,1618493139.764 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T13:25:39.764Z,1618493139.764 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T13:25:39.764Z,1618493139.764 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T13:26:10.024Z,1618493170.024 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T13:26:44.768Z,1618493204.768 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2021-04-15T13:30:40.306Z,1618493440.306 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T13:30:40.306Z,1618493440.306 [Default:CheckIn:C.Wait] Stopped
2021-04-15T13:30:40.306Z,1618493440.306 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T13:30:40.306Z,1618493440.306 [Default:CheckIn:D] Running Loop=1
2021-04-15T13:30:40.709Z,1618493440.709 [Default:CheckIn:D] Stopped
2021-04-15T13:30:40.709Z,1618493440.709 [Default:CheckIn:E] Running Loop=1
2021-04-15T13:30:41.138Z,1618493441.138 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 162.339421 min 
2021-04-15T13:30:41.138Z,1618493441.138 [Default:CheckIn:E] Stopped
2021-04-15T13:30:41.138Z,1618493441.138 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T13:30:41.139Z,1618493441.139 [Default:CheckIn] Stopped
2021-04-15T13:30:41.139Z,1618493441.139 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T13:30:41.139Z,1618493441.139 [Default:CheckIn](INFO): Running loop #30
2021-04-15T13:30:41.139Z,1618493441.139 [Default:CheckIn] Running Loop=30
2021-04-15T13:30:41.139Z,1618493441.139 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T13:30:41.139Z,1618493441.139 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T13:30:43.128Z,1618493443.128 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,133042.00,A,4131.88033,N,07040.35825,W,55.963,332.54,150421,,,A*4A
2021-04-15T13:30:43.130Z,1618493443.130 [NAL9602](INFO): GPS fix at 20210415T133042: (41.531339, -70.672637)
2021-04-15T13:30:43.201Z,1618493443.201 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T13:30:43.201Z,1618493443.201 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T13:30:46.838Z,1618493446.838 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20210415T104405/Courier0091.lzma
2021-04-15T13:30:47.846Z,1618493447.846 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0091.lzma.bak
2021-04-15T13:30:47.846Z,1618493447.846 [DataOverHttps](INFO): SBD MOMSN=106130
2021-04-15T13:30:56.891Z,1618493456.891 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20210415T104405/Express0092.lzma
2021-04-15T13:30:57.898Z,1618493457.898 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0092.lzma.bak
2021-04-15T13:30:57.898Z,1618493457.898 [DataOverHttps](INFO): SBD MOMSN=106133
2021-04-15T13:30:59.082Z,1618493459.082 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T13:30:59.100Z,1618493459.100 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T13:30:59.100Z,1618493459.100 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T13:31:00.095Z,1618493460.095 [NAL9602](INFO): SBD MO Status=0, MOMSN=15536, MT Status=0, MTMSN=0
2021-04-15T13:31:00.095Z,1618493460.095 [NAL9602](INFO): No messages in MT queue
2021-04-15T13:31:30.797Z,1618493490.797 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T13:33:25.137Z,1618493605.137 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2021-04-15T13:33:40.081Z,1618493620.081 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-04-15T13:33:40.101Z,1618493620.101 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2021-04-15T13:34:05.134Z,1618493645.134 [RDI_Pathfinder](ERROR): only read 0 of 4 data items
2021-04-15T13:34:05.139Z,1618493645.139 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2021-04-15T13:34:15.237Z,1618493655.237 [RDI_Pathfinder](ERROR): only read 1 of 4 data items
2021-04-15T13:34:15.242Z,1618493655.242 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2021-04-15T13:34:24.936Z,1618493664.936 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2021-04-15T13:34:24.955Z,1618493664.955 [RDI_PathfinderUp](ERROR): DVL uart error: serial timeout
2021-04-15T13:34:24.955Z,1618493664.955 [RDI_PathfinderUp] Communications Fault, FailCount= 1
2021-04-15T13:34:24.955Z,1618493664.955 [RDI_PathfinderUp](ERROR): Communications Fault
2021-04-15T13:34:25.020Z,1618493665.020 [CBIT](ERROR): Communications Fault in component: RDI_PathfinderUp
2021-04-15T13:34:25.407Z,1618493665.407 [RDI_PathfinderUp](INFO): Powering down
2021-04-15T13:34:26.177Z,1618493666.177 [CBIT](INFO): Clearing failed state for component RDI_PathfinderUp
2021-04-15T13:34:26.177Z,1618493666.177 [RDI_PathfinderUp] No Fault, FailCount= 1
2021-04-15T13:35:20.307Z,1618493720.307 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-04-15T13:35:59.548Z,1618493759.548 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T13:35:59.548Z,1618493759.548 [Default:CheckIn:C.Wait] Stopped
2021-04-15T13:35:59.548Z,1618493759.548 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T13:35:59.548Z,1618493759.548 [Default:CheckIn:D] Running Loop=1
2021-04-15T13:35:59.980Z,1618493759.980 [Default:CheckIn:D] Stopped
2021-04-15T13:35:59.980Z,1618493759.980 [Default:CheckIn:E] Running Loop=1
2021-04-15T13:36:00.304Z,1618493760.304 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 167.660612 min 
2021-04-15T13:36:00.304Z,1618493760.304 [Default:CheckIn:E] Stopped
2021-04-15T13:36:00.304Z,1618493760.304 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T13:36:00.304Z,1618493760.304 [Default:CheckIn] Stopped
2021-04-15T13:36:00.304Z,1618493760.304 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T13:36:00.304Z,1618493760.304 [Default:CheckIn](INFO): Running loop #31
2021-04-15T13:36:00.304Z,1618493760.304 [Default:CheckIn] Running Loop=31
2021-04-15T13:36:00.304Z,1618493760.304 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T13:36:00.304Z,1618493760.304 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T13:36:02.314Z,1618493762.314 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,133601.00,A,4132.74864,N,07041.22012,W,2.099,267.13,150421,,,A*76
2021-04-15T13:36:02.317Z,1618493762.317 [NAL9602](INFO): GPS fix at 20210415T133601: (41.545811, -70.687002)
2021-04-15T13:36:02.327Z,1618493762.327 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T13:36:02.327Z,1618493762.327 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T13:36:06.182Z,1618493766.182 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20210415T104405/Courier0094.lzma
2021-04-15T13:36:07.185Z,1618493767.185 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0094.lzma.bak
2021-04-15T13:36:07.185Z,1618493767.185 [DataOverHttps](INFO): SBD MOMSN=106138
2021-04-15T13:36:15.648Z,1618493775.648 [NAL9602](INFO): SBD MO Status=0, MOMSN=15537, MT Status=0, MTMSN=0
2021-04-15T13:36:15.648Z,1618493775.648 [NAL9602](INFO): No messages in MT queue
2021-04-15T13:36:16.222Z,1618493776.222 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20210415T104405/Express0095.lzma
2021-04-15T13:36:17.225Z,1618493777.225 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0095.lzma.bak
2021-04-15T13:36:17.225Z,1618493777.225 [DataOverHttps](INFO): SBD MOMSN=106141
2021-04-15T13:36:18.491Z,1618493778.491 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T13:36:18.491Z,1618493778.491 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T13:36:18.491Z,1618493778.491 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T13:36:46.348Z,1618493806.348 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T13:41:19.079Z,1618494079.079 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-15T13:41:19.079Z,1618494079.079 [Default:CheckIn:C.Wait] Stopped
2021-04-15T13:41:19.079Z,1618494079.079 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-15T13:41:19.079Z,1618494079.079 [Default:CheckIn:D] Running Loop=1
2021-04-15T13:41:19.463Z,1618494079.463 [Default:CheckIn:D] Stopped
2021-04-15T13:41:19.463Z,1618494079.463 [Default:CheckIn:E] Running Loop=1
2021-04-15T13:41:19.884Z,1618494079.884 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 172.985335 min 
2021-04-15T13:41:19.884Z,1618494079.884 [Default:CheckIn:E] Stopped
2021-04-15T13:41:19.885Z,1618494079.885 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-15T13:41:19.885Z,1618494079.885 [Default:CheckIn] Stopped
2021-04-15T13:41:19.885Z,1618494079.885 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-15T13:41:19.885Z,1618494079.885 [Default:CheckIn](INFO): Running loop #32
2021-04-15T13:41:19.885Z,1618494079.885 [Default:CheckIn] Running Loop=32
2021-04-15T13:41:19.885Z,1618494079.885 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-15T13:41:19.885Z,1618494079.885 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-15T13:41:21.873Z,1618494081.873 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,134121.00,A,4132.76009,N,07041.30719,W,0.292,315.85,150421,,,A*7A
2021-04-15T13:41:21.891Z,1618494081.891 [NAL9602](INFO): GPS fix at 20210415T134121: (41.546002, -70.688453)
2021-04-15T13:41:21.941Z,1618494081.941 [Default:CheckIn:Read_GPS] Stopped
2021-04-15T13:41:21.941Z,1618494081.941 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-15T13:41:25.501Z,1618494085.501 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210415T104405/Courier0097.lzma
2021-04-15T13:41:26.497Z,1618494086.497 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Courier0097.lzma.bak
2021-04-15T13:41:26.497Z,1618494086.497 [DataOverHttps](INFO): SBD MOMSN=106145
2021-04-15T13:41:34.433Z,1618494094.433 [NAL9602](INFO): SBD MO Status=0, MOMSN=15538, MT Status=0, MTMSN=0
2021-04-15T13:41:34.433Z,1618494094.433 [NAL9602](INFO): No messages in MT queue
2021-04-15T13:41:35.535Z,1618494095.535 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20210415T104405/Express0098.lzma
2021-04-15T13:41:36.537Z,1618494096.537 [DataOverHttps](INFO): Moved sent file to Logs/20210415T104405/Express0098.lzma.bak
2021-04-15T13:41:36.537Z,1618494096.537 [DataOverHttps](INFO): SBD MOMSN=106148
2021-04-15T13:41:37.681Z,1618494097.681 [Default:CheckIn:Read_Iridium] Stopped
2021-04-15T13:41:37.681Z,1618494097.681 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-15T13:41:37.682Z,1618494097.682 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-15T13:41:45.354Z,1618494105.354 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude
2021-04-15T13:42:05.146Z,1618494125.146 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-15T13:42:16.700Z,1618494136.700 [DataOverHttps](IMPORTANT): SBD MTMSN=20210415T134215