2020-09-10T19:46:09.598Z,1599767169.598 [Supervisor](DEBUG): Initializing supervisor.
2020-09-10T19:46:09.601Z,1599767169.601 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-09-10T19:46:09.602Z,1599767169.602 [SyncHandler](INFO): Protected caller Thread ID is 1458
2020-09-10T19:46:09.602Z,1599767169.602 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-09-10T19:46:09.603Z,1599767169.603 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-09-10T19:46:09.603Z,1599767169.603 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1459
2020-09-10T19:46:09.606Z,1599767169.606 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-09-10T19:46:09.626Z,1599767169.626 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-09-10T19:46:09.627Z,1599767169.627 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-09-10T19:46:09.627Z,1599767169.627 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1460
2020-09-10T19:46:09.628Z,1599767169.628 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-09-10T19:46:09.629Z,1599767169.629 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-09-10T19:46:09.629Z,1599767169.629 [logger ThreadHandler](INFO): Protected caller Thread ID is 1461
2020-09-10T19:46:09.631Z,1599767169.631 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-09-10T19:46:09.631Z,1599767169.631 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-09-10T19:46:09.633Z,1599767169.633 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-09-10T19:46:09.727Z,1599767169.727 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-09-10T19:46:09.728Z,1599767169.728 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-09-10T19:46:10.314Z,1599767170.314 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-09-10T19:46:10.315Z,1599767170.315 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2020-09-10T19:46:10.503Z,1599767170.503 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2020-09-10T19:46:10.504Z,1599767170.504 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-09-10T19:46:10.602Z,1599767170.602 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-09-10T19:46:10.603Z,1599767170.603 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-09-10T19:46:10.704Z,1599767170.704 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-09-10T19:46:10.704Z,1599767170.704 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-09-10T19:46:10.784Z,1599767170.784 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-09-10T19:46:10.920Z,1599767170.920 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-09-10T19:46:10.920Z,1599767170.920 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-09-10T19:46:11.204Z,1599767171.204 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-09-10T19:46:11.204Z,1599767171.204 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-09-10T19:46:11.648Z,1599767171.648 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-09-10T19:46:11.649Z,1599767171.649 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-09-10T19:46:11.790Z,1599767171.790 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-09-10T19:46:11.791Z,1599767171.791 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-09-10T19:46:11.981Z,1599767171.981 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-09-10T19:46:11.981Z,1599767171.981 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-09-10T19:46:12.440Z,1599767172.440 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-09-10T19:46:12.440Z,1599767172.440 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-09-10T19:46:12.652Z,1599767172.652 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-09-10T19:46:12.653Z,1599767172.653 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-09-10T19:46:12.852Z,1599767172.852 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-09-10T19:46:12.852Z,1599767172.852 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-09-10T19:46:13.252Z,1599767173.252 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-09-10T19:46:13.253Z,1599767173.253 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-09-10T19:46:13.577Z,1599767173.577 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-09-10T19:46:13.579Z,1599767173.579 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2020-09-10T19:46:13.580Z,1599767173.580 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2020-09-10T19:46:13.662Z,1599767173.662 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2020-09-10T19:46:13.818Z,1599767173.818 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2020-09-10T19:46:13.924Z,1599767173.924 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2020-09-10T19:46:14.009Z,1599767174.009 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2020-09-10T19:46:14.102Z,1599767174.102 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2020-09-10T19:46:14.365Z,1599767174.365 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2020-09-10T19:46:14.892Z,1599767174.892 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-09-10T19:46:14.893Z,1599767174.893 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2020-09-10T19:46:15.084Z,1599767175.084 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2020-09-10T19:46:15.778Z,1599767175.778 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2020-09-10T19:46:15.926Z,1599767175.926 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2020-09-10T19:46:16.155Z,1599767176.155 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/root/
2020-09-10T19:46:16.156Z,1599767176.156 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-09-10T19:46:16.169Z,1599767176.169 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2020-09-10T19:46:16.432Z,1599767176.432 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2020-09-10T19:46:16.432Z,1599767176.432 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-09-10T19:46:16.551Z,1599767176.551 [VerticalControl](DEBUG): Construct VerticalControl.
2020-09-10T19:46:16.769Z,1599767176.769 [VerticalControl] Loaded
2020-09-10T19:46:16.770Z,1599767176.770 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-09-10T19:46:16.773Z,1599767176.773 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-09-10T19:46:16.903Z,1599767176.903 [HorizontalControl] Loaded
2020-09-10T19:46:16.903Z,1599767176.903 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-09-10T19:46:16.904Z,1599767176.904 [SpeedControl](DEBUG): Construct SpeedControl.
2020-09-10T19:46:16.909Z,1599767176.909 [SpeedControl] Loaded
2020-09-10T19:46:16.910Z,1599767176.910 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-09-10T19:46:16.910Z,1599767176.910 [LoopControl](DEBUG): Construct LoopControl.
2020-09-10T19:46:16.911Z,1599767176.911 [LoopControl] Loaded
2020-09-10T19:46:16.911Z,1599767176.911 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-09-10T19:46:16.911Z,1599767176.911 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-09-10T19:46:16.912Z,1599767176.912 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-09-10T19:46:17.103Z,1599767177.103 [DepthRateCalculator] Loaded
2020-09-10T19:46:17.103Z,1599767177.103 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-09-10T19:46:17.176Z,1599767177.176 [PitchRateCalculator] Loaded
2020-09-10T19:46:17.176Z,1599767177.176 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-09-10T19:46:17.196Z,1599767177.196 [SpeedCalculator] Loaded
2020-09-10T19:46:17.196Z,1599767177.196 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-09-10T19:46:17.217Z,1599767177.217 [TempGradientCalculator] Loaded
2020-09-10T19:46:17.217Z,1599767177.217 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-09-10T19:46:17.222Z,1599767177.222 [YawRateCalculator] Loaded
2020-09-10T19:46:17.222Z,1599767177.222 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-09-10T19:46:17.250Z,1599767177.250 [ElevatorOffsetCalculator] Loaded
2020-09-10T19:46:17.250Z,1599767177.250 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-09-10T19:46:17.250Z,1599767177.250 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-09-10T19:46:17.251Z,1599767177.251 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-09-10T19:46:17.277Z,1599767177.277 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-09-10T19:46:17.277Z,1599767177.277 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-09-10T19:46:17.358Z,1599767177.358 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-09-10T19:46:17.358Z,1599767177.358 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-09-10T19:46:17.633Z,1599767177.633 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-09-10T19:46:17.634Z,1599767177.634 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-09-10T19:46:17.729Z,1599767177.729 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-09-10T19:46:17.730Z,1599767177.730 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-09-10T19:46:18.066Z,1599767178.066 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-09-10T19:46:18.070Z,1599767178.070 [AHRS_M2](INFO): created writer for : platform_orientation
2020-09-10T19:46:18.072Z,1599767178.072 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-09-10T19:46:18.077Z,1599767178.077 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-09-10T19:46:18.078Z,1599767178.078 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-09-10T19:46:18.083Z,1599767178.083 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-09-10T19:46:18.083Z,1599767178.083 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-09-10T19:46:18.088Z,1599767178.088 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-09-10T19:46:18.157Z,1599767178.157 [AHRS_M2] Loaded
2020-09-10T19:46:18.157Z,1599767178.157 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-09-10T19:46:18.232Z,1599767178.232 [DataOverHttps] Loaded
2020-09-10T19:46:18.232Z,1599767178.232 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-09-10T19:46:18.233Z,1599767178.233 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4090D4E0
2020-09-10T19:46:18.234Z,1599767178.234 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1543
2020-09-10T19:46:18.263Z,1599767178.263 [Depth_Keller] Loaded
2020-09-10T19:46:18.263Z,1599767178.263 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-09-10T19:46:18.268Z,1599767178.268 [DropWeight] Loaded
2020-09-10T19:46:18.268Z,1599767178.268 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-09-10T19:46:18.378Z,1599767178.378 [NAL9602] Loaded
2020-09-10T19:46:18.378Z,1599767178.378 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-09-10T19:46:18.425Z,1599767178.425 [Onboard] Loaded
2020-09-10T19:46:18.425Z,1599767178.425 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2020-09-10T19:46:18.426Z,1599767178.426 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4093D4E0
2020-09-10T19:46:18.427Z,1599767178.427 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1544
2020-09-10T19:46:18.445Z,1599767178.445 [Radio_Surface] Loaded
2020-09-10T19:46:18.446Z,1599767178.446 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-09-10T19:46:18.447Z,1599767178.447 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4096D4E0
2020-09-10T19:46:18.447Z,1599767178.447 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1545
2020-09-10T19:46:18.592Z,1599767178.592 [DAT] Loaded
2020-09-10T19:46:18.592Z,1599767178.592 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2020-09-10T19:46:20.221Z,1599767180.221 [BPC1] Loaded
2020-09-10T19:46:20.222Z,1599767180.222 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-09-10T19:46:20.253Z,1599767180.253 [AMEcho] Loaded
2020-09-10T19:46:20.253Z,1599767180.253 [ComponentRegistry](DEBUG): SyncComponent "AMEcho" handled in the control thread.
2020-09-10T19:46:20.253Z,1599767180.253 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-09-10T19:46:20.254Z,1599767180.254 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-09-10T19:46:20.367Z,1599767180.367 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-09-10T19:46:20.367Z,1599767180.367 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-09-10T19:46:20.387Z,1599767180.387 [NavChart] Loaded
2020-09-10T19:46:20.387Z,1599767180.387 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-09-10T19:46:20.391Z,1599767180.391 [UniversalFixResidualReporter] Loaded
2020-09-10T19:46:20.391Z,1599767180.391 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-09-10T19:46:20.392Z,1599767180.392 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-09-10T19:46:20.392Z,1599767180.392 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-09-10T19:46:20.521Z,1599767180.521 [SBIT](DEBUG): Construct Startup Built In Test.
2020-09-10T19:46:20.532Z,1599767180.532 [SBIT] Loaded
2020-09-10T19:46:20.533Z,1599767180.533 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-09-10T19:46:20.533Z,1599767180.533 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-09-10T19:46:20.546Z,1599767180.546 [IBIT] Loaded
2020-09-10T19:46:20.546Z,1599767180.546 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-09-10T19:46:20.549Z,1599767180.549 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-09-10T19:46:20.685Z,1599767180.685 [CBIT] Loaded
2020-09-10T19:46:20.685Z,1599767180.685 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-09-10T19:46:20.685Z,1599767180.685 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-09-10T19:46:20.686Z,1599767180.686 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-09-10T19:46:20.802Z,1599767180.802 [BuoyancyServo] Loaded
2020-09-10T19:46:20.803Z,1599767180.803 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-09-10T19:46:20.830Z,1599767180.830 [ElevatorServo] Loaded
2020-09-10T19:46:20.831Z,1599767180.831 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-09-10T19:46:20.858Z,1599767180.858 [MassServo] Loaded
2020-09-10T19:46:20.858Z,1599767180.858 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-09-10T19:46:20.885Z,1599767180.885 [RudderServo] Loaded
2020-09-10T19:46:20.885Z,1599767180.885 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-09-10T19:46:20.911Z,1599767180.911 [ThrusterServo] Loaded
2020-09-10T19:46:20.911Z,1599767180.911 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-09-10T19:46:20.912Z,1599767180.912 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-09-10T19:46:20.912Z,1599767180.912 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-09-10T19:46:20.930Z,1599767180.930 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-09-10T19:46:20.930Z,1599767180.930 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-09-10T19:46:21.160Z,1599767181.160 [BackSeatDriver] Loaded
2020-09-10T19:46:21.160Z,1599767181.160 [ComponentRegistry](DEBUG): Component "BackSeatDriver" handled in its own thread.
2020-09-10T19:46:21.161Z,1599767181.161 [BackSeatDriver ThreadHandler](DEBUG): Created PCaller Thread at 40B034E0
2020-09-10T19:46:21.162Z,1599767181.162 [BackSeatDriver ThreadHandler](INFO): Protected caller Thread ID is 1546
2020-09-10T19:46:21.190Z,1599767181.190 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2020-09-10T19:46:21.195Z,1599767181.195 [CTD_Seabird](INFO): created writer for : sea_water_density
2020-09-10T19:46:21.195Z,1599767181.195 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2020-09-10T19:46:21.201Z,1599767181.201 [CTD_Seabird](INFO): created writer for : depth
2020-09-10T19:46:21.201Z,1599767181.201 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2020-09-10T19:46:21.206Z,1599767181.206 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2020-09-10T19:46:21.207Z,1599767181.207 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2020-09-10T19:46:21.212Z,1599767181.212 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2020-09-10T19:46:21.212Z,1599767181.212 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2020-09-10T19:46:21.217Z,1599767181.217 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2020-09-10T19:46:21.218Z,1599767181.218 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2020-09-10T19:46:21.223Z,1599767181.223 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2020-09-10T19:46:21.223Z,1599767181.223 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2020-09-10T19:46:21.229Z,1599767181.229 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2020-09-10T19:46:21.255Z,1599767181.255 [CTD_Seabird] Loaded
2020-09-10T19:46:21.256Z,1599767181.256 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2020-09-10T19:46:21.257Z,1599767181.257 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B334E0
2020-09-10T19:46:21.257Z,1599767181.257 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1547
2020-09-10T19:46:21.278Z,1599767181.278 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470
2020-09-10T19:46:21.279Z,1599767181.279 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470
2020-09-10T19:46:21.282Z,1599767181.282 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650
2020-09-10T19:46:21.283Z,1599767181.283 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650
2020-09-10T19:46:21.287Z,1599767181.287 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl
2020-09-10T19:46:21.287Z,1599767181.287 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl
2020-09-10T19:46:21.291Z,1599767181.291 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm
2020-09-10T19:46:21.291Z,1599767181.291 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm
2020-09-10T19:46:21.295Z,1599767181.295 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm
2020-09-10T19:46:21.295Z,1599767181.295 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm
2020-09-10T19:46:21.300Z,1599767181.300 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm
2020-09-10T19:46:21.300Z,1599767181.300 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm
2020-09-10T19:46:21.304Z,1599767181.304 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm
2020-09-10T19:46:21.304Z,1599767181.304 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm
2020-09-10T19:46:21.308Z,1599767181.308 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water
2020-09-10T19:46:21.312Z,1599767181.312 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water
2020-09-10T19:46:21.313Z,1599767181.313 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-09-10T19:46:21.313Z,1599767181.313 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-09-10T19:46:21.317Z,1599767181.317 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-09-10T19:46:21.317Z,1599767181.317 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-09-10T19:46:21.321Z,1599767181.321 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-09-10T19:46:21.321Z,1599767181.321 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-09-10T19:46:21.326Z,1599767181.326 [WetLabsBB2FL] Loaded
2020-09-10T19:46:21.326Z,1599767181.326 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2020-09-10T19:46:21.327Z,1599767181.327 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B634E0
2020-09-10T19:46:21.327Z,1599767181.327 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1548
2020-09-10T19:46:21.328Z,1599767181.328 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-09-10T19:46:21.332Z,1599767181.332 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-09-10T19:46:21.332Z,1599767181.332 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-09-10T19:46:21.339Z,1599767181.339 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-09-10T19:46:21.340Z,1599767181.340 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B934E0
2020-09-10T19:46:21.340Z,1599767181.340 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1549
2020-09-10T19:46:21.345Z,1599767181.345 [Supervisor](INFO): Main Thread ID is 822
2020-09-10T19:46:21.345Z,1599767181.345 [Supervisor](DEBUG): Running supervisor.
2020-09-10T19:46:21.346Z,1599767181.346 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1550
2020-09-10T19:46:21.348Z,1599767181.348 [controlThread ThreadHandler](INFO): Handler Thread ID is 1551
2020-09-10T19:46:21.349Z,1599767181.349 [controlThread](DEBUG): Initializing ControlThread
2020-09-10T19:46:21.349Z,1599767181.349 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-09-10T19:46:21.351Z,1599767181.351 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-09-10T19:46:21.352Z,1599767181.352 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-09-10T19:46:21.352Z,1599767181.352 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-09-10T19:46:21.353Z,1599767181.353 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-09-10T19:46:21.353Z,1599767181.353 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-09-10T19:46:21.353Z,1599767181.353 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-09-10T19:46:21.354Z,1599767181.354 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-09-10T19:46:21.354Z,1599767181.354 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-09-10T19:46:21.354Z,1599767181.354 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-09-10T19:46:21.362Z,1599767181.362 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-09-10T19:46:21.363Z,1599767181.363 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-09-10T19:46:21.363Z,1599767181.363 [SBIT](INFO): Initialize SBIT Component.
2020-09-10T19:46:21.364Z,1599767181.364 [SBIT](IMPORTANT): git: 2020-08-31
2020-09-10T19:46:21.364Z,1599767181.364 [SBIT](INFO): git hash: b6c0ec5a69f4280de3f7606c4f2437bb78ebd873
2020-09-10T19:46:21.364Z,1599767181.364 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-09-10T19:46:21.365Z,1599767181.365 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
Kernel Reported: #1 PREEMPT Thu Aug 6 12:04:53 PDT 2020
2020-09-10T19:46:21.366Z,1599767181.366 [SBIT](INFO): Beginning SBIT in 75.000000 seconds.
2020-09-10T19:46:21.367Z,1599767181.367 [IBIT](INFO): Initialize IBIT Component.
2020-09-10T19:46:21.368Z,1599767181.368 [CBIT](DEBUG): Initialize CBIT Component.
2020-09-10T19:46:21.369Z,1599767181.369 [logger ThreadHandler](INFO): Handler Thread ID is 1552
2020-09-10T19:46:21.380Z,1599767181.380 [CBIT](DEBUG): Initialized mux pins.
2020-09-10T19:46:21.380Z,1599767181.380 [CBIT](DEBUG): Initializing the watchdog timer.
2020-09-10T19:46:21.388Z,1599767181.388 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1553
2020-09-10T19:46:21.389Z,1599767181.389 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-09-10T19:46:21.400Z,1599767181.400 [Onboard ThreadHandler](INFO): Handler Thread ID is 1554
2020-09-10T19:46:21.404Z,1599767181.404 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-09-10T19:46:21.404Z,1599767181.404 [CBIT](DEBUG): Initializing heartbeat.
2020-09-10T19:46:21.418Z,1599767181.418 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1555
2020-09-10T19:46:21.440Z,1599767181.440 [BackSeatDriver ThreadHandler](INFO): Handler Thread ID is 1556
2020-09-10T19:46:21.456Z,1599767181.456 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1557
2020-09-10T19:46:21.457Z,1599767181.457 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2020-09-10T19:46:21.461Z,1599767181.461 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1559
2020-09-10T19:46:21.462Z,1599767181.462 [WetLabsBB2FL](INFO): Powering down
2020-09-10T19:46:21.476Z,1599767181.476 [CBIT](DEBUG): Deactivating GF circuits.
2020-09-10T19:46:21.476Z,1599767181.476 [CBIT](DEBUG): Deactivating emergency mode.
2020-09-10T19:46:21.488Z,1599767181.488 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1560
2020-09-10T19:46:21.491Z,1599767181.491 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-09-10T19:46:21.491Z,1599767181.491 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-09-10T19:46:21.492Z,1599767181.492 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-09-10T19:46:21.492Z,1599767181.492 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-09-10T19:46:21.492Z,1599767181.492 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-09-10T19:46:21.492Z,1599767181.492 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-09-10T19:46:21.492Z,1599767181.492 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-09-10T19:46:21.492Z,1599767181.492 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-09-10T19:46:21.492Z,1599767181.492 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-09-10T19:46:21.493Z,1599767181.493 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-09-10T19:46:21.493Z,1599767181.493 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-09-10T19:46:21.493Z,1599767181.493 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-09-10T19:46:21.493Z,1599767181.493 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-09-10T19:46:21.493Z,1599767181.493 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-09-10T19:46:21.493Z,1599767181.493 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-09-10T19:46:21.494Z,1599767181.494 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-09-10T19:46:21.512Z,1599767181.512 [CBIT](DEBUG): Backplane powered.
2020-09-10T19:46:21.514Z,1599767181.514 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-09-10T19:46:21.524Z,1599767181.524 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-09-10T19:46:21.534Z,1599767181.534 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2020-09-10T19:46:21.535Z,1599767181.535 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-09-10T19:46:21.611Z,1599767181.611 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-09-10T19:46:21.628Z,1599767181.628 [Default:A.Wait](DEBUG): Construct Wait.
2020-09-10T19:46:21.630Z,1599767181.630 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-09-10T19:46:21.649Z,1599767181.649 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-09-10T19:46:21.682Z,1599767181.682 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-09-10T19:46:21.703Z,1599767181.703 [Default:E.Execute](DEBUG): Construct Execute.
2020-09-10T19:46:21.722Z,1599767181.722 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2020-09-10T19:46:21.726Z,1599767181.726 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,DAT,BPC1,AMEcho,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2020-09-10T19:46:21.736Z,1599767181.736 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-09-10T19:46:21.769Z,1599767181.769 [Depth_Keller](ERROR): Pressure reading out of range: 1650.297119 decibar
2020-09-10T19:46:21.772Z,1599767181.772 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-09-10T19:46:21.772Z,1599767181.772 [DAT](INFO): Powering up
2020-09-10T19:46:21.772Z,1599767181.772 [DAT](DEBUG): Initializing DAT.
2020-09-10T19:46:21.824Z,1599767181.824 [Radio_Surface](INFO): Powering up
2020-09-10T19:46:21.825Z,1599767181.825 [AMEcho](INFO): Powering up
2020-09-10T19:46:21.844Z,1599767181.844 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-09-10T19:46:21.860Z,1599767181.860 [DepthRateCalculator](ERROR): Depth measurement is not active
2020-09-10T19:46:21.897Z,1599767181.897 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-09-10T19:46:21.917Z,1599767181.917 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-09-10T19:46:21.918Z,1599767181.918 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-09-10T19:46:21.928Z,1599767181.928 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-09-10T19:46:21.929Z,1599767181.929 [MassServo](DEBUG): Initializing EZServoServo.
2020-09-10T19:46:21.940Z,1599767181.940 [MassServo](DEBUG): Initializing MassServo.
2020-09-10T19:46:21.941Z,1599767181.941 [RudderServo](DEBUG): Initializing EZServoServo.
2020-09-10T19:46:21.952Z,1599767181.952 [RudderServo](DEBUG): Initializing RudderServo.
2020-09-10T19:46:21.953Z,1599767181.953 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-09-10T19:46:21.965Z,1599767181.965 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-09-10T19:46:22.242Z,1599767182.242 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2020-09-10T19:46:22.242Z,1599767182.242 [DropWeight] Hardware Fault, FailCount= 1
2020-09-10T19:46:22.242Z,1599767182.242 [DropWeight](ERROR): Hardware Fault
2020-09-10T19:46:22.416Z,1599767182.416 [AMEcho](INFO): Powering down
2020-09-10T19:46:22.437Z,1599767182.437 [CommandLine](FAULT): Scheduling is paused
2020-09-10T19:46:22.437Z,1599767182.437 [CBIT](INFO): Critical error at 20200910T194622
2020-09-10T19:46:22.438Z,1599767182.438 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2020-09-10T19:46:22.448Z,1599767182.448 [CBIT](ERROR): Hardware Fault in component: DropWeight
2020-09-10T19:46:22.449Z,1599767182.449 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2020-09-10T19:46:22.864Z,1599767182.864 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2020-09-10T19:46:22.864Z,1599767182.864 [RudderServo](FAULT): Rudder failed to initialize
2020-09-10T19:46:22.864Z,1599767182.864 [RudderServo] Communications Fault, FailCount= 1
2020-09-10T19:46:22.864Z,1599767182.864 [RudderServo](ERROR): Communications Fault
2020-09-10T19:46:22.973Z,1599767182.973 [CBIT](INFO): Critical error at 20200910T194622
2020-09-10T19:46:22.976Z,1599767182.976 [CBIT](ERROR): Communications Fault in component: RudderServo
2020-09-10T19:46:23.137Z,1599767183.137 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-09-10T19:46:23.137Z,1599767183.137 [RudderServo](INFO): Powering down
2020-09-10T19:46:23.826Z,1599767183.826 [RudderServo](DEBUG): Initializing EZServoServo.
2020-09-10T19:46:23.945Z,1599767183.945 [RudderServo](DEBUG): Initializing RudderServo.
2020-09-10T19:46:23.949Z,1599767183.949 [CBIT](INFO): Clearing failed state for component RudderServo
2020-09-10T19:46:23.949Z,1599767183.949 [RudderServo] No Fault, FailCount= 1
2020-09-10T19:46:32.281Z,1599767192.281 [DAT](INFO): DAT read: 

