2021-04-20T14:21:39.464Z,1618928499.464 [Supervisor](DEBUG): Initializing supervisor.
2021-04-20T14:21:39.468Z,1618928499.468 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2021-04-20T14:21:39.469Z,1618928499.469 [SyncHandler](INFO): Protected caller Thread ID is 820
2021-04-20T14:21:39.469Z,1618928499.469 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2021-04-20T14:21:39.470Z,1618928499.470 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2021-04-20T14:21:39.470Z,1618928499.470 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 821
2021-04-20T14:21:39.474Z,1618928499.474 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2021-04-20T14:21:39.493Z,1618928499.493 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2021-04-20T14:21:39.494Z,1618928499.494 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2021-04-20T14:21:39.494Z,1618928499.494 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 822
2021-04-20T14:21:39.496Z,1618928499.496 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2021-04-20T14:21:39.497Z,1618928499.497 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2021-04-20T14:21:39.497Z,1618928499.497 [logger ThreadHandler](INFO): Protected caller Thread ID is 823
2021-04-20T14:21:39.501Z,1618928499.501 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2021-04-20T14:21:39.502Z,1618928499.502 [Supervisor](INFO): Looking for Config files in directory: Config/
2021-04-20T14:21:39.506Z,1618928499.506 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2021-04-20T14:21:39.855Z,1618928499.855 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2021-04-20T14:21:39.856Z,1618928499.856 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2021-04-20T14:21:40.481Z,1618928500.481 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2021-04-20T14:21:40.483Z,1618928500.483 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2021-04-20T14:21:40.585Z,1618928500.585 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2021-04-20T14:21:40.585Z,1618928500.585 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2021-04-20T14:21:41.114Z,1618928501.114 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2021-04-20T14:21:41.116Z,1618928501.116 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2021-04-20T14:21:41.213Z,1618928501.213 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2021-04-20T14:21:41.214Z,1618928501.214 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2021-04-20T14:21:41.296Z,1618928501.296 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2021-04-20T14:21:41.660Z,1618928501.660 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2021-04-20T14:21:41.662Z,1618928501.662 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2021-04-20T14:21:41.812Z,1618928501.812 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2021-04-20T14:21:41.814Z,1618928501.814 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2021-04-20T14:21:41.941Z,1618928501.941 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2021-04-20T14:21:41.943Z,1618928501.943 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2021-04-20T14:21:42.187Z,1618928502.187 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2021-04-20T14:21:42.188Z,1618928502.188 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2021-04-20T14:21:43.206Z,1618928503.206 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2021-04-20T14:21:43.208Z,1618928503.208 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2021-04-20T14:21:43.577Z,1618928503.577 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2021-04-20T14:21:43.578Z,1618928503.578 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2021-04-20T14:21:43.658Z,1618928503.658 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2021-04-20T14:21:43.858Z,1618928503.858 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2021-04-20T14:21:43.859Z,1618928503.859 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2021-04-20T14:21:44.073Z,1618928504.073 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2021-04-20T14:21:44.073Z,1618928504.073 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2021-04-20T14:21:44.326Z,1618928504.326 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2021-04-20T14:21:44.328Z,1618928504.328 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-brizo/
2021-04-20T14:21:44.331Z,1618928504.331 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Control.cfg
2021-04-20T14:21:44.430Z,1618928504.430 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Sensor.cfg
2021-04-20T14:21:44.581Z,1618928504.581 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Simulator.cfg
2021-04-20T14:21:44.669Z,1618928504.669 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/secure.cfg
2021-04-20T14:21:44.753Z,1618928504.753 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Servo.cfg
2021-04-20T14:21:44.864Z,1618928504.864 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/vehicle.cfg
2021-04-20T14:21:45.054Z,1618928505.054 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Battery.cfg
2021-04-20T14:21:45.314Z,1618928505.314 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2021-04-20T14:21:45.316Z,1618928505.316 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Science.cfg
2021-04-20T14:21:45.454Z,1618928505.454 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/logger.cfg
2021-04-20T14:21:45.551Z,1618928505.551 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/BIT.cfg
2021-04-20T14:21:45.658Z,1618928505.658 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Navigation.cfg
2021-04-20T14:21:45.754Z,1618928505.754 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2021-04-20T14:21:45.766Z,1618928505.766 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2021-04-20T14:21:45.872Z,1618928505.872 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2021-04-20T14:21:45.874Z,1618928505.874 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2021-04-20T14:21:45.890Z,1618928505.890 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2021-04-20T14:21:45.891Z,1618928505.891 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2021-04-20T14:21:45.948Z,1618928505.948 [DepthRateCalculator] Loaded
2021-04-20T14:21:45.948Z,1618928505.948 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2021-04-20T14:21:45.953Z,1618928505.953 [PitchRateCalculator] Loaded
2021-04-20T14:21:45.953Z,1618928505.953 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2021-04-20T14:21:45.964Z,1618928505.964 [SpeedCalculator] Loaded
2021-04-20T14:21:45.964Z,1618928505.964 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2021-04-20T14:21:45.976Z,1618928505.976 [TempGradientCalculator] Loaded
2021-04-20T14:21:45.977Z,1618928505.977 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2021-04-20T14:21:45.981Z,1618928505.981 [YawRateCalculator] Loaded
2021-04-20T14:21:45.982Z,1618928505.982 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2021-04-20T14:21:46.001Z,1618928506.001 [ElevatorOffsetCalculator] Loaded
2021-04-20T14:21:46.002Z,1618928506.002 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2021-04-20T14:21:46.002Z,1618928506.002 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2021-04-20T14:21:46.003Z,1618928506.003 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2021-04-20T14:21:46.070Z,1618928506.070 [VerticalControl](DEBUG): Construct VerticalControl.
2021-04-20T14:21:46.126Z,1618928506.126 [VerticalControl] Loaded
2021-04-20T14:21:46.126Z,1618928506.126 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2021-04-20T14:21:46.128Z,1618928506.128 [HorizontalControl](DEBUG): Construct HorizontalControl.
2021-04-20T14:21:46.165Z,1618928506.165 [HorizontalControl] Loaded
2021-04-20T14:21:46.166Z,1618928506.166 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2021-04-20T14:21:46.168Z,1618928506.168 [SpeedControl](DEBUG): Construct SpeedControl.
2021-04-20T14:21:46.171Z,1618928506.171 [SpeedControl] Loaded
2021-04-20T14:21:46.171Z,1618928506.171 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2021-04-20T14:21:46.173Z,1618928506.173 [LoopControl](DEBUG): Construct LoopControl.
2021-04-20T14:21:46.174Z,1618928506.174 [LoopControl] Loaded
2021-04-20T14:21:46.174Z,1618928506.174 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2021-04-20T14:21:46.174Z,1618928506.174 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2021-04-20T14:21:46.175Z,1618928506.175 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2021-04-20T14:21:46.271Z,1618928506.271 [DeadReckonUsingMultipleVelocitySources] Loaded
2021-04-20T14:21:46.271Z,1618928506.271 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2021-04-20T14:21:46.284Z,1618928506.284 [NavChart] Loaded
2021-04-20T14:21:46.284Z,1618928506.284 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2021-04-20T14:21:46.289Z,1618928506.289 [UniversalFixResidualReporter] Loaded
2021-04-20T14:21:46.289Z,1618928506.289 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2021-04-20T14:21:46.290Z,1618928506.290 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2021-04-20T14:21:46.291Z,1618928506.291 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2021-04-20T14:21:46.415Z,1618928506.415 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2021-04-20T14:21:46.416Z,1618928506.416 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2021-04-20T14:21:47.127Z,1618928507.127 [AHRS_M2] Loaded
2021-04-20T14:21:47.127Z,1618928507.127 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2021-04-20T14:21:47.417Z,1618928507.417 [BackseatComponent] Loaded
2021-04-20T14:21:47.417Z,1618928507.417 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2021-04-20T14:21:47.434Z,1618928507.434 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408674E0
2021-04-20T14:21:47.436Z,1618928507.436 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 905
2021-04-20T14:21:47.447Z,1618928507.447 [LcmUniversalReporter] Loaded
2021-04-20T14:21:47.447Z,1618928507.447 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2021-04-20T14:21:48.922Z,1618928508.922 [BPC1] Loaded
2021-04-20T14:21:48.922Z,1618928508.922 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2021-04-20T14:21:49.070Z,1618928509.070 [DataOverHttps] Loaded
2021-04-20T14:21:49.071Z,1618928509.071 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2021-04-20T14:21:49.072Z,1618928509.072 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408974E0
2021-04-20T14:21:49.072Z,1618928509.072 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 906
2021-04-20T14:21:49.091Z,1618928509.091 [Depth_Keller] Loaded
2021-04-20T14:21:49.091Z,1618928509.091 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2021-04-20T14:21:49.096Z,1618928509.096 [DropWeight] Loaded
2021-04-20T14:21:49.096Z,1618928509.096 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2021-04-20T14:21:49.129Z,1618928509.129 [DVL_micro] Loaded
2021-04-20T14:21:49.130Z,1618928509.130 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2021-04-20T14:21:49.187Z,1618928509.187 [NAL9602] Loaded
2021-04-20T14:21:49.187Z,1618928509.187 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2021-04-20T14:21:49.215Z,1618928509.215 [Onboard] Loaded
2021-04-20T14:21:49.215Z,1618928509.215 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2021-04-20T14:21:49.216Z,1618928509.216 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408C74E0
2021-04-20T14:21:49.217Z,1618928509.217 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 907
2021-04-20T14:21:49.229Z,1618928509.229 [Radio_Surface] Loaded
2021-04-20T14:21:49.229Z,1618928509.229 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2021-04-20T14:21:49.230Z,1618928509.230 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408F74E0
2021-04-20T14:21:49.231Z,1618928509.231 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 908
2021-04-20T14:21:49.309Z,1618928509.309 [DAT] Loaded
2021-04-20T14:21:49.309Z,1618928509.309 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2021-04-20T14:21:49.310Z,1618928509.310 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2021-04-20T14:21:49.310Z,1618928509.310 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2021-04-20T14:21:49.442Z,1618928509.442 [BuoyancyServo] Loaded
2021-04-20T14:21:49.442Z,1618928509.442 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2021-04-20T14:21:49.461Z,1618928509.461 [ElevatorServo] Loaded
2021-04-20T14:21:49.461Z,1618928509.461 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2021-04-20T14:21:49.479Z,1618928509.479 [MassServo] Loaded
2021-04-20T14:21:49.479Z,1618928509.479 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2021-04-20T14:21:49.497Z,1618928509.497 [RudderServo] Loaded
2021-04-20T14:21:49.497Z,1618928509.497 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2021-04-20T14:21:49.514Z,1618928509.514 [ThrusterServo] Loaded
2021-04-20T14:21:49.514Z,1618928509.514 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2021-04-20T14:21:49.515Z,1618928509.515 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2021-04-20T14:21:49.515Z,1618928509.515 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2021-04-20T14:21:49.592Z,1618928509.592 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2021-04-20T14:21:49.592Z,1618928509.592 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2021-04-20T14:21:49.634Z,1618928509.634 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2021-04-20T14:21:49.635Z,1618928509.635 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2021-04-20T14:21:50.074Z,1618928510.074 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2021-04-20T14:21:50.075Z,1618928510.075 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2021-04-20T14:21:50.289Z,1618928510.289 [CTD_Seabird] Loaded
2021-04-20T14:21:50.290Z,1618928510.290 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2021-04-20T14:21:50.291Z,1618928510.291 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A7F4E0
2021-04-20T14:21:50.291Z,1618928510.291 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 910
2021-04-20T14:21:50.323Z,1618928510.323 [ESPComponent] Loaded
2021-04-20T14:21:50.323Z,1618928510.323 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2021-04-20T14:21:50.342Z,1618928510.342 [PAR_Licor] Loaded
2021-04-20T14:21:50.342Z,1618928510.342 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2021-04-20T14:21:50.372Z,1618928510.372 [WetLabsBB2FL] Loaded
2021-04-20T14:21:50.373Z,1618928510.373 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2021-04-20T14:21:50.374Z,1618928510.374 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AAF4E0
2021-04-20T14:21:50.374Z,1618928510.374 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 911
2021-04-20T14:21:50.375Z,1618928510.375 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2021-04-20T14:21:50.375Z,1618928510.375 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2021-04-20T14:21:50.540Z,1618928510.540 [SBIT](DEBUG): Construct Startup Built In Test.
2021-04-20T14:21:50.549Z,1618928510.549 [SBIT] Loaded
2021-04-20T14:21:50.549Z,1618928510.549 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2021-04-20T14:21:50.552Z,1618928510.552 [IBIT](DEBUG): Construct Initiated Built In Test.
2021-04-20T14:21:50.564Z,1618928510.564 [IBIT] Loaded
2021-04-20T14:21:50.565Z,1618928510.565 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2021-04-20T14:21:50.570Z,1618928510.570 [CBIT](DEBUG): Construct Continuous Built In Test.
2021-04-20T14:21:50.669Z,1618928510.669 [CBIT] Loaded
2021-04-20T14:21:50.670Z,1618928510.670 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2021-04-20T14:21:50.670Z,1618928510.670 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2021-04-20T14:21:50.676Z,1618928510.676 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2021-04-20T14:21:50.679Z,1618928510.679 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2021-04-20T14:21:50.689Z,1618928510.689 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2021-04-20T14:21:50.690Z,1618928510.690 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B1B4E0
2021-04-20T14:21:50.690Z,1618928510.690 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 912
2021-04-20T14:21:50.695Z,1618928510.695 [Supervisor](INFO): Main Thread ID is 816
2021-04-20T14:21:50.695Z,1618928510.695 [Supervisor](DEBUG): Running supervisor.
2021-04-20T14:21:50.696Z,1618928510.696 [CommandLine ThreadHandler](INFO): Handler Thread ID is 913
2021-04-20T14:21:50.698Z,1618928510.698 [controlThread ThreadHandler](INFO): Handler Thread ID is 914
2021-04-20T14:21:50.699Z,1618928510.699 [controlThread](DEBUG): Initializing ControlThread
2021-04-20T14:21:50.700Z,1618928510.700 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2021-04-20T14:21:50.700Z,1618928510.700 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2021-04-20T14:21:50.700Z,1618928510.700 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2021-04-20T14:21:50.701Z,1618928510.701 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2021-04-20T14:21:50.701Z,1618928510.701 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2021-04-20T14:21:50.702Z,1618928510.702 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2021-04-20T14:21:50.702Z,1618928510.702 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2021-04-20T14:21:50.704Z,1618928510.704 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2021-04-20T14:21:50.705Z,1618928510.705 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2021-04-20T14:21:50.705Z,1618928510.705 [LoopControl](DEBUG): Initialize LoopControlComponent.
2021-04-20T14:21:50.706Z,1618928510.706 [NavChart](DEBUG): Initialize NavChart Navigation.
2021-04-20T14:21:50.706Z,1618928510.706 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2021-04-20T14:21:50.714Z,1618928510.714 [SBIT](INFO): Initialize SBIT Component.
2021-04-20T14:21:50.715Z,1618928510.715 [SBIT](IMPORTANT): git: 2021-04-12
2021-04-20T14:21:50.715Z,1618928510.715 [SBIT](INFO): git hash: 4d37ca66b772b9605b4b6eba7ca05c94731fcf29
2021-04-20T14:21:50.715Z,1618928510.715 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2021-04-20T14:21:50.715Z,1618928510.715 [SBIT](IMPORTANT): Kernel Version:#1 PREEMPT Tue Sep 24 11:12:27 PDT 2019
2021-04-20T14:21:50.717Z,1618928510.717 [SBIT](INFO): Beginning SBIT in 24.000000 seconds.
2021-04-20T14:21:50.717Z,1618928510.717 [IBIT](INFO): Initialize IBIT Component.
2021-04-20T14:21:50.718Z,1618928510.718 [CBIT](DEBUG): Initialize CBIT Component.
2021-04-20T14:21:50.719Z,1618928510.719 [logger ThreadHandler](INFO): Handler Thread ID is 915
2021-04-20T14:21:50.730Z,1618928510.730 [CBIT](DEBUG): Initialized mux pins.
2021-04-20T14:21:50.730Z,1618928510.730 [CBIT](DEBUG): Initializing the watchdog timer.
2021-04-20T14:21:50.738Z,1618928510.738 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 916
2021-04-20T14:21:50.750Z,1618928510.750 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 917
2021-04-20T14:21:50.751Z,1618928510.751 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2021-04-20T14:21:50.754Z,1618928510.754 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2021-04-20T14:21:50.754Z,1618928510.754 [CBIT](DEBUG): Initializing heartbeat.
2021-04-20T14:21:50.762Z,1618928510.762 [Onboard ThreadHandler](INFO): Handler Thread ID is 918
2021-04-20T14:21:50.792Z,1618928510.792 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 919
2021-04-20T14:21:50.802Z,1618928510.802 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 920
2021-04-20T14:21:50.803Z,1618928510.803 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2021-04-20T14:21:50.807Z,1618928510.807 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 922
2021-04-20T14:21:50.810Z,1618928510.810 [WetLabsBB2FL](INFO): Powering up
2021-04-20T14:21:50.811Z,1618928510.811 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 924
2021-04-20T14:21:50.820Z,1618928510.820 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2021-04-20T14:21:50.820Z,1618928510.820 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2021-04-20T14:21:50.821Z,1618928510.821 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2021-04-20T14:21:50.821Z,1618928510.821 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2021-04-20T14:21:50.821Z,1618928510.821 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2021-04-20T14:21:50.821Z,1618928510.821 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2021-04-20T14:21:50.821Z,1618928510.821 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2021-04-20T14:21:50.821Z,1618928510.821 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2021-04-20T14:21:50.822Z,1618928510.822 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2021-04-20T14:21:50.822Z,1618928510.822 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2021-04-20T14:21:50.822Z,1618928510.822 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2021-04-20T14:21:50.822Z,1618928510.822 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2021-04-20T14:21:50.822Z,1618928510.822 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2021-04-20T14:21:50.823Z,1618928510.823 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2021-04-20T14:21:50.823Z,1618928510.823 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2021-04-20T14:21:50.823Z,1618928510.823 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2021-04-20T14:21:50.826Z,1618928510.826 [CBIT](DEBUG): Deactivating GF circuits.
2021-04-20T14:21:50.826Z,1618928510.826 [CBIT](DEBUG): Deactivating emergency mode.
2021-04-20T14:21:50.862Z,1618928510.862 [CBIT](DEBUG): Backplane powered.
2021-04-20T14:21:50.863Z,1618928510.863 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2021-04-20T14:21:50.889Z,1618928510.889 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2021-04-20T14:21:50.912Z,1618928510.912 [MissionManager](DEBUG):
2021-04-20T14:21:50.913Z,1618928510.913 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2021-04-20T14:21:50.987Z,1618928510.987 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2021-04-20T14:21:50.988Z,1618928510.988 [Default:A.Wait](DEBUG): Construct Wait.
2021-04-20T14:21:51.002Z,1618928511.002 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-04-20T14:21:51.045Z,1618928511.045 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-04-20T14:21:51.078Z,1618928511.078 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-04-20T14:21:51.104Z,1618928511.104 [Default:E.Execute](DEBUG): Construct Execute.
2021-04-20T14:21:51.107Z,1618928511.107 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2021-04-20T14:21:51.118Z,1618928511.118 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,DAT,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2021-04-20T14:21:51.130Z,1618928511.130 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2021-04-20T14:21:51.194Z,1618928511.194 [Radio_Surface](INFO): Powering up
2021-04-20T14:21:51.417Z,1618928511.417 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2021-04-20T14:21:51.417Z,1618928511.417 [DAT](INFO): Powering up
2021-04-20T14:21:51.426Z,1618928511.426 [DAT](DEBUG): Initializing DAT.
2021-04-20T14:21:51.468Z,1618928511.468 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2021-04-20T14:21:51.474Z,1618928511.474 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2021-04-20T14:21:51.475Z,1618928511.475 [ElevatorServo](DEBUG): Initializing EZServoServo.
2021-04-20T14:21:51.482Z,1618928511.482 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2021-04-20T14:21:51.483Z,1618928511.483 [MassServo](DEBUG): Initializing EZServoServo.
2021-04-20T14:21:51.490Z,1618928511.490 [MassServo](DEBUG): Initializing MassServo.
2021-04-20T14:21:51.491Z,1618928511.491 [RudderServo](DEBUG): Initializing EZServoServo.
2021-04-20T14:21:51.499Z,1618928511.499 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2021-04-20T14:21:51.522Z,1618928511.522 [RudderServo](DEBUG): Initializing RudderServo.
2021-04-20T14:21:51.523Z,1618928511.523 [ThrusterServo](DEBUG): Initializing EZServoServo.
2021-04-20T14:21:51.530Z,1618928511.530 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2021-04-20T14:21:53.422Z,1618928513.422 [WetLabsBB2FL](INFO): Powering down
2021-04-20T14:22:05.735Z,1618928525.735 [DAT](INFO): commRate: 800
2021-04-20T14:22:07.752Z,1618928527.752 [DAT](INFO): entering command mode
2021-04-20T14:22:08.156Z,1618928528.156 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:08.560Z,1618928528.560 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:08.973Z,1618928528.973 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:09.368Z,1618928529.368 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:09.777Z,1618928529.777 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:10.176Z,1618928530.176 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:10.580Z,1618928530.580 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:10.984Z,1618928530.984 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:11.402Z,1618928531.402 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:11.792Z,1618928531.792 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:12.196Z,1618928532.196 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:12.600Z,1618928532.600 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:13.008Z,1618928533.008 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:13.408Z,1618928533.408 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:13.821Z,1618928533.821 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:14.216Z,1618928534.216 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:14.620Z,1618928534.620 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:15.024Z,1618928535.024 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:15.428Z,1618928535.428 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:15.507Z,1618928535.507 [SBIT](IMPORTANT): Beginning Startup BIT
2021-04-20T14:22:15.515Z,1618928535.515 [CBIT](IMPORTANT): Beginning ground fault scan
2021-04-20T14:22:15.832Z,1618928535.832 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:16.252Z,1618928536.252 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:16.649Z,1618928536.649 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:17.044Z,1618928537.044 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:17.452Z,1618928537.452 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:17.876Z,1618928537.876 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:18.281Z,1618928538.281 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:18.672Z,1618928538.672 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:19.073Z,1618928539.073 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:19.468Z,1618928539.468 [NAL9602](INFO): Powering up NAL9602
2021-04-20T14:22:19.469Z,1618928539.469 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:19.873Z,1618928539.873 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:20.277Z,1618928540.277 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:20.283Z,1618928540.283 [CommandLine](IMPORTANT): got command report mod platform_orientation
2021-04-20T14:22:20.484Z,1618928540.484 [Reporter](INFO): platform_orientation 4.507849 rad
2021-04-20T14:22:20.680Z,1618928540.680 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:20.831Z,1618928540.831 [Reporter](INFO): platform_orientation 4.507914 rad
2021-04-20T14:22:21.094Z,1618928541.094 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:21.155Z,1618928541.155 [Reporter](INFO): platform_orientation 4.507933 rad
2021-04-20T14:22:21.508Z,1618928541.508 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:21.576Z,1618928541.576 [Reporter](INFO): platform_orientation 4.507890 rad
2021-04-20T14:22:21.892Z,1618928541.892 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:21.968Z,1618928541.968 [Reporter](INFO): platform_orientation 4.507867 rad
2021-04-20T14:22:22.296Z,1618928542.296 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:22.471Z,1618928542.471 [Reporter](INFO): platform_orientation 4.507862 rad
2021-04-20T14:22:22.700Z,1618928542.700 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:22.773Z,1618928542.773 [Reporter](INFO): platform_orientation 4.507909 rad
2021-04-20T14:22:23.104Z,1618928543.104 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-20T14:22:23.104Z,1618928543.104 [DAT](FAULT): failed to enter command mode
2021-04-20T14:22:23.193Z,1618928543.193 [Reporter](INFO): platform_orientation 4.507940 rad
2021-04-20T14:22:23.508Z,1618928543.508 [DAT](INFO): entering command mode
2021-04-20T14:22:23.667Z,1618928543.667 [Reporter](INFO): platform_orientation 4.507982 rad
2021-04-20T14:22:23.921Z,1618928543.921 [DAT](INFO): setting verbose to 3
2021-04-20T14:22:24.007Z,1618928544.007 [Reporter](INFO): platform_orientation 4.507911 rad
2021-04-20T14:22:24.331Z,1618928544.331 [DAT](INFO): set verbose to 3
2021-04-20T14:22:24.331Z,1618928544.331 [DAT](INFO): setting DatVerbose to 27440
2021-04-20T14:22:24.429Z,1618928544.429 [Reporter](INFO): platform_orientation 4.507926 rad
2021-04-20T14:22:24.727Z,1618928544.727 [DAT](INFO): set DatVerbose to 27440
2021-04-20T14:22:24.727Z,1618928544.727 [DAT](INFO): setting transmit power to 8
2021-04-20T14:22:24.935Z,1618928544.935 [Reporter](INFO): platform_orientation 4.507868 rad
2021-04-20T14:22:25.125Z,1618928545.125 [DAT](INFO): set transmit power to 8
2021-04-20T14:22:25.126Z,1618928545.126 [DAT](INFO): setting local address to 8
2021-04-20T14:22:25.220Z,1618928545.220 [Reporter](INFO): platform_orientation 4.507829 rad
2021-04-20T14:22:25.439Z,1618928545.439 [CommandLine](IMPORTANT): got command report clear
2021-04-20T14:22:25.529Z,1618928545.529 [DAT](INFO): set local address to 8
2021-04-20T14:22:26.410Z,1618928546.410 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.010426
CHAN A1 (24V): -0.002080
CHAN A2 (12V): -0.000325
CHAN A3 (5V): 0.000555
CHAN B0 (3.3V): -0.001137
CHAN B1 (3.15aV): 0.000353
CHAN B2 (3.15bV): 0.000077
CHAN B3 (GND): 0.000525
OPEN: -0.004597
Full Scale Calc: 4.765 mA, -1.589 mA
2021-04-20T14:22:30.376Z,1618928550.376 [NAL9602](INFO): NAL9602 initialized
2021-04-20T14:23:09.621Z,1618928589.621 [SBIT](IMPORTANT): SBIT PASSED
2021-04-20T14:23:09.621Z,1618928589.621 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2021-04-20T14:23:09.622Z,1618928589.622 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;
2021-04-20T14:23:09.622Z,1618928589.622 [SBIT](IMPORTANT): BackseatComponent.loadAtStartup=1 bool;
2021-04-20T14:23:09.622Z,1618928589.622 [SBIT](IMPORTANT): BackseatComponent.simulateHardware=1 bool;
2021-04-20T14:23:09.622Z,1618928589.622 [SBIT](IMPORTANT): Express linearApproximation CTD_Seabird.bin_median_sea_water_salinity 0.010000 practical_salinity_unit;
2021-04-20T14:23:09.622Z,1618928589.622 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=214.815570 cubic_centimeter;
2021-04-20T14:23:09.622Z,1618928589.622 [SBIT](IMPORTANT): VerticalControl.massDefault=-1 millimeter;
2021-04-20T14:23:10.012Z,1618928590.012 [MissionManager](IMPORTANT): Started mission Startup
2021-04-20T14:23:10.012Z,1618928590.012 [Startup] Running Loop=1
2021-04-20T14:23:10.012Z,1618928590.012 [Startup](DEBUG): Aggregate::initialize Startup
2021-04-20T14:23:10.012Z,1618928590.012 [Startup:A.GoToSurface] Running Loop=1
2021-04-20T14:23:10.012Z,1618928590.012 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-04-20T14:23:10.013Z,1618928590.013 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-04-20T14:23:10.014Z,1618928590.014 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-04-20T14:23:10.014Z,1618928590.014 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-04-20T14:23:10.015Z,1618928590.015 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-04-20T14:23:10.015Z,1618928590.015 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-04-20T14:23:10.016Z,1618928590.016 [Startup:StartupSatComms] Running Loop=1
2021-04-20T14:23:10.016Z,1618928590.016 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2021-04-20T14:23:10.017Z,1618928590.017 [Startup:StartupSatComms:A] Running Loop=1
2021-04-20T14:23:10.412Z,1618928590.412 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2021-04-20T14:23:22.591Z,1618928602.591 [CommandLine](IMPORTANT): got command burn on
2021-04-20T14:23:22.591Z,1618928602.591 [CommandLine](IMPORTANT): Activating dropweight wire
2021-04-20T14:23:59.427Z,1618928639.427 [CommandLine](IMPORTANT): got command burn off
2021-04-20T14:23:59.428Z,1618928639.428 [CommandLine](IMPORTANT): Deactivating dropweight wire
2021-04-20T14:24:04.605Z,1618928644.605 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005630
2021-04-20T14:24:10.197Z,1618928650.197 [Startup:StartupSatComms:A](INFO): Timed out from 2021-04-20T14:23:10.0Z
2021-04-20T14:24:10.197Z,1618928650.197 [Startup:StartupSatComms:A] Stopped
2021-04-20T14:24:10.197Z,1618928650.197 [Startup:StartupSatComms:B] Running Loop=1
2021-04-20T14:24:10.584Z,1618928650.584 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-04-20T14:24:16.958Z,1618928656.958 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20210420T142139/Courier0000.lzma
2021-04-20T14:24:17.960Z,1618928657.960 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0000.lzma.bak
2021-04-20T14:24:17.960Z,1618928657.960 [DataOverHttps](INFO): SBD MOMSN=15589998
2021-04-20T14:24:33.684Z,1618928673.684 [DataOverHttps](INFO): Sending 1009 bytes from file Logs/20210420T142139/Express0001.lzma
2021-04-20T14:24:34.683Z,1618928674.683 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0001.lzma.bak
2021-04-20T14:24:34.684Z,1618928674.684 [DataOverHttps](INFO): SBD MOMSN=15590001
2021-04-20T14:24:36.043Z,1618928676.043 [Startup:StartupSatComms:B] Stopped
2021-04-20T14:24:36.043Z,1618928676.043 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2021-04-20T14:24:36.043Z,1618928676.043 [Startup:StartupSatComms] Stopped
2021-04-20T14:24:36.043Z,1618928676.043 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2021-04-20T14:24:36.044Z,1618928676.044 [Startup](INFO): Completed Startup
2021-04-20T14:24:36.044Z,1618928676.044 [MissionManager](INFO): Startup is completed.
2021-04-20T14:24:36.044Z,1618928676.044 [MissionManager](INFO): Uninitializing Mission Startup
2021-04-20T14:24:36.044Z,1618928676.044 [Startup] Stopped
2021-04-20T14:24:36.045Z,1618928676.045 [Startup](DEBUG): Aggregate::uninitialize Startup
2021-04-20T14:24:36.045Z,1618928676.045 [Startup:A.GoToSurface] Stopped
2021-04-20T14:24:36.045Z,1618928676.045 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-04-20T14:24:36.445Z,1618928676.445 [MissionManager](IMPORTANT): Started mission Default
2021-04-20T14:24:36.445Z,1618928676.445 [Default] Running Loop=1
2021-04-20T14:24:36.445Z,1618928676.445 [Default](DEBUG): Aggregate::initialize Default
2021-04-20T14:24:36.445Z,1618928676.445 [Default:B.GoToSurface] Running Loop=1
2021-04-20T14:24:36.445Z,1618928676.445 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-04-20T14:24:36.462Z,1618928676.462 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-04-20T14:24:36.462Z,1618928676.462 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-04-20T14:24:36.462Z,1618928676.462 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-04-20T14:24:36.463Z,1618928676.463 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-04-20T14:24:36.463Z,1618928676.463 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-04-20T14:24:36.463Z,1618928676.463 [Default:A.Wait] Running Loop=1
2021-04-20T14:24:36.463Z,1618928676.463 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-04-20T14:24:49.793Z,1618928689.793 [Default:A.Wait](INFO): Done Waiting.
2021-04-20T14:24:49.793Z,1618928689.793 [Default:A.Wait] Stopped
2021-04-20T14:24:49.793Z,1618928689.793 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T14:24:50.197Z,1618928690.197 [Default:CheckIn] Running Loop=1
2021-04-20T14:24:50.197Z,1618928690.197 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T14:24:50.197Z,1618928690.197 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T14:24:50.609Z,1618928690.609 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2021-04-20T14:24:50.983Z,1618928690.983 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2021-04-20T14:24:50.983Z,1618928690.983 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T14:24:50.994Z,1618928690.994 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T14:24:51.453Z,1618928691.453 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T14:24:51.454Z,1618928691.454 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2021-04-20T14:26:31.167Z,1618928791.167 [DVL_micro](ERROR): only read 3 of 4 data items
2021-04-20T14:26:31.168Z,1618928791.168 [DVL_micro](ERROR): Failed to parse:
:BI,-00092,+00048,+00467,+
2021-04-20T14:27:33.380Z,1618928853.380 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-04-20T14:27:51.971Z,1618928871.971 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2021-04-20T14:27:51.971Z,1618928871.971 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T14:27:51.982Z,1618928871.982 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T14:27:52.386Z,1618928872.386 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T14:27:52.386Z,1618928872.386 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2021-04-20T14:28:51.418Z,1618928931.418 [DVL_micro](ERROR): DVL uart error: serial timeout
2021-04-20T14:28:51.418Z,1618928931.418 [DVL_micro] Communications Fault, FailCount= 1
2021-04-20T14:28:51.418Z,1618928931.418 [DVL_micro](ERROR): Communications Fault
2021-04-20T14:28:51.418Z,1618928931.418 [DVL_micro](ERROR): Failed to parse:
2021-04-20T14:28:51.441Z,1618928931.441 [CBIT](ERROR): Communications Fault in component: DVL_micro
2021-04-20T14:28:51.822Z,1618928931.822 [DVL_micro](INFO): Powering down
2021-04-20T14:28:52.600Z,1618928932.600 [CBIT](INFO): Clearing failed state for component DVL_micro
2021-04-20T14:28:52.600Z,1618928932.600 [DVL_micro] No Fault, FailCount= 1
2021-04-20T14:29:50.372Z,1618928990.372 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-20T14:24:50.2Z
2021-04-20T14:29:50.372Z,1618928990.372 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T14:29:50.372Z,1618928990.372 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T14:29:50.745Z,1618928990.745 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-04-20T14:29:57.777Z,1618928997.777 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210420T142139/Courier0004.lzma
2021-04-20T14:29:58.780Z,1618928998.780 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0004.lzma.bak
2021-04-20T14:29:58.780Z,1618928998.780 [DataOverHttps](INFO): SBD MOMSN=15590027
2021-04-20T14:30:04.326Z,1618929004.326 [CommandLine](IMPORTANT): got command failComponent
2021-04-20T14:30:04.327Z,1618929004.327 [CommandLine](IMPORTANT): Failed components:
2021-04-20T14:30:04.327Z,1618929004.327 [CommandLine](IMPORTANT): No failed Components.
2021-04-20T14:30:14.294Z,1618929014.294 [DataOverHttps](INFO): Sending 188 bytes from file Logs/20210420T142139/Express0005.lzma
2021-04-20T14:30:15.296Z,1618929015.296 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0005.lzma.bak
2021-04-20T14:30:15.296Z,1618929015.296 [DataOverHttps](INFO): SBD MOMSN=15590029
2021-04-20T14:30:16.643Z,1618929016.643 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T14:30:16.643Z,1618929016.643 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T14:30:16.644Z,1618929016.644 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T14:30:25.916Z,1618929025.916 [BPC1](ERROR): Battery stick #6 (s/n: 00CA) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2021-04-20T14:30:25.917Z,1618929025.917 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6.
2021-04-20T14:30:25.921Z,1618929025.921 [BPC1](INFO): Received data from all battery sticks.
2021-04-20T14:30:52.964Z,1618929052.964 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2021-04-20T14:30:52.964Z,1618929052.964 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T14:30:52.974Z,1618929052.974 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T14:30:53.380Z,1618929053.380 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T14:30:53.380Z,1618929053.380 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2021-04-20T14:31:45.975Z,1618929105.975 [CommandLine](IMPORTANT): got command burn off
2021-04-20T14:31:45.975Z,1618929105.975 [CommandLine](IMPORTANT): Deactivating dropweight wire
2021-04-20T14:32:33.552Z,1618929153.552 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-04-20T14:32:33.552Z,1618929153.552 [NAL9602] Data Fault, FailCount= 1
2021-04-20T14:32:33.552Z,1618929153.552 [NAL9602](ERROR): Data Fault
2021-04-20T14:32:33.570Z,1618929153.570 [CBIT](ERROR): Data Fault in component: NAL9602
2021-04-20T14:32:33.952Z,1618929153.952 [NAL9602](INFO): Powering down
2021-04-20T14:32:34.800Z,1618929154.800 [CBIT](INFO): Clearing failed state for component NAL9602
2021-04-20T14:32:34.800Z,1618929154.800 [NAL9602] No Fault, FailCount= 1
2021-04-20T14:33:04.256Z,1618929184.256 [NAL9602](INFO): Powering up NAL9602
2021-04-20T14:33:15.195Z,1618929195.195 [NAL9602](INFO): NAL9602 initialized
2021-04-20T14:33:53.965Z,1618929233.965 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2021-04-20T14:33:53.965Z,1618929233.965 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T14:33:53.975Z,1618929233.975 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T14:33:54.369Z,1618929234.369 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T14:33:54.369Z,1618929234.369 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2021-04-20T14:34:31.530Z,1618929271.530 [DVL_micro](ERROR): only read 3 of 4 data items
2021-04-20T14:34:31.530Z,1618929271.530 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,+99999.99
2021-04-20T14:35:17.182Z,1618929317.182 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T14:35:17.182Z,1618929317.182 [Default:CheckIn:C.Wait] Stopped
2021-04-20T14:35:17.182Z,1618929317.182 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T14:35:17.182Z,1618929317.182 [Default:CheckIn:D] Running Loop=1
2021-04-20T14:35:17.609Z,1618929317.609 [Default:CheckIn:D] Stopped
2021-04-20T14:35:17.609Z,1618929317.609 [Default:CheckIn:E] Running Loop=1
2021-04-20T14:35:17.985Z,1618929317.985 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.686057 min
2021-04-20T14:35:17.985Z,1618929317.985 [Default:CheckIn:E] Stopped
2021-04-20T14:35:17.985Z,1618929317.985 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T14:35:17.985Z,1618929317.985 [Default:CheckIn] Stopped
2021-04-20T14:35:17.985Z,1618929317.985 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T14:35:17.985Z,1618929317.985 [Default:CheckIn](INFO): Running loop #2
2021-04-20T14:35:17.985Z,1618929317.985 [Default:CheckIn] Running Loop=2
2021-04-20T14:35:17.985Z,1618929317.985 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T14:35:17.985Z,1618929317.985 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T14:36:54.951Z,1618929414.951 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2021-04-20T14:36:54.951Z,1618929414.951 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T14:36:54.961Z,1618929414.961 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T14:36:55.371Z,1618929415.371 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T14:36:55.371Z,1618929415.371 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2021-04-20T14:39:55.939Z,1618929595.939 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2021-04-20T14:39:55.939Z,1618929595.939 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T14:39:55.949Z,1618929595.949 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T14:39:56.386Z,1618929596.386 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T14:39:56.386Z,1618929596.386 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2021-04-20T14:40:18.196Z,1618929618.196 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-20T14:35:17.0Z
2021-04-20T14:40:18.196Z,1618929618.196 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T14:40:18.196Z,1618929618.196 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T14:40:23.146Z,1618929623.146 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20210420T142139/Courier0007.lzma
2021-04-20T14:40:24.148Z,1618929624.148 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0007.lzma.bak
2021-04-20T14:40:24.148Z,1618929624.148 [DataOverHttps](INFO): SBD MOMSN=15590043
2021-04-20T14:40:39.618Z,1618929639.618 [DataOverHttps](INFO): Sending 271 bytes from file Logs/20210420T142139/Express0008.lzma
2021-04-20T14:40:40.620Z,1618929640.620 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0008.lzma.bak
2021-04-20T14:40:40.620Z,1618929640.620 [DataOverHttps](INFO): SBD MOMSN=15590045
2021-04-20T14:40:42.007Z,1618929642.007 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T14:40:42.007Z,1618929642.007 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T14:40:42.007Z,1618929642.007 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T14:42:56.992Z,1618929776.992 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2021-04-20T14:42:56.992Z,1618929776.992 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T14:42:57.002Z,1618929777.002 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T14:42:57.399Z,1618929777.399 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T14:42:57.399Z,1618929777.399 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2021-04-20T14:43:17.576Z,1618929797.576 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-04-20T14:43:17.576Z,1618929797.576 [NAL9602] Data Fault, FailCount= 2
2021-04-20T14:43:17.576Z,1618929797.576 [NAL9602](ERROR): Data Fault
2021-04-20T14:43:17.594Z,1618929797.594 [CBIT](ERROR): Data Fault in component: NAL9602
2021-04-20T14:43:17.976Z,1618929797.976 [NAL9602](INFO): Powering down
2021-04-20T14:43:18.841Z,1618929798.841 [CBIT](INFO): Clearing failed state for component NAL9602
2021-04-20T14:43:18.841Z,1618929798.841 [NAL9602] No Fault, FailCount= 2
2021-04-20T14:43:48.276Z,1618929828.276 [NAL9602](INFO): Powering up NAL9602
2021-04-20T14:43:57.183Z,1618929837.183 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2021-04-20T14:43:57.184Z,1618929837.184 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+2.0,1489.0,000
2021-04-20T14:43:59.188Z,1618929839.188 [NAL9602](INFO): NAL9602 initialized
2021-04-20T14:45:42.640Z,1618929942.640 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T14:45:42.640Z,1618929942.640 [Default:CheckIn:C.Wait] Stopped
2021-04-20T14:45:42.640Z,1618929942.640 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T14:45:42.640Z,1618929942.640 [Default:CheckIn:D] Running Loop=1
2021-04-20T14:45:43.027Z,1618929943.027 [Default:CheckIn:D] Stopped
2021-04-20T14:45:43.027Z,1618929943.027 [Default:CheckIn:E] Running Loop=1
2021-04-20T14:45:43.441Z,1618929943.441 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.109690 min
2021-04-20T14:45:43.441Z,1618929943.441 [Default:CheckIn:E] Stopped
2021-04-20T14:45:43.441Z,1618929943.441 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T14:45:43.441Z,1618929943.441 [Default:CheckIn] Stopped
2021-04-20T14:45:43.441Z,1618929943.441 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T14:45:43.441Z,1618929943.441 [Default:CheckIn](INFO): Running loop #3
2021-04-20T14:45:43.442Z,1618929943.442 [Default:CheckIn] Running Loop=3
2021-04-20T14:45:43.442Z,1618929943.442 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T14:45:43.442Z,1618929943.442 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T14:45:57.976Z,1618929957.976 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2021-04-20T14:45:57.976Z,1618929957.976 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T14:45:57.986Z,1618929957.986 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T14:45:58.396Z,1618929958.396 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T14:45:58.396Z,1618929958.396 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2021-04-20T14:48:42.398Z,1618930122.398 [DVL_micro](ERROR): only read 2 of 4 data items
2021-04-20T14:48:42.398Z,1618930122.398 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,,+9999.99
2021-04-20T14:48:58.967Z,1618930138.967 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2021-04-20T14:48:58.967Z,1618930138.967 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T14:48:58.990Z,1618930138.990 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T14:48:59.406Z,1618930139.406 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T14:48:59.406Z,1618930139.406 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2021-04-20T14:50:43.607Z,1618930243.607 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-20T14:45:43.4Z
2021-04-20T14:50:43.607Z,1618930243.607 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T14:50:43.607Z,1618930243.607 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T14:50:50.181Z,1618930250.181 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210420T142139/Courier0010.lzma
2021-04-20T14:50:51.172Z,1618930251.172 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0010.lzma.bak
2021-04-20T14:50:51.172Z,1618930251.172 [DataOverHttps](INFO): SBD MOMSN=15590095
2021-04-20T14:51:08.189Z,1618930268.189 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20210420T142139/Express0011.lzma
2021-04-20T14:51:09.192Z,1618930269.192 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0011.lzma.bak
2021-04-20T14:51:09.192Z,1618930269.192 [DataOverHttps](INFO): SBD MOMSN=15590099
2021-04-20T14:51:09.800Z,1618930269.800 [DVL_micro](ERROR): Failed to parse:99.99,+9999.99,+9999.99,+9999.99
2021-04-20T14:51:10.219Z,1618930270.219 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T14:51:10.220Z,1618930270.220 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T14:51:10.220Z,1618930270.220 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T14:51:59.876Z,1618930319.876 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2021-04-20T14:51:59.876Z,1618930319.876 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T14:51:59.886Z,1618930319.886 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T14:52:00.296Z,1618930320.296 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T14:52:00.296Z,1618930320.296 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2021-04-20T14:54:01.468Z,1618930441.468 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-04-20T14:54:01.468Z,1618930441.468 [NAL9602] Data Fault, FailCount= 3
2021-04-20T14:54:01.468Z,1618930441.468 [NAL9602](ERROR): Data Fault
2021-04-20T14:54:01.522Z,1618930441.522 [CBIT](ERROR): Data Fault in component: NAL9602
2021-04-20T14:54:01.876Z,1618930441.876 [NAL9602](INFO): Powering down
2021-04-20T14:54:02.701Z,1618930442.701 [CBIT](INFO): Clearing failed state for component NAL9602
2021-04-20T14:54:02.701Z,1618930442.701 [NAL9602] No Fault, FailCount= 3
2021-04-20T14:54:32.172Z,1618930472.172 [NAL9602](INFO): Powering up NAL9602
2021-04-20T14:54:43.088Z,1618930483.088 [NAL9602](INFO): NAL9602 initialized
2021-04-20T14:55:00.872Z,1618930500.872 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2021-04-20T14:55:00.872Z,1618930500.872 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T14:55:00.882Z,1618930500.882 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T14:55:01.289Z,1618930501.289 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T14:55:01.289Z,1618930501.289 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2021-04-20T14:56:10.768Z,1618930570.768 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T14:56:10.768Z,1618930570.768 [Default:CheckIn:C.Wait] Stopped
2021-04-20T14:56:10.768Z,1618930570.768 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T14:56:10.768Z,1618930570.768 [Default:CheckIn:D] Running Loop=1
2021-04-20T14:56:11.180Z,1618930571.180 [Default:CheckIn:D] Stopped
2021-04-20T14:56:11.180Z,1618930571.180 [Default:CheckIn:E] Running Loop=1
2021-04-20T14:56:11.600Z,1618930571.600 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.578918 min
2021-04-20T14:56:11.600Z,1618930571.600 [Default:CheckIn:E] Stopped
2021-04-20T14:56:11.600Z,1618930571.600 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T14:56:11.600Z,1618930571.600 [Default:CheckIn] Stopped
2021-04-20T14:56:11.600Z,1618930571.600 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T14:56:11.601Z,1618930571.601 [Default:CheckIn](INFO): Running loop #4
2021-04-20T14:56:11.601Z,1618930571.601 [Default:CheckIn] Running Loop=4
2021-04-20T14:56:11.601Z,1618930571.601 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T14:56:11.601Z,1618930571.601 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T14:58:01.867Z,1618930681.867 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12
2021-04-20T14:58:01.867Z,1618930681.867 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T14:58:01.877Z,1618930681.877 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T14:58:02.335Z,1618930682.335 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T14:58:02.335Z,1618930682.335 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12
2021-04-20T15:01:02.860Z,1618930862.860 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13
2021-04-20T15:01:02.860Z,1618930862.860 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T15:01:02.871Z,1618930862.871 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T15:01:03.282Z,1618930863.282 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T15:01:03.282Z,1618930863.282 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13
2021-04-20T15:01:11.754Z,1618930871.754 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-20T14:56:11.6Z
2021-04-20T15:01:11.754Z,1618930871.754 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T15:01:11.754Z,1618930871.754 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T15:01:12.556Z,1618930872.556 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T15:01:12.556Z,1618930872.556 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T15:01:12.556Z,1618930872.556 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T15:01:28.770Z,1618930888.770 [DVL_micro](ERROR): DVL uart error: serial timeout
2021-04-20T15:01:28.770Z,1618930888.770 [DVL_micro] Communications Fault, FailCount= 1
2021-04-20T15:01:28.770Z,1618930888.770 [DVL_micro](ERROR): Communications Fault
2021-04-20T15:01:28.770Z,1618930888.770 [DVL_micro](ERROR): Failed to parse:
2021-04-20T15:01:28.797Z,1618930888.797 [CBIT](ERROR): Communications Fault in component: DVL_micro
2021-04-20T15:01:29.174Z,1618930889.174 [DVL_micro](INFO): Powering down
2021-04-20T15:01:29.947Z,1618930889.947 [CBIT](INFO): Clearing failed state for component DVL_micro
2021-04-20T15:01:29.947Z,1618930889.947 [DVL_micro] No Fault, FailCount= 1
2021-04-20T15:04:00.228Z,1618931040.228 [DAT](INFO): unknown deviceResponse_: Acoustic Wakeup
2021-04-20T15:04:00.230Z,1618931040.230 [DAT](INFO): commRate: 800
2021-04-20T15:04:01.035Z,1618931041.035 [DAT](INFO): unknown deviceResponse_: Lowpower
2021-04-20T15:04:03.884Z,1618931043.884 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 14
2021-04-20T15:04:03.884Z,1618931043.884 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T15:04:03.894Z,1618931043.894 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T15:04:04.300Z,1618931044.300 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T15:04:04.300Z,1618931044.300 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 14
2021-04-20T15:04:44.648Z,1618931084.648 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-04-20T15:04:44.648Z,1618931084.648 [NAL9602] Data Fault, FailCount= 4
2021-04-20T15:04:44.648Z,1618931084.648 [NAL9602](ERROR): Data Fault
2021-04-20T15:04:44.697Z,1618931084.697 [CBIT](ERROR): Data Fault in component: NAL9602
2021-04-20T15:04:45.052Z,1618931085.052 [NAL9602](INFO): Powering down
2021-04-20T15:04:45.882Z,1618931085.882 [CBIT](INFO): Clearing failed state for component NAL9602
2021-04-20T15:04:45.882Z,1618931085.882 [NAL9602] No Fault, FailCount= 4
2021-04-20T15:05:15.360Z,1618931115.360 [NAL9602](INFO): Powering up NAL9602
2021-04-20T15:05:26.264Z,1618931126.264 [NAL9602](INFO): NAL9602 initialized
2021-04-20T15:06:13.163Z,1618931173.163 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T15:06:13.163Z,1618931173.163 [Default:CheckIn:C.Wait] Stopped
2021-04-20T15:06:13.163Z,1618931173.163 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T15:06:13.164Z,1618931173.164 [Default:CheckIn:D] Running Loop=1
2021-04-20T15:06:13.576Z,1618931173.576 [Default:CheckIn:D] Stopped
2021-04-20T15:06:13.576Z,1618931173.576 [Default:CheckIn:E] Running Loop=1
2021-04-20T15:06:13.948Z,1618931173.948 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 41.618840 min
2021-04-20T15:06:13.948Z,1618931173.948 [Default:CheckIn:E] Stopped
2021-04-20T15:06:13.948Z,1618931173.948 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T15:06:13.948Z,1618931173.948 [Default:CheckIn] Stopped
2021-04-20T15:06:13.948Z,1618931173.948 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T15:06:13.949Z,1618931173.949 [Default:CheckIn](INFO): Running loop #5
2021-04-20T15:06:13.949Z,1618931173.949 [Default:CheckIn] Running Loop=5
2021-04-20T15:06:13.949Z,1618931173.949 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T15:06:13.949Z,1618931173.949 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T15:07:04.874Z,1618931224.874 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 15
2021-04-20T15:07:04.874Z,1618931224.874 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T15:07:04.885Z,1618931224.885 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T15:07:05.293Z,1618931225.293 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T15:07:05.293Z,1618931225.293 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 15
2021-04-20T15:10:05.863Z,1618931405.863 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 16
2021-04-20T15:10:05.863Z,1618931405.863 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T15:10:05.874Z,1618931405.874 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T15:10:06.279Z,1618931406.279 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T15:10:06.279Z,1618931406.279 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 16
2021-04-20T15:11:14.124Z,1618931474.124 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-20T15:06:13.9Z
2021-04-20T15:11:14.124Z,1618931474.124 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T15:11:14.125Z,1618931474.125 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T15:11:21.261Z,1618931481.261 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210420T142139/Courier0013.lzma
2021-04-20T15:11:22.264Z,1618931482.264 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0013.lzma.bak
2021-04-20T15:11:22.264Z,1618931482.264 [DataOverHttps](INFO): SBD MOMSN=15590221
2021-04-20T15:11:31.079Z,1618931491.079 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2021-04-20T15:11:31.079Z,1618931491.079 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+21.3,009.0,000
2021-04-20T15:11:37.697Z,1618931497.697 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210420T142139/Courier0016.lzma
2021-04-20T15:11:38.700Z,1618931498.700 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0016.lzma.bak
2021-04-20T15:11:38.700Z,1618931498.700 [DataOverHttps](INFO): SBD MOMSN=15590223
2021-04-20T15:11:54.096Z,1618931514.096 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20210420T142139/Express0014.lzma
2021-04-20T15:11:55.092Z,1618931515.092 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0014.lzma.bak
2021-04-20T15:11:55.092Z,1618931515.092 [DataOverHttps](INFO): SBD MOMSN=15590228
2021-04-20T15:12:10.550Z,1618931530.550 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20210420T142139/Express0017.lzma
2021-04-20T15:12:11.552Z,1618931531.552 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0017.lzma.bak
2021-04-20T15:12:11.552Z,1618931531.552 [DataOverHttps](INFO): SBD MOMSN=15590236
2021-04-20T15:12:12.692Z,1618931532.692 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T15:12:12.692Z,1618931532.692 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T15:12:12.692Z,1618931532.692 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T15:13:06.831Z,1618931586.831 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 17
2021-04-20T15:13:06.831Z,1618931586.831 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T15:13:06.842Z,1618931586.842 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T15:13:07.248Z,1618931587.248 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T15:13:07.248Z,1618931587.248 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 17
2021-04-20T15:13:53.692Z,1618931633.692 [DVL_micro](ERROR): only read 3 of 4 data items
2021-04-20T15:13:53.692Z,1618931633.692 [DVL_micro](ERROR): Failed to parse:
:BI,+00034,+00016,+00527,+
2021-04-20T15:15:27.841Z,1618931727.841 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-04-20T15:15:27.841Z,1618931727.841 [NAL9602] Data Fault, FailCount= 5
2021-04-20T15:15:27.841Z,1618931727.841 [NAL9602](ERROR): Data Fault
2021-04-20T15:15:27.891Z,1618931727.891 [CBIT](ERROR): Data Fault in component: NAL9602
2021-04-20T15:15:27.891Z,1618931727.891 [CBIT](CRITICAL): Data Fault in component: NAL9602
2021-04-20T15:15:28.224Z,1618931728.224 [NAL9602](INFO): Powering down
2021-04-20T15:15:28.254Z,1618931728.254 [CommandLine](FAULT): Scheduling is paused
2021-04-20T15:15:28.255Z,1618931728.255 [CBIT](INFO): Critical error at 20210420T151527
2021-04-20T15:15:28.255Z,1618931728.255 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2021-04-20T15:16:07.822Z,1618931767.822 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 18
2021-04-20T15:16:07.822Z,1618931767.822 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T15:16:07.833Z,1618931767.833 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T15:16:08.236Z,1618931768.236 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T15:16:08.236Z,1618931768.236 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 18
2021-04-20T15:16:18.733Z,1618931778.733 [DVL_micro](ERROR): only read 2 of 4 data items
2021-04-20T15:16:18.733Z,1618931778.733 [DVL_micro](ERROR): Failed to parse:
:BI,+0202,+0085,I
2021-04-20T15:17:13.276Z,1618931833.276 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T15:17:13.276Z,1618931833.276 [Default:CheckIn:C.Wait] Stopped
2021-04-20T15:17:13.277Z,1618931833.277 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T15:17:13.277Z,1618931833.277 [Default:CheckIn:D] Running Loop=1
2021-04-20T15:17:13.676Z,1618931833.676 [Default:CheckIn:D] Stopped
2021-04-20T15:17:13.677Z,1618931833.677 [Default:CheckIn:E] Running Loop=1
2021-04-20T15:17:14.089Z,1618931834.089 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 52.620512 min
2021-04-20T15:17:14.089Z,1618931834.089 [Default:CheckIn:E] Stopped
2021-04-20T15:17:14.089Z,1618931834.089 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T15:17:14.089Z,1618931834.089 [Default:CheckIn] Stopped
2021-04-20T15:17:14.089Z,1618931834.089 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T15:17:14.090Z,1618931834.090 [Default:CheckIn](INFO): Running loop #6
2021-04-20T15:17:14.090Z,1618931834.090 [Default:CheckIn] Running Loop=6
2021-04-20T15:17:14.090Z,1618931834.090 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T15:17:14.090Z,1618931834.090 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T15:17:28.229Z,1618931848.229 [CBIT](INFO): Clearing failed state for component NAL9602
2021-04-20T15:17:28.229Z,1618931848.229 [NAL9602] No Fault, FailCount= 5
2021-04-20T15:17:28.612Z,1618931848.612 [NAL9602](INFO): Powering up NAL9602
2021-04-20T15:17:39.524Z,1618931859.524 [NAL9602](INFO): NAL9602 initialized
2021-04-20T15:18:43.760Z,1618931923.760 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,+9999.99,+9999.99
2021-04-20T15:19:08.831Z,1618931948.831 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 19
2021-04-20T15:19:08.831Z,1618931948.831 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T15:19:08.866Z,1618931948.866 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T15:19:09.276Z,1618931949.276 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T15:19:09.276Z,1618931949.276 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 19
2021-04-20T15:22:09.883Z,1618932129.883 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 20
2021-04-20T15:22:09.883Z,1618932129.883 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T15:22:09.894Z,1618932129.894 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T15:22:10.295Z,1618932130.295 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T15:22:10.295Z,1618932130.295 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 20
2021-04-20T15:22:14.309Z,1618932134.309 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-20T15:17:14.1Z
2021-04-20T15:22:14.309Z,1618932134.309 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T15:22:14.309Z,1618932134.309 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T15:22:19.135Z,1618932139.135 [DataOverHttps](INFO): Sending 105 bytes from file Logs/20210420T142139/Courier0019.lzma
2021-04-20T15:22:20.136Z,1618932140.136 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0019.lzma.bak
2021-04-20T15:22:20.136Z,1618932140.136 [DataOverHttps](INFO): SBD MOMSN=15590279
2021-04-20T15:22:35.606Z,1618932155.606 [DataOverHttps](INFO): Sending 175 bytes from file Logs/20210420T142139/Express0020.lzma
2021-04-20T15:22:36.608Z,1618932156.608 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0020.lzma.bak
2021-04-20T15:22:36.608Z,1618932156.608 [DataOverHttps](INFO): SBD MOMSN=15590282
2021-04-20T15:22:37.794Z,1618932157.794 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T15:22:37.794Z,1618932157.794 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T15:22:37.794Z,1618932157.794 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T15:25:10.858Z,1618932310.858 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 21
2021-04-20T15:25:10.858Z,1618932310.858 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T15:25:10.868Z,1618932310.868 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T15:25:11.272Z,1618932311.272 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T15:25:11.272Z,1618932311.272 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 21
2021-04-20T15:26:04.183Z,1618932364.183 [DVL_micro](ERROR): only read 3 of 4 data items
2021-04-20T15:26:04.183Z,1618932364.183 [DVL_micro](ERROR): Failed to parse:
:BI,-00013,-0897,+00000,I
2021-04-20T15:27:38.313Z,1618932458.313 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T15:27:38.313Z,1618932458.313 [Default:CheckIn:C.Wait] Stopped
2021-04-20T15:27:38.313Z,1618932458.313 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T15:27:38.314Z,1618932458.314 [Default:CheckIn:D] Running Loop=1
2021-04-20T15:27:38.724Z,1618932458.724 [Default:CheckIn:D] Stopped
2021-04-20T15:27:38.724Z,1618932458.724 [Default:CheckIn:E] Running Loop=1
2021-04-20T15:27:39.133Z,1618932459.133 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 63.037984 min
2021-04-20T15:27:39.133Z,1618932459.133 [Default:CheckIn:E] Stopped
2021-04-20T15:27:39.133Z,1618932459.133 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T15:27:39.133Z,1618932459.133 [Default:CheckIn] Stopped
2021-04-20T15:27:39.133Z,1618932459.133 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T15:27:39.133Z,1618932459.133 [Default:CheckIn](INFO): Running loop #7
2021-04-20T15:27:39.133Z,1618932459.133 [Default:CheckIn] Running Loop=7
2021-04-20T15:27:39.133Z,1618932459.133 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T15:27:39.134Z,1618932459.134 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T15:27:42.744Z,1618932462.744 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-04-20T15:27:42.744Z,1618932462.744 [NAL9602] Data Fault, FailCount= 1
2021-04-20T15:27:42.744Z,1618932462.744 [NAL9602](ERROR): Data Fault
2021-04-20T15:27:42.790Z,1618932462.790 [CBIT](ERROR): Data Fault in component: NAL9602
2021-04-20T15:27:43.144Z,1618932463.144 [NAL9602](INFO): Powering down
2021-04-20T15:27:43.989Z,1618932463.989 [CBIT](INFO): Clearing failed state for component NAL9602
2021-04-20T15:27:43.989Z,1618932463.989 [NAL9602] No Fault, FailCount= 1
2021-04-20T15:28:11.839Z,1618932491.839 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 22
2021-04-20T15:28:11.839Z,1618932491.839 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T15:28:11.849Z,1618932491.849 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T15:28:12.256Z,1618932492.256 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T15:28:12.256Z,1618932492.256 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 22
2021-04-20T15:28:13.448Z,1618932493.448 [NAL9602](INFO): Powering up NAL9602
2021-04-20T15:28:24.352Z,1618932504.352 [NAL9602](INFO): NAL9602 initialized
2021-04-20T15:31:12.847Z,1618932672.847 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 23
2021-04-20T15:31:12.847Z,1618932672.847 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T15:31:12.858Z,1618932672.858 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T15:31:13.268Z,1618932673.268 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T15:31:13.268Z,1618932673.268 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 23
2021-04-20T15:32:39.329Z,1618932759.329 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-20T15:27:39.1Z
2021-04-20T15:32:39.329Z,1618932759.329 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T15:32:39.329Z,1618932759.329 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T15:32:45.017Z,1618932765.017 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210420T142139/Courier0022.lzma
2021-04-20T15:32:46.020Z,1618932766.020 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0022.lzma.bak
2021-04-20T15:32:46.020Z,1618932766.020 [DataOverHttps](INFO): SBD MOMSN=15590304
2021-04-20T15:33:01.762Z,1618932781.762 [DataOverHttps](INFO): Sending 148 bytes from file Logs/20210420T142139/Express0023.lzma
2021-04-20T15:33:02.764Z,1618932782.764 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0023.lzma.bak
2021-04-20T15:33:02.764Z,1618932782.764 [DataOverHttps](INFO): SBD MOMSN=15590306
2021-04-20T15:33:03.941Z,1618932783.941 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T15:33:03.962Z,1618932783.962 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T15:33:03.962Z,1618932783.962 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T15:33:32.209Z,1618932812.209 [DVL_micro](ERROR): Failed to parse:99.99,+9999.99,+9999.99,+9999.99
2021-04-20T15:34:13.837Z,1618932853.837 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 24
2021-04-20T15:34:13.837Z,1618932853.837 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T15:34:13.848Z,1618932853.848 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T15:34:14.257Z,1618932854.257 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T15:34:14.257Z,1618932854.257 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 24
2021-04-20T15:37:14.839Z,1618933034.839 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 25
2021-04-20T15:37:14.839Z,1618933034.839 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T15:37:14.885Z,1618933034.885 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T15:37:15.291Z,1618933035.291 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T15:37:15.291Z,1618933035.291 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 25
2021-04-20T15:38:04.558Z,1618933084.558 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T15:38:04.559Z,1618933084.559 [Default:CheckIn:C.Wait] Stopped
2021-04-20T15:38:04.559Z,1618933084.559 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T15:38:04.559Z,1618933084.559 [Default:CheckIn:D] Running Loop=1
2021-04-20T15:38:04.920Z,1618933084.920 [Default:CheckIn:D] Stopped
2021-04-20T15:38:04.920Z,1618933084.920 [Default:CheckIn:E] Running Loop=1
2021-04-20T15:38:05.331Z,1618933085.331 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 73.474585 min
2021-04-20T15:38:05.331Z,1618933085.331 [Default:CheckIn:E] Stopped
2021-04-20T15:38:05.331Z,1618933085.331 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T15:38:05.331Z,1618933085.331 [Default:CheckIn] Stopped
2021-04-20T15:38:05.331Z,1618933085.331 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T15:38:05.331Z,1618933085.331 [Default:CheckIn](INFO): Running loop #8
2021-04-20T15:38:05.332Z,1618933085.332 [Default:CheckIn] Running Loop=8
2021-04-20T15:38:05.332Z,1618933085.332 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T15:38:05.332Z,1618933085.332 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T15:38:05.724Z,1618933085.724 [BPC1](ERROR): Battery stick #6 (s/n: 00CA) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2021-04-20T15:38:05.725Z,1618933085.725 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6.
2021-04-20T15:38:05.728Z,1618933085.728 [BPC1](INFO): Received data from all battery sticks.
2021-04-20T15:38:27.537Z,1618933107.537 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-04-20T15:38:27.537Z,1618933107.537 [NAL9602] Data Fault, FailCount= 2
2021-04-20T15:38:27.537Z,1618933107.537 [NAL9602](ERROR): Data Fault
2021-04-20T15:38:27.592Z,1618933107.592 [CBIT](ERROR): Data Fault in component: NAL9602
2021-04-20T15:38:27.944Z,1618933107.944 [NAL9602](INFO): Powering down
2021-04-20T15:38:28.761Z,1618933108.761 [CBIT](INFO): Clearing failed state for component NAL9602
2021-04-20T15:38:28.761Z,1618933108.761 [NAL9602] No Fault, FailCount= 2
2021-04-20T15:38:58.232Z,1618933138.232 [NAL9602](INFO): Powering up NAL9602
2021-04-20T15:39:09.144Z,1618933149.144 [NAL9602](INFO): NAL9602 initialized
2021-04-20T15:40:15.818Z,1618933215.818 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 26
2021-04-20T15:40:15.818Z,1618933215.818 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T15:40:15.829Z,1618933215.829 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T15:40:16.237Z,1618933216.237 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T15:40:16.237Z,1618933216.237 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 26
2021-04-20T15:40:49.836Z,1618933249.836 [DVL_micro](ERROR): only read 3 of 4 data items
2021-04-20T15:40:49.836Z,1618933249.836 [DVL_micro](ERROR): Failed to parse:
:BI,-00236,-01562,+00985,+00000+00000000.00,+00000000.00,+00000000.00,9999.99,000.00
2021-04-20T15:43:05.565Z,1618933385.565 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-20T15:38:05.3Z
2021-04-20T15:43:05.565Z,1618933385.565 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T15:43:05.565Z,1618933385.565 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T15:43:11.465Z,1618933391.465 [DataOverHttps](INFO): Sending 51 bytes from file Logs/20210420T142139/Courier0025.lzma
2021-04-20T15:43:12.468Z,1618933392.468 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0025.lzma.bak
2021-04-20T15:43:12.468Z,1618933392.468 [DataOverHttps](INFO): SBD MOMSN=15590328
2021-04-20T15:43:16.874Z,1618933396.874 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 27
2021-04-20T15:43:16.874Z,1618933396.874 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T15:43:16.889Z,1618933396.889 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T15:43:17.335Z,1618933397.335 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T15:43:17.335Z,1618933397.335 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 27
2021-04-20T15:43:27.910Z,1618933407.910 [DataOverHttps](INFO): Sending 148 bytes from file Logs/20210420T142139/Express0026.lzma
2021-04-20T15:43:28.912Z,1618933408.912 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0026.lzma.bak
2021-04-20T15:43:28.912Z,1618933408.912 [DataOverHttps](INFO): SBD MOMSN=15590330
2021-04-20T15:43:30.201Z,1618933410.201 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T15:43:30.201Z,1618933410.201 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T15:43:30.201Z,1618933410.201 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T15:45:45.115Z,1618933545.115 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2021-04-20T15:45:45.115Z,1618933545.115 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+21.6,0000.0,1489.WI,-00262,-01333,+00836,+00000,A
2021-04-20T15:46:17.854Z,1618933577.854 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 28
2021-04-20T15:46:17.854Z,1618933577.854 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T15:46:17.865Z,1618933577.865 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T15:46:18.283Z,1618933578.283 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T15:46:18.283Z,1618933578.283 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 28
2021-04-20T15:48:30.776Z,1618933710.776 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T15:48:30.776Z,1618933710.776 [Default:CheckIn:C.Wait] Stopped
2021-04-20T15:48:30.776Z,1618933710.776 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T15:48:30.777Z,1618933710.777 [Default:CheckIn:D] Running Loop=1
2021-04-20T15:48:31.189Z,1618933711.189 [Default:CheckIn:D] Stopped
2021-04-20T15:48:31.189Z,1618933711.189 [Default:CheckIn:E] Running Loop=1
2021-04-20T15:48:31.585Z,1618933711.585 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 83.912394 min
2021-04-20T15:48:31.585Z,1618933711.585 [Default:CheckIn:E] Stopped
2021-04-20T15:48:31.585Z,1618933711.585 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T15:48:31.585Z,1618933711.585 [Default:CheckIn] Stopped
2021-04-20T15:48:31.585Z,1618933711.585 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T15:48:31.585Z,1618933711.585 [Default:CheckIn](INFO): Running loop #9
2021-04-20T15:48:31.585Z,1618933711.585 [Default:CheckIn] Running Loop=9
2021-04-20T15:48:31.585Z,1618933711.585 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T15:48:31.585Z,1618933711.585 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T15:49:11.561Z,1618933751.561 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-04-20T15:49:11.561Z,1618933751.561 [NAL9602] Data Fault, FailCount= 3
2021-04-20T15:49:11.561Z,1618933751.561 [NAL9602](ERROR): Data Fault
2021-04-20T15:49:11.579Z,1618933751.579 [CBIT](ERROR): Data Fault in component: NAL9602
2021-04-20T15:49:11.960Z,1618933751.960 [NAL9602](INFO): Powering down
2021-04-20T15:49:12.785Z,1618933752.785 [CBIT](INFO): Clearing failed state for component NAL9602
2021-04-20T15:49:12.785Z,1618933752.785 [NAL9602] No Fault, FailCount= 3
2021-04-20T15:49:18.854Z,1618933758.854 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 29
2021-04-20T15:49:18.854Z,1618933758.854 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T15:49:18.864Z,1618933758.864 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T15:49:19.252Z,1618933759.252 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T15:49:19.252Z,1618933759.252 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 29
2021-04-20T15:49:42.256Z,1618933782.256 [NAL9602](INFO): Powering up NAL9602
2021-04-20T15:49:53.174Z,1618933793.174 [NAL9602](INFO): NAL9602 initialized
2021-04-20T15:50:22.657Z,1618933822.657 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2021-04-20T15:50:22.657Z,1618933822.657 [DVL_micro](ERROR): Failed to parse:
:TS,0,0000.0,1489.0,000
2021-04-20T15:50:40.442Z,1618933840.442 [DVL_micro](ERROR): only read 2 of 4 data items
2021-04-20T15:50:40.442Z,1618933840.442 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,,+9999.99
2021-04-20T15:52:19.844Z,1618933939.844 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 30
2021-04-20T15:52:19.844Z,1618933939.844 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T15:52:19.862Z,1618933939.862 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T15:52:20.271Z,1618933940.271 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T15:52:20.271Z,1618933940.271 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 30
2021-04-20T15:53:31.761Z,1618934011.761 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-20T15:48:31.6Z
2021-04-20T15:53:31.761Z,1618934011.761 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T15:53:31.761Z,1618934011.761 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T15:53:37.073Z,1618934017.073 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210420T142139/Courier0028.lzma
2021-04-20T15:53:38.076Z,1618934018.076 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0028.lzma.bak
2021-04-20T15:53:38.076Z,1618934018.076 [DataOverHttps](INFO): SBD MOMSN=15590413
2021-04-20T15:53:53.462Z,1618934033.462 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20210420T142139/Express0029.lzma
2021-04-20T15:53:54.464Z,1618934034.464 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0029.lzma.bak
2021-04-20T15:53:54.464Z,1618934034.464 [DataOverHttps](INFO): SBD MOMSN=15590415
2021-04-20T15:53:55.604Z,1618934035.604 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T15:53:55.604Z,1618934035.604 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T15:53:55.604Z,1618934035.604 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T15:55:20.839Z,1618934120.839 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 31
2021-04-20T15:55:20.839Z,1618934120.839 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T15:55:20.850Z,1618934120.850 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T15:55:21.248Z,1618934121.248 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T15:55:21.248Z,1618934121.248 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 31
2021-04-20T15:58:21.816Z,1618934301.816 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 32
2021-04-20T15:58:21.816Z,1618934301.816 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T15:58:21.826Z,1618934301.826 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T15:58:22.241Z,1618934302.241 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T15:58:22.241Z,1618934302.241 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 32
2021-04-20T15:58:56.160Z,1618934336.160 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T15:58:56.160Z,1618934336.160 [Default:CheckIn:C.Wait] Stopped
2021-04-20T15:58:56.160Z,1618934336.160 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T15:58:56.160Z,1618934336.160 [Default:CheckIn:D] Running Loop=1
2021-04-20T15:58:56.583Z,1618934336.583 [Default:CheckIn:D] Stopped
2021-04-20T15:58:56.583Z,1618934336.583 [Default:CheckIn:E] Running Loop=1
2021-04-20T15:58:56.983Z,1618934336.983 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 94.335636 min
2021-04-20T15:58:56.983Z,1618934336.983 [Default:CheckIn:E] Stopped
2021-04-20T15:58:56.983Z,1618934336.983 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T15:58:56.984Z,1618934336.984 [Default:CheckIn] Stopped
2021-04-20T15:58:56.984Z,1618934336.984 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T15:58:56.984Z,1618934336.984 [Default:CheckIn](INFO): Running loop #10
2021-04-20T15:58:56.984Z,1618934336.984 [Default:CheckIn] Running Loop=10
2021-04-20T15:58:56.984Z,1618934336.984 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T15:58:56.984Z,1618934336.984 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T15:59:56.740Z,1618934396.740 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-04-20T15:59:56.740Z,1618934396.740 [NAL9602] Data Fault, FailCount= 4
2021-04-20T15:59:56.740Z,1618934396.740 [NAL9602](ERROR): Data Fault
2021-04-20T15:59:56.804Z,1618934396.804 [CBIT](ERROR): Data Fault in component: NAL9602
2021-04-20T15:59:57.144Z,1618934397.144 [NAL9602](INFO): Powering down
2021-04-20T15:59:57.981Z,1618934397.981 [CBIT](INFO): Clearing failed state for component NAL9602
2021-04-20T15:59:57.981Z,1618934397.981 [NAL9602] No Fault, FailCount= 4
2021-04-20T16:00:27.448Z,1618934427.448 [NAL9602](INFO): Powering up NAL9602
2021-04-20T16:00:38.365Z,1618934438.365 [NAL9602](INFO): NAL9602 initialized
2021-04-20T16:01:22.830Z,1618934482.830 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 33
2021-04-20T16:01:22.830Z,1618934482.830 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T16:01:22.840Z,1618934482.840 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T16:01:23.249Z,1618934483.249 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T16:01:23.249Z,1618934483.249 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 33
2021-04-20T16:03:57.148Z,1618934637.148 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-20T15:58:56.0Z
2021-04-20T16:03:57.149Z,1618934637.149 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T16:03:57.149Z,1618934637.149 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T16:04:02.429Z,1618934642.429 [DataOverHttps](INFO): Sending 37 bytes from file Logs/20210420T142139/Courier0031.lzma
2021-04-20T16:04:03.432Z,1618934643.432 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0031.lzma.bak
2021-04-20T16:04:03.432Z,1618934643.432 [DataOverHttps](INFO): SBD MOMSN=15590457
2021-04-20T16:04:18.890Z,1618934658.890 [DataOverHttps](INFO): Sending 149 bytes from file Logs/20210420T142139/Express0032.lzma
2021-04-20T16:04:19.892Z,1618934659.892 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0032.lzma.bak
2021-04-20T16:04:19.892Z,1618934659.892 [DataOverHttps](INFO): SBD MOMSN=15590459
2021-04-20T16:04:20.992Z,1618934660.992 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T16:04:20.992Z,1618934660.992 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T16:04:20.992Z,1618934660.992 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T16:04:23.814Z,1618934663.814 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 34
2021-04-20T16:04:23.814Z,1618934663.814 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T16:04:23.829Z,1618934663.829 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T16:04:24.247Z,1618934664.247 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T16:04:24.247Z,1618934664.247 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 34
2021-04-20T16:07:24.826Z,1618934844.826 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 35
2021-04-20T16:07:24.826Z,1618934844.826 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T16:07:24.837Z,1618934844.837 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T16:07:25.237Z,1618934845.237 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T16:07:25.237Z,1618934845.237 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 35
2021-04-20T16:09:21.588Z,1618934961.588 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T16:09:21.588Z,1618934961.588 [Default:CheckIn:C.Wait] Stopped
2021-04-20T16:09:21.588Z,1618934961.588 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T16:09:21.588Z,1618934961.588 [Default:CheckIn:D] Running Loop=1
2021-04-20T16:09:22.003Z,1618934962.003 [Default:CheckIn:D] Stopped
2021-04-20T16:09:22.003Z,1618934962.003 [Default:CheckIn:E] Running Loop=1
2021-04-20T16:09:22.397Z,1618934962.397 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 104.759302 min
2021-04-20T16:09:22.397Z,1618934962.397 [Default:CheckIn:E] Stopped
2021-04-20T16:09:22.397Z,1618934962.397 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T16:09:22.397Z,1618934962.397 [Default:CheckIn] Stopped
2021-04-20T16:09:22.397Z,1618934962.397 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T16:09:22.398Z,1618934962.398 [Default:CheckIn](INFO): Running loop #11
2021-04-20T16:09:22.398Z,1618934962.398 [Default:CheckIn] Running Loop=11
2021-04-20T16:09:22.398Z,1618934962.398 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T16:09:22.398Z,1618934962.398 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T16:10:25.831Z,1618935025.831 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 36
2021-04-20T16:10:25.831Z,1618935025.831 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T16:10:25.842Z,1618935025.842 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T16:10:26.260Z,1618935026.260 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T16:10:26.260Z,1618935026.260 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 36
2021-04-20T16:10:39.532Z,1618935039.532 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-04-20T16:10:39.532Z,1618935039.532 [NAL9602] Data Fault, FailCount= 5
2021-04-20T16:10:39.532Z,1618935039.532 [NAL9602](ERROR): Data Fault
2021-04-20T16:10:39.557Z,1618935039.557 [CBIT](ERROR): Data Fault in component: NAL9602
2021-04-20T16:10:39.588Z,1618935039.588 [CBIT](CRITICAL): Data Fault in component: NAL9602
2021-04-20T16:10:39.936Z,1618935039.936 [NAL9602](INFO): Powering down
2021-04-20T16:10:39.959Z,1618935039.959 [CBIT](INFO): Critical error at 20210420T161039
2021-04-20T16:12:39.569Z,1618935159.569 [CBIT](INFO): Clearing failed state for component NAL9602
2021-04-20T16:12:39.569Z,1618935159.569 [NAL9602] No Fault, FailCount= 5
2021-04-20T16:12:39.928Z,1618935159.928 [NAL9602](INFO): Powering up NAL9602
2021-04-20T16:12:50.844Z,1618935170.844 [NAL9602](INFO): NAL9602 initialized
2021-04-20T16:13:26.819Z,1618935206.819 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 37
2021-04-20T16:13:26.819Z,1618935206.819 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T16:13:26.829Z,1618935206.829 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T16:13:27.236Z,1618935207.236 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T16:13:27.236Z,1618935207.236 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 37
2021-04-20T16:14:22.616Z,1618935262.616 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-20T16:09:22.4Z
2021-04-20T16:14:22.616Z,1618935262.616 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T16:14:22.616Z,1618935262.616 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T16:14:28.802Z,1618935268.802 [DataOverHttps](INFO): Sending 82 bytes from file Logs/20210420T142139/Courier0034.lzma
2021-04-20T16:14:29.804Z,1618935269.804 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0034.lzma.bak
2021-04-20T16:14:29.804Z,1618935269.804 [DataOverHttps](INFO): SBD MOMSN=15590489
2021-04-20T16:14:45.294Z,1618935285.294 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20210420T142139/Express0035.lzma
2021-04-20T16:14:46.296Z,1618935286.296 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0035.lzma.bak
2021-04-20T16:14:46.296Z,1618935286.296 [DataOverHttps](INFO): SBD MOMSN=15590492
2021-04-20T16:14:47.656Z,1618935287.656 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T16:14:47.656Z,1618935287.656 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T16:14:47.656Z,1618935287.656 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T16:16:27.858Z,1618935387.858 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 38
2021-04-20T16:16:27.858Z,1618935387.858 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T16:16:27.869Z,1618935387.869 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T16:16:28.276Z,1618935388.276 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T16:16:28.276Z,1618935388.276 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 38
2021-04-20T16:18:06.810Z,1618935486.810 [DVL_micro](ERROR): only read 3 of 4 data items
2021-04-20T16:18:06.811Z,1618935486.811 [DVL_micro](ERROR): Failed to parse:
:RD,+99999.99,+9999.99,+9999.99
2021-04-20T16:19:28.851Z,1618935568.851 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 39
2021-04-20T16:19:28.851Z,1618935568.851 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T16:19:28.861Z,1618935568.861 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T16:19:29.263Z,1618935569.263 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T16:19:29.263Z,1618935569.263 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 39
2021-04-20T16:19:48.224Z,1618935588.224 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T16:19:48.224Z,1618935588.224 [Default:CheckIn:C.Wait] Stopped
2021-04-20T16:19:48.224Z,1618935588.224 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T16:19:48.224Z,1618935588.224 [Default:CheckIn:D] Running Loop=1
2021-04-20T16:19:48.639Z,1618935588.639 [Default:CheckIn:D] Stopped
2021-04-20T16:19:48.639Z,1618935588.639 [Default:CheckIn:E] Running Loop=1
2021-04-20T16:19:49.048Z,1618935589.048 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 115.203223 min
2021-04-20T16:19:49.048Z,1618935589.048 [Default:CheckIn:E] Stopped
2021-04-20T16:19:49.048Z,1618935589.048 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T16:19:49.048Z,1618935589.048 [Default:CheckIn] Stopped
2021-04-20T16:19:49.048Z,1618935589.048 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T16:19:49.048Z,1618935589.048 [Default:CheckIn](INFO): Running loop #12
2021-04-20T16:19:49.048Z,1618935589.048 [Default:CheckIn] Running Loop=12
2021-04-20T16:19:49.048Z,1618935589.048 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T16:19:49.049Z,1618935589.049 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T16:22:29.903Z,1618935749.903 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 40
2021-04-20T16:22:29.903Z,1618935749.903 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T16:22:29.946Z,1618935749.946 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T16:22:30.303Z,1618935750.303 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T16:22:30.303Z,1618935750.303 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 40
2021-04-20T16:22:52.476Z,1618935772.476 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-04-20T16:22:52.476Z,1618935772.476 [NAL9602] Data Fault, FailCount= 1
2021-04-20T16:22:52.476Z,1618935772.476 [NAL9602](ERROR): Data Fault
2021-04-20T16:22:52.538Z,1618935772.538 [CBIT](ERROR): Data Fault in component: NAL9602
2021-04-20T16:22:52.876Z,1618935772.876 [NAL9602](INFO): Powering down
2021-04-20T16:22:53.706Z,1618935773.706 [CBIT](INFO): Clearing failed state for component NAL9602
2021-04-20T16:22:53.706Z,1618935773.706 [NAL9602] No Fault, FailCount= 1
2021-04-20T16:23:09.455Z,1618935789.455 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,+00000000.0000.00,900.00
2021-04-20T16:23:23.180Z,1618935803.180 [NAL9602](INFO): Powering up NAL9602
2021-04-20T16:23:34.088Z,1618935814.088 [NAL9602](INFO): NAL9602 initialized
2021-04-20T16:24:49.275Z,1618935889.275 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-20T16:19:49.0Z
2021-04-20T16:24:49.276Z,1618935889.276 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T16:24:49.276Z,1618935889.276 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T16:24:55.349Z,1618935895.349 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210420T142139/Courier0037.lzma
2021-04-20T16:24:56.352Z,1618935896.352 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0037.lzma.bak
2021-04-20T16:24:56.352Z,1618935896.352 [DataOverHttps](INFO): SBD MOMSN=15590519
2021-04-20T16:25:11.761Z,1618935911.761 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20210420T142139/Express0038.lzma
2021-04-20T16:25:12.764Z,1618935912.764 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0038.lzma.bak
2021-04-20T16:25:12.764Z,1618935912.764 [DataOverHttps](INFO): SBD MOMSN=15590521
2021-04-20T16:25:13.897Z,1618935913.897 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T16:25:13.897Z,1618935913.897 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T16:25:13.897Z,1618935913.897 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T16:25:30.875Z,1618935930.875 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 41
2021-04-20T16:25:30.875Z,1618935930.875 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-04-20T16:25:30.885Z,1618935930.885 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-04-20T16:25:31.277Z,1618935931.277 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-04-20T16:25:31.277Z,1618935931.277 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 41
2021-04-20T16:28:03.206Z,1618936083.206 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162802.00,A,3648.16696,N,12147.28076,W,0.350,0.00,200421,,,A*7D
2021-04-20T16:28:03.209Z,1618936083.209 [NAL9602](INFO): GPS fix at 20210420T162802: (36.802783, -121.788013)
2021-04-20T16:28:35.256Z,1618936115.256 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-20T16:30:14.660Z,1618936214.660 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T16:30:14.660Z,1618936214.660 [Default:CheckIn:C.Wait] Stopped
2021-04-20T16:30:14.660Z,1618936214.660 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T16:30:14.660Z,1618936214.660 [Default:CheckIn:D] Running Loop=1
2021-04-20T16:30:15.067Z,1618936215.067 [Default:CheckIn:D] Stopped
2021-04-20T16:30:15.067Z,1618936215.067 [Default:CheckIn:E] Running Loop=1
2021-04-20T16:30:15.491Z,1618936215.491 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 125.643701 min
2021-04-20T16:30:15.491Z,1618936215.491 [Default:CheckIn:E] Stopped
2021-04-20T16:30:15.491Z,1618936215.491 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T16:30:15.491Z,1618936215.491 [Default:CheckIn] Stopped
2021-04-20T16:30:15.492Z,1618936215.492 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T16:30:15.492Z,1618936215.492 [Default:CheckIn](INFO): Running loop #13
2021-04-20T16:30:15.492Z,1618936215.492 [Default:CheckIn] Running Loop=13
2021-04-20T16:30:15.492Z,1618936215.492 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T16:30:15.492Z,1618936215.492 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T16:30:17.477Z,1618936217.477 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163016.00,A,3648.16921,N,12147.27820,W,0.525,0.00,200421,,,A*72
2021-04-20T16:30:17.480Z,1618936217.480 [NAL9602](INFO): GPS fix at 20210420T163016: (36.802820, -121.787970)
2021-04-20T16:30:17.535Z,1618936217.535 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T16:30:17.535Z,1618936217.535 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T16:30:24.810Z,1618936224.810 [DataOverHttps](INFO): Sending 221 bytes from file Logs/20210420T142139/Courier0040.lzma
2021-04-20T16:30:25.812Z,1618936225.812 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0040.lzma.bak
2021-04-20T16:30:25.812Z,1618936225.812 [DataOverHttps](INFO): SBD MOMSN=15590539
2021-04-20T16:30:41.542Z,1618936241.542 [DataOverHttps](INFO): Sending 260 bytes from file Logs/20210420T142139/Express0041.lzma
2021-04-20T16:30:42.544Z,1618936242.544 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0041.lzma.bak
2021-04-20T16:30:42.544Z,1618936242.544 [DataOverHttps](INFO): SBD MOMSN=15590542
2021-04-20T16:30:43.923Z,1618936243.923 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T16:30:43.923Z,1618936243.923 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T16:30:43.924Z,1618936243.924 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T16:31:39.269Z,1618936299.269 [NAL9602](INFO): SBD MO Status=2, MOMSN=2664, MT Status=2, MTMSN=0
2021-04-20T16:31:39.269Z,1618936299.269 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-20T16:32:18.061Z,1618936338.061 [NAL9602](INFO): SBD MO Status=0, MOMSN=2664, MT Status=0, MTMSN=0
2021-04-20T16:32:18.061Z,1618936338.061 [NAL9602](INFO): No messages in MT queue
2021-04-20T16:32:48.759Z,1618936368.759 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-20T16:35:42.479Z,1618936542.479 [DVL_micro](ERROR): Failed to parse:
:WI,+01344,+00270,+01287,+
2021-04-20T16:35:44.513Z,1618936544.513 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T16:35:44.513Z,1618936544.513 [Default:CheckIn:C.Wait] Stopped
2021-04-20T16:35:44.513Z,1618936544.513 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T16:35:44.514Z,1618936544.514 [Default:CheckIn:D] Running Loop=1
2021-04-20T16:35:44.922Z,1618936544.922 [Default:CheckIn:D] Stopped
2021-04-20T16:35:44.922Z,1618936544.922 [Default:CheckIn:E] Running Loop=1
2021-04-20T16:35:45.324Z,1618936545.324 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 131.141276 min
2021-04-20T16:35:45.325Z,1618936545.325 [Default:CheckIn:E] Stopped
2021-04-20T16:35:45.325Z,1618936545.325 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T16:35:45.325Z,1618936545.325 [Default:CheckIn] Stopped
2021-04-20T16:35:45.325Z,1618936545.325 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T16:35:45.325Z,1618936545.325 [Default:CheckIn](INFO): Running loop #14
2021-04-20T16:35:45.325Z,1618936545.325 [Default:CheckIn] Running Loop=14
2021-04-20T16:35:45.325Z,1618936545.325 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T16:35:45.325Z,1618936545.325 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T16:35:47.333Z,1618936547.333 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163547.00,A,3648.16550,N,12147.28144,W,0.233,0.00,200421,,,A*7D
2021-04-20T16:35:47.340Z,1618936547.340 [NAL9602](INFO): GPS fix at 20210420T163547: (36.802758, -121.788024)
2021-04-20T16:35:47.437Z,1618936547.437 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T16:35:47.437Z,1618936547.437 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T16:35:55.077Z,1618936555.077 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210420T142139/Courier0043.lzma
2021-04-20T16:35:56.080Z,1618936556.080 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0043.lzma.bak
2021-04-20T16:35:56.080Z,1618936556.080 [DataOverHttps](INFO): SBD MOMSN=15590559
2021-04-20T16:36:09.985Z,1618936569.985 [NAL9602](INFO): SBD MO Status=2, MOMSN=2665, MT Status=2, MTMSN=0
2021-04-20T16:36:09.985Z,1618936569.985 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-20T16:36:15.922Z,1618936575.922 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20210420T142139/Express0044.lzma
2021-04-20T16:36:16.928Z,1618936576.928 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0044.lzma.bak
2021-04-20T16:36:16.928Z,1618936576.928 [DataOverHttps](INFO): SBD MOMSN=15590562
2021-04-20T16:36:18.139Z,1618936578.139 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T16:36:18.139Z,1618936578.139 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T16:36:18.139Z,1618936578.139 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T16:36:44.375Z,1618936604.375 [NAL9602](INFO): SBD MO Status=2, MOMSN=2665, MT Status=2, MTMSN=0
2021-04-20T16:36:44.375Z,1618936604.375 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-20T16:37:14.291Z,1618936634.291 [NAL9602](INFO): SBD MO Status=2, MOMSN=2665, MT Status=2, MTMSN=0
2021-04-20T16:37:14.291Z,1618936634.291 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-20T16:38:01.945Z,1618936681.945 [NAL9602](INFO): SBD MO Status=2, MOMSN=2665, MT Status=2, MTMSN=0
2021-04-20T16:38:01.945Z,1618936681.945 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-20T16:38:25.041Z,1618936705.041 [NAL9602](INFO): SBD MO Status=2, MOMSN=2665, MT Status=2, MTMSN=0
2021-04-20T16:38:25.041Z,1618936705.041 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-20T16:38:46.855Z,1618936726.855 [NAL9602](INFO): SBD MO Status=0, MOMSN=2665, MT Status=0, MTMSN=0
2021-04-20T16:38:46.855Z,1618936726.855 [NAL9602](INFO): No messages in MT queue
2021-04-20T16:38:46.855Z,1618936726.855 [NAL9602](INFO): Failure count cleared after critical for NAL9602
2021-04-20T16:39:17.555Z,1618936757.555 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-20T16:40:47.699Z,1618936847.699 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2021-04-20T16:40:47.700Z,1618936847.700 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+21.5,0000.0,148
2021-04-20T16:41:18.779Z,1618936878.779 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T16:41:18.780Z,1618936878.780 [Default:CheckIn:C.Wait] Stopped
2021-04-20T16:41:18.780Z,1618936878.780 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T16:41:18.780Z,1618936878.780 [Default:CheckIn:D] Running Loop=1
2021-04-20T16:41:19.189Z,1618936879.189 [Default:CheckIn:D] Stopped
2021-04-20T16:41:19.189Z,1618936879.189 [Default:CheckIn:E] Running Loop=1
2021-04-20T16:41:19.586Z,1618936879.586 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 136.712386 min
2021-04-20T16:41:19.586Z,1618936879.586 [Default:CheckIn:E] Stopped
2021-04-20T16:41:19.586Z,1618936879.586 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T16:41:19.586Z,1618936879.586 [Default:CheckIn] Stopped
2021-04-20T16:41:19.587Z,1618936879.587 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T16:41:19.587Z,1618936879.587 [Default:CheckIn](INFO): Running loop #15
2021-04-20T16:41:19.587Z,1618936879.587 [Default:CheckIn] Running Loop=15
2021-04-20T16:41:19.587Z,1618936879.587 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T16:41:19.587Z,1618936879.587 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T16:41:21.712Z,1618936881.712 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164121.00,A,3648.13555,N,12147.21125,W,0.000,26.83,200421,,,A*4D
2021-04-20T16:41:21.714Z,1618936881.714 [NAL9602](INFO): GPS fix at 20210420T164121: (36.802259, -121.786854)
2021-04-20T16:41:21.725Z,1618936881.725 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T16:41:21.725Z,1618936881.725 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T16:41:28.661Z,1618936888.661 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210420T142139/Courier0046.lzma
2021-04-20T16:41:29.664Z,1618936889.664 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0046.lzma.bak
2021-04-20T16:41:29.664Z,1618936889.664 [DataOverHttps](INFO): SBD MOMSN=15590580
2021-04-20T16:41:35.966Z,1618936895.966 [NAL9602](INFO): SBD MO Status=0, MOMSN=2666, MT Status=0, MTMSN=0
2021-04-20T16:41:35.966Z,1618936895.966 [NAL9602](INFO): No messages in MT queue
2021-04-20T16:41:45.850Z,1618936905.850 [DataOverHttps](INFO): Sending 133 bytes from file Logs/20210420T142139/Express0047.lzma
2021-04-20T16:41:46.852Z,1618936906.852 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0047.lzma.bak
2021-04-20T16:41:46.852Z,1618936906.852 [DataOverHttps](INFO): SBD MOMSN=15590583
2021-04-20T16:41:47.881Z,1618936907.881 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T16:41:47.881Z,1618936907.881 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T16:41:47.881Z,1618936907.881 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T16:42:06.433Z,1618936926.433 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-20T16:43:06.803Z,1618936986.803 [DataOverHttps](IMPORTANT): SBD MTMSN=20210420T164306
2021-04-20T16:43:14.230Z,1618936994.230 [DataOverHttps](INFO): Received command:ibit
2021-04-20T16:43:14.306Z,1618936994.306 [CommandLine](IMPORTANT): got command ibit
2021-04-20T16:43:14.364Z,1618936994.364 [IBIT](IMPORTANT): Beginning Initiated BIT
2021-04-20T16:43:14.365Z,1618936994.365 [IBIT](IMPORTANT): Beginning control surface checks.
2021-04-20T16:43:14.372Z,1618936994.372 [CBIT](IMPORTANT): Beginning ground fault scan
2021-04-20T16:43:16.000Z,1618936996.000 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164315.00,A,3648.13582,N,12147.21099,W,0.000,26.83,200421,,,D*41
2021-04-20T16:43:16.009Z,1618936996.009 [NAL9602](INFO): GPS fix at 20210420T164315: (36.802264, -121.786850)
2021-04-20T16:43:25.283Z,1618937005.283 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.002855
CHAN A1 (24V): -0.002009
CHAN A2 (12V): -0.000164
CHAN A3 (5V): 0.000389
CHAN B0 (3.3V): 0.000814
CHAN B1 (3.15aV): -0.000081
CHAN B2 (3.15bV): -0.000432
CHAN B3 (GND): 0.000273
OPEN: 0.004016
Full Scale Calc: 4.765 mA, -1.589 mA
2021-04-20T16:43:32.091Z,1618937012.091 [NAL9602](INFO): SBD MO Status=0, MOMSN=2667, MT Status=0, MTMSN=0
2021-04-20T16:43:32.091Z,1618937012.091 [NAL9602](INFO): No messages in MT queue
2021-04-20T16:43:33.323Z,1618937013.323 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164333.00,A,3648.13585,N,12147.21066,W,0.000,26.83,200421,,,D*42
2021-04-20T16:43:33.330Z,1618937013.330 [NAL9602](INFO): GPS fix at 20210420T164333: (36.802264, -121.786844)
2021-04-20T16:43:36.535Z,1618937016.535 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164336.00,A,3648.13591,N,12147.21051,W,0.019,26.83,200421,,,D*4E
2021-04-20T16:43:36.538Z,1618937016.538 [NAL9602](INFO): GPS fix at 20210420T164336: (36.802265, -121.786842)
2021-04-20T16:43:39.370Z,1618937019.370 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164339.00,A,3648.13594,N,12147.21043,W,0.019,26.83,200421,,,D*47
2021-04-20T16:43:39.372Z,1618937019.372 [NAL9602](INFO): GPS fix at 20210420T164339: (36.802266, -121.786840)
2021-04-20T16:43:42.197Z,1618937022.197 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164342.00,A,3648.13603,N,12147.21032,W,0.019,26.83,200421,,,D*40
2021-04-20T16:43:42.200Z,1618937022.200 [NAL9602](INFO): GPS fix at 20210420T164342: (36.802267, -121.786839)
2021-04-20T16:43:45.478Z,1618937025.478 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164345.00,A,3648.13603,N,12147.21035,W,0.019,26.83,200421,,,D*40
2021-04-20T16:43:45.480Z,1618937025.480 [NAL9602](INFO): GPS fix at 20210420T164345: (36.802267, -121.786839)
2021-04-20T16:43:48.253Z,1618937028.253 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164348.00,A,3648.13591,N,12147.21041,W,0.019,26.83,200421,,,D*46
2021-04-20T16:43:48.256Z,1618937028.256 [NAL9602](INFO): GPS fix at 20210420T164348: (36.802265, -121.786840)
2021-04-20T16:43:51.497Z,1618937031.497 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164351.00,A,3648.13581,N,12147.21040,W,0.019,26.83,200421,,,D*4E
2021-04-20T16:43:51.500Z,1618937031.500 [NAL9602](INFO): GPS fix at 20210420T164351: (36.802264, -121.786840)
2021-04-20T16:43:54.317Z,1618937034.317 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164354.00,A,3648.13577,N,12147.21042,W,0.019,26.83,200421,,,D*40
2021-04-20T16:43:54.320Z,1618937034.320 [NAL9602](INFO): GPS fix at 20210420T164354: (36.802263, -121.786840)
2021-04-20T16:43:57.558Z,1618937037.558 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164357.00,A,3648.13577,N,12147.21048,W,0.019,26.83,200421,,,D*49
2021-04-20T16:43:57.560Z,1618937037.560 [NAL9602](INFO): GPS fix at 20210420T164357: (36.802263, -121.786841)
2021-04-20T16:44:00.386Z,1618937040.386 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164400.00,A,3648.13576,N,12147.21050,W,0.058,26.83,200421,,,D*41
2021-04-20T16:44:00.388Z,1618937040.388 [NAL9602](INFO): GPS fix at 20210420T164400: (36.802263, -121.786842)
2021-04-20T16:44:00.406Z,1618937040.406 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 2
Latitude: 36.802261 Longitude: -121.786842
2021-04-20T16:44:00.816Z,1618937040.816 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 359.478271
Voltage: 16.611000
2021-04-20T16:44:00.817Z,1618937040.817 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2021-04-20T16:44:00.817Z,1618937040.817 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2021-04-20T16:44:01.256Z,1618937041.256 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2021-04-20T16:44:01.257Z,1618937041.257 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2021-04-20T16:44:01.257Z,1618937041.257 [IBIT](IMPORTANT): Pressure:8.104609 PSI
2021-04-20T16:44:01.257Z,1618937041.257 [IBIT](IMPORTANT): Humidity:15.565865 %
2021-04-20T16:44:01.652Z,1618937041.652 [IBIT](IMPORTANT): Vehicle Pitch:-0.964526 degrees
2021-04-20T16:44:01.653Z,1618937041.653 [IBIT](IMPORTANT): Vehicle Roll:8.239785 degrees
2021-04-20T16:44:01.653Z,1618937041.653 [IBIT](IMPORTANT): Vehicle Heading:198.638519 degrees
2021-04-20T16:44:02.097Z,1618937042.097 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2021-04-20T16:44:02.097Z,1618937042.097 [IBIT](IMPORTANT): buoyancyNeutral: 214.815567 cc
2021-04-20T16:44:02.102Z,1618937042.102 [IBIT](IMPORTANT): massDefault: -0.100000 cm
2021-04-20T16:44:02.102Z,1618937042.102 [IBIT](IMPORTANT): stopDepth: 265.000000 m
2021-04-20T16:44:02.103Z,1618937042.103 [IBIT](IMPORTANT): abortDepth: 300.000000 m
2021-04-20T16:44:02.103Z,1618937042.103 [IBIT](IMPORTANT): IBIT PASSED
2021-04-20T16:44:32.699Z,1618937072.699 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-20T16:45:43.004Z,1618937143.004 [DVL_micro](ERROR): only read 3 of 4 data items
2021-04-20T16:45:43.004Z,1618937143.004 [DVL_micro](ERROR): Failed to parse:
:BI,01202,+00703,+00000,I
2021-04-20T16:45:44.614Z,1618937144.614 [BPC1](FAULT): Battery stick #6 (s/n: 00CA) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2021-04-20T16:45:44.615Z,1618937144.615 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6.
2021-04-20T16:45:44.617Z,1618937144.617 [BPC1](INFO): Received data from all battery sticks.
2021-04-20T16:46:48.523Z,1618937208.523 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T16:46:48.523Z,1618937208.523 [Default:CheckIn:C.Wait] Stopped
2021-04-20T16:46:48.523Z,1618937208.523 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T16:46:48.523Z,1618937208.523 [Default:CheckIn:D] Running Loop=1
2021-04-20T16:46:48.937Z,1618937208.937 [Default:CheckIn:D] Stopped
2021-04-20T16:46:48.937Z,1618937208.937 [Default:CheckIn:E] Running Loop=1
2021-04-20T16:46:49.354Z,1618937209.354 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 142.208203 min
2021-04-20T16:46:49.354Z,1618937209.354 [Default:CheckIn:E] Stopped
2021-04-20T16:46:49.354Z,1618937209.354 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T16:46:49.354Z,1618937209.354 [Default:CheckIn] Stopped
2021-04-20T16:46:49.354Z,1618937209.354 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T16:46:49.355Z,1618937209.355 [Default:CheckIn](INFO): Running loop #16
2021-04-20T16:46:49.355Z,1618937209.355 [Default:CheckIn] Running Loop=16
2021-04-20T16:46:49.355Z,1618937209.355 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T16:46:49.355Z,1618937209.355 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T16:46:51.345Z,1618937211.345 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164651.00,A,3648.13383,N,12147.21227,W,0.019,26.83,200421,,,D*4C
2021-04-20T16:46:51.348Z,1618937211.348 [NAL9602](INFO): GPS fix at 20210420T164651: (36.802231, -121.786871)
2021-04-20T16:46:51.386Z,1618937211.386 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T16:46:51.386Z,1618937211.386 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T16:46:58.669Z,1618937218.669 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20210420T142139/Courier0049.lzma
2021-04-20T16:46:59.672Z,1618937219.672 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0049.lzma.bak
2021-04-20T16:46:59.672Z,1618937219.672 [DataOverHttps](INFO): SBD MOMSN=15590603
2021-04-20T16:47:02.270Z,1618937222.270 [DVL_micro](ERROR): only read 2 of 4 data items
2021-04-20T16:47:02.271Z,1618937222.271 [DVL_micro](ERROR): Failed to parse:
:BI,+01238,-01294+00000,I
2021-04-20T16:47:04.699Z,1618937224.699 [NAL9602](INFO): SBD MO Status=0, MOMSN=2668, MT Status=0, MTMSN=0
2021-04-20T16:47:04.700Z,1618937224.700 [NAL9602](INFO): No messages in MT queue
2021-04-20T16:47:15.648Z,1618937235.648 [DataOverHttps](INFO): Sending 903 bytes from file Logs/20210420T142139/Express0050.lzma
2021-04-20T16:47:16.648Z,1618937236.648 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0050.lzma.bak
2021-04-20T16:47:16.648Z,1618937236.648 [DataOverHttps](INFO): SBD MOMSN=15590607
2021-04-20T16:47:32.505Z,1618937252.505 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20210420T142139/Express0053.lzma
2021-04-20T16:47:33.508Z,1618937253.508 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0053.lzma.bak
2021-04-20T16:47:33.508Z,1618937253.508 [DataOverHttps](INFO): SBD MOMSN=15590634
2021-04-20T16:47:34.589Z,1618937254.589 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T16:47:34.589Z,1618937254.589 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T16:47:34.589Z,1618937254.589 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T16:47:35.383Z,1618937255.383 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-20T16:48:08.117Z,1618937288.117 [DVL_micro](ERROR): only read 3 of 4 data items
2021-04-20T16:48:08.117Z,1618937288.117 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,+9999.999
2021-04-20T16:52:35.243Z,1618937555.243 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T16:52:35.243Z,1618937555.243 [Default:CheckIn:C.Wait] Stopped
2021-04-20T16:52:35.243Z,1618937555.243 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T16:52:35.243Z,1618937555.243 [Default:CheckIn:D] Running Loop=1
2021-04-20T16:52:35.713Z,1618937555.713 [Default:CheckIn:D] Stopped
2021-04-20T16:52:35.713Z,1618937555.713 [Default:CheckIn:E] Running Loop=1
2021-04-20T16:52:36.066Z,1618937556.066 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 147.987809 min
2021-04-20T16:52:36.066Z,1618937556.066 [Default:CheckIn:E] Stopped
2021-04-20T16:52:36.066Z,1618937556.066 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T16:52:36.066Z,1618937556.066 [Default:CheckIn] Stopped
2021-04-20T16:52:36.066Z,1618937556.066 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T16:52:36.067Z,1618937556.067 [Default:CheckIn](INFO): Running loop #17
2021-04-20T16:52:36.067Z,1618937556.067 [Default:CheckIn] Running Loop=17
2021-04-20T16:52:36.067Z,1618937556.067 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T16:52:36.067Z,1618937556.067 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T16:52:38.078Z,1618937558.078 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165238.00,A,3648.13407,N,12147.21344,W,0.019,26.83,200421,,,D*49
2021-04-20T16:52:38.080Z,1618937558.080 [NAL9602](INFO): GPS fix at 20210420T165238: (36.802234, -121.786891)
2021-04-20T16:52:38.121Z,1618937558.121 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T16:52:38.121Z,1618937558.121 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T16:52:45.625Z,1618937565.625 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210420T142139/Courier0055.lzma
2021-04-20T16:52:46.628Z,1618937566.628 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0055.lzma.bak
2021-04-20T16:52:46.628Z,1618937566.628 [DataOverHttps](INFO): SBD MOMSN=15590651
2021-04-20T16:52:52.609Z,1618937572.609 [NAL9602](INFO): SBD MO Status=0, MOMSN=2669, MT Status=0, MTMSN=0
2021-04-20T16:52:52.609Z,1618937572.609 [NAL9602](INFO): No messages in MT queue
2021-04-20T16:53:02.426Z,1618937582.426 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210420T142139/Express0056.lzma
2021-04-20T16:53:03.428Z,1618937583.428 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0056.lzma.bak
2021-04-20T16:53:03.428Z,1618937583.428 [DataOverHttps](INFO): SBD MOMSN=15590654
2021-04-20T16:53:04.742Z,1618937584.742 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T16:53:04.742Z,1618937584.742 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T16:53:04.742Z,1618937584.742 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T16:53:23.316Z,1618937603.316 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-20T16:55:36.246Z,1618937736.246 [DVL_micro](ERROR): only read 2 of 4 data items
2021-04-20T16:55:36.246Z,1618937736.246 [DVL_micro](ERROR): Failed to parse:
:BI,+0181,+01032,
2021-04-20T16:58:03.763Z,1618937883.763 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2021-04-20T16:58:03.763Z,1618937883.763 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35,0000.0,1489.0,000
2021-04-20T16:58:05.389Z,1618937885.389 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T16:58:05.389Z,1618937885.389 [Default:CheckIn:C.Wait] Stopped
2021-04-20T16:58:05.389Z,1618937885.389 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T16:58:05.390Z,1618937885.390 [Default:CheckIn:D] Running Loop=1
2021-04-20T16:58:05.798Z,1618937885.798 [Default:CheckIn:D] Stopped
2021-04-20T16:58:05.798Z,1618937885.798 [Default:CheckIn:E] Running Loop=1
2021-04-20T16:58:06.224Z,1618937886.224 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 153.489144 min
2021-04-20T16:58:06.224Z,1618937886.224 [Default:CheckIn:E] Stopped
2021-04-20T16:58:06.224Z,1618937886.224 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T16:58:06.224Z,1618937886.224 [Default:CheckIn] Stopped
2021-04-20T16:58:06.224Z,1618937886.224 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T16:58:06.224Z,1618937886.224 [Default:CheckIn](INFO): Running loop #18
2021-04-20T16:58:06.225Z,1618937886.225 [Default:CheckIn] Running Loop=18
2021-04-20T16:58:06.225Z,1618937886.225 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T16:58:06.225Z,1618937886.225 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T16:58:08.209Z,1618937888.209 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165808.00,A,3648.13485,N,12147.21174,W,0.019,26.83,200421,,,D*4B
2021-04-20T16:58:08.212Z,1618937888.212 [NAL9602](INFO): GPS fix at 20210420T165808: (36.802248, -121.786862)
2021-04-20T16:58:08.259Z,1618937888.259 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T16:58:08.259Z,1618937888.259 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T16:58:18.413Z,1618937898.413 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210420T142139/Courier0058.lzma
2021-04-20T16:58:19.416Z,1618937899.416 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0058.lzma.bak
2021-04-20T16:58:19.417Z,1618937899.417 [DataOverHttps](INFO): SBD MOMSN=15590706
2021-04-20T16:58:35.301Z,1618937915.301 [DataOverHttps](INFO): Sending 134 bytes from file Logs/20210420T142139/Express0059.lzma
2021-04-20T16:58:35.749Z,1618937915.749 [NAL9602](INFO): SBD MO Status=2, MOMSN=2670, MT Status=2, MTMSN=0
2021-04-20T16:58:35.749Z,1618937915.749 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-20T16:58:36.304Z,1618937916.304 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0059.lzma.bak
2021-04-20T16:58:36.304Z,1618937916.304 [DataOverHttps](INFO): SBD MOMSN=15590709
2021-04-20T16:58:37.393Z,1618937917.393 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T16:58:37.393Z,1618937917.393 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T16:58:37.393Z,1618937917.393 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T16:58:44.643Z,1618937924.643 [NAL9602](INFO): SBD MO Status=0, MOMSN=2670, MT Status=0, MTMSN=0
2021-04-20T16:58:44.643Z,1618937924.643 [NAL9602](INFO): No messages in MT queue
2021-04-20T16:59:15.343Z,1618937955.343 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-20T17:03:01.680Z,1618938181.680 [DVL_micro](ERROR): Failed to parse:
9.99,+9999.99,+99999.99
2021-04-20T17:03:38.033Z,1618938218.033 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T17:03:38.034Z,1618938218.034 [Default:CheckIn:C.Wait] Stopped
2021-04-20T17:03:38.034Z,1618938218.034 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T17:03:38.034Z,1618938218.034 [Default:CheckIn:D] Running Loop=1
2021-04-20T17:03:38.435Z,1618938218.435 [Default:CheckIn:D] Stopped
2021-04-20T17:03:38.435Z,1618938218.435 [Default:CheckIn:E] Running Loop=1
2021-04-20T17:03:38.852Z,1618938218.852 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 159.033154 min
2021-04-20T17:03:38.852Z,1618938218.852 [Default:CheckIn:E] Stopped
2021-04-20T17:03:38.852Z,1618938218.852 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T17:03:38.852Z,1618938218.852 [Default:CheckIn] Stopped
2021-04-20T17:03:38.852Z,1618938218.852 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T17:03:38.852Z,1618938218.852 [Default:CheckIn](INFO): Running loop #19
2021-04-20T17:03:38.853Z,1618938218.853 [Default:CheckIn] Running Loop=19
2021-04-20T17:03:38.853Z,1618938218.853 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T17:03:38.853Z,1618938218.853 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T17:03:40.853Z,1618938220.853 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170340.00,A,3648.13408,N,12147.21311,W,0.019,26.83,200421,,,D*4C
2021-04-20T17:03:40.856Z,1618938220.856 [NAL9602](INFO): GPS fix at 20210420T170340: (36.802235, -121.786885)
2021-04-20T17:03:40.891Z,1618938220.891 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T17:03:40.891Z,1618938220.891 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T17:03:48.021Z,1618938228.021 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210420T142139/Courier0061.lzma
2021-04-20T17:03:49.024Z,1618938229.024 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0061.lzma.bak
2021-04-20T17:03:49.024Z,1618938229.024 [DataOverHttps](INFO): SBD MOMSN=15590729
2021-04-20T17:03:57.420Z,1618938237.420 [NAL9602](INFO): SBD MO Status=2, MOMSN=2671, MT Status=2, MTMSN=0
2021-04-20T17:03:57.420Z,1618938237.420 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-20T17:04:07.894Z,1618938247.894 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20210420T142139/Express0062.lzma
2021-04-20T17:04:08.896Z,1618938248.896 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0062.lzma.bak
2021-04-20T17:04:08.896Z,1618938248.896 [DataOverHttps](INFO): SBD MOMSN=15590732
2021-04-20T17:04:10.016Z,1618938250.016 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T17:04:10.016Z,1618938250.016 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T17:04:10.016Z,1618938250.016 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T17:04:16.501Z,1618938256.501 [NAL9602](INFO): SBD MO Status=0, MOMSN=2671, MT Status=0, MTMSN=0
2021-04-20T17:04:16.501Z,1618938256.501 [NAL9602](INFO): No messages in MT queue
2021-04-20T17:04:47.215Z,1618938287.215 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-20T17:08:01.601Z,1618938481.601 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2021-04-20T17:08:01.601Z,1618938481.601 [DVL_micro](ERROR): Failed to parse:
:TS,0000+21.5,0000.0,1489.0,000
2021-04-20T17:09:10.652Z,1618938550.652 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T17:09:10.653Z,1618938550.653 [Default:CheckIn:C.Wait] Stopped
2021-04-20T17:09:10.653Z,1618938550.653 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T17:09:10.653Z,1618938550.653 [Default:CheckIn:D] Running Loop=1
2021-04-20T17:09:11.054Z,1618938551.054 [Default:CheckIn:D] Stopped
2021-04-20T17:09:11.055Z,1618938551.055 [Default:CheckIn:E] Running Loop=1
2021-04-20T17:09:11.462Z,1618938551.462 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 164.576823 min
2021-04-20T17:09:11.462Z,1618938551.462 [Default:CheckIn:E] Stopped
2021-04-20T17:09:11.462Z,1618938551.462 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T17:09:11.462Z,1618938551.462 [Default:CheckIn] Stopped
2021-04-20T17:09:11.462Z,1618938551.462 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T17:09:11.463Z,1618938551.463 [Default:CheckIn](INFO): Running loop #20
2021-04-20T17:09:11.463Z,1618938551.463 [Default:CheckIn] Running Loop=20
2021-04-20T17:09:11.463Z,1618938551.463 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T17:09:11.463Z,1618938551.463 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T17:09:13.469Z,1618938553.469 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170913.00,A,3648.13536,N,12147.21196,W,0.000,26.83,200421,,,D*49
2021-04-20T17:09:13.481Z,1618938553.481 [NAL9602](INFO): GPS fix at 20210420T170913: (36.802256, -121.786866)
2021-04-20T17:09:13.495Z,1618938553.495 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T17:09:13.495Z,1618938553.495 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T17:09:20.357Z,1618938560.357 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210420T142139/Courier0064.lzma
2021-04-20T17:09:21.360Z,1618938561.360 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0064.lzma.bak
2021-04-20T17:09:21.360Z,1618938561.360 [DataOverHttps](INFO): SBD MOMSN=15590752
2021-04-20T17:09:26.797Z,1618938566.797 [NAL9602](INFO): SBD MO Status=0, MOMSN=2672, MT Status=0, MTMSN=0
2021-04-20T17:09:26.797Z,1618938566.797 [NAL9602](INFO): No messages in MT queue
2021-04-20T17:09:37.314Z,1618938577.314 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210420T142139/Express0065.lzma
2021-04-20T17:09:38.316Z,1618938578.316 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0065.lzma.bak
2021-04-20T17:09:38.317Z,1618938578.317 [DataOverHttps](INFO): SBD MOMSN=15590755
2021-04-20T17:09:39.353Z,1618938579.353 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T17:09:39.353Z,1618938579.353 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T17:09:39.353Z,1618938579.353 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T17:09:57.539Z,1618938597.539 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-20T17:10:29.461Z,1618938629.461 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2021-04-20T17:10:29.461Z,1618938629.461 [DVL_micro](ERROR): Failed to parse:
:TS,000000,35,0000.0,1489.0,000
2021-04-20T17:14:40.042Z,1618938880.042 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T17:14:40.042Z,1618938880.042 [Default:CheckIn:C.Wait] Stopped
2021-04-20T17:14:40.042Z,1618938880.042 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T17:14:40.042Z,1618938880.042 [Default:CheckIn:D] Running Loop=1
2021-04-20T17:14:40.457Z,1618938880.457 [Default:CheckIn:D] Stopped
2021-04-20T17:14:40.457Z,1618938880.457 [Default:CheckIn:E] Running Loop=1
2021-04-20T17:14:40.850Z,1618938880.850 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 170.066862 min
2021-04-20T17:14:40.850Z,1618938880.850 [Default:CheckIn:E] Stopped
2021-04-20T17:14:40.850Z,1618938880.850 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T17:14:40.850Z,1618938880.850 [Default:CheckIn] Stopped
2021-04-20T17:14:40.850Z,1618938880.850 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T17:14:40.850Z,1618938880.850 [Default:CheckIn](INFO): Running loop #21
2021-04-20T17:14:40.850Z,1618938880.850 [Default:CheckIn] Running Loop=21
2021-04-20T17:14:40.850Z,1618938880.850 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T17:14:40.851Z,1618938880.851 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T17:14:42.861Z,1618938882.861 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171442.00,A,3648.13518,N,12147.21197,W,0.019,26.83,200421,,,D*44
2021-04-20T17:14:42.863Z,1618938882.863 [NAL9602](INFO): GPS fix at 20210420T171442: (36.802253, -121.786866)
2021-04-20T17:14:42.874Z,1618938882.874 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T17:14:42.874Z,1618938882.874 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T17:14:49.769Z,1618938889.769 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210420T142139/Courier0067.lzma
2021-04-20T17:14:50.772Z,1618938890.772 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0067.lzma.bak
2021-04-20T17:14:50.772Z,1618938890.772 [DataOverHttps](INFO): SBD MOMSN=15590775
2021-04-20T17:15:06.722Z,1618938906.722 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210420T142139/Express0068.lzma
2021-04-20T17:15:07.724Z,1618938907.724 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0068.lzma.bak
2021-04-20T17:15:07.724Z,1618938907.724 [DataOverHttps](INFO): SBD MOMSN=15590779
2021-04-20T17:15:08.747Z,1618938908.747 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T17:15:08.747Z,1618938908.747 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T17:15:08.747Z,1618938908.747 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T17:15:11.563Z,1618938911.563 [NAL9602](INFO): SBD MO Status=0, MOMSN=2673, MT Status=0, MTMSN=0
2021-04-20T17:15:11.563Z,1618938911.563 [NAL9602](INFO): No messages in MT queue
2021-04-20T17:15:42.250Z,1618938942.250 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-20T17:18:04.869Z,1618939084.869 [DVL_micro](ERROR): only read 3 of 4 data items
2021-04-20T17:18:04.874Z,1618939084.874 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.999,+9999.99
2021-04-20T17:20:09.418Z,1618939209.418 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T17:20:09.419Z,1618939209.419 [Default:CheckIn:C.Wait] Stopped
2021-04-20T17:20:09.419Z,1618939209.419 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T17:20:09.419Z,1618939209.419 [Default:CheckIn:D] Running Loop=1
2021-04-20T17:20:09.829Z,1618939209.829 [Default:CheckIn:D] Stopped
2021-04-20T17:20:09.829Z,1618939209.829 [Default:CheckIn:E] Running Loop=1
2021-04-20T17:20:10.198Z,1618939210.198 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 175.556396 min
2021-04-20T17:20:10.198Z,1618939210.198 [Default:CheckIn:E] Stopped
2021-04-20T17:20:10.199Z,1618939210.199 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T17:20:10.199Z,1618939210.199 [Default:CheckIn] Stopped
2021-04-20T17:20:10.199Z,1618939210.199 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T17:20:10.199Z,1618939210.199 [Default:CheckIn](INFO): Running loop #22
2021-04-20T17:20:10.199Z,1618939210.199 [Default:CheckIn] Running Loop=22
2021-04-20T17:20:10.199Z,1618939210.199 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T17:20:10.199Z,1618939210.199 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T17:20:12.183Z,1618939212.183 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172012.00,A,3648.14085,N,12147.20702,W,0.058,33.12,200421,,,D*42
2021-04-20T17:20:12.185Z,1618939212.185 [NAL9602](INFO): GPS fix at 20210420T172012: (36.802348, -121.786784)
2021-04-20T17:20:12.200Z,1618939212.200 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T17:20:12.201Z,1618939212.201 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T17:20:22.061Z,1618939222.061 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210420T142139/Courier0070.lzma
2021-04-20T17:20:23.064Z,1618939223.064 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0070.lzma.bak
2021-04-20T17:20:23.064Z,1618939223.064 [DataOverHttps](INFO): SBD MOMSN=15590805
2021-04-20T17:20:30.801Z,1618939230.801 [NAL9602](INFO): SBD MO Status=0, MOMSN=2674, MT Status=0, MTMSN=0
2021-04-20T17:20:30.801Z,1618939230.801 [NAL9602](INFO): No messages in MT queue
2021-04-20T17:20:38.833Z,1618939238.833 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210420T142139/Express0071.lzma
2021-04-20T17:20:39.836Z,1618939239.836 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0071.lzma.bak
2021-04-20T17:20:39.836Z,1618939239.836 [DataOverHttps](INFO): SBD MOMSN=15590808
2021-04-20T17:20:40.917Z,1618939240.917 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T17:20:40.917Z,1618939240.917 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T17:20:40.917Z,1618939240.917 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T17:21:01.503Z,1618939261.503 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-20T17:23:22.510Z,1618939402.510 [DVL_micro](ERROR): Failed to parse:
:BI,+00985,-02856,+0000,I
2021-04-20T17:25:41.493Z,1618939541.493 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T17:25:41.493Z,1618939541.493 [Default:CheckIn:C.Wait] Stopped
2021-04-20T17:25:41.493Z,1618939541.493 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T17:25:41.493Z,1618939541.493 [Default:CheckIn:D] Running Loop=1
2021-04-20T17:25:41.901Z,1618939541.901 [Default:CheckIn:D] Stopped
2021-04-20T17:25:41.901Z,1618939541.901 [Default:CheckIn:E] Running Loop=1
2021-04-20T17:25:42.324Z,1618939542.324 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 181.090934 min
2021-04-20T17:25:42.324Z,1618939542.324 [Default:CheckIn:E] Stopped
2021-04-20T17:25:42.324Z,1618939542.324 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T17:25:42.324Z,1618939542.324 [Default:CheckIn] Stopped
2021-04-20T17:25:42.324Z,1618939542.324 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T17:25:42.324Z,1618939542.324 [Default:CheckIn](INFO): Running loop #23
2021-04-20T17:25:42.324Z,1618939542.324 [Default:CheckIn] Running Loop=23
2021-04-20T17:25:42.324Z,1618939542.324 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T17:25:42.324Z,1618939542.325 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T17:25:44.310Z,1618939544.309 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172544.00,A,3648.13816,N,12147.20533,W,0.019,163.90,200421,,,D*7A
2021-04-20T17:25:44.312Z,1618939544.312 [NAL9602](INFO): GPS fix at 20210420T172544: (36.802303, -121.786755)
2021-04-20T17:25:44.323Z,1618939544.323 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T17:25:44.323Z,1618939544.323 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T17:25:52.085Z,1618939552.085 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210420T142139/Courier0073.lzma
2021-04-20T17:25:53.088Z,1618939553.088 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0073.lzma.bak
2021-04-20T17:25:53.088Z,1618939553.088 [DataOverHttps](INFO): SBD MOMSN=15590835
2021-04-20T17:25:55.217Z,1618939555.217 [DVL_micro](ERROR): only read 2 of 4 data items
2021-04-20T17:25:55.217Z,1618939555.217 [DVL_micro](ERROR): Failed to parse:
:RD,+99999.99,+99999.99
2021-04-20T17:26:11.902Z,1618939571.902 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210420T142139/Express0074.lzma
2021-04-20T17:26:12.904Z,1618939572.904 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0074.lzma.bak
2021-04-20T17:26:12.904Z,1618939572.904 [DataOverHttps](INFO): SBD MOMSN=15590838
2021-04-20T17:26:14.303Z,1618939574.303 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T17:26:14.303Z,1618939574.303 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T17:26:14.303Z,1618939574.303 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T17:26:16.317Z,1618939576.317 [NAL9602](INFO): SBD MO Status=0, MOMSN=2675, MT Status=0, MTMSN=0
2021-04-20T17:26:16.317Z,1618939576.317 [NAL9602](INFO): No messages in MT queue
2021-04-20T17:26:47.060Z,1618939607.060 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-20T17:28:30.140Z,1618939710.140 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00
2021-04-20T17:31:05.288Z,1618939865.288 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,0.00,+00000009.99,000.00
2021-04-20T17:31:14.990Z,1618939874.990 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T17:31:14.990Z,1618939874.990 [Default:CheckIn:C.Wait] Stopped
2021-04-20T17:31:14.990Z,1618939874.990 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T17:31:14.990Z,1618939874.990 [Default:CheckIn:D] Running Loop=1
2021-04-20T17:31:15.422Z,1618939875.422 [Default:CheckIn:D] Stopped
2021-04-20T17:31:15.422Z,1618939875.422 [Default:CheckIn:E] Running Loop=1
2021-04-20T17:31:15.794Z,1618939875.794 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 186.649609 min
2021-04-20T17:31:15.794Z,1618939875.794 [Default:CheckIn:E] Stopped
2021-04-20T17:31:15.794Z,1618939875.794 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T17:31:15.794Z,1618939875.794 [Default:CheckIn] Stopped
2021-04-20T17:31:15.794Z,1618939875.794 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T17:31:15.795Z,1618939875.795 [Default:CheckIn](INFO): Running loop #24
2021-04-20T17:31:15.795Z,1618939875.795 [Default:CheckIn] Running Loop=24
2021-04-20T17:31:15.795Z,1618939875.795 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T17:31:15.795Z,1618939875.795 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T17:31:17.800Z,1618939877.800 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173117.00,A,3648.13913,N,12147.20585,W,0.097,163.90,200421,,,D*76
2021-04-20T17:31:17.802Z,1618939877.802 [NAL9602](INFO): GPS fix at 20210420T173117: (36.802319, -121.786764)
2021-04-20T17:31:17.812Z,1618939877.812 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T17:31:17.812Z,1618939877.812 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T17:31:25.142Z,1618939885.142 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210420T142139/Courier0076.lzma
2021-04-20T17:31:26.144Z,1618939886.144 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0076.lzma.bak
2021-04-20T17:31:26.144Z,1618939886.144 [DataOverHttps](INFO): SBD MOMSN=15590864
2021-04-20T17:31:42.078Z,1618939902.078 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20210420T142139/Express0077.lzma
2021-04-20T17:31:43.080Z,1618939903.080 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0077.lzma.bak
2021-04-20T17:31:43.080Z,1618939903.080 [DataOverHttps](INFO): SBD MOMSN=15590867
2021-04-20T17:31:44.105Z,1618939904.105 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T17:31:44.105Z,1618939904.105 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T17:31:44.105Z,1618939904.105 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T17:32:36.217Z,1618939956.217 [NAL9602](INFO): SBD MO Status=2, MOMSN=2676, MT Status=2, MTMSN=0
2021-04-20T17:32:36.217Z,1618939956.217 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-20T17:33:06.515Z,1618939986.515 [NAL9602](INFO): SBD MO Status=2, MOMSN=2676, MT Status=2, MTMSN=0
2021-04-20T17:33:06.515Z,1618939986.515 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-20T17:34:15.663Z,1618940055.663 [NAL9602](INFO): SBD MO Status=2, MOMSN=2676, MT Status=2, MTMSN=0
2021-04-20T17:34:15.663Z,1618940055.663 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-20T17:35:02.921Z,1618940102.921 [NAL9602](INFO): SBD MO Status=2, MOMSN=2676, MT Status=2, MTMSN=0
2021-04-20T17:35:02.921Z,1618940102.921 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-20T17:35:15.037Z,1618940115.037 [NAL9602](INFO): SBD MO Status=0, MOMSN=2676, MT Status=0, MTMSN=0
2021-04-20T17:35:15.037Z,1618940115.037 [NAL9602](INFO): No messages in MT queue
2021-04-20T17:35:45.739Z,1618940145.739 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-20T17:36:44.754Z,1618940204.754 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T17:36:44.755Z,1618940204.755 [Default:CheckIn:C.Wait] Stopped
2021-04-20T17:36:44.755Z,1618940204.755 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T17:36:44.755Z,1618940204.755 [Default:CheckIn:D] Running Loop=1
2021-04-20T17:36:45.161Z,1618940205.161 [Default:CheckIn:D] Stopped
2021-04-20T17:36:45.161Z,1618940205.161 [Default:CheckIn:E] Running Loop=1
2021-04-20T17:36:45.553Z,1618940205.553 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 192.145264 min
2021-04-20T17:36:45.553Z,1618940205.553 [Default:CheckIn:E] Stopped
2021-04-20T17:36:45.553Z,1618940205.553 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T17:36:45.553Z,1618940205.553 [Default:CheckIn] Stopped
2021-04-20T17:36:45.553Z,1618940205.553 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T17:36:45.554Z,1618940205.554 [Default:CheckIn](INFO): Running loop #25
2021-04-20T17:36:45.554Z,1618940205.554 [Default:CheckIn] Running Loop=25
2021-04-20T17:36:45.554Z,1618940205.554 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T17:36:45.554Z,1618940205.554 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T17:36:47.569Z,1618940207.569 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173647.00,A,3648.13823,N,12147.20670,W,0.078,163.90,200421,,,D*7E
2021-04-20T17:36:47.572Z,1618940207.572 [NAL9602](INFO): GPS fix at 20210420T173647: (36.802304, -121.786778)
2021-04-20T17:36:47.584Z,1618940207.584 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T17:36:47.584Z,1618940207.584 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T17:36:55.361Z,1618940215.361 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210420T142139/Courier0079.lzma
2021-04-20T17:36:56.364Z,1618940216.364 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0079.lzma.bak
2021-04-20T17:36:56.364Z,1618940216.364 [DataOverHttps](INFO): SBD MOMSN=15590888
2021-04-20T17:37:12.246Z,1618940232.246 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20210420T142139/Express0080.lzma
2021-04-20T17:37:13.248Z,1618940233.248 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0080.lzma.bak
2021-04-20T17:37:13.248Z,1618940233.248 [DataOverHttps](INFO): SBD MOMSN=15590896
2021-04-20T17:37:14.305Z,1618940234.305 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T17:37:14.305Z,1618940234.305 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T17:37:14.305Z,1618940234.305 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T17:37:15.881Z,1618940235.881 [NAL9602](INFO): SBD MO Status=2, MOMSN=2677, MT Status=2, MTMSN=0
2021-04-20T17:37:15.881Z,1618940235.881 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-20T17:37:37.697Z,1618940257.697 [NAL9602](INFO): SBD MO Status=2, MOMSN=2677, MT Status=2, MTMSN=0
2021-04-20T17:37:37.697Z,1618940257.697 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-20T17:37:49.413Z,1618940269.413 [NAL9602](INFO): SBD MO Status=0, MOMSN=2677, MT Status=0, MTMSN=0
2021-04-20T17:37:49.413Z,1618940269.413 [NAL9602](INFO): No messages in MT queue
2021-04-20T17:38:20.134Z,1618940300.134 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-20T17:38:55.684Z,1618940335.684 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2021-04-20T17:38:55.684Z,1618940335.684 [DVL_micro](ERROR): Failed to parse:
:TS,000000,38,0000.0,10
2021-04-20T17:42:14.958Z,1618940534.958 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T17:42:14.958Z,1618940534.958 [Default:CheckIn:C.Wait] Stopped
2021-04-20T17:42:14.958Z,1618940534.958 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T17:42:14.959Z,1618940534.959 [Default:CheckIn:D] Running Loop=1
2021-04-20T17:42:15.359Z,1618940535.359 [Default:CheckIn:D] Stopped
2021-04-20T17:42:15.359Z,1618940535.359 [Default:CheckIn:E] Running Loop=1
2021-04-20T17:42:15.771Z,1618940535.771 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 197.648568 min
2021-04-20T17:42:15.771Z,1618940535.771 [Default:CheckIn:E] Stopped
2021-04-20T17:42:15.771Z,1618940535.771 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T17:42:15.771Z,1618940535.771 [Default:CheckIn] Stopped
2021-04-20T17:42:15.771Z,1618940535.771 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T17:42:15.772Z,1618940535.772 [Default:CheckIn](INFO): Running loop #26
2021-04-20T17:42:15.772Z,1618940535.772 [Default:CheckIn] Running Loop=26
2021-04-20T17:42:15.772Z,1618940535.772 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T17:42:15.772Z,1618940535.772 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T17:42:17.759Z,1618940537.759 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174217.00,A,3648.13854,N,12147.20658,W,0.078,163.90,200421,,,D*72
2021-04-20T17:42:17.761Z,1618940537.761 [NAL9602](INFO): GPS fix at 20210420T174217: (36.802309, -121.786776)
2021-04-20T17:42:17.797Z,1618940537.797 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T17:42:17.797Z,1618940537.797 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T17:42:25.633Z,1618940545.633 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210420T142139/Courier0082.lzma
2021-04-20T17:42:26.636Z,1618940546.636 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0082.lzma.bak
2021-04-20T17:42:26.636Z,1618940546.636 [DataOverHttps](INFO): SBD MOMSN=15590917
2021-04-20T17:42:42.498Z,1618940562.498 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210420T142139/Express0083.lzma
2021-04-20T17:42:43.500Z,1618940563.500 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0083.lzma.bak
2021-04-20T17:42:43.500Z,1618940563.500 [DataOverHttps](INFO): SBD MOMSN=15590922
2021-04-20T17:42:44.870Z,1618940564.870 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T17:42:44.870Z,1618940564.870 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T17:42:44.870Z,1618940564.870 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T17:44:10.925Z,1618940650.925 [DVL_micro](ERROR): only read 2 of 4 data items
2021-04-20T17:44:10.925Z,1618940650.925 [DVL_micro](ERROR): Failed to parse:
:RD,+99999.99,+99999.99
2021-04-20T17:44:24.629Z,1618940664.629 [NAL9602](INFO): SBD MO Status=2, MOMSN=2678, MT Status=2, MTMSN=0
2021-04-20T17:44:24.629Z,1618940664.629 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-20T17:44:34.725Z,1618940674.725 [NAL9602](INFO): SBD MO Status=0, MOMSN=2678, MT Status=0, MTMSN=0
2021-04-20T17:44:34.725Z,1618940674.725 [NAL9602](INFO): No messages in MT queue
2021-04-20T17:45:05.431Z,1618940705.431 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-20T17:47:45.442Z,1618940865.442 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T17:47:45.442Z,1618940865.442 [Default:CheckIn:C.Wait] Stopped
2021-04-20T17:47:45.442Z,1618940865.442 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T17:47:45.442Z,1618940865.442 [Default:CheckIn:D] Running Loop=1
2021-04-20T17:47:45.829Z,1618940865.829 [Default:CheckIn:D] Stopped
2021-04-20T17:47:45.830Z,1618940865.830 [Default:CheckIn:E] Running Loop=1
2021-04-20T17:47:46.236Z,1618940866.236 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 203.156413 min
2021-04-20T17:47:46.236Z,1618940866.236 [Default:CheckIn:E] Stopped
2021-04-20T17:47:46.236Z,1618940866.236 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T17:47:46.236Z,1618940866.236 [Default:CheckIn] Stopped
2021-04-20T17:47:46.236Z,1618940866.236 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T17:47:46.236Z,1618940866.236 [Default:CheckIn](INFO): Running loop #27
2021-04-20T17:47:46.236Z,1618940866.236 [Default:CheckIn] Running Loop=27
2021-04-20T17:47:46.237Z,1618940866.237 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T17:47:46.237Z,1618940866.237 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T17:47:48.245Z,1618940868.245 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174748.00,A,3648.13856,N,12147.20564,W,0.097,163.90,200421,,,D*72
2021-04-20T17:47:48.248Z,1618940868.248 [NAL9602](INFO): GPS fix at 20210420T174748: (36.802309, -121.786761)
2021-04-20T17:47:48.283Z,1618940868.283 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T17:47:48.283Z,1618940868.283 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T17:47:55.489Z,1618940875.489 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210420T142139/Courier0085.lzma
2021-04-20T17:47:56.492Z,1618940876.492 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0085.lzma.bak
2021-04-20T17:47:56.492Z,1618940876.492 [DataOverHttps](INFO): SBD MOMSN=15590939
2021-04-20T17:48:17.066Z,1618940897.066 [NAL9602](INFO): SBD MO Status=2, MOMSN=2679, MT Status=2, MTMSN=0
2021-04-20T17:48:17.067Z,1618940897.067 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-20T17:48:17.826Z,1618940897.826 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20210420T142139/Express0086.lzma
2021-04-20T17:48:18.828Z,1618940898.828 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0086.lzma.bak
2021-04-20T17:48:18.828Z,1618940898.828 [DataOverHttps](INFO): SBD MOMSN=15590945
2021-04-20T17:48:19.904Z,1618940899.904 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T17:48:19.904Z,1618940899.904 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T17:48:19.905Z,1618940899.905 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T17:49:09.179Z,1618940949.179 [NAL9602](INFO): SBD MO Status=2, MOMSN=2679, MT Status=2, MTMSN=0
2021-04-20T17:49:09.179Z,1618940949.179 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-20T17:49:41.510Z,1618940981.510 [NAL9602](INFO): SBD MO Status=2, MOMSN=2679, MT Status=2, MTMSN=0
2021-04-20T17:49:41.511Z,1618940981.511 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-20T17:50:17.521Z,1618941017.521 [NAL9602](INFO): SBD MO Status=2, MOMSN=2679, MT Status=2, MTMSN=0
2021-04-20T17:50:17.521Z,1618941017.521 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-20T17:50:59.545Z,1618941059.545 [NAL9602](INFO): SBD MO Status=2, MOMSN=2679, MT Status=2, MTMSN=0
2021-04-20T17:50:59.545Z,1618941059.545 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-20T17:52:03.343Z,1618941123.343 [DataOverHttps](IMPORTANT): SBD MTMSN=20210420T175203
2021-04-20T17:52:14.457Z,1618941134.457 [DataOverHttps](INFO): Received command:ibit
2021-04-20T17:52:14.510Z,1618941134.510 [CommandLine](IMPORTANT): got command ibit
2021-04-20T17:52:14.848Z,1618941134.848 [IBIT](IMPORTANT): Beginning Initiated BIT
2021-04-20T17:52:14.848Z,1618941134.848 [IBIT](IMPORTANT): Beginning control surface checks.
2021-04-20T17:52:14.856Z,1618941134.856 [CBIT](IMPORTANT): Beginning ground fault scan
2021-04-20T17:52:26.199Z,1618941146.199 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.004155
CHAN A1 (24V): -0.002298
CHAN A2 (12V): -0.000534
CHAN A3 (5V): 0.000157
CHAN B0 (3.3V): 0.001013
CHAN B1 (3.15aV): 0.000642
CHAN B2 (3.15bV): 0.000700
CHAN B3 (GND): 0.000410
OPEN: 0.004199
Full Scale Calc: 4.765 mA, -1.589 mA
2021-04-20T17:52:50.881Z,1618941170.881 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-04-20T17:52:52.025Z,1618941172.025 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175252.00,A,3648.13884,N,12147.20491,W,0.078,163.90,200421,,,A*7D
2021-04-20T17:52:52.028Z,1618941172.028 [NAL9602](INFO): GPS fix at 20210420T175252: (36.802314, -121.786749)
2021-04-20T17:52:55.243Z,1618941175.243 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175255.00,A,3648.13865,N,12147.20495,W,0.117,163.90,200421,,,A*79
2021-04-20T17:52:55.245Z,1618941175.245 [NAL9602](INFO): GPS fix at 20210420T175255: (36.802311, -121.786749)
2021-04-20T17:52:58.469Z,1618941178.469 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175258.00,A,3648.13843,N,12147.20493,W,0.058,163.90,200421,,,A*7C
2021-04-20T17:52:58.471Z,1618941178.471 [NAL9602](INFO): GPS fix at 20210420T175258: (36.802307, -121.786749)
2021-04-20T17:53:01.301Z,1618941181.301 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175301.00,A,3648.13819,N,12147.20501,W,0.019,163.90,200421,,,A*71
2021-04-20T17:53:01.304Z,1618941181.304 [NAL9602](INFO): GPS fix at 20210420T175301: (36.802303, -121.786750)
2021-04-20T17:53:04.591Z,1618941184.591 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175304.00,A,3648.13805,N,12147.20525,W,0.039,163.90,200421,,,A*7D
2021-04-20T17:53:04.593Z,1618941184.593 [NAL9602](INFO): GPS fix at 20210420T175304: (36.802301, -121.786754)
2021-04-20T17:53:07.365Z,1618941187.365 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175307.00,A,3648.13801,N,12147.20555,W,0.136,163.90,200421,,,A*73
2021-04-20T17:53:07.367Z,1618941187.367 [NAL9602](INFO): GPS fix at 20210420T175307: (36.802300, -121.786759)
2021-04-20T17:53:10.201Z,1618941190.201 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175310.00,A,3648.13802,N,12147.20574,W,0.097,163.90,200421,,,A*7F
2021-04-20T17:53:10.203Z,1618941190.203 [NAL9602](INFO): GPS fix at 20210420T175310: (36.802300, -121.786762)
2021-04-20T17:53:13.417Z,1618941193.417 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175313.00,A,3648.13804,N,12147.20577,W,0.156,163.90,200421,,,A*75
2021-04-20T17:53:13.420Z,1618941193.420 [NAL9602](INFO): GPS fix at 20210420T175313: (36.802301, -121.786763)
2021-04-20T17:53:16.255Z,1618941196.255 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175316.00,A,3648.13802,N,12147.20581,W,0.097,163.90,200421,,,A*73
2021-04-20T17:53:16.257Z,1618941196.257 [NAL9602](INFO): GPS fix at 20210420T175316: (36.802300, -121.786764)
2021-04-20T17:53:19.197Z,1618941199.197 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175319.00,A,3648.13792,N,12147.20557,W,0.039,163.90,200421,,,A*75
2021-04-20T17:53:19.203Z,1618941199.203 [NAL9602](INFO): GPS fix at 20210420T175319: (36.802299, -121.786760)
2021-04-20T17:53:22.329Z,1618941202.329 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175322.00,A,3648.13786,N,12147.20544,W,0.058,163.90,200421,,,A*7D
2021-04-20T17:53:22.332Z,1618941202.332 [NAL9602](INFO): GPS fix at 20210420T175322: (36.802298, -121.786757)
2021-04-20T17:53:25.153Z,1618941205.153 [BPC1](ERROR): Battery stick #6 (s/n: 00CA) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2021-04-20T17:53:25.155Z,1618941205.155 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6.
2021-04-20T17:53:25.157Z,1618941205.157 [BPC1](INFO): Received data from all battery sticks.
2021-04-20T17:53:25.227Z,1618941205.227 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175325.00,A,3648.13788,N,12147.20540,W,0.000,163.90,200421,,,A*7D
2021-04-20T17:53:25.229Z,1618941205.229 [NAL9602](INFO): GPS fix at 20210420T175325: (36.802298, -121.786757)
2021-04-20T17:53:28.389Z,1618941208.389 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175328.00,A,3648.13791,N,12147.20529,W,0.058,163.90,200421,,,A*7A
2021-04-20T17:53:28.400Z,1618941208.400 [NAL9602](INFO): GPS fix at 20210420T175328: (36.802298, -121.786755)
2021-04-20T17:53:31.215Z,1618941211.215 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175331.00,A,3648.13796,N,12147.20525,W,0.019,163.90,200421,,,A*7C
2021-04-20T17:53:31.217Z,1618941211.217 [NAL9602](INFO): GPS fix at 20210420T175331: (36.802299, -121.786754)
2021-04-20T17:53:34.445Z,1618941214.445 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175334.00,A,3648.13802,N,12147.20540,W,0.000,163.90,200421,,,A*70
2021-04-20T17:53:34.447Z,1618941214.447 [NAL9602](INFO): GPS fix at 20210420T175334: (36.802300, -121.786757)
2021-04-20T17:53:37.274Z,1618941217.274 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175337.00,A,3648.13813,N,12147.20572,W,0.097,163.90,200421,,,D*79
2021-04-20T17:53:37.276Z,1618941217.276 [NAL9602](INFO): GPS fix at 20210420T175337: (36.802302, -121.786762)
2021-04-20T17:53:40.517Z,1618941220.517 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175340.00,A,3648.13810,N,12147.20591,W,0.039,163.90,200421,,,D*73
2021-04-20T17:53:40.519Z,1618941220.519 [NAL9602](INFO): GPS fix at 20210420T175340: (36.802302, -121.786765)
2021-04-20T17:53:43.342Z,1618941223.342 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175343.00,A,3648.13807,N,12147.20609,W,0.019,163.90,200421,,,D*76
2021-04-20T17:53:43.344Z,1618941223.344 [NAL9602](INFO): GPS fix at 20210420T175343: (36.802301, -121.786768)
2021-04-20T17:53:46.165Z,1618941226.165 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175346.00,A,3648.13814,N,12147.20614,W,0.058,163.90,200421,,,D*78
2021-04-20T17:53:46.168Z,1618941226.168 [NAL9602](INFO): GPS fix at 20210420T175346: (36.802302, -121.786769)
2021-04-20T17:53:49.392Z,1618941229.392 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175349.00,A,3648.13814,N,12147.20618,W,0.058,163.90,200421,,,D*7B
2021-04-20T17:53:49.395Z,1618941229.395 [NAL9602](INFO): GPS fix at 20210420T175349: (36.802302, -121.786770)
2021-04-20T17:53:52.219Z,1618941232.219 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175352.00,A,3648.13811,N,12147.20626,W,0.058,163.90,200421,,,D*79
2021-04-20T17:53:52.221Z,1618941232.221 [NAL9602](INFO): GPS fix at 20210420T175352: (36.802302, -121.786771)
2021-04-20T17:53:55.454Z,1618941235.454 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175355.00,A,3648.13819,N,12147.20615,W,0.039,163.90,200421,,,D*71
2021-04-20T17:53:55.456Z,1618941235.456 [NAL9602](INFO): GPS fix at 20210420T175355: (36.802303, -121.786769)
2021-04-20T17:53:58.295Z,1618941238.295 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175358.00,A,3648.13821,N,12147.20601,W,0.039,163.90,200421,,,D*72
2021-04-20T17:53:58.297Z,1618941238.297 [NAL9602](INFO): GPS fix at 20210420T175358: (36.802304, -121.786767)
2021-04-20T17:54:01.514Z,1618941241.514 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175401.00,A,3648.13809,N,12147.20597,W,0.039,163.90,200421,,,A*7A
2021-04-20T17:54:01.516Z,1618941241.516 [NAL9602](INFO): GPS fix at 20210420T175401: (36.802301, -121.786766)
2021-04-20T17:54:04.347Z,1618941244.347 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175404.00,A,3648.13808,N,12147.20591,W,0.019,163.90,200421,,,A*7A
2021-04-20T17:54:04.349Z,1618941244.349 [NAL9602](INFO): GPS fix at 20210420T175404: (36.802301, -121.786765)
2021-04-20T17:54:05.588Z,1618941245.588 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2021-04-20T17:54:06.055Z,1618941246.055 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.532000
2021-04-20T17:54:06.055Z,1618941246.055 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2021-04-20T17:54:06.056Z,1618941246.056 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2021-04-20T17:54:06.437Z,1618941246.437 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2021-04-20T17:54:06.437Z,1618941246.437 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2021-04-20T17:54:06.437Z,1618941246.437 [IBIT](IMPORTANT): Pressure:8.201329 PSI
2021-04-20T17:54:06.438Z,1618941246.438 [IBIT](IMPORTANT): Humidity:14.204616 %
2021-04-20T17:54:06.812Z,1618941246.812 [IBIT](IMPORTANT): Vehicle Pitch:-0.413400 degrees
2021-04-20T17:54:06.812Z,1618941246.812 [IBIT](IMPORTANT): Vehicle Roll:19.288214 degrees
2021-04-20T17:54:06.813Z,1618941246.813 [IBIT](IMPORTANT): Vehicle Heading:208.854782 degrees
2021-04-20T17:54:07.169Z,1618941247.169 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175407.00,A,3648.13808,N,12147.20567,W,0.058,163.90,200421,,,A*75
2021-04-20T17:54:07.171Z,1618941247.171 [NAL9602](INFO): GPS fix at 20210420T175407: (36.802301, -121.786761)
2021-04-20T17:54:07.196Z,1618941247.196 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2021-04-20T17:54:07.196Z,1618941247.196 [IBIT](IMPORTANT): buoyancyNeutral: 214.815567 cc
2021-04-20T17:54:07.197Z,1618941247.197 [IBIT](IMPORTANT): massDefault: -0.100000 cm
2021-04-20T17:54:07.197Z,1618941247.197 [IBIT](IMPORTANT): stopDepth: 265.000000 m
2021-04-20T17:54:07.197Z,1618941247.197 [IBIT](IMPORTANT): abortDepth: 300.000000 m
2021-04-20T17:54:07.197Z,1618941247.197 [IBIT](IMPORTANT): IBIT FAILED
2021-04-20T17:54:07.618Z,1618941247.618 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T17:54:07.619Z,1618941247.619 [Default:CheckIn:C.Wait] Stopped
2021-04-20T17:54:07.619Z,1618941247.619 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T17:54:07.619Z,1618941247.619 [Default:CheckIn:D] Running Loop=1
2021-04-20T17:54:07.991Z,1618941247.991 [Default:CheckIn:D] Stopped
2021-04-20T17:54:07.991Z,1618941247.991 [Default:CheckIn:E] Running Loop=1
2021-04-20T17:54:08.436Z,1618941248.436 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 209.525765 min
2021-04-20T17:54:08.436Z,1618941248.436 [Default:CheckIn:E] Stopped
2021-04-20T17:54:08.436Z,1618941248.436 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T17:54:08.436Z,1618941248.436 [Default:CheckIn] Stopped
2021-04-20T17:54:08.436Z,1618941248.436 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T17:54:08.437Z,1618941248.437 [Default:CheckIn](INFO): Running loop #28
2021-04-20T17:54:08.437Z,1618941248.437 [Default:CheckIn] Running Loop=28
2021-04-20T17:54:08.437Z,1618941248.437 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T17:54:08.437Z,1618941248.437 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T17:54:09.789Z,1618941249.789 [CommandLine](IMPORTANT): got command failComponent
2021-04-20T17:54:09.789Z,1618941249.789 [CommandLine](IMPORTANT): Failed components:
2021-04-20T17:54:09.789Z,1618941249.789 [CommandLine](IMPORTANT): No failed Components.
2021-04-20T17:54:10.401Z,1618941250.401 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175410.00,A,3648.13800,N,12147.20541,W,0.078,163.90,200421,,,A*7D
2021-04-20T17:54:10.416Z,1618941250.416 [NAL9602](INFO): GPS fix at 20210420T175410: (36.802300, -121.786757)
2021-04-20T17:54:10.431Z,1618941250.431 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T17:54:10.431Z,1618941250.431 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T17:54:21.325Z,1618941261.325 [DataOverHttps](INFO): Sending 84 bytes from file Logs/20210420T142139/Courier0088.lzma
2021-04-20T17:54:22.329Z,1618941262.329 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0088.lzma.bak
2021-04-20T17:54:22.329Z,1618941262.329 [DataOverHttps](INFO): SBD MOMSN=15590970
2021-04-20T17:54:38.293Z,1618941278.293 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210420T142139/Courier0091.lzma
2021-04-20T17:54:39.297Z,1618941279.297 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0091.lzma.bak
2021-04-20T17:54:39.297Z,1618941279.297 [DataOverHttps](INFO): SBD MOMSN=15590973
2021-04-20T17:54:42.807Z,1618941282.807 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-20T17:54:51.808Z,1618941291.808 [CommandLine](IMPORTANT): got command ibit
2021-04-20T17:54:52.128Z,1618941292.128 [IBIT](IMPORTANT): Beginning Initiated BIT
2021-04-20T17:54:52.128Z,1618941292.128 [IBIT](IMPORTANT): Beginning control surface checks.
2021-04-20T17:54:52.156Z,1618941292.156 [CBIT](IMPORTANT): Beginning ground fault scan
2021-04-20T17:54:53.729Z,1618941293.729 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175453.00,A,3648.13811,N,12147.20431,W,0.136,163.90,200421,,,D*72
2021-04-20T17:54:53.732Z,1618941293.732 [NAL9602](INFO): GPS fix at 20210420T175453: (36.802302, -121.786738)
2021-04-20T17:54:54.119Z,1618941294.119 [CommandLine](IMPORTANT): got command failComponent
2021-04-20T17:54:54.120Z,1618941294.120 [CommandLine](IMPORTANT): Failed components:
2021-04-20T17:54:54.120Z,1618941294.120 [CommandLine](IMPORTANT): No failed Components.
2021-04-20T17:54:55.512Z,1618941295.512 [DataOverHttps](INFO): Sending 863 bytes from file Logs/20210420T142139/Express0089.lzma
2021-04-20T17:54:56.512Z,1618941296.512 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0089.lzma.bak
2021-04-20T17:54:56.512Z,1618941296.512 [DataOverHttps](INFO): SBD MOMSN=15590975
2021-04-20T17:55:03.086Z,1618941303.086 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.005201
CHAN A1 (24V): -0.002214
CHAN A2 (12V): -0.000198
CHAN A3 (5V): 0.000008
CHAN B0 (3.3V): 0.000343
CHAN B1 (3.15aV): 0.000698
CHAN B2 (3.15bV): 0.000225
CHAN B3 (GND): 0.000449
OPEN: 0.004270
Full Scale Calc: 4.765 mA, -1.589 mA
2021-04-20T17:55:12.829Z,1618941312.829 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20210420T142139/Express0092.lzma
2021-04-20T17:55:13.832Z,1618941313.832 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0092.lzma.bak
2021-04-20T17:55:13.832Z,1618941313.832 [DataOverHttps](INFO): SBD MOMSN=15591005
2021-04-20T17:55:24.425Z,1618941324.425 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-04-20T17:55:24.506Z,1618941324.506 [NAL9602](ERROR): received:
+CSQ:0
OK79, 2, 0, 0, 0
OK
2021-04-20T17:55:38.597Z,1618941338.597 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 5
Latitude: 36.802303 Longitude: -121.786736
2021-04-20T17:55:38.983Z,1618941338.983 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.532000
2021-04-20T17:55:38.984Z,1618941338.984 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2021-04-20T17:55:38.984Z,1618941338.984 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2021-04-20T17:55:39.410Z,1618941339.410 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2021-04-20T17:55:39.411Z,1618941339.411 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2021-04-20T17:55:39.411Z,1618941339.411 [IBIT](IMPORTANT): Pressure:8.230090 PSI
2021-04-20T17:55:39.411Z,1618941339.411 [IBIT](IMPORTANT): Humidity:14.210719 %
2021-04-20T17:55:39.795Z,1618941339.795 [IBIT](IMPORTANT): Vehicle Pitch:-0.408901 degrees
2021-04-20T17:55:39.796Z,1618941339.796 [IBIT](IMPORTANT): Vehicle Roll:19.034603 degrees
2021-04-20T17:55:39.796Z,1618941339.796 [IBIT](IMPORTANT): Vehicle Heading:209.480652 degrees
2021-04-20T17:55:40.194Z,1618941340.194 [NAL9602](INFO): SBD MO Status=0, MOMSN=2679, MT Status=0, MTMSN=0
2021-04-20T17:55:40.194Z,1618941340.194 [NAL9602](INFO): No messages in MT queue
2021-04-20T17:55:40.210Z,1618941340.210 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2021-04-20T17:55:40.210Z,1618941340.210 [IBIT](IMPORTANT): buoyancyNeutral: 214.815567 cc
2021-04-20T17:55:40.210Z,1618941340.210 [IBIT](IMPORTANT): massDefault: -0.100000 cm
2021-04-20T17:55:40.211Z,1618941340.211 [IBIT](IMPORTANT): stopDepth: 265.000000 m
2021-04-20T17:55:40.211Z,1618941340.211 [IBIT](IMPORTANT): abortDepth: 300.000000 m
2021-04-20T17:55:40.211Z,1618941340.211 [IBIT](IMPORTANT): IBIT PASSED
2021-04-20T17:55:40.599Z,1618941340.599 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T17:55:40.599Z,1618941340.599 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T17:55:40.599Z,1618941340.599 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T17:56:10.879Z,1618941370.879 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-20T18:00:41.242Z,1618941641.242 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T18:00:41.243Z,1618941641.243 [Default:CheckIn:C.Wait] Stopped
2021-04-20T18:00:41.243Z,1618941641.243 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T18:00:41.243Z,1618941641.243 [Default:CheckIn:D] Running Loop=1
2021-04-20T18:00:41.638Z,1618941641.638 [Default:CheckIn:D] Stopped
2021-04-20T18:00:41.638Z,1618941641.638 [Default:CheckIn:E] Running Loop=1
2021-04-20T18:00:42.046Z,1618941642.046 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 216.086540 min
2021-04-20T18:00:42.046Z,1618941642.046 [Default:CheckIn:E] Stopped
2021-04-20T18:00:42.046Z,1618941642.046 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T18:00:42.046Z,1618941642.046 [Default:CheckIn] Stopped
2021-04-20T18:00:42.046Z,1618941642.046 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T18:00:42.047Z,1618941642.047 [Default:CheckIn](INFO): Running loop #29
2021-04-20T18:00:42.047Z,1618941642.047 [Default:CheckIn] Running Loop=29
2021-04-20T18:00:42.047Z,1618941642.047 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T18:00:42.047Z,1618941642.047 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T18:00:44.061Z,1618941644.061 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180044.00,A,3648.13777,N,12147.20423,W,0.058,0.00,200421,,,A*77
2021-04-20T18:00:44.063Z,1618941644.063 [NAL9602](INFO): GPS fix at 20210420T180044: (36.802296, -121.786737)
2021-04-20T18:00:44.074Z,1618941644.074 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T18:00:44.074Z,1618941644.074 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T18:00:51.209Z,1618941651.209 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210420T142139/Courier0094.lzma
2021-04-20T18:00:52.212Z,1618941652.212 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0094.lzma.bak
2021-04-20T18:00:52.212Z,1618941652.212 [DataOverHttps](INFO): SBD MOMSN=15591056
2021-04-20T18:01:08.179Z,1618941668.179 [DataOverHttps](INFO): Sending 790 bytes from file Logs/20210420T142139/Express0095.lzma
2021-04-20T18:01:09.180Z,1618941669.180 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0095.lzma.bak
2021-04-20T18:01:09.180Z,1618941669.180 [DataOverHttps](INFO): SBD MOMSN=15591082
2021-04-20T18:01:10.346Z,1618941670.346 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T18:01:10.346Z,1618941670.346 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T18:01:10.347Z,1618941670.347 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T18:01:23.261Z,1618941683.261 [DVL_micro](ERROR): only read 0 of 4 data items
2021-04-20T18:01:23.261Z,1618941683.261 [DVL_micro](ERROR): Failed to parse:
:RD,,+9999.99,+9999.99,+9999.99
2021-04-20T18:02:21.871Z,1618941741.871 [DVL_micro](ERROR): only read 3 of 4 data items
2021-04-20T18:02:21.871Z,1618941741.871 [DVL_micro](ERROR): Failed to parse:
:BI,-00307,-01420,+01666I
2021-04-20T18:02:32.745Z,1618941752.745 [NAL9602](INFO): SBD MO Status=0, MOMSN=2680, MT Status=0, MTMSN=0
2021-04-20T18:02:32.745Z,1618941752.745 [NAL9602](INFO): No messages in MT queue
2021-04-20T18:02:39.623Z,1618941759.623 [DVL_micro](ERROR): Failed to parse:
:SA,-00.82,+16.93,199.0
2021-04-20T18:03:03.451Z,1618941783.451 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-20T18:06:10.969Z,1618941970.969 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T18:06:10.969Z,1618941970.969 [Default:CheckIn:C.Wait] Stopped
2021-04-20T18:06:10.970Z,1618941970.970 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T18:06:10.974Z,1618941970.974 [Default:CheckIn:D] Running Loop=1
2021-04-20T18:06:11.429Z,1618941971.429 [Default:CheckIn:D] Stopped
2021-04-20T18:06:11.429Z,1618941971.429 [Default:CheckIn:E] Running Loop=1
2021-04-20T18:06:11.798Z,1618941971.798 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 221.583057 min
2021-04-20T18:06:11.798Z,1618941971.798 [Default:CheckIn:E] Stopped
2021-04-20T18:06:11.799Z,1618941971.799 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T18:06:11.799Z,1618941971.799 [Default:CheckIn] Stopped
2021-04-20T18:06:11.799Z,1618941971.799 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T18:06:11.799Z,1618941971.799 [Default:CheckIn](INFO): Running loop #30
2021-04-20T18:06:11.799Z,1618941971.799 [Default:CheckIn] Running Loop=30
2021-04-20T18:06:11.799Z,1618941971.799 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T18:06:11.799Z,1618941971.799 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T18:06:13.793Z,1618941973.793 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180613.00,A,3648.13724,N,12147.20285,W,0.019,0.00,200421,,,A*7A
2021-04-20T18:06:13.796Z,1618941973.796 [NAL9602](INFO): GPS fix at 20210420T180613: (36.802287, -121.786714)
2021-04-20T18:06:13.842Z,1618941973.842 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T18:06:13.842Z,1618941973.842 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T18:06:22.177Z,1618941982.177 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210420T142139/Courier0097.lzma
2021-04-20T18:06:23.180Z,1618941983.180 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0097.lzma.bak
2021-04-20T18:06:23.180Z,1618941983.180 [DataOverHttps](INFO): SBD MOMSN=15591145
2021-04-20T18:06:25.930Z,1618941985.930 [NAL9602](INFO): SBD MO Status=0, MOMSN=2681, MT Status=0, MTMSN=0
2021-04-20T18:06:25.930Z,1618941985.930 [NAL9602](INFO): No messages in MT queue
2021-04-20T18:06:38.923Z,1618941998.923 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20210420T142139/Express0098.lzma
2021-04-20T18:06:39.924Z,1618941999.924 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0098.lzma.bak
2021-04-20T18:06:39.924Z,1618941999.924 [DataOverHttps](INFO): SBD MOMSN=15591151
2021-04-20T18:06:41.292Z,1618942001.292 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T18:06:41.293Z,1618942001.293 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T18:06:41.293Z,1618942001.293 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T18:06:56.619Z,1618942016.619 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-20T18:07:57.239Z,1618942077.239 [DVL_micro](ERROR): Failed to parse:
:B,-01285,+01350,+00000,I
2021-04-20T18:08:35.617Z,1618942115.617 [DVL_micro](ERROR): only read 3 of 4 data items
2021-04-20T18:08:35.617Z,1618942115.617 [DVL_micro](ERROR): Failed to parse:
:BI,+0109,+01276,+00000,I
2021-04-20T18:10:40.057Z,1618942240.057 [DVL_micro](ERROR): Failed to parse:
:SA,-00.87,+15.07,350.2
2021-04-20T18:11:41.872Z,1618942301.872 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T18:11:41.872Z,1618942301.872 [Default:CheckIn:C.Wait] Stopped
2021-04-20T18:11:41.872Z,1618942301.872 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T18:11:41.873Z,1618942301.873 [Default:CheckIn:D] Running Loop=1
2021-04-20T18:11:42.270Z,1618942302.270 [Default:CheckIn:D] Stopped
2021-04-20T18:11:42.270Z,1618942302.270 [Default:CheckIn:E] Running Loop=1
2021-04-20T18:11:42.686Z,1618942302.686 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 227.097087 min
2021-04-20T18:11:42.686Z,1618942302.686 [Default:CheckIn:E] Stopped
2021-04-20T18:11:42.686Z,1618942302.686 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T18:11:42.686Z,1618942302.686 [Default:CheckIn] Stopped
2021-04-20T18:11:42.686Z,1618942302.686 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T18:11:42.687Z,1618942302.687 [Default:CheckIn](INFO): Running loop #31
2021-04-20T18:11:42.687Z,1618942302.687 [Default:CheckIn] Running Loop=31
2021-04-20T18:11:42.687Z,1618942302.687 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T18:11:42.687Z,1618942302.687 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T18:11:44.686Z,1618942304.686 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181144.00,A,3648.39168,N,12147.10884,W,4.529,4.10,200421,,,D*72
2021-04-20T18:11:44.688Z,1618942304.688 [NAL9602](INFO): GPS fix at 20210420T181144: (36.806528, -121.785147)
2021-04-20T18:11:44.706Z,1618942304.706 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T18:11:44.706Z,1618942304.706 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T18:11:52.544Z,1618942312.544 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210420T142139/Courier0100.lzma
2021-04-20T18:11:53.432Z,1618942313.432 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0100.lzma.bak
2021-04-20T18:11:53.432Z,1618942313.432 [DataOverHttps](INFO): SBD MOMSN=15591182
2021-04-20T18:12:12.190Z,1618942332.190 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210420T142139/Express0101.lzma
2021-04-20T18:12:13.192Z,1618942333.192 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0101.lzma.bak
2021-04-20T18:12:13.193Z,1618942333.193 [DataOverHttps](INFO): SBD MOMSN=15591186
2021-04-20T18:12:14.272Z,1618942334.272 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T18:12:14.272Z,1618942334.272 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T18:12:14.272Z,1618942334.272 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T18:12:31.269Z,1618942351.269 [NAL9602](INFO): SBD MO Status=2, MOMSN=2682, MT Status=2, MTMSN=0
2021-04-20T18:12:31.269Z,1618942351.269 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-20T18:13:20.162Z,1618942400.162 [NAL9602](INFO): SBD MO Status=0, MOMSN=2682, MT Status=0, MTMSN=0
2021-04-20T18:13:20.162Z,1618942400.162 [NAL9602](INFO): No messages in MT queue
2021-04-20T18:13:50.865Z,1618942430.865 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-20T18:15:55.340Z,1618942555.340 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2021-04-20T18:15:55.340Z,1618942555.340 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,00.0,1489.0,000
2021-04-20T18:17:14.945Z,1618942634.945 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T18:17:14.946Z,1618942634.946 [Default:CheckIn:C.Wait] Stopped
2021-04-20T18:17:14.946Z,1618942634.946 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T18:17:14.946Z,1618942634.946 [Default:CheckIn:D] Running Loop=1
2021-04-20T18:17:15.351Z,1618942635.351 [Default:CheckIn:D] Stopped
2021-04-20T18:17:15.351Z,1618942635.351 [Default:CheckIn:E] Running Loop=1
2021-04-20T18:17:15.761Z,1618942635.761 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 232.648438 min
2021-04-20T18:17:15.761Z,1618942635.761 [Default:CheckIn:E] Stopped
2021-04-20T18:17:15.761Z,1618942635.761 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T18:17:15.761Z,1618942635.761 [Default:CheckIn] Stopped
2021-04-20T18:17:15.761Z,1618942635.761 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T18:17:15.762Z,1618942635.762 [Default:CheckIn](INFO): Running loop #32
2021-04-20T18:17:15.762Z,1618942635.762 [Default:CheckIn] Running Loop=32
2021-04-20T18:17:15.762Z,1618942635.762 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T18:17:15.762Z,1618942635.762 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T18:17:17.765Z,1618942637.765 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181717.00,A,3648.34418,N,12147.74478,W,4.724,250.93,200421,,,D*77
2021-04-20T18:17:17.767Z,1618942637.767 [NAL9602](INFO): GPS fix at 20210420T181717: (36.805736, -121.795746)
2021-04-20T18:17:17.778Z,1618942637.778 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T18:17:17.778Z,1618942637.778 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T18:17:24.773Z,1618942644.773 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210420T142139/Courier0103.lzma
2021-04-20T18:17:25.776Z,1618942645.776 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0103.lzma.bak
2021-04-20T18:17:25.776Z,1618942645.776 [DataOverHttps](INFO): SBD MOMSN=15591213
2021-04-20T18:17:40.793Z,1618942660.793 [NAL9602](INFO): SBD MO Status=0, MOMSN=2683, MT Status=0, MTMSN=0
2021-04-20T18:17:40.793Z,1618942660.793 [NAL9602](INFO): No messages in MT queue
2021-04-20T18:17:41.806Z,1618942661.806 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20210420T142139/Express0104.lzma
2021-04-20T18:17:42.808Z,1618942662.808 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0104.lzma.bak
2021-04-20T18:17:42.808Z,1618942662.808 [DataOverHttps](INFO): SBD MOMSN=15591216
2021-04-20T18:17:44.033Z,1618942664.033 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T18:17:44.033Z,1618942664.033 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T18:17:44.034Z,1618942664.034 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T18:18:11.497Z,1618942691.497 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-20T18:18:35.337Z,1618942715.337 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2021-04-20T18:18:35.337Z,1618942715.337 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+22.2,0000.0,1489.WI,+01198,-00343,+01538,+00000,A
2021-04-20T18:22:44.683Z,1618942964.683 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T18:22:44.683Z,1618942964.683 [Default:CheckIn:C.Wait] Stopped
2021-04-20T18:22:44.683Z,1618942964.683 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T18:22:44.683Z,1618942964.683 [Default:CheckIn:D] Running Loop=1
2021-04-20T18:22:45.082Z,1618942965.082 [Default:CheckIn:D] Stopped
2021-04-20T18:22:45.083Z,1618942965.083 [Default:CheckIn:E] Running Loop=1
2021-04-20T18:22:45.505Z,1618942965.505 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 238.143962 min
2021-04-20T18:22:45.505Z,1618942965.505 [Default:CheckIn:E] Stopped
2021-04-20T18:22:45.506Z,1618942965.506 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T18:22:45.506Z,1618942965.506 [Default:CheckIn] Stopped
2021-04-20T18:22:45.506Z,1618942965.506 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T18:22:45.506Z,1618942965.506 [Default:CheckIn](INFO): Running loop #33
2021-04-20T18:22:45.506Z,1618942965.506 [Default:CheckIn] Running Loop=33
2021-04-20T18:22:45.506Z,1618942965.506 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T18:22:45.506Z,1618942965.506 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T18:22:47.487Z,1618942967.487 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182247.00,A,3648.32384,N,12148.28095,W,8.670,266.77,200421,,,A*77
2021-04-20T18:22:47.489Z,1618942967.489 [NAL9602](INFO): GPS fix at 20210420T182247: (36.805397, -121.804682)
2021-04-20T18:22:47.500Z,1618942967.500 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T18:22:47.500Z,1618942967.500 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T18:22:54.822Z,1618942974.822 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210420T142139/Courier0106.lzma
2021-04-20T18:22:55.824Z,1618942975.824 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0106.lzma.bak
2021-04-20T18:22:55.824Z,1618942975.824 [DataOverHttps](INFO): SBD MOMSN=15591224
2021-04-20T18:23:08.909Z,1618942988.909 [NAL9602](INFO): SBD MO Status=0, MOMSN=2684, MT Status=0, MTMSN=0
2021-04-20T18:23:08.909Z,1618942988.909 [NAL9602](INFO): No messages in MT queue
2021-04-20T18:23:11.766Z,1618942991.766 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20210420T142139/Express0107.lzma
2021-04-20T18:23:12.768Z,1618942992.768 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0107.lzma.bak
2021-04-20T18:23:12.769Z,1618942992.769 [DataOverHttps](INFO): SBD MOMSN=15591230
2021-04-20T18:23:14.167Z,1618942994.167 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T18:23:14.167Z,1618942994.167 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T18:23:14.167Z,1618942994.167 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T18:23:39.615Z,1618943019.615 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-20T18:28:14.891Z,1618943294.891 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T18:28:14.891Z,1618943294.891 [Default:CheckIn:C.Wait] Stopped
2021-04-20T18:28:14.891Z,1618943294.891 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T18:28:14.891Z,1618943294.891 [Default:CheckIn:D] Running Loop=1
2021-04-20T18:28:15.280Z,1618943295.280 [Default:CheckIn:D] Stopped
2021-04-20T18:28:15.280Z,1618943295.280 [Default:CheckIn:E] Running Loop=1
2021-04-20T18:28:15.684Z,1618943295.684 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 243.647249 min
2021-04-20T18:28:15.684Z,1618943295.684 [Default:CheckIn:E] Stopped
2021-04-20T18:28:15.684Z,1618943295.684 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T18:28:15.684Z,1618943295.684 [Default:CheckIn] Stopped
2021-04-20T18:28:15.685Z,1618943295.685 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T18:28:15.685Z,1618943295.685 [Default:CheckIn](INFO): Running loop #34
2021-04-20T18:28:15.685Z,1618943295.685 [Default:CheckIn] Running Loop=34
2021-04-20T18:28:15.685Z,1618943295.685 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T18:28:15.685Z,1618943295.685 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T18:28:17.682Z,1618943297.682 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182817.00,A,3648.23390,N,12149.10157,W,6.065,251.09,200421,,,A*79
2021-04-20T18:28:17.684Z,1618943297.684 [NAL9602](INFO): GPS fix at 20210420T182817: (36.803898, -121.818359)
2021-04-20T18:28:17.732Z,1618943297.732 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T18:28:17.732Z,1618943297.732 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T18:28:27.857Z,1618943307.857 [NAL9602](INFO): SBD MO Status=0, MOMSN=2685, MT Status=0, MTMSN=0
2021-04-20T18:28:27.857Z,1618943307.857 [NAL9602](INFO): No messages in MT queue
2021-04-20T18:28:39.933Z,1618943319.933 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210420T142139/Courier0109.lzma
2021-04-20T18:28:40.936Z,1618943320.936 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0109.lzma.bak
2021-04-20T18:28:40.936Z,1618943320.936 [DataOverHttps](INFO): SBD MOMSN=15591242
2021-04-20T18:28:57.834Z,1618943337.834 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20210420T142139/Express0110.lzma
2021-04-20T18:28:58.569Z,1618943338.569 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-20T18:28:59.840Z,1618943339.840 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0110.lzma.bak
2021-04-20T18:28:59.840Z,1618943339.840 [DataOverHttps](INFO): SBD MOMSN=15591249
2021-04-20T18:29:01.005Z,1618943341.005 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T18:29:01.005Z,1618943341.005 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T18:29:01.005Z,1618943341.005 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T18:30:20.258Z,1618943420.258 [DAT](INFO): unknown deviceResponse_: Acoustic Wakeup
2021-04-20T18:30:20.260Z,1618943420.260 [DAT](INFO): commRate: 800
2021-04-20T18:30:21.049Z,1618943421.049 [DAT](INFO): unknown deviceResponse_: Lowpower
2021-04-20T18:31:23.677Z,1618943483.677 [DVL_micro](ERROR): only read 3 of 4 data items
2021-04-20T18:31:23.677Z,1618943483.677 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,+99999.99
2021-04-20T18:33:40.338Z,1618943620.338 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting.
2021-04-20T18:33:42.347Z,1618943622.347 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.747627
2021-04-20T18:33:58.833Z,1618943638.833 [DVL_micro](ERROR): only read 3 of 4 data items
2021-04-20T18:33:58.833Z,1618943638.833 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.999,+9999.99,+9999.99
2021-04-20T18:34:01.690Z,1618943641.690 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T18:34:01.691Z,1618943641.691 [Default:CheckIn:C.Wait] Stopped
2021-04-20T18:34:01.691Z,1618943641.691 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T18:34:01.691Z,1618943641.691 [Default:CheckIn:D] Running Loop=1
2021-04-20T18:34:02.091Z,1618943642.091 [Default:CheckIn:D] Stopped
2021-04-20T18:34:02.091Z,1618943642.091 [Default:CheckIn:E] Running Loop=1
2021-04-20T18:34:02.494Z,1618943642.494 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 249.427425 min
2021-04-20T18:34:02.494Z,1618943642.494 [Default:CheckIn:E] Stopped
2021-04-20T18:34:02.494Z,1618943642.494 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T18:34:02.494Z,1618943642.494 [Default:CheckIn] Stopped
2021-04-20T18:34:02.495Z,1618943642.495 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T18:34:02.495Z,1618943642.495 [Default:CheckIn](INFO): Running loop #35
2021-04-20T18:34:02.495Z,1618943642.495 [Default:CheckIn] Running Loop=35
2021-04-20T18:34:02.495Z,1618943642.495 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T18:34:02.495Z,1618943642.495 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T18:34:04.489Z,1618943644.489 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183404.00,A,3648.19133,N,12149.84718,W,5.287,252.70,200421,,,A*74
2021-04-20T18:34:04.492Z,1618943644.492 [NAL9602](INFO): GPS fix at 20210420T183404: (36.803189, -121.830786)
2021-04-20T18:34:04.502Z,1618943644.502 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T18:34:04.502Z,1618943644.502 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T18:34:15.494Z,1618943655.494 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-04-20T18:34:17.869Z,1618943657.869 [NAL9602](INFO): SBD MO Status=1, MOMSN=2686, MT Status=0, MTMSN=0
2021-04-20T18:34:17.922Z,1618943657.922 [NAL9602](INFO): Sent 72 bytes from file Logs/20210420T142139/Courier0112.lzma
2021-04-20T18:34:17.922Z,1618943657.922 [NAL9602](INFO): Packets left to send: 0
2021-04-20T18:34:25.223Z,1618943665.223 [NAL9602](INFO): SBD MO Status=1, MOMSN=2687, MT Status=0, MTMSN=0
2021-04-20T18:34:25.279Z,1618943665.279 [NAL9602](INFO): Sent 142 bytes from file Logs/20210420T142139/Express0113.lzma
2021-04-20T18:34:25.279Z,1618943665.279 [NAL9602](INFO): Packets left to send: 0
2021-04-20T18:34:32.461Z,1618943672.461 [NAL9602](INFO): SBD MO Status=0, MOMSN=2688, MT Status=0, MTMSN=0
2021-04-20T18:34:32.549Z,1618943672.549 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T18:34:32.549Z,1618943672.549 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T18:34:32.550Z,1618943672.550 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T18:34:50.646Z,1618943690.646 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-04-20T18:35:03.161Z,1618943703.161 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-20T18:35:25.787Z,1618943725.787 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-04-20T18:36:00.942Z,1618943760.942 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-04-20T18:36:28.811Z,1618943788.811 [DVL_micro](ERROR): only read 3 of 4 data items
2021-04-20T18:36:28.811Z,1618943788.811 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+99999.99,+9999.99
2021-04-20T18:36:36.083Z,1618943796.083 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-04-20T18:36:51.694Z,1618943811.694 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003114
2021-04-20T18:38:59.101Z,1618943939.101 [DVL_micro](ERROR): only read 1 of 4 data items
2021-04-20T18:38:59.101Z,1618943939.101 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,,+9999.99,+9999.99
2021-04-20T18:39:33.045Z,1618943973.045 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T18:39:33.045Z,1618943973.045 [Default:CheckIn:C.Wait] Stopped
2021-04-20T18:39:33.045Z,1618943973.045 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T18:39:33.045Z,1618943973.045 [Default:CheckIn:D] Running Loop=1
2021-04-20T18:39:33.450Z,1618943973.450 [Default:CheckIn:D] Stopped
2021-04-20T18:39:33.450Z,1618943973.450 [Default:CheckIn:E] Running Loop=1
2021-04-20T18:39:33.858Z,1618943973.858 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 254.950081 min
2021-04-20T18:39:33.858Z,1618943973.858 [Default:CheckIn:E] Stopped
2021-04-20T18:39:33.858Z,1618943973.858 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T18:39:33.858Z,1618943973.858 [Default:CheckIn] Stopped
2021-04-20T18:39:33.858Z,1618943973.858 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T18:39:33.859Z,1618943973.859 [Default:CheckIn](INFO): Running loop #36
2021-04-20T18:39:33.859Z,1618943973.859 [Default:CheckIn] Running Loop=36
2021-04-20T18:39:33.859Z,1618943973.859 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T18:39:33.859Z,1618943973.859 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T18:39:35.866Z,1618943975.866 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183935.00,A,3648.04636,N,12150.50909,W,7.289,251.52,200421,,,A*75
2021-04-20T18:39:35.868Z,1618943975.868 [NAL9602](INFO): GPS fix at 20210420T183935: (36.800773, -121.841818)
2021-04-20T18:39:35.903Z,1618943975.903 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T18:39:35.903Z,1618943975.903 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T18:39:43.369Z,1618943983.369 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210420T142139/Courier0115.lzma
2021-04-20T18:39:44.373Z,1618943984.373 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0115.lzma.bak
2021-04-20T18:39:44.373Z,1618943984.373 [DataOverHttps](INFO): SBD MOMSN=15591280
2021-04-20T18:39:48.819Z,1618943988.819 [NAL9602](INFO): SBD MO Status=0, MOMSN=2689, MT Status=0, MTMSN=0
2021-04-20T18:39:48.819Z,1618943988.819 [NAL9602](INFO): No messages in MT queue
2021-04-20T18:40:09.066Z,1618944009.066 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20210420T142139/Express0116.lzma
2021-04-20T18:40:10.068Z,1618944010.068 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Express0116.lzma.bak
2021-04-20T18:40:10.068Z,1618944010.068 [DataOverHttps](INFO): SBD MOMSN=15591285
2021-04-20T18:40:11.126Z,1618944011.126 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T18:40:11.126Z,1618944011.126 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T18:40:11.126Z,1618944011.126 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T18:40:19.215Z,1618944019.215 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-20T18:41:33.970Z,1618944093.970 [DVL_micro](ERROR): Failed to parse:
:WI,+01021,-01098,+01161,+00000,A
2021-04-20T18:42:27.717Z,1618944147.717 [DVL_micro](ERROR): Failed to parse:
:BI,+00986,-01382,+01203,+00000,I
2021-04-20T18:42:31.710Z,1618944151.710 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.259174
2021-04-20T18:43:02.834Z,1618944182.834 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-04-20T18:43:37.974Z,1618944217.974 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-04-20T18:43:50.434Z,1618944230.434 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002751
2021-04-20T18:44:04.283Z,1618944244.283 [DVL_micro](ERROR): only read 2 of 4 data items
2021-04-20T18:44:04.283Z,1618944244.283 [DVL_micro](ERROR): Failed to parse:
:BI,+01614,-01057+00000,I
2021-04-20T18:45:11.760Z,1618944311.760 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T18:45:11.760Z,1618944311.760 [Default:CheckIn:C.Wait] Stopped
2021-04-20T18:45:11.760Z,1618944311.760 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T18:45:11.760Z,1618944311.760 [Default:CheckIn:D] Running Loop=1
2021-04-20T18:45:12.155Z,1618944312.155 [Default:CheckIn:D] Stopped
2021-04-20T18:45:12.155Z,1618944312.155 [Default:CheckIn:E] Running Loop=1
2021-04-20T18:45:12.558Z,1618944312.558 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 260.595150 min
2021-04-20T18:45:12.558Z,1618944312.558 [Default:CheckIn:E] Stopped
2021-04-20T18:45:12.558Z,1618944312.558 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T18:45:12.558Z,1618944312.558 [Default:CheckIn] Stopped
2021-04-20T18:45:12.558Z,1618944312.558 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T18:45:12.558Z,1618944312.558 [Default:CheckIn](INFO): Running loop #37
2021-04-20T18:45:12.559Z,1618944312.559 [Default:CheckIn] Running Loop=37
2021-04-20T18:45:12.559Z,1618944312.559 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T18:45:12.559Z,1618944312.559 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T18:45:14.564Z,1618944314.564 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184514.00,A,3647.96957,N,12150.58445,W,1.886,74.61,200421,,,D*4F
2021-04-20T18:45:14.567Z,1618944314.567 [NAL9602](INFO): GPS fix at 20210420T184514: (36.799493, -121.843074)
2021-04-20T18:45:14.577Z,1618944314.577 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T18:45:14.578Z,1618944314.578 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T18:45:23.061Z,1618944323.061 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210420T142139/Courier0118.lzma
2021-04-20T18:45:25.068Z,1618944325.068 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0118.lzma.bak
2021-04-20T18:45:25.068Z,1618944325.068 [DataOverHttps](INFO): SBD MOMSN=15591300
2021-04-20T18:45:47.293Z,1618944347.293 [NAL9602](INFO): SBD MO Status=0, MOMSN=2690, MT Status=0, MTMSN=0
2021-04-20T18:45:47.293Z,1618944347.293 [NAL9602](INFO): No messages in MT queue
2021-04-20T18:46:17.995Z,1618944377.995 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-20T18:46:25.315Z,1618944385.315 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.247345
2021-04-20T18:46:34.201Z,1618944394.201 [DVL_micro](ERROR): Failed to parse:00000000000,35.0,+21.5,0000.0,1489.0,000
2021-04-20T18:46:49.176Z,1618944409.176 [NAL9602](INFO): SBD MO Status=1, MOMSN=2691, MT Status=0, MTMSN=0
2021-04-20T18:46:49.226Z,1618944409.226 [NAL9602](INFO): Sent 130 bytes from file Logs/20210420T142139/Express0119.lzma
2021-04-20T18:46:49.226Z,1618944409.226 [NAL9602](INFO): Packets left to send: 0
2021-04-20T18:46:56.438Z,1618944416.438 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-04-20T18:46:57.237Z,1618944417.237 [DVL_micro](ERROR): only read 2 of 4 data items
2021-04-20T18:46:57.238Z,1618944417.238 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.999+9999.99,+9999.99
2021-04-20T18:46:57.240Z,1618944417.240 [NAL9602](INFO): SBD MO Status=0, MOMSN=2692, MT Status=0, MTMSN=0
2021-04-20T18:46:57.328Z,1618944417.328 [Default:CheckIn:Read_Iridium] Stopped
2021-04-20T18:46:57.328Z,1618944417.328 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-20T18:46:57.328Z,1618944417.328 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-20T18:47:27.929Z,1618944447.929 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-20T18:47:31.594Z,1618944451.594 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-04-20T18:47:50.070Z,1618944470.070 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002908
2021-04-20T18:48:29.375Z,1618944509.375 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2021-04-20T18:48:29.375Z,1618944509.375 [DVL_micro](ERROR): Failed to parse:
:TS,000000000000014.2,0000.0,1489.0,000
2021-04-20T18:51:57.886Z,1618944717.886 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-20T18:51:57.886Z,1618944717.886 [Default:CheckIn:C.Wait] Stopped
2021-04-20T18:51:57.887Z,1618944717.887 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-20T18:51:57.887Z,1618944717.887 [Default:CheckIn:D] Running Loop=1
2021-04-20T18:51:58.304Z,1618944718.304 [Default:CheckIn:D] Stopped
2021-04-20T18:51:58.304Z,1618944718.304 [Default:CheckIn:E] Running Loop=1
2021-04-20T18:51:58.702Z,1618944718.702 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 267.364307 min
2021-04-20T18:51:58.702Z,1618944718.702 [Default:CheckIn:E] Stopped
2021-04-20T18:51:58.702Z,1618944718.702 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-20T18:51:58.702Z,1618944718.702 [Default:CheckIn] Stopped
2021-04-20T18:51:58.702Z,1618944718.702 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-20T18:51:58.702Z,1618944718.702 [Default:CheckIn](INFO): Running loop #38
2021-04-20T18:51:58.702Z,1618944718.702 [Default:CheckIn] Running Loop=38
2021-04-20T18:51:58.703Z,1618944718.703 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-20T18:51:58.703Z,1618944718.703 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-20T18:52:00.715Z,1618944720.715 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185200.00,A,3647.97245,N,12150.47063,W,0.467,16.16,200421,,,D*4D
2021-04-20T18:52:00.717Z,1618944720.717 [NAL9602](INFO): GPS fix at 20210420T185200: (36.799541, -121.841177)
2021-04-20T18:52:00.731Z,1618944720.731 [UniversalFixResidualReporter](INFO): Fix residual: 79.0 %DT, over the last 814.6 m. Residual distance 643.5 m at bearing -76.6 degrees. Fix at (36.7995, -121.8412) with 169.0 m made good.
2021-04-20T18:52:00.731Z,1618944720.731 [Default:CheckIn:Read_GPS] Stopped
2021-04-20T18:52:00.731Z,1618944720.731 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-20T18:52:10.874Z,1618944730.874 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20210420T142139/Courier0121.lzma
2021-04-20T18:52:11.876Z,1618944731.876 [DataOverHttps](INFO): Moved sent file to Logs/20210420T142139/Courier0121.lzma.bak
2021-04-20T18:52:11.877Z,1618944731.877 [DataOverHttps](IMPORTANT): SBD MOMSN=15591336, MTMSN=20210420T185211
2021-04-20T18:52:14.886Z,1618944734.886 [NAL9602](INFO): SBD MO Status=0, MOMSN=2693, MT Status=0, MTMSN=0
2021-04-20T18:52:14.886Z,1618944734.886 [NAL9602](INFO): No messages in MT queue
2021-04-20T18:52:22.354Z,1618944742.354 [DataOverHttps](INFO): Received command:restart logs