2020-09-10T19:46:32.283Z,1599767192.283 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2020-09-10T19:46:33.493Z,1599767193.493 [DAT](INFO): DAT read: MF Frequency Band

2020-09-10T19:46:33.495Z,1599767193.495 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.12.21

2020-09-10T19:46:33.495Z,1599767193.495 [DAT](INFO): DAT read: Sep 10 2020 19:46:09 

2020-09-10T19:46:34.302Z,1599767194.302 [DAT](INFO): DAT read: Features enabled [Bearing]

2020-09-10T19:46:34.303Z,1599767194.303 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2020-09-10T19:46:34.303Z,1599767194.303 [DAT](INFO): commRate: 800
2020-09-10T19:46:34.304Z,1599767194.304 [DAT](INFO): commRate: 800
2020-09-10T19:46:34.709Z,1599767194.709 [DAT](INFO): entering command mode
2020-09-10T19:46:35.109Z,1599767195.109 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:35.514Z,1599767195.514 [DAT](INFO): DAT read: 

2020-09-10T19:46:35.514Z,1599767195.514 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:35.917Z,1599767195.917 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:36.321Z,1599767196.321 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:36.725Z,1599767196.725 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:37.129Z,1599767197.129 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:37.533Z,1599767197.533 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:37.937Z,1599767197.937 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:38.341Z,1599767198.341 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:38.745Z,1599767198.745 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:39.149Z,1599767199.149 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:39.553Z,1599767199.553 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:39.961Z,1599767199.961 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:40.361Z,1599767200.361 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:40.766Z,1599767200.766 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:41.169Z,1599767201.169 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:41.573Z,1599767201.573 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:41.978Z,1599767201.978 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:42.381Z,1599767202.381 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:42.785Z,1599767202.785 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:43.185Z,1599767203.185 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:43.593Z,1599767203.593 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:43.993Z,1599767203.993 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:44.401Z,1599767204.401 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:44.805Z,1599767204.805 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:45.209Z,1599767205.209 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:45.616Z,1599767205.616 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:46.017Z,1599767206.017 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:46.417Z,1599767206.417 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:46.825Z,1599767206.825 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:47.229Z,1599767207.229 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:47.644Z,1599767207.644 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:48.041Z,1599767208.041 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:48.441Z,1599767208.441 [NAL9602](INFO): Powering up NAL9602
2020-09-10T19:46:48.442Z,1599767208.442 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:48.845Z,1599767208.845 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:49.261Z,1599767209.261 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:49.653Z,1599767209.653 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:50.053Z,1599767210.053 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-10T19:46:50.053Z,1599767210.053 [DAT](FAULT): failed to enter command mode
2020-09-10T19:46:50.461Z,1599767210.461 [DAT](INFO): entering command mode
2020-09-10T19:46:50.869Z,1599767210.869 [DAT](INFO): DAT read: user:1>

2020-09-10T19:46:50.870Z,1599767210.870 [DAT](INFO): DAT read: Command '+++' not found

2020-09-10T19:46:50.871Z,1599767210.871 [DAT](INFO): DAT read: Error

2020-09-10T19:46:50.871Z,1599767210.871 [DAT](INFO): setting verbose to 3
2020-09-10T19:46:51.265Z,1599767211.265 [DAT](INFO): DAT read: user:2>

2020-09-10T19:46:51.266Z,1599767211.266 [DAT](INFO): DAT read: Verbose         | 3           

2020-09-10T19:46:51.267Z,1599767211.267 [DAT](INFO): set verbose to 3
2020-09-10T19:46:51.267Z,1599767211.267 [DAT](INFO): setting DatVerbose to 27440
2020-09-10T19:46:51.673Z,1599767211.673 [DAT](INFO): DAT read: user:3>

2020-09-10T19:46:51.674Z,1599767211.674 [DAT](INFO): DAT read: DatVerbose      | 27440       

2020-09-10T19:46:51.675Z,1599767211.675 [DAT](INFO): set DatVerbose to 27440
2020-09-10T19:46:51.675Z,1599767211.675 [DAT](INFO): setting transmit power to 8
2020-09-10T19:46:52.077Z,1599767212.077 [DAT](INFO): DAT read: user:4>

2020-09-10T19:46:52.078Z,1599767212.078 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2020-09-10T19:46:52.079Z,1599767212.079 [DAT](INFO): set transmit power to 8
2020-09-10T19:46:52.079Z,1599767212.079 [DAT](INFO): setting local address to 9
2020-09-10T19:46:52.483Z,1599767212.483 [DAT](INFO): DAT read: user:5>

2020-09-10T19:46:52.484Z,1599767212.484 [DAT](INFO): DAT read: LocalAddr       | 9           

2020-09-10T19:46:52.484Z,1599767212.484 [DAT](INFO): set local address to 9
2020-09-10T19:46:59.353Z,1599767219.353 [NAL9602](INFO): NAL9602 initialized
2020-09-10T19:47:36.946Z,1599767256.946 [SBIT](IMPORTANT): Beginning Startup BIT
2020-09-10T19:47:36.950Z,1599767256.950 [CBIT](IMPORTANT): Beginning ground fault scan
2020-09-10T19:47:47.888Z,1599767267.888 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.002017
CHAN A1 (24V): 0.000811
CHAN A2 (12V): -0.006991
CHAN A3 (5V): -0.002345
CHAN B0 (3.3V): 0.000988
CHAN B1 (3.15aV): -0.000547
CHAN B2 (3.15bV): 0.000586
CHAN B3 (GND): 0.001466
OPEN: 0.005835
Full Scale Calc: 4.765 mA, -1.589 mA
2020-09-10T19:48:30.686Z,1599767310.686 [SBIT](IMPORTANT): SBIT PASSED
2020-09-10T19:48:30.687Z,1599767310.687 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-09-10T19:48:30.704Z,1599767310.704 [SBIT](IMPORTANT): AMEcho.enabled=1 bool;

2020-09-10T19:48:30.704Z,1599767310.704 [SBIT](IMPORTANT): CBIT.gf24Offset=145 microampere;

2020-09-10T19:48:30.704Z,1599767310.704 [SBIT](IMPORTANT): DAT.loadAtStartup=1 bool;

2020-09-10T19:48:30.704Z,1599767310.704 [SBIT](IMPORTANT): DAT.sbdAddress=0 enum;

2020-09-10T19:48:30.704Z,1599767310.704 [SBIT](IMPORTANT): DAT.surfaceThreshold=5 meter;

2020-09-10T19:48:30.704Z,1599767310.704 [SBIT](IMPORTANT): DAT.verbosity=3 count;

2020-09-10T19:48:30.704Z,1599767310.704 [SBIT](IMPORTANT): Express linearApproximation AMEcho.altitude 1.000000 meter;

2020-09-10T19:48:30.704Z,1599767310.704 [SBIT](IMPORTANT): Express none ThrusterServo.component_avgCurrent;

2020-09-10T19:48:30.705Z,1599767310.705 [SBIT](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 1.000000 liter_per_second;

2020-09-10T19:48:30.705Z,1599767310.705 [SBIT](IMPORTANT): Express linearApproximation height_above_sea_floor 5.000000 meter;

2020-09-10T19:48:30.705Z,1599767310.705 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=13 volt;

2020-09-10T19:48:30.705Z,1599767310.705 [SBIT](IMPORTANT): RDI_Pathfinder.loadAtStartup=0 bool;

2020-09-10T19:48:30.705Z,1599767310.705 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=146.161014 cubic_centimeter;

2020-09-10T19:48:30.705Z,1599767310.705 [SBIT](IMPORTANT): VerticalControl.massDefault=13.952984 millimeter;

2020-09-10T19:48:30.705Z,1599767310.705 [SBIT](IMPORTANT): WetLabsUBAT.loadAtStartup=0 bool;

2020-09-10T19:48:31.093Z,1599767311.093 [MissionManager](IMPORTANT): Started mission Startup
2020-09-10T19:48:31.094Z,1599767311.094 [Startup] Running Loop=1
2020-09-10T19:48:31.094Z,1599767311.094 [Startup](DEBUG): Aggregate::initialize Startup
2020-09-10T19:48:31.094Z,1599767311.094 [Startup:A.GoToSurface] Running Loop=1
2020-09-10T19:48:31.094Z,1599767311.094 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-09-10T19:48:31.095Z,1599767311.095 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-09-10T19:48:31.095Z,1599767311.095 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-09-10T19:48:31.095Z,1599767311.095 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-09-10T19:48:31.096Z,1599767311.096 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-09-10T19:48:31.096Z,1599767311.096 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-09-10T19:48:31.097Z,1599767311.097 [Startup:StartupSatComms] Running Loop=1
2020-09-10T19:48:31.098Z,1599767311.098 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-09-10T19:48:31.098Z,1599767311.098 [Startup:StartupSatComms:A] Running Loop=1
2020-09-10T19:48:31.490Z,1599767311.490 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-09-10T19:48:31.870Z,1599767311.870 [AMEcho](INFO): Powering up
2020-09-10T19:48:49.207Z,1599767329.207 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005268
2020-09-10T19:49:14.694Z,1599767354.694 [NAL9602](INFO): SBD MO Status=2, MOMSN=9600, MT Status=2, MTMSN=0
2020-09-10T19:49:14.695Z,1599767354.695 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-09-10T19:49:21.609Z,1599767361.609 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2020-09-10T19:49:21.609Z,1599767361.609 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-09-10T19:49:21.633Z,1599767361.633 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-09-10T19:49:21.994Z,1599767361.994 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-09-10T19:49:21.994Z,1599767361.994 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2020-09-10T19:49:31.266Z,1599767371.266 [Startup:StartupSatComms:A](INFO): Timed out from 2020-09-10T19:48:31.1Z
2020-09-10T19:49:31.266Z,1599767371.266 [Startup:StartupSatComms:A] Stopped
2020-09-10T19:49:31.266Z,1599767371.266 [Startup:StartupSatComms:B] Running Loop=1
2020-09-10T19:49:31.666Z,1599767371.666 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-09-10T19:49:38.927Z,1599767378.927 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200910T190929/Courier0022.lzma
2020-09-10T19:49:39.930Z,1599767379.930 [DataOverHttps](INFO): Moved sent file to Logs/20200910T190929/Courier0022.lzma.bak
2020-09-10T19:49:39.930Z,1599767379.930 [DataOverHttps](INFO): SBD MOMSN=12647777
2020-09-10T19:49:55.416Z,1599767395.416 [DataOverHttps](INFO): Sending 242 bytes from file Logs/20200910T194609/Courier0000.lzma
2020-09-10T19:49:56.417Z,1599767396.417 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Courier0000.lzma.bak
2020-09-10T19:49:56.418Z,1599767396.418 [DataOverHttps](INFO): SBD MOMSN=12647779
2020-09-10T19:49:59.138Z,1599767399.138 [NAL9602](INFO): SBD MO Status=2, MOMSN=9600, MT Status=2, MTMSN=0
2020-09-10T19:49:59.139Z,1599767399.139 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-09-10T19:50:12.083Z,1599767412.083 [DataOverHttps](INFO): Sending 110 bytes from file Logs/20200910T190929/Express0023.lzma
2020-09-10T19:50:13.086Z,1599767413.086 [DataOverHttps](INFO): Moved sent file to Logs/20200910T190929/Express0023.lzma.bak
2020-09-10T19:50:13.086Z,1599767413.086 [DataOverHttps](INFO): SBD MOMSN=12647784
2020-09-10T19:50:24.986Z,1599767424.986 [NAL9602](INFO): SBD MO Status=2, MOMSN=9600, MT Status=2, MTMSN=0
2020-09-10T19:50:24.987Z,1599767424.987 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-09-10T19:50:29.609Z,1599767429.609 [DataOverHttps](INFO): Sending 1086 bytes from file Logs/20200910T194609/Express0001.lzma
2020-09-10T19:50:30.610Z,1599767430.610 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Express0001.lzma.bak
2020-09-10T19:50:30.610Z,1599767430.610 [DataOverHttps](INFO): SBD MOMSN=12647787
2020-09-10T19:50:31.477Z,1599767431.477 [Startup:StartupSatComms:B](INFO): Timed out from 2020-09-10T19:49:31.3Z
2020-09-10T19:50:31.478Z,1599767431.478 [Startup:StartupSatComms:B] Stopped
2020-09-10T19:50:31.478Z,1599767431.478 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-09-10T19:50:31.478Z,1599767431.478 [Startup:StartupSatComms] Stopped
2020-09-10T19:50:31.478Z,1599767431.478 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-09-10T19:50:31.479Z,1599767431.479 [Startup](INFO): Completed Startup
2020-09-10T19:50:31.479Z,1599767431.479 [MissionManager](INFO): Startup is completed.
2020-09-10T19:50:31.479Z,1599767431.479 [MissionManager](INFO): Uninitializing Mission Startup
2020-09-10T19:50:31.479Z,1599767431.479 [Startup] Stopped
2020-09-10T19:50:31.479Z,1599767431.479 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-09-10T19:50:31.479Z,1599767431.479 [Startup:A.GoToSurface] Stopped
2020-09-10T19:50:31.479Z,1599767431.479 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-09-10T19:50:31.903Z,1599767431.903 [MissionManager](IMPORTANT): Started mission Default
2020-09-10T19:50:31.903Z,1599767431.903 [Default] Running Loop=1
2020-09-10T19:50:31.903Z,1599767431.903 [Default](DEBUG): Aggregate::initialize Default
2020-09-10T19:50:31.905Z,1599767431.905 [Default:B.GoToSurface] Running Loop=1
2020-09-10T19:50:31.905Z,1599767431.905 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-09-10T19:50:31.905Z,1599767431.905 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-09-10T19:50:31.906Z,1599767431.906 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-09-10T19:50:31.906Z,1599767431.906 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-09-10T19:50:31.907Z,1599767431.907 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-09-10T19:50:31.907Z,1599767431.907 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-09-10T19:50:31.907Z,1599767431.907 [Default:A.Wait] Running Loop=1
2020-09-10T19:50:31.907Z,1599767431.907 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-09-10T19:50:32.436Z,1599767432.436 [AMEcho](INFO): Powering down
2020-09-10T19:50:33.475Z,1599767433.475 [AMEcho](INFO): Powering up
2020-09-10T19:50:45.208Z,1599767445.208 [Default:A.Wait](INFO): Done Waiting.
2020-09-10T19:50:45.208Z,1599767445.208 [Default:A.Wait] Stopped
2020-09-10T19:50:45.208Z,1599767445.208 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-09-10T19:50:45.605Z,1599767445.605 [Default:CheckIn] Running Loop=1
2020-09-10T19:50:45.605Z,1599767445.605 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-09-10T19:50:45.605Z,1599767445.605 [Default:CheckIn:Read_GPS] Running Loop=1
2020-09-10T19:50:46.007Z,1599767446.007 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-09-10T19:50:52.062Z,1599767452.062 [NAL9602](INFO): SBD MO Status=2, MOMSN=9600, MT Status=2, MTMSN=0
2020-09-10T19:50:52.062Z,1599767452.062 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-09-10T19:51:31.666Z,1599767491.666 [NAL9602](INFO): SBD MO Status=2, MOMSN=9600, MT Status=2, MTMSN=0
2020-09-10T19:51:31.669Z,1599767491.669 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-09-10T19:52:02.357Z,1599767522.357 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-09-10T19:52:06.799Z,1599767526.799 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195205.00,A,3648.16638,N,12147.28722,W,0.778,20.94,100920,,,A*44
2020-09-10T19:52:06.802Z,1599767526.802 [NAL9602](INFO): GPS fix at 20200910T195205: (36.802773, -121.788120)
2020-09-10T19:52:06.813Z,1599767526.813 [Default:CheckIn:Read_GPS] Stopped
2020-09-10T19:52:06.813Z,1599767526.813 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-09-10T19:52:07.235Z,1599767527.235 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-09-10T19:52:17.180Z,1599767537.180 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20200910T194609/Courier0004.lzma
2020-09-10T19:52:18.182Z,1599767538.182 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Courier0004.lzma.bak
2020-09-10T19:52:18.182Z,1599767538.182 [DataOverHttps](INFO): SBD MOMSN=12647817
2020-09-10T19:52:35.048Z,1599767555.048 [DataOverHttps](INFO): Sending 322 bytes from file Logs/20200910T194609/Express0005.lzma
2020-09-10T19:52:36.049Z,1599767556.049 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Express0005.lzma.bak
2020-09-10T19:52:36.049Z,1599767556.049 [DataOverHttps](INFO): SBD MOMSN=12647820
2020-09-10T19:52:37.616Z,1599767557.616 [Default:CheckIn:Read_Iridium] Stopped
2020-09-10T19:52:37.616Z,1599767557.616 [Default:CheckIn:C.Wait] Running Loop=1
2020-09-10T19:52:37.616Z,1599767557.616 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-09-10T19:52:39.524Z,1599767559.524 [NAL9602](INFO): Not Powering down - fast GPS
2020-09-10T19:57:38.129Z,1599767858.129 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-09-10T19:57:38.129Z,1599767858.129 [Default:CheckIn:C.Wait] Stopped
2020-09-10T19:57:38.129Z,1599767858.129 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-09-10T19:57:38.130Z,1599767858.130 [Default:CheckIn:D] Running Loop=1
2020-09-10T19:57:38.519Z,1599767858.519 [Default:CheckIn:D] Stopped
2020-09-10T19:57:38.519Z,1599767858.519 [Default:CheckIn:E] Running Loop=1
2020-09-10T19:57:38.899Z,1599767858.899 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 7.110257 min 
2020-09-10T19:57:38.899Z,1599767858.899 [Default:CheckIn:E] Stopped
2020-09-10T19:57:38.899Z,1599767858.899 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-09-10T19:57:38.899Z,1599767858.899 [Default:CheckIn] Stopped
2020-09-10T19:57:38.899Z,1599767858.899 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-09-10T19:57:38.899Z,1599767858.899 [Default:CheckIn](INFO): Running loop #2
2020-09-10T19:57:38.899Z,1599767858.899 [Default:CheckIn] Running Loop=2
2020-09-10T19:57:38.899Z,1599767858.899 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-09-10T19:57:38.899Z,1599767858.899 [Default:CheckIn:Read_GPS] Running Loop=1
2020-09-10T19:57:40.909Z,1599767860.909 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195739.00,A,3648.16439,N,12147.27247,W,0.486,131.15,100920,,,A*7E
2020-09-10T19:57:40.911Z,1599767860.911 [NAL9602](INFO): GPS fix at 20200910T195739: (36.802740, -121.787875)
2020-09-10T19:57:40.921Z,1599767860.921 [Default:CheckIn:Read_GPS] Stopped
2020-09-10T19:57:40.921Z,1599767860.921 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-09-10T19:57:48.275Z,1599767868.275 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200910T194609/Courier0007.lzma
2020-09-10T19:57:49.277Z,1599767869.277 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Courier0007.lzma.bak
2020-09-10T19:57:49.278Z,1599767869.278 [DataOverHttps](INFO): SBD MOMSN=12647824
2020-09-10T19:58:05.555Z,1599767885.555 [DataOverHttps](INFO): Sending 159 bytes from file Logs/20200910T194609/Express0008.lzma
2020-09-10T19:58:06.558Z,1599767886.558 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Express0008.lzma.bak
2020-09-10T19:58:06.558Z,1599767886.558 [DataOverHttps](INFO): SBD MOMSN=12647827
2020-09-10T19:58:08.403Z,1599767888.403 [Default:CheckIn:Read_Iridium] Stopped
2020-09-10T19:58:08.403Z,1599767888.403 [Default:CheckIn:C.Wait] Running Loop=1
2020-09-10T19:58:08.403Z,1599767888.403 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-09-10T19:58:11.613Z,1599767891.613 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2020-09-10T19:58:11.696Z,1599767891.696 [NAL9602](FAULT): received: 
+CSQ:0

OK00, 2, 0, 0, 0

OK
2020-09-10T19:58:11.696Z,1599767891.696 [NAL9602] Data Fault, FailCount= 1
2020-09-10T19:58:11.696Z,1599767891.696 [NAL9602](ERROR): Data Fault
2020-09-10T19:58:11.716Z,1599767891.716 [CBIT](ERROR): Data Fault in component: NAL9602
2020-09-10T19:58:12.017Z,1599767892.017 [NAL9602](INFO): Powering down
2020-09-10T19:58:12.864Z,1599767892.864 [CBIT](INFO): Clearing failed state for component NAL9602
2020-09-10T19:58:12.864Z,1599767892.864 [NAL9602] No Fault, FailCount= 1
2020-09-10T19:58:26.167Z,1599767906.167 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2020-09-10T19:58:42.321Z,1599767922.321 [NAL9602](INFO): Powering up NAL9602
2020-09-10T19:58:53.229Z,1599767933.229 [NAL9602](INFO): NAL9602 initialized
2020-09-10T19:59:24.332Z,1599767964.332 [NAL9602](INFO): Not Powering down - fast GPS
2020-09-10T20:01:22.319Z,1599768082.319 [CBIT](INFO): Clearing failed state for component DropWeight
2020-09-10T20:01:22.319Z,1599768082.319 [DropWeight] No Fault, FailCount= 1
2020-09-10T20:03:08.972Z,1599768188.972 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-09-10T20:03:08.972Z,1599768188.972 [Default:CheckIn:C.Wait] Stopped
2020-09-10T20:03:08.973Z,1599768188.973 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-09-10T20:03:08.973Z,1599768188.973 [Default:CheckIn:D] Running Loop=1
2020-09-10T20:03:09.371Z,1599768189.371 [Default:CheckIn:D] Stopped
2020-09-10T20:03:09.371Z,1599768189.371 [Default:CheckIn:E] Running Loop=1
2020-09-10T20:03:09.789Z,1599768189.789 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.624455 min 
2020-09-10T20:03:09.789Z,1599768189.789 [Default:CheckIn:E] Stopped
2020-09-10T20:03:09.789Z,1599768189.789 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-09-10T20:03:09.789Z,1599768189.789 [Default:CheckIn] Stopped
2020-09-10T20:03:09.789Z,1599768189.789 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-09-10T20:03:09.789Z,1599768189.789 [Default:CheckIn](INFO): Running loop #3
2020-09-10T20:03:09.789Z,1599768189.789 [Default:CheckIn] Running Loop=3
2020-09-10T20:03:09.789Z,1599768189.789 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-09-10T20:03:09.789Z,1599768189.789 [Default:CheckIn:Read_GPS] Running Loop=1
2020-09-10T20:03:14.209Z,1599768194.209 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-09-10T20:03:44.923Z,1599768224.923 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200343.00,A,3648.16527,N,12147.31077,W,0.039,0.00,100920,,,A*77
2020-09-10T20:03:44.925Z,1599768224.925 [NAL9602](INFO): GPS fix at 20200910T200343: (36.802754, -121.788513)
2020-09-10T20:03:44.941Z,1599768224.941 [Default:CheckIn:Read_GPS] Stopped
2020-09-10T20:03:44.941Z,1599768224.941 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-09-10T20:03:52.323Z,1599768232.323 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200910T194609/Courier0010.lzma
2020-09-10T20:03:53.325Z,1599768233.325 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Courier0010.lzma.bak
2020-09-10T20:03:53.325Z,1599768233.325 [DataOverHttps](INFO): SBD MOMSN=12647830
2020-09-10T20:04:09.201Z,1599768249.201 [DataOverHttps](INFO): Sending 403 bytes from file Logs/20200910T194609/Express0011.lzma
2020-09-10T20:04:10.201Z,1599768250.201 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Express0011.lzma.bak
2020-09-10T20:04:10.202Z,1599768250.202 [DataOverHttps](INFO): SBD MOMSN=12647833
2020-09-10T20:04:11.991Z,1599768251.991 [Default:CheckIn:Read_Iridium] Stopped
2020-09-10T20:04:11.991Z,1599768251.991 [Default:CheckIn:C.Wait] Running Loop=1
2020-09-10T20:04:11.991Z,1599768251.991 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-09-10T20:04:17.237Z,1599768257.237 [NAL9602](INFO): Not Powering down - fast GPS
2020-09-10T20:09:12.578Z,1599768552.578 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-09-10T20:09:12.578Z,1599768552.578 [Default:CheckIn:C.Wait] Stopped
2020-09-10T20:09:12.578Z,1599768552.578 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-09-10T20:09:12.578Z,1599768552.578 [Default:CheckIn:D] Running Loop=1
2020-09-10T20:09:12.971Z,1599768552.971 [Default:CheckIn:D] Stopped
2020-09-10T20:09:12.971Z,1599768552.971 [Default:CheckIn:E] Running Loop=1
2020-09-10T20:09:13.378Z,1599768553.378 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.684454 min 
2020-09-10T20:09:13.379Z,1599768553.379 [Default:CheckIn:E] Stopped
2020-09-10T20:09:13.379Z,1599768553.379 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-09-10T20:09:13.379Z,1599768553.379 [Default:CheckIn] Stopped
2020-09-10T20:09:13.379Z,1599768553.379 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-09-10T20:09:13.379Z,1599768553.379 [Default:CheckIn](INFO): Running loop #4
2020-09-10T20:09:13.379Z,1599768553.379 [Default:CheckIn] Running Loop=4
2020-09-10T20:09:13.379Z,1599768553.379 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-09-10T20:09:13.379Z,1599768553.379 [Default:CheckIn:Read_GPS] Running Loop=1
2020-09-10T20:09:15.391Z,1599768555.391 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200913.00,A,3648.15756,N,12147.27842,W,0.661,217.79,100920,,,A*77
2020-09-10T20:09:15.393Z,1599768555.393 [NAL9602](INFO): GPS fix at 20200910T200913: (36.802626, -121.787974)
2020-09-10T20:09:15.405Z,1599768555.405 [Default:CheckIn:Read_GPS] Stopped
2020-09-10T20:09:15.405Z,1599768555.405 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-09-10T20:09:22.583Z,1599768562.583 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200910T194609/Courier0013.lzma
2020-09-10T20:09:23.585Z,1599768563.585 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Courier0013.lzma.bak
2020-09-10T20:09:23.586Z,1599768563.586 [DataOverHttps](INFO): SBD MOMSN=12647838
2020-09-10T20:09:40.520Z,1599768580.520 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20200910T194609/Express0014.lzma
2020-09-10T20:09:41.521Z,1599768581.521 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Express0014.lzma.bak
2020-09-10T20:09:41.522Z,1599768581.522 [DataOverHttps](INFO): SBD MOMSN=12647841
2020-09-10T20:09:43.287Z,1599768583.287 [Default:CheckIn:Read_Iridium] Stopped
2020-09-10T20:09:43.287Z,1599768583.287 [Default:CheckIn:C.Wait] Running Loop=1
2020-09-10T20:09:43.287Z,1599768583.287 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-09-10T20:09:44.482Z,1599768584.482 [NAL9602](INFO): SBD MO Status=0, MOMSN=9600, MT Status=0, MTMSN=0
2020-09-10T20:09:44.482Z,1599768584.482 [NAL9602](INFO): No messages in MT queue
2020-09-10T20:10:15.181Z,1599768615.181 [NAL9602](INFO): Not Powering down - fast GPS
2020-09-10T20:14:43.847Z,1599768883.847 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-09-10T20:14:43.847Z,1599768883.847 [Default:CheckIn:C.Wait] Stopped
2020-09-10T20:14:43.847Z,1599768883.847 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-09-10T20:14:43.847Z,1599768883.847 [Default:CheckIn:D] Running Loop=1
2020-09-10T20:14:44.308Z,1599768884.308 [Default:CheckIn:D] Stopped
2020-09-10T20:14:44.308Z,1599768884.308 [Default:CheckIn:E] Running Loop=1
2020-09-10T20:14:44.660Z,1599768884.660 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 24.206740 min 
2020-09-10T20:14:44.660Z,1599768884.660 [Default:CheckIn:E] Stopped
2020-09-10T20:14:44.660Z,1599768884.660 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-09-10T20:14:44.661Z,1599768884.661 [Default:CheckIn] Stopped
2020-09-10T20:14:44.661Z,1599768884.661 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-09-10T20:14:44.661Z,1599768884.661 [Default:CheckIn](INFO): Running loop #5
2020-09-10T20:14:44.661Z,1599768884.661 [Default:CheckIn] Running Loop=5
2020-09-10T20:14:44.661Z,1599768884.661 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-09-10T20:14:44.661Z,1599768884.661 [Default:CheckIn:Read_GPS] Running Loop=1
2020-09-10T20:14:46.671Z,1599768886.671 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201445.00,A,3648.16402,N,12147.28157,W,0.311,217.79,100920,,,A*79
2020-09-10T20:14:46.673Z,1599768886.673 [NAL9602](INFO): GPS fix at 20200910T201445: (36.802734, -121.788026)
2020-09-10T20:14:46.683Z,1599768886.683 [Default:CheckIn:Read_GPS] Stopped
2020-09-10T20:14:46.683Z,1599768886.683 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-09-10T20:14:54.163Z,1599768894.163 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200910T194609/Courier0016.lzma
2020-09-10T20:14:55.165Z,1599768895.165 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Courier0016.lzma.bak
2020-09-10T20:14:55.166Z,1599768895.166 [DataOverHttps](INFO): SBD MOMSN=12647845
2020-09-10T20:15:11.059Z,1599768911.059 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20200910T194609/Express0017.lzma
2020-09-10T20:15:12.061Z,1599768912.061 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Express0017.lzma.bak
2020-09-10T20:15:12.062Z,1599768912.062 [DataOverHttps](INFO): SBD MOMSN=12647848
2020-09-10T20:15:13.751Z,1599768913.751 [Default:CheckIn:Read_Iridium] Stopped
2020-09-10T20:15:13.751Z,1599768913.751 [Default:CheckIn:C.Wait] Running Loop=1
2020-09-10T20:15:13.751Z,1599768913.751 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-09-10T20:17:22.217Z,1599769042.217 [BPC1](INFO): Calculating totals. Valid battery stick count: 50. Valid reserve battery stick count: 5.
2020-09-10T20:17:22.220Z,1599769042.220 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle.
2020-09-10T20:18:38.965Z,1599769118.965 [NAL9602](INFO): SBD MO Status=2, MOMSN=9601, MT Status=2, MTMSN=0
2020-09-10T20:18:38.965Z,1599769118.965 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-09-10T20:19:02.807Z,1599769142.807 [NAL9602](INFO): SBD MO Status=2, MOMSN=9601, MT Status=2, MTMSN=0
2020-09-10T20:19:02.807Z,1599769142.807 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-09-10T20:19:49.265Z,1599769189.265 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-09-10T20:20:14.333Z,1599769214.333 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-09-10T20:20:14.333Z,1599769214.333 [Default:CheckIn:C.Wait] Stopped
2020-09-10T20:20:14.333Z,1599769214.333 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-09-10T20:20:14.333Z,1599769214.333 [Default:CheckIn:D] Running Loop=1
2020-09-10T20:20:14.726Z,1599769214.726 [Default:CheckIn:D] Stopped
2020-09-10T20:20:14.726Z,1599769214.726 [Default:CheckIn:E] Running Loop=1
2020-09-10T20:20:15.131Z,1599769215.131 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.713715 min 
2020-09-10T20:20:15.131Z,1599769215.131 [Default:CheckIn:E] Stopped
2020-09-10T20:20:15.131Z,1599769215.131 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-09-10T20:20:15.131Z,1599769215.131 [Default:CheckIn] Stopped
2020-09-10T20:20:15.131Z,1599769215.131 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-09-10T20:20:15.131Z,1599769215.131 [Default:CheckIn](INFO): Running loop #6
2020-09-10T20:20:15.131Z,1599769215.131 [Default:CheckIn] Running Loop=6
2020-09-10T20:20:15.132Z,1599769215.132 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-09-10T20:20:15.132Z,1599769215.132 [Default:CheckIn:Read_GPS] Running Loop=1
2020-09-10T20:20:17.138Z,1599769217.138 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202016.00,A,3648.16393,N,12147.28437,W,0.272,0.00,100920,,,A*7A
2020-09-10T20:20:17.141Z,1599769217.141 [NAL9602](INFO): GPS fix at 20200910T202016: (36.802732, -121.788073)
2020-09-10T20:20:17.151Z,1599769217.151 [Default:CheckIn:Read_GPS] Stopped
2020-09-10T20:20:17.151Z,1599769217.151 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-09-10T20:20:24.360Z,1599769224.360 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20200910T194609/Courier0019.lzma
2020-09-10T20:20:25.361Z,1599769225.361 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Courier0019.lzma.bak
2020-09-10T20:20:25.362Z,1599769225.362 [DataOverHttps](INFO): SBD MOMSN=12647851
2020-09-10T20:20:43.716Z,1599769243.716 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20200910T194609/Express0020.lzma
2020-09-10T20:20:45.932Z,1599769245.932 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Express0020.lzma.bak
2020-09-10T20:20:45.933Z,1599769245.933 [DataOverHttps](INFO): SBD MOMSN=12647855
2020-09-10T20:20:46.655Z,1599769246.655 [Default:CheckIn:Read_Iridium] Stopped
2020-09-10T20:20:46.655Z,1599769246.655 [Default:CheckIn:C.Wait] Running Loop=1
2020-09-10T20:20:46.677Z,1599769246.677 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-09-10T20:20:49.473Z,1599769249.473 [NAL9602](INFO): Not Powering down - fast GPS
2020-09-10T20:25:47.230Z,1599769547.230 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-09-10T20:25:47.230Z,1599769547.230 [Default:CheckIn:C.Wait] Stopped
2020-09-10T20:25:47.230Z,1599769547.230 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-09-10T20:25:47.230Z,1599769547.230 [Default:CheckIn:D] Running Loop=1
2020-09-10T20:25:47.635Z,1599769547.635 [Default:CheckIn:D] Stopped
2020-09-10T20:25:47.635Z,1599769547.635 [Default:CheckIn:E] Running Loop=1
2020-09-10T20:25:48.051Z,1599769548.051 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 35.262187 min 
2020-09-10T20:25:48.051Z,1599769548.051 [Default:CheckIn:E] Stopped
2020-09-10T20:25:48.051Z,1599769548.051 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-09-10T20:25:48.051Z,1599769548.051 [Default:CheckIn] Stopped
2020-09-10T20:25:48.052Z,1599769548.052 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-09-10T20:25:48.052Z,1599769548.052 [Default:CheckIn](INFO): Running loop #7
2020-09-10T20:25:48.052Z,1599769548.052 [Default:CheckIn] Running Loop=7
2020-09-10T20:25:48.052Z,1599769548.052 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-09-10T20:25:48.052Z,1599769548.052 [Default:CheckIn:Read_GPS] Running Loop=1
2020-09-10T20:25:50.055Z,1599769550.055 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202549.00,A,3648.15931,N,12147.27461,W,0.467,0.00,100920,,,A*7A
2020-09-10T20:25:50.066Z,1599769550.066 [NAL9602](INFO): GPS fix at 20200910T202549: (36.802655, -121.787910)
2020-09-10T20:25:50.076Z,1599769550.076 [Default:CheckIn:Read_GPS] Stopped
2020-09-10T20:25:50.076Z,1599769550.076 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-09-10T20:25:57.275Z,1599769557.275 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200910T194609/Courier0022.lzma
2020-09-10T20:25:58.278Z,1599769558.278 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Courier0022.lzma.bak
2020-09-10T20:25:58.278Z,1599769558.278 [DataOverHttps](INFO): SBD MOMSN=12647859
2020-09-10T20:26:14.304Z,1599769574.304 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20200910T194609/Express0023.lzma
2020-09-10T20:26:15.306Z,1599769575.306 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Express0023.lzma.bak
2020-09-10T20:26:15.306Z,1599769575.306 [DataOverHttps](INFO): SBD MOMSN=12647862
2020-09-10T20:26:17.135Z,1599769577.135 [Default:CheckIn:Read_Iridium] Stopped
2020-09-10T20:26:17.135Z,1599769577.135 [Default:CheckIn:C.Wait] Running Loop=1
2020-09-10T20:26:17.135Z,1599769577.135 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-09-10T20:26:20.758Z,1599769580.758 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2020-09-10T20:26:20.832Z,1599769580.832 [NAL9602](FAULT): received: 
+CSQ:0

OK01, 2, 0, 0, 0

OK
2020-09-10T20:26:20.832Z,1599769580.832 [NAL9602] Data Fault, FailCount= 1
2020-09-10T20:26:20.832Z,1599769580.832 [NAL9602](ERROR): Data Fault
2020-09-10T20:26:20.852Z,1599769580.852 [CBIT](ERROR): Data Fault in component: NAL9602
2020-09-10T20:26:21.157Z,1599769581.157 [NAL9602](INFO): Powering down
2020-09-10T20:26:21.992Z,1599769581.992 [CBIT](INFO): Clearing failed state for component NAL9602
2020-09-10T20:26:21.992Z,1599769581.992 [NAL9602] No Fault, FailCount= 1
2020-09-10T20:26:51.483Z,1599769611.483 [NAL9602](INFO): Powering up NAL9602
2020-09-10T20:27:02.389Z,1599769622.389 [NAL9602](INFO): NAL9602 initialized
2020-09-10T20:27:33.506Z,1599769653.506 [NAL9602](INFO): Not Powering down - fast GPS
2020-09-10T20:31:17.755Z,1599769877.755 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-09-10T20:31:17.755Z,1599769877.755 [Default:CheckIn:C.Wait] Stopped
2020-09-10T20:31:17.755Z,1599769877.755 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-09-10T20:31:17.756Z,1599769877.756 [Default:CheckIn:D] Running Loop=1
2020-09-10T20:31:18.163Z,1599769878.163 [Default:CheckIn:D] Stopped
2020-09-10T20:31:18.163Z,1599769878.163 [Default:CheckIn:E] Running Loop=1
2020-09-10T20:31:18.553Z,1599769878.553 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 40.770988 min 
2020-09-10T20:31:18.553Z,1599769878.553 [Default:CheckIn:E] Stopped
2020-09-10T20:31:18.553Z,1599769878.553 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-09-10T20:31:18.553Z,1599769878.553 [Default:CheckIn] Stopped
2020-09-10T20:31:18.554Z,1599769878.554 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-09-10T20:31:18.554Z,1599769878.554 [Default:CheckIn](INFO): Running loop #8
2020-09-10T20:31:18.554Z,1599769878.554 [Default:CheckIn] Running Loop=8
2020-09-10T20:31:18.554Z,1599769878.554 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-09-10T20:31:18.554Z,1599769878.554 [Default:CheckIn:Read_GPS] Running Loop=1
2020-09-10T20:31:20.567Z,1599769880.567 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203118.00,A,3648.16627,N,12147.28960,W,0.272,0.00,100920,,,A*71
2020-09-10T20:31:20.569Z,1599769880.569 [NAL9602](INFO): GPS fix at 20200910T203118: (36.802771, -121.788160)
2020-09-10T20:31:20.579Z,1599769880.579 [Default:CheckIn:Read_GPS] Stopped
2020-09-10T20:31:20.579Z,1599769880.579 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-09-10T20:31:22.181Z,1599769882.181 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-09-10T20:31:23.885Z,1599769883.885 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2020-09-10T20:31:23.885Z,1599769883.885 [DropWeight] Hardware Fault, FailCount= 1
2020-09-10T20:31:23.885Z,1599769883.885 [DropWeight](ERROR): Hardware Fault
2020-09-10T20:31:23.958Z,1599769883.958 [CBIT](INFO): Critical error at 20200910T203123
2020-09-10T20:31:23.970Z,1599769883.970 [CBIT](ERROR): Hardware Fault in component: DropWeight
2020-09-10T20:31:23.971Z,1599769883.971 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2020-09-10T20:31:24.250Z,1599769884.250 [CBIT](INFO): Critical error at 20200910T203123
2020-09-10T20:31:28.015Z,1599769888.015 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200910T194609/Courier0025.lzma
2020-09-10T20:31:29.017Z,1599769889.017 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Courier0025.lzma.bak
2020-09-10T20:31:29.018Z,1599769889.018 [DataOverHttps](INFO): SBD MOMSN=12647865
2020-09-10T20:31:45.220Z,1599769905.220 [DataOverHttps](INFO): Sending 184 bytes from file Logs/20200910T194609/Express0026.lzma
2020-09-10T20:31:46.221Z,1599769906.221 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Express0026.lzma.bak
2020-09-10T20:31:46.222Z,1599769906.222 [DataOverHttps](INFO): SBD MOMSN=12647868
2020-09-10T20:31:48.063Z,1599769908.063 [Default:CheckIn:Read_Iridium] Stopped
2020-09-10T20:31:48.063Z,1599769908.063 [Default:CheckIn:C.Wait] Running Loop=1
2020-09-10T20:31:48.063Z,1599769908.063 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-09-10T20:31:52.890Z,1599769912.890 [NAL9602](INFO): Not Powering down - fast GPS
2020-09-10T20:36:48.646Z,1599770208.646 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-09-10T20:36:48.646Z,1599770208.646 [Default:CheckIn:C.Wait] Stopped
2020-09-10T20:36:48.646Z,1599770208.646 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-09-10T20:36:48.646Z,1599770208.646 [Default:CheckIn:D] Running Loop=1
2020-09-10T20:36:49.064Z,1599770209.064 [Default:CheckIn:D] Stopped
2020-09-10T20:36:49.064Z,1599770209.064 [Default:CheckIn:E] Running Loop=1
2020-09-10T20:36:49.449Z,1599770209.449 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 46.286015 min 
2020-09-10T20:36:49.449Z,1599770209.449 [Default:CheckIn:E] Stopped
2020-09-10T20:36:49.449Z,1599770209.449 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-09-10T20:36:49.450Z,1599770209.450 [Default:CheckIn] Stopped
2020-09-10T20:36:49.450Z,1599770209.450 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-09-10T20:36:49.450Z,1599770209.450 [Default:CheckIn](INFO): Running loop #9
2020-09-10T20:36:49.450Z,1599770209.450 [Default:CheckIn] Running Loop=9
2020-09-10T20:36:49.450Z,1599770209.450 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-09-10T20:36:49.450Z,1599770209.450 [Default:CheckIn:Read_GPS] Running Loop=1
2020-09-10T20:36:51.463Z,1599770211.463 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203650.00,A,3648.16369,N,12147.29021,W,0.233,0.00,100920,,,A*7D
2020-09-10T20:36:51.465Z,1599770211.465 [NAL9602](INFO): GPS fix at 20200910T203650: (36.802728, -121.788170)
2020-09-10T20:36:51.475Z,1599770211.475 [Default:CheckIn:Read_GPS] Stopped
2020-09-10T20:36:51.475Z,1599770211.475 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-09-10T20:36:58.399Z,1599770218.399 [DataOverHttps](INFO): Sending 148 bytes from file Logs/20200910T194609/Courier0028.lzma
2020-09-10T20:36:59.401Z,1599770219.401 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Courier0028.lzma.bak
2020-09-10T20:36:59.402Z,1599770219.402 [DataOverHttps](INFO): SBD MOMSN=12647872
2020-09-10T20:37:15.272Z,1599770235.272 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20200910T194609/Express0029.lzma
2020-09-10T20:37:16.274Z,1599770236.274 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Express0029.lzma.bak
2020-09-10T20:37:16.274Z,1599770236.274 [DataOverHttps](INFO): SBD MOMSN=12647877
2020-09-10T20:37:18.214Z,1599770238.214 [Default:CheckIn:Read_Iridium] Stopped
2020-09-10T20:37:18.214Z,1599770238.214 [Default:CheckIn:C.Wait] Running Loop=1
2020-09-10T20:37:18.215Z,1599770238.215 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-09-10T20:41:53.317Z,1599770513.317 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-09-10T20:42:18.786Z,1599770538.786 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-09-10T20:42:18.786Z,1599770538.786 [Default:CheckIn:C.Wait] Stopped
2020-09-10T20:42:18.786Z,1599770538.786 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-09-10T20:42:18.786Z,1599770538.786 [Default:CheckIn:D] Running Loop=1
2020-09-10T20:42:19.181Z,1599770539.181 [Default:CheckIn:D] Stopped
2020-09-10T20:42:19.181Z,1599770539.181 [Default:CheckIn:E] Running Loop=1
2020-09-10T20:42:19.591Z,1599770539.591 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.787960 min 
2020-09-10T20:42:19.591Z,1599770539.591 [Default:CheckIn:E] Stopped
2020-09-10T20:42:19.591Z,1599770539.591 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-09-10T20:42:19.591Z,1599770539.591 [Default:CheckIn] Stopped
2020-09-10T20:42:19.592Z,1599770539.592 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-09-10T20:42:19.592Z,1599770539.592 [Default:CheckIn](INFO): Running loop #10
2020-09-10T20:42:19.592Z,1599770539.592 [Default:CheckIn] Running Loop=10
2020-09-10T20:42:19.592Z,1599770539.592 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-09-10T20:42:19.592Z,1599770539.592 [Default:CheckIn:Read_GPS] Running Loop=1
2020-09-10T20:42:21.598Z,1599770541.598 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204220.00,A,3648.16531,N,12147.28611,W,0.369,0.00,100920,,,A*78
2020-09-10T20:42:21.600Z,1599770541.600 [NAL9602](INFO): GPS fix at 20200910T204220: (36.802755, -121.788102)
2020-09-10T20:42:21.611Z,1599770541.611 [Default:CheckIn:Read_GPS] Stopped
2020-09-10T20:42:21.611Z,1599770541.611 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-09-10T20:42:28.501Z,1599770548.501 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20200910T194609/Courier0031.lzma
2020-09-10T20:42:29.501Z,1599770549.501 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Courier0031.lzma.bak
2020-09-10T20:42:29.502Z,1599770549.502 [DataOverHttps](INFO): SBD MOMSN=12647881
2020-09-10T20:42:45.197Z,1599770565.197 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20200910T194609/Express0032.lzma
2020-09-10T20:42:46.198Z,1599770566.198 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Express0032.lzma.bak
2020-09-10T20:42:46.198Z,1599770566.198 [DataOverHttps](INFO): SBD MOMSN=12647884
2020-09-10T20:42:47.886Z,1599770567.886 [Default:CheckIn:Read_Iridium] Stopped
2020-09-10T20:42:47.887Z,1599770567.887 [Default:CheckIn:C.Wait] Running Loop=1
2020-09-10T20:42:47.887Z,1599770567.887 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-09-10T20:42:53.521Z,1599770573.521 [NAL9602](INFO): Not Powering down - fast GPS
2020-09-10T20:46:24.064Z,1599770784.064 [CBIT](INFO): Clearing failed state for component DropWeight
2020-09-10T20:46:24.064Z,1599770784.064 [DropWeight] No Fault, FailCount= 1
2020-09-10T20:47:48.447Z,1599770868.447 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-09-10T20:47:48.447Z,1599770868.447 [Default:CheckIn:C.Wait] Stopped
2020-09-10T20:47:48.447Z,1599770868.447 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-09-10T20:47:48.447Z,1599770868.447 [Default:CheckIn:D] Running Loop=1
2020-09-10T20:47:48.855Z,1599770868.855 [Default:CheckIn:D] Stopped
2020-09-10T20:47:48.855Z,1599770868.855 [Default:CheckIn:E] Running Loop=1
2020-09-10T20:47:49.267Z,1599770869.267 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 57.282524 min 
2020-09-10T20:47:49.267Z,1599770869.267 [Default:CheckIn:E] Stopped
2020-09-10T20:47:49.267Z,1599770869.267 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-09-10T20:47:49.267Z,1599770869.267 [Default:CheckIn] Stopped
2020-09-10T20:47:49.268Z,1599770869.268 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-09-10T20:47:49.268Z,1599770869.268 [Default:CheckIn](INFO): Running loop #11
2020-09-10T20:47:49.268Z,1599770869.268 [Default:CheckIn] Running Loop=11
2020-09-10T20:47:49.268Z,1599770869.268 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-09-10T20:47:49.268Z,1599770869.268 [Default:CheckIn:Read_GPS] Running Loop=1
2020-09-10T20:47:51.265Z,1599770871.265 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204750.00,A,3648.15953,N,12147.27690,W,0.894,0.00,100920,,,A*7E
2020-09-10T20:47:51.267Z,1599770871.267 [NAL9602](INFO): GPS fix at 20200910T204750: (36.802659, -121.787948)
2020-09-10T20:47:51.278Z,1599770871.278 [Default:CheckIn:Read_GPS] Stopped
2020-09-10T20:47:51.278Z,1599770871.278 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-09-10T20:47:58.887Z,1599770878.887 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200910T194609/Courier0034.lzma
2020-09-10T20:47:59.889Z,1599770879.889 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Courier0034.lzma.bak
2020-09-10T20:47:59.890Z,1599770879.890 [DataOverHttps](INFO): SBD MOMSN=12647888
2020-09-10T20:48:15.684Z,1599770895.684 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20200910T194609/Express0035.lzma
2020-09-10T20:48:16.685Z,1599770896.685 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Express0035.lzma.bak
2020-09-10T20:48:16.686Z,1599770896.686 [DataOverHttps](INFO): SBD MOMSN=12647891
2020-09-10T20:48:18.348Z,1599770898.348 [Default:CheckIn:Read_Iridium] Stopped
2020-09-10T20:48:18.348Z,1599770898.348 [Default:CheckIn:C.Wait] Running Loop=1
2020-09-10T20:48:18.348Z,1599770898.348 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-09-10T20:48:21.973Z,1599770901.973 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2020-09-10T20:48:22.056Z,1599770902.056 [NAL9602](FAULT): received: 
+CSQ:0

OK01, 2, 0, 0, 0

OK
2020-09-10T20:48:22.056Z,1599770902.056 [NAL9602] Data Fault, FailCount= 1
2020-09-10T20:48:22.056Z,1599770902.056 [NAL9602](ERROR): Data Fault
2020-09-10T20:48:22.111Z,1599770902.111 [CBIT](ERROR): Data Fault in component: NAL9602
2020-09-10T20:48:22.373Z,1599770902.373 [NAL9602](INFO): Powering down
2020-09-10T20:48:22.777Z,1599770902.777 [NAL9602](FAULT): LCB fault:  Software Overcurrent.
2020-09-10T20:48:22.777Z,1599770902.777 [NAL9602] Hardware Fault, FailCount= 1
2020-09-10T20:48:22.777Z,1599770902.777 [NAL9602](ERROR): Hardware Fault
2020-09-10T20:48:23.200Z,1599770903.200 [CBIT](INFO): Clearing failed state for component NAL9602
2020-09-10T20:48:23.200Z,1599770903.200 [NAL9602] No Fault, FailCount= 1
2020-09-10T20:48:52.681Z,1599770932.681 [NAL9602](INFO): Powering up NAL9602
2020-09-10T20:49:03.581Z,1599770943.581 [NAL9602](INFO): NAL9602 initialized
2020-09-10T20:49:34.689Z,1599770974.689 [NAL9602](INFO): Not Powering down - fast GPS
2020-09-10T20:53:18.922Z,1599771198.922 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-09-10T20:53:18.922Z,1599771198.922 [Default:CheckIn:C.Wait] Stopped
2020-09-10T20:53:18.922Z,1599771198.922 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-09-10T20:53:18.923Z,1599771198.923 [Default:CheckIn:D] Running Loop=1
2020-09-10T20:53:19.334Z,1599771199.334 [Default:CheckIn:D] Stopped
2020-09-10T20:53:19.334Z,1599771199.334 [Default:CheckIn:E] Running Loop=1
2020-09-10T20:53:19.725Z,1599771199.725 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.790507 min 
2020-09-10T20:53:19.725Z,1599771199.725 [Default:CheckIn:E] Stopped
2020-09-10T20:53:19.726Z,1599771199.726 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-09-10T20:53:19.726Z,1599771199.726 [Default:CheckIn] Stopped
2020-09-10T20:53:19.726Z,1599771199.726 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-09-10T20:53:19.726Z,1599771199.726 [Default:CheckIn](INFO): Running loop #12
2020-09-10T20:53:19.726Z,1599771199.726 [Default:CheckIn] Running Loop=12
2020-09-10T20:53:19.726Z,1599771199.726 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-09-10T20:53:19.726Z,1599771199.726 [Default:CheckIn:Read_GPS] Running Loop=1
2020-09-10T20:53:21.743Z,1599771201.743 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205320.00,A,3648.16299,N,12147.28159,W,0.680,332.32,100920,,,A*77
2020-09-10T20:53:21.745Z,1599771201.745 [NAL9602](INFO): GPS fix at 20200910T205320: (36.802717, -121.788027)
2020-09-10T20:53:21.755Z,1599771201.755 [Default:CheckIn:Read_GPS] Stopped
2020-09-10T20:53:21.755Z,1599771201.755 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-09-10T20:53:24.165Z,1599771204.165 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-09-10T20:53:29.011Z,1599771209.011 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20200910T194609/Courier0037.lzma
2020-09-10T20:53:30.014Z,1599771210.014 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Courier0037.lzma.bak
2020-09-10T20:53:30.014Z,1599771210.014 [DataOverHttps](INFO): SBD MOMSN=12647894
2020-09-10T20:53:45.712Z,1599771225.712 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20200910T194609/Express0038.lzma
2020-09-10T20:53:46.714Z,1599771226.714 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Express0038.lzma.bak
2020-09-10T20:53:46.714Z,1599771226.714 [DataOverHttps](INFO): SBD MOMSN=12647897
2020-09-10T20:53:48.418Z,1599771228.418 [Default:CheckIn:Read_Iridium] Stopped
2020-09-10T20:53:48.418Z,1599771228.418 [Default:CheckIn:C.Wait] Running Loop=1
2020-09-10T20:53:48.418Z,1599771228.418 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-09-10T20:53:54.872Z,1599771234.872 [NAL9602](INFO): Not Powering down - fast GPS
2020-09-10T20:58:48.999Z,1599771528.999 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-09-10T20:58:48.000Z,1599771529.000 [Default:CheckIn:C.Wait] Stopped
2020-09-10T20:58:48.000Z,1599771529.000 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-09-10T20:58:48.000Z,1599771529.000 [Default:CheckIn:D] Running Loop=1
2020-09-10T20:58:49.389Z,1599771529.389 [Default:CheckIn:D] Stopped
2020-09-10T20:58:49.389Z,1599771529.389 [Default:CheckIn:E] Running Loop=1
2020-09-10T20:58:49.796Z,1599771529.796 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 68.291431 min 
2020-09-10T20:58:49.796Z,1599771529.796 [Default:CheckIn:E] Stopped
2020-09-10T20:58:49.796Z,1599771529.796 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-09-10T20:58:49.796Z,1599771529.796 [Default:CheckIn] Stopped
2020-09-10T20:58:49.796Z,1599771529.796 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-09-10T20:58:49.796Z,1599771529.796 [Default:CheckIn](INFO): Running loop #13
2020-09-10T20:58:49.796Z,1599771529.796 [Default:CheckIn] Running Loop=13
2020-09-10T20:58:49.797Z,1599771529.797 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-09-10T20:58:49.797Z,1599771529.797 [Default:CheckIn:Read_GPS] Running Loop=1
2020-09-10T20:58:51.807Z,1599771531.807 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205850.00,A,3648.16708,N,12147.29119,W,0.428,332.32,100920,,,A*73
2020-09-10T20:58:51.809Z,1599771531.809 [NAL9602](INFO): GPS fix at 20200910T205850: (36.802785, -121.788186)
2020-09-10T20:58:51.820Z,1599771531.820 [Default:CheckIn:Read_GPS] Stopped
2020-09-10T20:58:51.820Z,1599771531.820 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-09-10T20:58:59.067Z,1599771539.067 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200910T194609/Courier0040.lzma
2020-09-10T20:59:00.070Z,1599771540.070 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Courier0040.lzma.bak
2020-09-10T20:59:00.070Z,1599771540.070 [DataOverHttps](INFO): SBD MOMSN=12647902
2020-09-10T20:59:16.936Z,1599771556.936 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20200910T194609/Express0041.lzma
2020-09-10T20:59:17.937Z,1599771557.937 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Express0041.lzma.bak
2020-09-10T20:59:17.938Z,1599771557.938 [DataOverHttps](INFO): SBD MOMSN=12647905
2020-09-10T20:59:19.699Z,1599771559.699 [Default:CheckIn:Read_Iridium] Stopped
2020-09-10T20:59:19.699Z,1599771559.699 [Default:CheckIn:C.Wait] Running Loop=1
2020-09-10T20:59:19.699Z,1599771559.699 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-09-10T21:02:17.470Z,1599771737.470 [NAL9602](INFO): SBD MO Status=2, MOMSN=9601, MT Status=2, MTMSN=0
2020-09-10T21:02:17.470Z,1599771737.470 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-09-10T21:03:54.426Z,1599771834.426 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-09-10T21:04:20.310Z,1599771860.310 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-09-10T21:04:20.310Z,1599771860.310 [Default:CheckIn:C.Wait] Stopped
2020-09-10T21:04:20.310Z,1599771860.310 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-09-10T21:04:20.311Z,1599771860.311 [Default:CheckIn:D] Running Loop=1
2020-09-10T21:04:20.725Z,1599771860.725 [Default:CheckIn:D] Stopped
2020-09-10T21:04:20.726Z,1599771860.726 [Default:CheckIn:E] Running Loop=1
2020-09-10T21:04:21.122Z,1599771861.122 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 73.813704 min 
2020-09-10T21:04:21.122Z,1599771861.122 [Default:CheckIn:E] Stopped
2020-09-10T21:04:21.123Z,1599771861.123 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-09-10T21:04:21.123Z,1599771861.123 [Default:CheckIn] Stopped
2020-09-10T21:04:21.123Z,1599771861.123 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-09-10T21:04:21.123Z,1599771861.123 [Default:CheckIn](INFO): Running loop #14
2020-09-10T21:04:21.123Z,1599771861.123 [Default:CheckIn] Running Loop=14
2020-09-10T21:04:21.123Z,1599771861.123 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-09-10T21:04:21.123Z,1599771861.123 [Default:CheckIn:Read_GPS] Running Loop=1
2020-09-10T21:04:23.135Z,1599771863.135 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210422.00,A,3648.16609,N,12147.28403,W,0.525,332.32,100920,,,A*7D
2020-09-10T21:04:23.137Z,1599771863.137 [NAL9602](INFO): GPS fix at 20200910T210422: (36.802768, -121.788067)
2020-09-10T21:04:23.148Z,1599771863.148 [Default:CheckIn:Read_GPS] Stopped
2020-09-10T21:04:23.148Z,1599771863.148 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-09-10T21:04:30.975Z,1599771870.975 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200910T194609/Courier0043.lzma
2020-09-10T21:04:31.977Z,1599771871.977 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Courier0043.lzma.bak
2020-09-10T21:04:31.978Z,1599771871.978 [DataOverHttps](INFO): SBD MOMSN=12647909
2020-09-10T21:04:47.768Z,1599771887.768 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20200910T194609/Express0044.lzma
2020-09-10T21:04:48.770Z,1599771888.770 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Express0044.lzma.bak
2020-09-10T21:04:48.770Z,1599771888.770 [DataOverHttps](INFO): SBD MOMSN=12647912
2020-09-10T21:04:50.620Z,1599771890.620 [Default:CheckIn:Read_Iridium] Stopped
2020-09-10T21:04:50.620Z,1599771890.620 [Default:CheckIn:C.Wait] Running Loop=1
2020-09-10T21:04:50.620Z,1599771890.620 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-09-10T21:04:55.449Z,1599771895.449 [NAL9602](INFO): Not Powering down - fast GPS
2020-09-10T21:09:51.201Z,1599772191.201 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-09-10T21:09:51.201Z,1599772191.201 [Default:CheckIn:C.Wait] Stopped
2020-09-10T21:09:51.201Z,1599772191.201 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-09-10T21:09:51.201Z,1599772191.201 [Default:CheckIn:D] Running Loop=1
2020-09-10T21:09:51.612Z,1599772191.612 [Default:CheckIn:D] Stopped
2020-09-10T21:09:51.613Z,1599772191.613 [Default:CheckIn:E] Running Loop=1
2020-09-10T21:09:52.028Z,1599772192.028 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 79.328483 min 
2020-09-10T21:09:52.028Z,1599772192.028 [Default:CheckIn:E] Stopped
2020-09-10T21:09:52.028Z,1599772192.028 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-09-10T21:09:52.028Z,1599772192.028 [Default:CheckIn] Stopped
2020-09-10T21:09:52.028Z,1599772192.028 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-09-10T21:09:52.028Z,1599772192.028 [Default:CheckIn](INFO): Running loop #15
2020-09-10T21:09:52.028Z,1599772192.028 [Default:CheckIn] Running Loop=15
2020-09-10T21:09:52.029Z,1599772192.029 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-09-10T21:09:52.029Z,1599772192.029 [Default:CheckIn:Read_GPS] Running Loop=1
2020-09-10T21:09:54.027Z,1599772194.027 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210953.00,A,3648.16462,N,12147.28237,W,0.214,332.32,100920,,,A*7D
2020-09-10T21:09:54.030Z,1599772194.030 [NAL9602](INFO): GPS fix at 20200910T210953: (36.802744, -121.788039)
2020-09-10T21:09:54.061Z,1599772194.061 [Default:CheckIn:Read_GPS] Stopped
2020-09-10T21:09:54.061Z,1599772194.061 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-09-10T21:10:01.283Z,1599772201.283 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200910T194609/Courier0046.lzma
2020-09-10T21:10:02.286Z,1599772202.286 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Courier0046.lzma.bak
2020-09-10T21:10:02.286Z,1599772202.286 [DataOverHttps](INFO): SBD MOMSN=12647916
2020-09-10T21:10:18.304Z,1599772218.304 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20200910T194609/Express0047.lzma
2020-09-10T21:10:19.306Z,1599772219.306 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Express0047.lzma.bak
2020-09-10T21:10:19.306Z,1599772219.306 [DataOverHttps](INFO): SBD MOMSN=12647919
2020-09-10T21:10:21.098Z,1599772221.098 [Default:CheckIn:Read_Iridium] Stopped
2020-09-10T21:10:21.099Z,1599772221.099 [Default:CheckIn:C.Wait] Running Loop=1
2020-09-10T21:10:21.099Z,1599772221.099 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-09-10T21:10:24.725Z,1599772224.725 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2020-09-10T21:10:24.800Z,1599772224.800 [NAL9602](FAULT): received: 
+CSQ:0

OK01, 2, 0, 0, 0

OK
2020-09-10T21:10:24.800Z,1599772224.800 [NAL9602] Data Fault, FailCount= 1
2020-09-10T21:10:24.800Z,1599772224.800 [NAL9602](ERROR): Data Fault
2020-09-10T21:10:24.822Z,1599772224.822 [CBIT](ERROR): Data Fault in component: NAL9602
2020-09-10T21:10:25.129Z,1599772225.129 [NAL9602](INFO): Powering down
2020-09-10T21:10:25.963Z,1599772225.963 [CBIT](INFO): Clearing failed state for component NAL9602
2020-09-10T21:10:25.963Z,1599772225.963 [NAL9602] No Fault, FailCount= 1
2020-09-10T21:10:55.433Z,1599772255.433 [NAL9602](INFO): Powering up NAL9602
2020-09-10T21:11:06.339Z,1599772266.339 [NAL9602](INFO): NAL9602 initialized
2020-09-10T21:11:37.445Z,1599772297.445 [NAL9602](INFO): Not Powering down - fast GPS
2020-09-10T21:15:21.678Z,1599772521.678 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-09-10T21:15:21.678Z,1599772521.678 [Default:CheckIn:C.Wait] Stopped
2020-09-10T21:15:21.678Z,1599772521.678 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-09-10T21:15:21.678Z,1599772521.678 [Default:CheckIn:D] Running Loop=1
2020-09-10T21:15:22.079Z,1599772522.079 [Default:CheckIn:D] Stopped
2020-09-10T21:15:22.079Z,1599772522.079 [Default:CheckIn:E] Running Loop=1
2020-09-10T21:15:22.494Z,1599772522.494 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 84.836263 min 
2020-09-10T21:15:22.494Z,1599772522.494 [Default:CheckIn:E] Stopped
2020-09-10T21:15:22.494Z,1599772522.494 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-09-10T21:15:22.494Z,1599772522.494 [Default:CheckIn] Stopped
2020-09-10T21:15:22.494Z,1599772522.494 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-09-10T21:15:22.495Z,1599772522.495 [Default:CheckIn](INFO): Running loop #16
2020-09-10T21:15:22.495Z,1599772522.495 [Default:CheckIn] Running Loop=16
2020-09-10T21:15:22.495Z,1599772522.495 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-09-10T21:15:22.495Z,1599772522.495 [Default:CheckIn:Read_GPS] Running Loop=1
2020-09-10T21:15:24.493Z,1599772524.493 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211523.00,A,3648.16563,N,12147.27546,W,0.253,0.00,100920,,,A*79
2020-09-10T21:15:24.495Z,1599772524.495 [NAL9602](INFO): GPS fix at 20200910T211523: (36.802760, -121.787924)
2020-09-10T21:15:24.506Z,1599772524.506 [Default:CheckIn:Read_GPS] Stopped
2020-09-10T21:15:24.506Z,1599772524.506 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-09-10T21:15:26.125Z,1599772526.125 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-09-10T21:15:31.339Z,1599772531.339 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200910T194609/Courier0049.lzma
2020-09-10T21:15:32.343Z,1599772532.343 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Courier0049.lzma.bak
2020-09-10T21:15:32.343Z,1599772532.343 [DataOverHttps](INFO): SBD MOMSN=12647922
2020-09-10T21:15:49.324Z,1599772549.324 [DataOverHttps](INFO): Sending 172 bytes from file Logs/20200910T194609/Express0050.lzma
2020-09-10T21:15:50.326Z,1599772550.326 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Express0050.lzma.bak
2020-09-10T21:15:50.326Z,1599772550.326 [DataOverHttps](INFO): SBD MOMSN=12647925
2020-09-10T21:15:51.987Z,1599772551.987 [Default:CheckIn:Read_Iridium] Stopped
2020-09-10T21:15:51.987Z,1599772551.987 [Default:CheckIn:C.Wait] Running Loop=1
2020-09-10T21:15:51.987Z,1599772551.987 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-09-10T21:15:56.825Z,1599772556.825 [NAL9602](INFO): Not Powering down - fast GPS
2020-09-10T21:16:25.509Z,1599772585.509 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2020-09-10T21:16:25.509Z,1599772585.509 [DropWeight] Hardware Fault, FailCount= 1
2020-09-10T21:16:25.509Z,1599772585.509 [DropWeight](ERROR): Hardware Fault
2020-09-10T21:16:25.530Z,1599772585.530 [CBIT](INFO): Critical error at 20200910T211625
2020-09-10T21:16:25.532Z,1599772585.532 [CBIT](ERROR): Hardware Fault in component: DropWeight
2020-09-10T21:16:25.533Z,1599772585.533 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2020-09-10T21:16:25.964Z,1599772585.964 [CBIT](INFO): Critical error at 20200910T211625
2020-09-10T21:20:52.579Z,1599772852.579 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-09-10T21:20:52.580Z,1599772852.580 [Default:CheckIn:C.Wait] Stopped
2020-09-10T21:20:52.580Z,1599772852.580 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-09-10T21:20:52.580Z,1599772852.580 [Default:CheckIn:D] Running Loop=1
2020-09-10T21:20:52.965Z,1599772852.965 [Default:CheckIn:D] Stopped
2020-09-10T21:20:52.965Z,1599772852.965 [Default:CheckIn:E] Running Loop=1
2020-09-10T21:20:53.375Z,1599772853.375 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 90.351034 min 
2020-09-10T21:20:53.375Z,1599772853.375 [Default:CheckIn:E] Stopped
2020-09-10T21:20:53.375Z,1599772853.375 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-09-10T21:20:53.375Z,1599772853.375 [Default:CheckIn] Stopped
2020-09-10T21:20:53.376Z,1599772853.376 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-09-10T21:20:53.376Z,1599772853.376 [Default:CheckIn](INFO): Running loop #17
2020-09-10T21:20:53.376Z,1599772853.376 [Default:CheckIn] Running Loop=17
2020-09-10T21:20:53.376Z,1599772853.376 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-09-10T21:20:53.376Z,1599772853.376 [Default:CheckIn:Read_GPS] Running Loop=1
2020-09-10T21:20:55.387Z,1599772855.387 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212054.00,A,3648.16296,N,12147.28332,W,0.117,0.00,100920,,,A*7B
2020-09-10T21:20:55.389Z,1599772855.389 [NAL9602](INFO): GPS fix at 20200910T212054: (36.802716, -121.788055)
2020-09-10T21:20:55.417Z,1599772855.417 [Default:CheckIn:Read_GPS] Stopped
2020-09-10T21:20:55.417Z,1599772855.417 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-09-10T21:21:02.432Z,1599772862.432 [DataOverHttps](INFO): Sending 149 bytes from file Logs/20200910T194609/Courier0052.lzma
2020-09-10T21:21:03.433Z,1599772863.433 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Courier0052.lzma.bak
2020-09-10T21:21:03.434Z,1599772863.434 [DataOverHttps](INFO): SBD MOMSN=12647929
2020-09-10T21:21:19.296Z,1599772879.296 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20200910T194609/Express0053.lzma
2020-09-10T21:21:20.298Z,1599772880.298 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Express0053.lzma.bak
2020-09-10T21:21:20.298Z,1599772880.298 [DataOverHttps](INFO): SBD MOMSN=12647934
2020-09-10T21:21:22.131Z,1599772882.131 [Default:CheckIn:Read_Iridium] Stopped
2020-09-10T21:21:22.131Z,1599772882.131 [Default:CheckIn:C.Wait] Running Loop=1
2020-09-10T21:21:22.131Z,1599772882.131 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-09-10T21:21:30.217Z,1599772890.217 [NAL9602](INFO): SBD MO Status=2, MOMSN=9601, MT Status=2, MTMSN=0
2020-09-10T21:21:30.217Z,1599772890.217 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-09-10T21:26:01.702Z,1599773161.702 [NAL9602](INFO): SBD MO Status=2, MOMSN=9601, MT Status=2, MTMSN=0
2020-09-10T21:26:01.703Z,1599773161.703 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-09-10T21:26:02.109Z,1599773162.109 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-09-10T21:26:22.722Z,1599773182.722 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-09-10T21:26:22.722Z,1599773182.722 [Default:CheckIn:C.Wait] Stopped
2020-09-10T21:26:22.722Z,1599773182.722 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-09-10T21:26:22.723Z,1599773182.723 [Default:CheckIn:D] Running Loop=1
2020-09-10T21:26:23.126Z,1599773183.126 [Default:CheckIn:D] Stopped
2020-09-10T21:26:23.126Z,1599773183.126 [Default:CheckIn:E] Running Loop=1
2020-09-10T21:26:23.535Z,1599773183.535 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 95.853711 min 
2020-09-10T21:26:23.535Z,1599773183.535 [Default:CheckIn:E] Stopped
2020-09-10T21:26:23.535Z,1599773183.535 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-09-10T21:26:23.535Z,1599773183.535 [Default:CheckIn] Stopped
2020-09-10T21:26:23.535Z,1599773183.535 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-09-10T21:26:23.535Z,1599773183.535 [Default:CheckIn](INFO): Running loop #18
2020-09-10T21:26:23.536Z,1599773183.536 [Default:CheckIn] Running Loop=18
2020-09-10T21:26:23.536Z,1599773183.536 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-09-10T21:26:23.536Z,1599773183.536 [Default:CheckIn:Read_GPS] Running Loop=1
2020-09-10T21:26:25.543Z,1599773185.543 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212624.00,A,3648.15927,N,12147.28338,W,0.039,0.00,100920,,,A*7F
2020-09-10T21:26:25.555Z,1599773185.555 [NAL9602](INFO): GPS fix at 20200910T212624: (36.802655, -121.788056)
2020-09-10T21:26:25.582Z,1599773185.582 [Default:CheckIn:Read_GPS] Stopped
2020-09-10T21:26:25.583Z,1599773185.583 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-09-10T21:26:32.435Z,1599773192.435 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20200910T194609/Courier0055.lzma
2020-09-10T21:26:33.438Z,1599773193.438 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Courier0055.lzma.bak
2020-09-10T21:26:33.438Z,1599773193.438 [DataOverHttps](INFO): SBD MOMSN=12647938
2020-09-10T21:26:49.355Z,1599773209.355 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20200910T194609/Express0056.lzma
2020-09-10T21:26:50.358Z,1599773210.358 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Express0056.lzma.bak
2020-09-10T21:26:50.358Z,1599773210.358 [DataOverHttps](INFO): SBD MOMSN=12647941
2020-09-10T21:26:52.275Z,1599773212.275 [Default:CheckIn:Read_Iridium] Stopped
2020-09-10T21:26:52.275Z,1599773212.275 [Default:CheckIn:C.Wait] Running Loop=1
2020-09-10T21:26:52.275Z,1599773212.275 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-09-10T21:26:57.516Z,1599773217.516 [NAL9602](INFO): Not Powering down - fast GPS
2020-09-10T21:29:37.092Z,1599773377.092 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2020-09-10T21:29:50.424Z,1599773390.424 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2020-09-10T21:30:02.958Z,1599773402.958 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2020-09-10T21:30:15.484Z,1599773415.484 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2020-09-10T21:30:28.409Z,1599773428.409 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2020-09-10T21:30:41.469Z,1599773441.469 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2020-09-10T21:30:54.256Z,1599773454.256 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2020-09-10T21:31:07.186Z,1599773467.186 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2020-09-10T21:31:19.714Z,1599773479.714 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2020-09-10T21:31:25.787Z,1599773485.787 [CBIT](INFO): Clearing failed state for component DropWeight
2020-09-10T21:31:25.787Z,1599773485.787 [DropWeight] No Fault, FailCount= 1
2020-09-10T21:31:32.642Z,1599773492.642 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2020-09-10T21:31:45.170Z,1599773505.170 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2020-09-10T21:31:52.851Z,1599773512.851 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-09-10T21:31:52.851Z,1599773512.851 [Default:CheckIn:C.Wait] Stopped
2020-09-10T21:31:52.851Z,1599773512.851 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-09-10T21:31:52.851Z,1599773512.851 [Default:CheckIn:D] Running Loop=1
2020-09-10T21:31:53.254Z,1599773513.254 [Default:CheckIn:D] Stopped
2020-09-10T21:31:53.254Z,1599773513.254 [Default:CheckIn:E] Running Loop=1
2020-09-10T21:31:53.659Z,1599773513.659 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 101.355851 min 
2020-09-10T21:31:53.659Z,1599773513.659 [Default:CheckIn:E] Stopped
2020-09-10T21:31:53.659Z,1599773513.659 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-09-10T21:31:53.659Z,1599773513.659 [Default:CheckIn] Stopped
2020-09-10T21:31:53.659Z,1599773513.659 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-09-10T21:31:53.659Z,1599773513.659 [Default:CheckIn](INFO): Running loop #19
2020-09-10T21:31:53.659Z,1599773513.659 [Default:CheckIn] Running Loop=19
2020-09-10T21:31:53.660Z,1599773513.660 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-09-10T21:31:53.660Z,1599773513.660 [Default:CheckIn:Read_GPS] Running Loop=1
2020-09-10T21:31:55.677Z,1599773515.677 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213154.00,A,3648.16680,N,12147.28937,W,1.244,0.00,100920,,,A*73
2020-09-10T21:31:55.679Z,1599773515.679 [NAL9602](INFO): GPS fix at 20200910T213154: (36.802780, -121.788156)
2020-09-10T21:31:55.689Z,1599773515.689 [Default:CheckIn:Read_GPS] Stopped
2020-09-10T21:31:55.689Z,1599773515.689 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-09-10T21:31:58.117Z,1599773518.117 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2020-09-10T21:32:02.691Z,1599773522.691 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20200910T194609/Courier0058.lzma
2020-09-10T21:32:03.694Z,1599773523.694 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Courier0058.lzma.bak
2020-09-10T21:32:03.694Z,1599773523.694 [DataOverHttps](INFO): SBD MOMSN=12647945
2020-09-10T21:32:20.646Z,1599773540.646 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20200910T194609/Express0059.lzma
2020-09-10T21:32:20.782Z,1599773540.782 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Express0059.lzma.bak
2020-09-10T21:32:20.782Z,1599773540.782 [DataOverHttps](INFO): SBD MOMSN=12647949
2020-09-10T21:32:22.365Z,1599773542.365 [Default:CheckIn:Read_Iridium] Stopped
2020-09-10T21:32:22.365Z,1599773542.365 [Default:CheckIn:C.Wait] Running Loop=1
2020-09-10T21:32:22.365Z,1599773542.365 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-09-10T21:34:08.999Z,1599773648.999 [NAL9602](INFO): SBD MO Status=2, MOMSN=9601, MT Status=2, MTMSN=0
2020-09-10T21:34:08.999Z,1599773648.999 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-09-10T21:34:23.542Z,1599773663.542 [NAL9602](INFO): SBD MO Status=0, MOMSN=9601, MT Status=0, MTMSN=0
2020-09-10T21:34:23.542Z,1599773663.542 [NAL9602](INFO): No messages in MT queue
2020-09-10T21:34:54.245Z,1599773694.245 [NAL9602](INFO): Not Powering down - fast GPS
2020-09-10T21:37:22.926Z,1599773842.926 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-09-10T21:37:22.927Z,1599773842.927 [Default:CheckIn:C.Wait] Stopped
2020-09-10T21:37:22.927Z,1599773842.927 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-09-10T21:37:22.927Z,1599773842.927 [Default:CheckIn:D] Running Loop=1
2020-09-10T21:37:23.332Z,1599773843.332 [Default:CheckIn:D] Stopped
2020-09-10T21:37:23.333Z,1599773843.333 [Default:CheckIn:E] Running Loop=1
2020-09-10T21:37:23.747Z,1599773843.747 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 106.857153 min 
2020-09-10T21:37:23.747Z,1599773843.747 [Default:CheckIn:E] Stopped
2020-09-10T21:37:23.748Z,1599773843.748 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-09-10T21:37:23.748Z,1599773843.748 [Default:CheckIn] Stopped
2020-09-10T21:37:23.748Z,1599773843.748 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-09-10T21:37:23.748Z,1599773843.748 [Default:CheckIn](INFO): Running loop #20
2020-09-10T21:37:23.748Z,1599773843.748 [Default:CheckIn] Running Loop=20
2020-09-10T21:37:23.748Z,1599773843.748 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-09-10T21:37:23.748Z,1599773843.748 [Default:CheckIn:Read_GPS] Running Loop=1
2020-09-10T21:37:25.751Z,1599773845.751 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213725.00,A,3648.16397,N,12147.28179,W,0.233,0.00,100920,,,A*73
2020-09-10T21:37:25.753Z,1599773845.753 [NAL9602](INFO): GPS fix at 20200910T213725: (36.802733, -121.788030)
2020-09-10T21:37:25.763Z,1599773845.763 [Default:CheckIn:Read_GPS] Stopped
2020-09-10T21:37:25.763Z,1599773845.763 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-09-10T21:37:33.767Z,1599773853.767 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200910T194609/Courier0061.lzma
2020-09-10T21:37:34.770Z,1599773854.770 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Courier0061.lzma.bak
2020-09-10T21:37:34.770Z,1599773854.770 [DataOverHttps](INFO): SBD MOMSN=12647953
2020-09-10T21:37:50.552Z,1599773870.552 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20200910T194609/Express0062.lzma
2020-09-10T21:37:51.554Z,1599773871.554 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Express0062.lzma.bak
2020-09-10T21:37:51.554Z,1599773871.554 [DataOverHttps](INFO): SBD MOMSN=12647956
2020-09-10T21:37:53.231Z,1599773873.231 [Default:CheckIn:Read_Iridium] Stopped
2020-09-10T21:37:53.231Z,1599773873.231 [Default:CheckIn:C.Wait] Running Loop=1
2020-09-10T21:37:53.231Z,1599773873.231 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-09-10T21:37:58.470Z,1599773878.470 [NAL9602](INFO): SBD MO Status=2, MOMSN=9602, MT Status=2, MTMSN=0
2020-09-10T21:37:58.471Z,1599773878.471 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-09-10T21:38:58.266Z,1599773938.266 [NAL9602](INFO): SBD MO Status=2, MOMSN=9602, MT Status=2, MTMSN=0
2020-09-10T21:38:58.266Z,1599773938.266 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-09-10T21:42:24.310Z,1599774144.310 [NAL9602](INFO): SBD MO Status=2, MOMSN=9602, MT Status=2, MTMSN=0
2020-09-10T21:42:24.310Z,1599774144.310 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-09-10T21:42:28.349Z,1599774148.349 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-09-10T21:42:53.839Z,1599774173.839 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-09-10T21:42:53.839Z,1599774173.839 [Default:CheckIn:C.Wait] Stopped
2020-09-10T21:42:53.839Z,1599774173.839 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-09-10T21:42:53.840Z,1599774173.840 [Default:CheckIn:D] Running Loop=1
2020-09-10T21:42:54.254Z,1599774174.254 [Default:CheckIn:D] Stopped
2020-09-10T21:42:54.254Z,1599774174.254 [Default:CheckIn:E] Running Loop=1
2020-09-10T21:42:54.654Z,1599774174.654 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 112.372502 min 
2020-09-10T21:42:54.655Z,1599774174.655 [Default:CheckIn:E] Stopped
2020-09-10T21:42:54.655Z,1599774174.655 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-09-10T21:42:54.655Z,1599774174.655 [Default:CheckIn] Stopped
2020-09-10T21:42:54.655Z,1599774174.655 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-09-10T21:42:54.655Z,1599774174.655 [Default:CheckIn](INFO): Running loop #21
2020-09-10T21:42:54.655Z,1599774174.655 [Default:CheckIn] Running Loop=21
2020-09-10T21:42:54.655Z,1599774174.655 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-09-10T21:42:54.655Z,1599774174.655 [Default:CheckIn:Read_GPS] Running Loop=1
2020-09-10T21:42:56.659Z,1599774176.659 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214255.00,A,3648.16587,N,12147.28399,W,0.058,132.19,100920,,,A*7A
2020-09-10T21:42:56.661Z,1599774176.661 [NAL9602](INFO): GPS fix at 20200910T214255: (36.802765, -121.788066)
2020-09-10T21:42:56.672Z,1599774176.672 [Default:CheckIn:Read_GPS] Stopped
2020-09-10T21:42:56.672Z,1599774176.672 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-09-10T21:43:04.299Z,1599774184.299 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200910T194609/Courier0064.lzma
2020-09-10T21:43:05.302Z,1599774185.302 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Courier0064.lzma.bak
2020-09-10T21:43:05.302Z,1599774185.302 [DataOverHttps](INFO): SBD MOMSN=12647960
2020-09-10T21:43:21.391Z,1599774201.391 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20200910T194609/Express0065.lzma
2020-09-10T21:43:22.394Z,1599774202.394 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Express0065.lzma.bak
2020-09-10T21:43:22.394Z,1599774202.394 [DataOverHttps](INFO): SBD MOMSN=12647963
2020-09-10T21:43:24.139Z,1599774204.139 [Default:CheckIn:Read_Iridium] Stopped
2020-09-10T21:43:24.140Z,1599774204.140 [Default:CheckIn:C.Wait] Running Loop=1
2020-09-10T21:43:24.140Z,1599774204.140 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-09-10T21:43:29.381Z,1599774209.381 [NAL9602](INFO): Not Powering down - fast GPS
2020-09-10T21:43:58.132Z,1599774238.132 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2020-09-10T21:44:13.086Z,1599774253.086 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2020-09-10T21:48:23.115Z,1599774503.115 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 5.
2020-09-10T21:48:23.117Z,1599774503.117 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle.
2020-09-10T21:48:24.737Z,1599774504.737 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-09-10T21:48:24.737Z,1599774504.737 [Default:CheckIn:C.Wait] Stopped
2020-09-10T21:48:24.737Z,1599774504.737 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-09-10T21:48:24.737Z,1599774504.737 [Default:CheckIn:D] Running Loop=1
2020-09-10T21:48:25.143Z,1599774505.143 [Default:CheckIn:D] Stopped
2020-09-10T21:48:25.143Z,1599774505.143 [Default:CheckIn:E] Running Loop=1
2020-09-10T21:48:25.550Z,1599774505.550 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 117.887321 min 
2020-09-10T21:48:25.550Z,1599774505.550 [Default:CheckIn:E] Stopped
2020-09-10T21:48:25.550Z,1599774505.550 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-09-10T21:48:25.551Z,1599774505.551 [Default:CheckIn] Stopped
2020-09-10T21:48:25.551Z,1599774505.551 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-09-10T21:48:25.551Z,1599774505.551 [Default:CheckIn](INFO): Running loop #22
2020-09-10T21:48:25.551Z,1599774505.551 [Default:CheckIn] Running Loop=22
2020-09-10T21:48:25.551Z,1599774505.551 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-09-10T21:48:25.551Z,1599774505.551 [Default:CheckIn:Read_GPS] Running Loop=1
2020-09-10T21:48:27.600Z,1599774507.600 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214826.00,A,3648.16520,N,12147.28654,W,0.233,132.19,100920,,,A*72
2020-09-10T21:48:27.602Z,1599774507.602 [NAL9602](INFO): GPS fix at 20200910T214826: (36.802753, -121.788109)
2020-09-10T21:48:27.644Z,1599774507.644 [Default:CheckIn:Read_GPS] Stopped
2020-09-10T21:48:27.644Z,1599774507.644 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-09-10T21:48:34.519Z,1599774514.519 [DataOverHttps](INFO): Sending 83 bytes from file Logs/20200910T194609/Courier0067.lzma
2020-09-10T21:48:35.521Z,1599774515.521 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Courier0067.lzma.bak
2020-09-10T21:48:35.522Z,1599774515.522 [DataOverHttps](INFO): SBD MOMSN=12647967
2020-09-10T21:48:51.271Z,1599774531.271 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20200910T194609/Express0068.lzma
2020-09-10T21:48:52.274Z,1599774532.274 [DataOverHttps](INFO): Moved sent file to Logs/20200910T194609/Express0068.lzma.bak
2020-09-10T21:48:52.274Z,1599774532.274 [DataOverHttps](INFO): SBD MOMSN=12647971
2020-09-10T21:48:53.844Z,1599774533.844 [Default:CheckIn:Read_Iridium] Stopped
2020-09-10T21:48:53.845Z,1599774533.845 [Default:CheckIn:C.Wait] Running Loop=1
2020-09-10T21:48:53.845Z,1599774533.845 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-09-10T21:48:58.261Z,1599774538.261 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2020-09-10T21:48:58.344Z,1599774538.344 [NAL9602](FAULT): received: 
+SBDI: 2, 9602, 2, 0, 0, 0

OK
2020-09-10T21:48:58.344Z,1599774538.344 [NAL9602] Data Fault, FailCount= 1
2020-09-10T21:48:58.344Z,1599774538.344 [NAL9602](ERROR): Data Fault
2020-09-10T21:48:58.364Z,1599774538.364 [CBIT](ERROR): Data Fault in component: NAL9602
2020-09-10T21:48:58.665Z,1599774538.665 [NAL9602](INFO): Powering down
2020-09-10T21:48:59.067Z,1599774539.067 [NAL9602](FAULT): LCB fault:  Software Overcurrent.
2020-09-10T21:48:59.067Z,1599774539.067 [NAL9602] Hardware Fault, FailCount= 1
2020-09-10T21:48:59.067Z,1599774539.067 [NAL9602](ERROR): Hardware Fault
2020-09-10T21:48:59.495Z,1599774539.495 [CBIT](INFO): Clearing failed state for component NAL9602
2020-09-10T21:48:59.495Z,1599774539.495 [NAL9602] No Fault, FailCount= 1
2020-09-10T21:49:28.967Z,1599774568.967 [NAL9602](INFO): Powering up NAL9602
2020-09-10T21:49:39.877Z,1599774579.877 [NAL9602](INFO): NAL9602 initialized
2020-09-10T21:50:10.981Z,1599774610.981 [NAL9602](INFO): Not Powering down - fast GPS
2020-09-10T21:52:19.369Z,1599774739.369 [CommandLine](IMPORTANT): got command failComponent
2020-09-10T21:52:19.370Z,1599774739.370 [CommandLine](IMPORTANT): Failed components:
2020-09-10T21:52:19.370Z,1599774739.370 [CommandLine](IMPORTANT): No failed Components.
2020-09-10T21:52:21.641Z,1599774741.641 [CommandLine](IMPORTANT): got command quit
2020-09-10T21:52:22.648Z,1599774742.648 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-10T21:52:22.648Z,1599774742.648 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-09-10T21:52:22.800Z,1599774742.800 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2020-09-10T21:52:22.800Z,1599774742.800 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-09-10T21:52:22.801Z,1599774742.801 [CommandLine](INFO): Join timeout helper Thread ID is 1796
2020-09-10T21:52:22.801Z,1599774742.801 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2020-09-10T21:52:22.801Z,1599774742.801 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-09-10T21:52:22.802Z,1599774742.802 [NavChartDb](INFO): Join timeout helper Thread ID is 1797
2020-09-10T21:52:23.060Z,1599774743.060 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-10T21:52:23.060Z,1599774743.060 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-09-10T21:52:23.064Z,1599774743.064 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2020-09-10T21:52:23.064Z,1599774743.064 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-09-10T21:52:23.064Z,1599774743.064 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1798
2020-09-10T21:52:23.528Z,1599774743.528 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-10T21:52:23.529Z,1599774743.529 [WetLabsBB2FL](INFO): Powering down
2020-09-10T21:52:23.529Z,1599774743.529 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-09-10T21:52:23.548Z,1599774743.548 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2020-09-10T21:52:23.548Z,1599774743.548 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-09-10T21:52:23.548Z,1599774743.548 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1799
2020-09-10T21:52:24.136Z,1599774744.136 [CTD_Seabird](INFO): Powering down
2020-09-10T21:52:24.148Z,1599774744.148 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-10T21:52:24.149Z,1599774744.149 [CTD_Seabird](INFO): Powering down
2020-09-10T21:52:24.164Z,1599774744.164 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-09-10T21:52:24.176Z,1599774744.176 [ComponentRegistry](INFO): Shutting down BackSeatDriver ThreadHandler
2020-09-10T21:52:24.176Z,1599774744.176 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-09-10T21:52:24.176Z,1599774744.176 [BackSeatDriver](INFO): Join timeout helper Thread ID is 1800
2020-09-10T21:52:24.456Z,1599774744.456 [BackSeatDriver ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-10T21:52:24.456Z,1599774744.456 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-09-10T21:52:24.469Z,1599774744.469 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2020-09-10T21:52:24.469Z,1599774744.469 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-09-10T21:52:24.469Z,1599774744.469 [Radio_Surface](INFO): Join timeout helper Thread ID is 1801
2020-09-10T21:52:24.832Z,1599774744.832 [Radio_Surface](INFO): Powering down
2020-09-10T21:52:24.833Z,1599774744.833 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-10T21:52:24.833Z,1599774744.833 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-09-10T21:52:24.852Z,1599774744.852 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2020-09-10T21:52:24.852Z,1599774744.852 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-09-10T21:52:24.853Z,1599774744.853 [Onboard](INFO): Join timeout helper Thread ID is 1802
2020-09-10T21:52:25.552Z,1599774745.552 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2020-09-10T21:52:27.732Z,1599774747.732 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-10T21:52:27.732Z,1599774747.732 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-09-10T21:52:27.752Z,1599774747.752 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2020-09-10T21:52:27.752Z,1599774747.752 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-09-10T21:52:27.752Z,1599774747.752 [DataOverHttps](INFO): Join timeout helper Thread ID is 1803
2020-09-10T21:52:28.564Z,1599774748.564 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-10T21:52:28.564Z,1599774748.564 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-09-10T21:52:28.584Z,1599774748.584 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2020-09-10T21:52:28.584Z,1599774748.584 [logger ThreadHandler](INFO): Thread cancelled.
2020-09-10T21:52:28.584Z,1599774748.584 [logger](INFO): Join timeout helper Thread ID is 1804
2020-09-10T21:52:28.585Z,1599774748.585 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-10T21:52:28.585Z,1599774748.585 [logger ThreadHandler](INFO): Thread cancelled.
2020-09-10T21:52:28.586Z,1599774748.586 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2020-09-10T21:52:28.586Z,1599774748.586 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-09-10T21:52:28.587Z,1599774748.587 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2020-09-10T21:52:28.587Z,1599774748.587 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-09-10T21:52:28.587Z,1599774748.587 [controlThread](INFO): Join timeout helper Thread ID is 1805
2020-09-10T21:52:28.728Z,1599774748.728 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-10T21:52:28.728Z,1599774748.728 [controlThread](DEBUG): Uninitializing ControlThread
2020-09-10T21:52:28.729Z,1599774748.729 [AHRS_M2](INFO): Powering down
2020-09-10T21:52:28.800Z,1599774748.800 [NAL9602](INFO): Powering down
2020-09-10T21:52:28.801Z,1599774748.801 [DAT](INFO): Powering down
2020-09-10T21:52:29.088Z,1599774749.088 [AMEcho](INFO): Powering down
2020-09-10T21:52:29.089Z,1599774749.089 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2020-09-10T21:52:29.090Z,1599774749.090 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2020-09-10T21:52:29.090Z,1599774749.090 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2020-09-10T21:52:29.091Z,1599774749.091 [MissionManager](INFO): Uninitializing Mission Default
2020-09-10T21:52:29.091Z,1599774749.091 [Default] Stopped
2020-09-10T21:52:29.091Z,1599774749.091 [Default](DEBUG): Aggregate::uninitialize Default
2020-09-10T21:52:29.091Z,1599774749.091 [Default:B.GoToSurface] Stopped
2020-09-10T21:52:29.091Z,1599774749.091 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-09-10T21:52:29.091Z,1599774749.091 [Default:CheckIn] Stopped
2020-09-10T21:52:29.091Z,1599774749.091 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-09-10T21:52:29.091Z,1599774749.091 [Default:CheckIn:C.Wait] Stopped
2020-09-10T21:52:29.092Z,1599774749.092 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-09-10T21:52:29.094Z,1599774749.094 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2020-09-10T21:52:29.094Z,1599774749.094 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2020-09-10T21:52:29.094Z,1599774749.094 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2020-09-10T21:52:29.095Z,1599774749.095 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2020-09-10T21:52:29.095Z,1599774749.095 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2020-09-10T21:52:29.095Z,1599774749.095 [BuoyancyServo](INFO): Powering down
2020-09-10T21:52:29.108Z,1599774749.108 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2020-09-10T21:52:29.108Z,1599774749.108 [ElevatorServo](INFO): Powering down
2020-09-10T21:52:29.109Z,1599774749.109 [MassServo](DEBUG): Uninitialize Mass Servo.
2020-09-10T21:52:29.109Z,1599774749.109 [MassServo](INFO): Powering down
2020-09-10T21:52:29.110Z,1599774749.110 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-09-10T21:52:29.110Z,1599774749.110 [RudderServo](INFO): Powering down
2020-09-10T21:52:29.110Z,1599774749.110 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2020-09-10T21:52:29.111Z,1599774749.111 [ThrusterServo](INFO): Powering down
2020-09-10T21:52:29.111Z,1599774749.111 [SBIT](DEBUG): Uninitialize SBIT Component.
2020-09-10T21:52:29.112Z,1599774749.112 [IBIT](DEBUG): Uninitialize IBIT Component.
2020-09-10T21:52:29.112Z,1599774749.112 [CBIT](DEBUG): Uninitialize CBIT Component.
2020-09-10T21:52:29.112Z,1599774749.112 [CBIT](DEBUG): Powering off loads.
2020-09-10T21:52:29.124Z,1599774749.124 [CBIT](DEBUG): Disabling WDT.
2020-09-10T21:52:29.136Z,1599774749.136 [CBIT](DEBUG): Opening all GF detection circuits.
2020-09-10T21:52:29.136Z,1599774749.136 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-09-10T21:52:29.236Z,1599774749.236 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-09-10T21:52:29.238Z,1599774749.238 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-09-10T21:52:29.244Z,1599774749.244 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-09-10T21:52:29.302Z,1599774749.302 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-09-10T21:52:29.306Z,1599774749.306 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-09-10T21:52:29.309Z,1599774749.309 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-09-10T21:52:29.319Z,1599774749.319 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-09-10T21:52:29.393Z,1599774749.393 [logger ThreadHandler](INFO): Thread cancelled.