2019-07-18T20:32:18.516Z,1563481938.516 [Supervisor](DEBUG): Initializing supervisor.
2019-07-18T20:32:18.518Z,1563481938.518 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-07-18T20:32:18.519Z,1563481938.519 [SyncHandler](INFO): Protected caller Thread ID is 807
2019-07-18T20:32:18.519Z,1563481938.519 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-07-18T20:32:18.520Z,1563481938.520 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-07-18T20:32:18.521Z,1563481938.521 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 808
2019-07-18T20:32:18.523Z,1563481938.523 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-07-18T20:32:18.534Z,1563481938.534 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-07-18T20:32:18.535Z,1563481938.535 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-07-18T20:32:18.536Z,1563481938.536 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 809
2019-07-18T20:32:18.537Z,1563481938.537 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-07-18T20:32:18.537Z,1563481938.537 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-07-18T20:32:18.538Z,1563481938.538 [logger ThreadHandler](INFO): Protected caller Thread ID is 810
2019-07-18T20:32:18.540Z,1563481938.540 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-07-18T20:32:18.540Z,1563481938.540 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-07-18T20:32:18.544Z,1563481938.544 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-07-18T20:32:18.961Z,1563481938.961 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-07-18T20:32:18.963Z,1563481938.963 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-07-18T20:32:19.060Z,1563481939.060 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-07-18T20:32:19.060Z,1563481939.060 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-07-18T20:32:19.372Z,1563481939.372 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-07-18T20:32:19.373Z,1563481939.373 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-07-18T20:32:19.512Z,1563481939.512 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-07-18T20:32:19.512Z,1563481939.512 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-07-18T20:32:19.701Z,1563481939.701 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-07-18T20:32:19.703Z,1563481939.703 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-07-18T20:32:20.146Z,1563481940.146 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-07-18T20:32:20.147Z,1563481940.147 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-07-18T20:32:20.350Z,1563481940.350 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-07-18T20:32:20.351Z,1563481940.351 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-07-18T20:32:20.493Z,1563481940.493 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-07-18T20:32:20.495Z,1563481940.495 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-07-18T20:32:20.685Z,1563481940.685 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-07-18T20:32:20.687Z,1563481940.687 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-07-18T20:32:20.782Z,1563481940.782 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-07-18T20:32:20.783Z,1563481940.783 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-07-18T20:32:21.078Z,1563481941.078 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-07-18T20:32:21.078Z,1563481941.078 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-07-18T20:32:21.160Z,1563481941.160 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-07-18T20:32:21.262Z,1563481941.262 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-07-18T20:32:21.264Z,1563481941.264 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-07-18T20:32:21.846Z,1563481941.846 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-07-18T20:32:21.847Z,1563481941.847 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-07-18T20:32:22.445Z,1563481942.445 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-07-18T20:32:22.447Z,1563481942.447 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2019-07-18T20:32:22.451Z,1563481942.451 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2019-07-18T20:32:22.656Z,1563481942.656 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2019-07-18T20:32:22.756Z,1563481942.756 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2019-07-18T20:32:22.854Z,1563481942.854 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2019-07-18T20:32:23.080Z,1563481943.080 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-07-18T20:32:23.081Z,1563481943.081 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2019-07-18T20:32:23.166Z,1563481943.166 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2019-07-18T20:32:23.258Z,1563481943.258 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2019-07-18T20:32:23.355Z,1563481943.355 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2019-07-18T20:32:23.437Z,1563481943.437 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2019-07-18T20:32:23.543Z,1563481943.543 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2019-07-18T20:32:23.719Z,1563481943.719 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2019-07-18T20:32:23.846Z,1563481943.846 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2019-07-18T20:32:23.850Z,1563481943.850 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-07-18T20:32:24.594Z,1563481944.594 [AHRS_M2] Loaded
2019-07-18T20:32:24.594Z,1563481944.594 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-07-18T20:32:24.736Z,1563481944.736 [DataOverHttps] Loaded
2019-07-18T20:32:24.736Z,1563481944.736 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-07-18T20:32:24.737Z,1563481944.737 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407654E0
2019-07-18T20:32:24.738Z,1563481944.738 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 889
2019-07-18T20:32:24.751Z,1563481944.751 [Depth_Keller] Loaded
2019-07-18T20:32:24.751Z,1563481944.751 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-07-18T20:32:24.756Z,1563481944.756 [DropWeight] Loaded
2019-07-18T20:32:24.756Z,1563481944.756 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-07-18T20:32:24.814Z,1563481944.814 [DUSBL_Hydroid] Loaded
2019-07-18T20:32:24.814Z,1563481944.814 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2019-07-18T20:32:24.863Z,1563481944.863 [Micromodem] Loaded
2019-07-18T20:32:24.863Z,1563481944.863 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2019-07-18T20:32:24.963Z,1563481944.963 [NAL9602] Loaded
2019-07-18T20:32:24.963Z,1563481944.963 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-07-18T20:32:24.979Z,1563481944.979 [Onboard] Loaded
2019-07-18T20:32:24.979Z,1563481944.979 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-07-18T20:32:24.985Z,1563481944.985 [PowerOnly] Loaded
2019-07-18T20:32:24.986Z,1563481944.986 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2019-07-18T20:32:24.992Z,1563481944.992 [Radio_Surface] Loaded
2019-07-18T20:32:24.992Z,1563481944.992 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-07-18T20:32:24.994Z,1563481944.994 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407954E0
2019-07-18T20:32:24.994Z,1563481944.994 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 890
2019-07-18T20:32:25.039Z,1563481945.039 [RDI_Pathfinder] Loaded
2019-07-18T20:32:25.039Z,1563481945.039 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2019-07-18T20:32:26.546Z,1563481946.546 [BPC1] Loaded
2019-07-18T20:32:26.546Z,1563481946.546 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-07-18T20:32:26.547Z,1563481946.547 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-07-18T20:32:26.547Z,1563481946.547 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-07-18T20:32:26.572Z,1563481946.572 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-07-18T20:32:26.572Z,1563481946.572 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-07-18T20:32:26.698Z,1563481946.698 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-07-18T20:32:26.698Z,1563481946.698 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-07-18T20:32:26.719Z,1563481946.719 [NavChart] Loaded
2019-07-18T20:32:26.719Z,1563481946.719 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-07-18T20:32:26.723Z,1563481946.723 [UniversalFixResidualReporter] Loaded
2019-07-18T20:32:26.723Z,1563481946.723 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-07-18T20:32:26.724Z,1563481946.724 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-07-18T20:32:26.726Z,1563481946.726 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-07-18T20:32:26.859Z,1563481946.859 [BuoyancyServo] Loaded
2019-07-18T20:32:26.859Z,1563481946.859 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-07-18T20:32:26.874Z,1563481946.874 [ElevatorServo] Loaded
2019-07-18T20:32:26.875Z,1563481946.875 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-07-18T20:32:26.889Z,1563481946.889 [MassServo] Loaded
2019-07-18T20:32:26.890Z,1563481946.890 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-07-18T20:32:26.905Z,1563481946.905 [RudderServo] Loaded
2019-07-18T20:32:26.905Z,1563481946.905 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-07-18T20:32:26.920Z,1563481946.920 [ThrusterServo] Loaded
2019-07-18T20:32:26.920Z,1563481946.920 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-07-18T20:32:26.921Z,1563481946.921 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-07-18T20:32:26.922Z,1563481946.922 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-07-18T20:32:27.250Z,1563481947.250 [CTD_NeilBrown] Loaded
2019-07-18T20:32:27.250Z,1563481947.250 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-07-18T20:32:27.251Z,1563481947.251 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408E04E0
2019-07-18T20:32:27.252Z,1563481947.252 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 891
2019-07-18T20:32:27.297Z,1563481947.297 [WetLabsSeaOWL_UV_A] Loaded
2019-07-18T20:32:27.298Z,1563481947.298 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2019-07-18T20:32:27.299Z,1563481947.299 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409104E0
2019-07-18T20:32:27.299Z,1563481947.299 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 892
2019-07-18T20:32:27.300Z,1563481947.300 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-07-18T20:32:27.300Z,1563481947.300 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-07-18T20:32:27.751Z,1563481947.751 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-07-18T20:32:27.752Z,1563481947.752 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-07-18T20:32:27.896Z,1563481947.896 [DepthRateCalculator] Loaded
2019-07-18T20:32:27.896Z,1563481947.896 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-07-18T20:32:27.902Z,1563481947.902 [PitchRateCalculator] Loaded
2019-07-18T20:32:27.902Z,1563481947.902 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-07-18T20:32:27.915Z,1563481947.915 [SpeedCalculator] Loaded
2019-07-18T20:32:27.915Z,1563481947.915 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-07-18T20:32:27.936Z,1563481947.936 [TempGradientCalculator] Loaded
2019-07-18T20:32:27.937Z,1563481947.937 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-07-18T20:32:27.942Z,1563481947.942 [YawRateCalculator] Loaded
2019-07-18T20:32:27.942Z,1563481947.942 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-07-18T20:32:27.984Z,1563481947.984 [ElevatorOffsetCalculator] Loaded
2019-07-18T20:32:27.984Z,1563481947.984 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-07-18T20:32:27.985Z,1563481947.985 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-07-18T20:32:27.985Z,1563481947.985 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-07-18T20:32:28.152Z,1563481948.152 [SBIT](DEBUG): Construct Startup Built In Test.
2019-07-18T20:32:28.174Z,1563481948.174 [SBIT] Loaded
2019-07-18T20:32:28.174Z,1563481948.174 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-07-18T20:32:28.175Z,1563481948.175 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-07-18T20:32:28.187Z,1563481948.187 [IBIT] Loaded
2019-07-18T20:32:28.187Z,1563481948.187 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-07-18T20:32:28.190Z,1563481948.190 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-07-18T20:32:28.333Z,1563481948.333 [CBIT] Loaded
2019-07-18T20:32:28.333Z,1563481948.333 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-07-18T20:32:28.333Z,1563481948.333 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-07-18T20:32:28.334Z,1563481948.334 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-07-18T20:32:28.458Z,1563481948.458 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-07-18T20:32:28.458Z,1563481948.458 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-07-18T20:32:28.586Z,1563481948.586 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-07-18T20:32:28.586Z,1563481948.586 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-07-18T20:32:28.676Z,1563481948.676 [VerticalControl](DEBUG): Construct VerticalControl.
2019-07-18T20:32:28.761Z,1563481948.761 [VerticalControl] Loaded
2019-07-18T20:32:28.761Z,1563481948.761 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-07-18T20:32:28.762Z,1563481948.762 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-07-18T20:32:28.819Z,1563481948.819 [HorizontalControl] Loaded
2019-07-18T20:32:28.820Z,1563481948.820 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-07-18T20:32:28.820Z,1563481948.820 [SpeedControl](DEBUG): Construct SpeedControl.
2019-07-18T20:32:28.822Z,1563481948.822 [SpeedControl] Loaded
2019-07-18T20:32:28.822Z,1563481948.822 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-07-18T20:32:28.823Z,1563481948.823 [LoopControl](DEBUG): Construct LoopControl.
2019-07-18T20:32:28.823Z,1563481948.823 [LoopControl] Loaded
2019-07-18T20:32:28.824Z,1563481948.824 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-07-18T20:32:28.824Z,1563481948.824 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-07-18T20:32:28.825Z,1563481948.825 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-07-18T20:32:28.873Z,1563481948.873 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-07-18T20:32:28.877Z,1563481948.877 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-07-18T20:32:28.878Z,1563481948.878 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-07-18T20:32:28.884Z,1563481948.884 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-07-18T20:32:28.885Z,1563481948.885 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AEC4E0
2019-07-18T20:32:28.886Z,1563481948.886 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 893
2019-07-18T20:32:28.890Z,1563481948.890 [Supervisor](INFO): Main Thread ID is 803
2019-07-18T20:32:28.890Z,1563481948.890 [Supervisor](DEBUG): Running supervisor.
2019-07-18T20:32:28.891Z,1563481948.891 [CommandLine ThreadHandler](INFO): Handler Thread ID is 894
2019-07-18T20:32:28.893Z,1563481948.893 [controlThread ThreadHandler](INFO): Handler Thread ID is 895
2019-07-18T20:32:28.893Z,1563481948.893 [controlThread](DEBUG): Initializing ControlThread
2019-07-18T20:32:28.900Z,1563481948.900 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-07-18T20:32:28.900Z,1563481948.900 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-07-18T20:32:28.901Z,1563481948.901 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-07-18T20:32:28.902Z,1563481948.902 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-07-18T20:32:28.902Z,1563481948.902 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-07-18T20:32:28.902Z,1563481948.902 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-07-18T20:32:28.903Z,1563481948.903 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-07-18T20:32:28.903Z,1563481948.903 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-07-18T20:32:28.904Z,1563481948.904 [SBIT](INFO): Initialize SBIT Component.
2019-07-18T20:32:28.904Z,1563481948.904 [SBIT](IMPORTANT): git: 2019-07-16A
2019-07-18T20:32:28.904Z,1563481948.904 [SBIT](INFO): git hash: 5b3bfb91c2b42ce18c1af41de1400573ebf5a9f6
2019-07-18T20:32:28.905Z,1563481948.905 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-07-18T20:32:28.906Z,1563481948.906 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-07-18T20:32:28.907Z,1563481948.907 [SBIT](INFO): Beginning SBIT in 28.000000 seconds.
2019-07-18T20:32:28.908Z,1563481948.908 [IBIT](INFO): Initialize IBIT Component.
2019-07-18T20:32:28.909Z,1563481948.909 [CBIT](DEBUG): Initialize CBIT Component.
2019-07-18T20:32:28.909Z,1563481948.909 [logger ThreadHandler](INFO): Handler Thread ID is 896
2019-07-18T20:32:28.921Z,1563481948.921 [CBIT](DEBUG): Initialized mux pins.
2019-07-18T20:32:28.921Z,1563481948.921 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2019-07-18T20:32:28.921Z,1563481948.921 [CBIT](DEBUG): Initializing the watchdog timer.
2019-07-18T20:32:28.929Z,1563481948.929 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 897
2019-07-18T20:32:28.930Z,1563481948.930 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-07-18T20:32:28.941Z,1563481948.941 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 898
2019-07-18T20:32:28.945Z,1563481948.945 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-07-18T20:32:28.945Z,1563481948.945 [CBIT](DEBUG): Initializing heartbeat.
2019-07-18T20:32:28.953Z,1563481948.953 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 899
2019-07-18T20:32:28.954Z,1563481948.954 [CTD_NeilBrown](INFO): Powering down
2019-07-18T20:32:28.981Z,1563481948.981 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 900
2019-07-18T20:32:28.982Z,1563481948.982 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-07-18T20:32:29.007Z,1563481949.007 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 901
2019-07-18T20:32:29.016Z,1563481949.016 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-07-18T20:32:29.017Z,1563481949.017 [CBIT](DEBUG): Deactivating GF circuits.
2019-07-18T20:32:29.017Z,1563481949.017 [CBIT](DEBUG): Deactivating emergency mode.
2019-07-18T20:32:29.017Z,1563481949.017 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-07-18T20:32:29.017Z,1563481949.017 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-07-18T20:32:29.018Z,1563481949.018 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-07-18T20:32:29.018Z,1563481949.018 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-07-18T20:32:29.018Z,1563481949.018 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-07-18T20:32:29.018Z,1563481949.018 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-07-18T20:32:29.018Z,1563481949.018 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-07-18T20:32:29.018Z,1563481949.018 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-07-18T20:32:29.019Z,1563481949.019 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-07-18T20:32:29.019Z,1563481949.019 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-07-18T20:32:29.019Z,1563481949.019 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-07-18T20:32:29.019Z,1563481949.019 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-07-18T20:32:29.019Z,1563481949.019 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-07-18T20:32:29.019Z,1563481949.019 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-07-18T20:32:29.020Z,1563481949.020 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-07-18T20:32:29.053Z,1563481949.053 [CBIT](DEBUG): Backplane powered.
2019-07-18T20:32:29.053Z,1563481949.053 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-07-18T20:32:29.055Z,1563481949.055 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-07-18T20:32:29.055Z,1563481949.055 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-07-18T20:32:29.056Z,1563481949.056 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-07-18T20:32:29.057Z,1563481949.057 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-07-18T20:32:29.080Z,1563481949.080 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-07-18T20:32:29.114Z,1563481949.114 [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>


2019-07-18T20:32:29.115Z,1563481949.115 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-07-18T20:32:29.206Z,1563481949.206 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-07-18T20:32:29.207Z,1563481949.207 [Default:A.Wait](DEBUG): Construct Wait.
2019-07-18T20:32:29.209Z,1563481949.209 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-07-18T20:32:29.250Z,1563481949.250 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-07-18T20:32:29.252Z,1563481949.252 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-07-18T20:32:29.274Z,1563481949.274 [Default:E.Execute](DEBUG): Construct Execute.
2019-07-18T20:32:29.277Z,1563481949.277 [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>


2019-07-18T20:32:29.289Z,1563481949.289 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,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,
2019-07-18T20:32:29.297Z,1563481949.297 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-07-18T20:32:29.345Z,1563481949.345 [Radio_Surface](INFO): Powering up
2019-07-18T20:32:29.382Z,1563481949.382 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2019-07-18T20:32:29.382Z,1563481949.382 [DUSBL_Hydroid](INFO): Powering up
2019-07-18T20:32:29.383Z,1563481949.383 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2019-07-18T20:32:29.457Z,1563481949.457 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-07-18T20:32:29.519Z,1563481949.519 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-07-18T20:32:29.525Z,1563481949.525 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-07-18T20:32:29.526Z,1563481949.526 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-07-18T20:32:29.533Z,1563481949.533 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-07-18T20:32:29.534Z,1563481949.534 [MassServo](DEBUG): Initializing EZServoServo.
2019-07-18T20:32:29.541Z,1563481949.541 [MassServo](DEBUG): Initializing MassServo.
2019-07-18T20:32:29.542Z,1563481949.542 [RudderServo](DEBUG): Initializing EZServoServo.
2019-07-18T20:32:29.549Z,1563481949.549 [RudderServo](DEBUG): Initializing RudderServo.
2019-07-18T20:32:29.550Z,1563481949.550 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-07-18T20:32:29.557Z,1563481949.557 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-07-18T20:32:29.807Z,1563481949.807 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2019-07-18T20:32:29.807Z,1563481949.807 [DropWeight] Hardware Fault, FailCount= 1
2019-07-18T20:32:29.807Z,1563481949.807 [DropWeight](ERROR): Hardware Fault
2019-07-18T20:32:29.809Z,1563481949.809 [Micromodem](INFO): Powering up
2019-07-18T20:32:29.809Z,1563481949.809 [Micromodem](DEBUG): Initializing Micromodem.
2019-07-18T20:32:29.868Z,1563481949.868 [CommandLine](FAULT): Scheduling is paused
2019-07-18T20:32:29.868Z,1563481949.868 [CBIT](INFO): Critical error at 20190718T203229
2019-07-18T20:32:29.869Z,1563481949.869 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-07-18T20:32:29.871Z,1563481949.871 [CBIT](ERROR): Hardware Fault in component: DropWeight
2019-07-18T20:32:29.872Z,1563481949.872 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2019-07-18T20:32:30.461Z,1563481950.461 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-07-18T20:32:30.461Z,1563481950.461 [RudderServo](FAULT): Rudder failed to initialize
2019-07-18T20:32:30.461Z,1563481950.461 [RudderServo] Communications Fault, FailCount= 1
2019-07-18T20:32:30.461Z,1563481950.461 [RudderServo](ERROR): Communications Fault
2019-07-18T20:32:30.570Z,1563481950.570 [CBIT](INFO): Critical error at 20190718T203229
2019-07-18T20:32:30.573Z,1563481950.573 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-07-18T20:32:30.734Z,1563481950.734 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-07-18T20:32:30.734Z,1563481950.734 [RudderServo](INFO): Powering down
2019-07-18T20:32:31.417Z,1563481951.417 [RudderServo](DEBUG): Initializing EZServoServo.
2019-07-18T20:32:31.538Z,1563481951.538 [RudderServo](DEBUG): Initializing RudderServo.
2019-07-18T20:32:31.542Z,1563481951.542 [CBIT](INFO): Clearing failed state for component RudderServo
2019-07-18T20:32:31.542Z,1563481951.542 [RudderServo] No Fault, FailCount= 1
2019-07-18T20:32:34.659Z,1563481954.659 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2019-07-18T20:32:37.555Z,1563481957.555 [Micromodem](INFO): Nmea in: $CATMG,2019-07-18T20:32:36Z,RTC,RTC*7C

2019-07-18T20:32:37.555Z,1563481957.555 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2019-07-18T20:32:36Z,RTC,RTC*7C

2019-07-18T20:32:42.808Z,1563481962.808 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-07-18T20:32:46.031Z,1563481966.031 [Micromodem](ERROR): Nmea resend: $CCCFG,ALL,0*33

2019-07-18T20:32:46.823Z,1563481966.823 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31

2019-07-18T20:32:46.823Z,1563481966.823 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31

2019-07-18T20:32:47.230Z,1563481967.230 [DUSBL_Hydroid](INFO): DUSBL Version:O
2019-07-18T20:32:47.242Z,1563481967.242 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33

2019-07-18T20:32:47.242Z,1563481967.242 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64

2019-07-18T20:32:47.635Z,1563481967.635 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66

2019-07-18T20:32:47.635Z,1563481967.635 [Micromodem](INFO): Nmea out: $CCCFG,BND,1*3B

2019-07-18T20:32:48.034Z,1563481968.034 [Micromodem](INFO): Nmea in: $CACFG,BND,1*39

2019-07-18T20:32:48.034Z,1563481968.034 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F

2019-07-18T20:32:48.443Z,1563481968.443 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D

2019-07-18T20:32:48.443Z,1563481968.443 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E

2019-07-18T20:32:48.846Z,1563481968.846 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C

2019-07-18T20:32:48.847Z,1563481968.847 [Micromodem](INFO): Nmea out: $CCCLK,2019,07,18,20,32,49*4E

2019-07-18T20:32:49.247Z,1563481969.247 [Micromodem](INFO): Nmea in: $CACLK,2019,7,18,20,32,49*7C

2019-07-18T20:32:50.055Z,1563481970.055 [Micromodem](INFO): Nmea in: $CATMS,0,2019-07-18T20:32:50Z*74

2019-07-18T20:32:50.066Z,1563481970.066 [Micromodem](INFO): Nmea in: $CATMG,2019-07-18T20:32:50Z,USER_CMD,RTC*3D

2019-07-18T20:32:55.307Z,1563481975.307 [NAL9602](INFO): Powering up NAL9602
2019-07-18T20:32:57.375Z,1563481977.375 [SBIT](IMPORTANT): Beginning Startup BIT
2019-07-18T20:32:57.391Z,1563481977.391 [CBIT](IMPORTANT): Beginning ground fault scan
2019-07-18T20:33:06.321Z,1563481986.321 [NAL9602](INFO): NAL9602 initialized
2019-07-18T20:33:07.113Z,1563481987.113 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:33:08.421Z,1563481988.421 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.009776
CHAN A1 (24V): -0.028148
CHAN A2 (12V): -0.008347
CHAN A3 (5V): -0.002440
CHAN B0 (3.3V): 0.000269
CHAN B1 (3.15aV): 0.000357
CHAN B2 (3.15bV): -0.000092
CHAN B3 (GND): 0.002130
OPEN: 0.006681
Full Scale Calc: 4.765 mA, -1.589 mA
2019-07-18T20:33:35.173Z,1563482015.173 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-18T20:33:35.186Z,1563482015.186 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:33:45.846Z,1563482025.846 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-18T20:33:46.227Z,1563482026.227 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:33:50.610Z,1563482030.610 [SBIT](IMPORTANT): SBIT PASSED
2019-07-18T20:33:50.662Z,1563482030.662 [CommandLine](IMPORTANT): got command configSet list
2019-07-18T20:33:50.662Z,1563482030.662 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-07-18T20:33:50.666Z,1563482030.666 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold=45 count;

2019-07-18T20:33:50.666Z,1563482030.666 [CommandLine](IMPORTANT): ESPComponent.loadAtStartup=1 bool;

2019-07-18T20:33:50.666Z,1563482030.666 [CommandLine](IMPORTANT): ESPComponent.sampleTimeout=10 minute;

2019-07-18T20:33:50.666Z,1563482030.666 [CommandLine](IMPORTANT): ESPComponent.simulateHardware=1 bool;

2019-07-18T20:33:50.666Z,1563482030.666 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.acoustic_contact_range 2.000000 meter;

2019-07-18T20:33:50.666Z,1563482030.666 [CommandLine](IMPORTANT): HorizontalControl.kpHeading=0.8 none;

2019-07-18T20:33:50.666Z,1563482030.666 [CommandLine](IMPORTANT): HorizontalControl.rudDeadband=0.05 degree;

2019-07-18T20:33:50.666Z,1563482030.666 [CommandLine](IMPORTANT): Micromodem.surfaceThreshold=2 meter;

2019-07-18T20:33:50.666Z,1563482030.666 [CommandLine](IMPORTANT): NAL9602.fastGPSFix=1 bool;

2019-07-18T20:33:50.999Z,1563482030.999 [MissionManager](IMPORTANT): Started mission Startup
2019-07-18T20:33:50.999Z,1563482030.999 [Startup] Running Loop=1
2019-07-18T20:33:50.999Z,1563482030.999 [Startup](DEBUG): Aggregate::initialize Startup
2019-07-18T20:33:50.999Z,1563482030.999 [Startup:A.GoToSurface] Running Loop=1
2019-07-18T20:33:50.999Z,1563482030.999 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-07-18T20:33:51.000Z,1563482031.000 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-07-18T20:33:51.009Z,1563482031.009 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-07-18T20:33:51.009Z,1563482031.009 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-07-18T20:33:51.009Z,1563482031.009 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-07-18T20:33:51.010Z,1563482031.010 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-07-18T20:33:51.011Z,1563482031.011 [Startup:StartupSatComms] Running Loop=1
2019-07-18T20:33:51.011Z,1563482031.011 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-07-18T20:33:51.011Z,1563482031.011 [Startup:StartupSatComms:A] Running Loop=1
2019-07-18T20:33:51.398Z,1563482031.398 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-07-18T20:33:56.737Z,1563482036.737 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-18T20:33:57.538Z,1563482037.538 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:34:07.713Z,1563482047.713 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-18T20:34:08.438Z,1563482048.438 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:34:18.940Z,1563482058.940 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-18T20:34:19.358Z,1563482059.358 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:34:29.879Z,1563482069.879 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-18T20:34:29.964Z,1563482069.964 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:34:37.833Z,1563482077.833 [NAL9602](INFO): SBD MO Status=2, MOMSN=8306, MT Status=2, MTMSN=0
2019-07-18T20:34:37.833Z,1563482077.833 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-18T20:34:40.349Z,1563482080.349 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-18T20:34:40.763Z,1563482080.763 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:34:51.285Z,1563482091.285 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-18T20:34:51.292Z,1563482091.292 [Startup:StartupSatComms:A](INFO): Timed out from 2019-07-18T20:33:51.0Z
2019-07-18T20:34:51.292Z,1563482091.292 [Startup:StartupSatComms:A] Stopped
2019-07-18T20:34:51.292Z,1563482091.292 [Startup:StartupSatComms:B] Running Loop=1
2019-07-18T20:34:51.666Z,1563482091.666 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:34:51.673Z,1563482091.673 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-07-18T20:35:02.194Z,1563482102.194 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-18T20:35:02.263Z,1563482102.263 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:35:02.735Z,1563482102.735 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005161
2019-07-18T20:35:08.300Z,1563482108.300 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190718T172614/Courier0090.lzma
2019-07-18T20:35:09.107Z,1563482109.107 [DataOverHttps](INFO): Moved sent file to Logs/20190718T172614/Courier0090.lzma.bak
2019-07-18T20:35:09.107Z,1563482109.107 [DataOverHttps](INFO): SBD MOMSN=11454931
2019-07-18T20:35:12.781Z,1563482112.781 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:35:13.139Z,1563482113.139 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-18T20:35:21.536Z,1563482121.536 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20190718T203218/Courier0000.lzma
2019-07-18T20:35:22.342Z,1563482122.342 [DataOverHttps](INFO): Moved sent file to Logs/20190718T203218/Courier0000.lzma.bak
2019-07-18T20:35:22.342Z,1563482122.342 [DataOverHttps](INFO): SBD MOMSN=11454933
2019-07-18T20:35:23.605Z,1563482123.605 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:35:24.063Z,1563482124.063 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-18T20:35:29.161Z,1563482129.161 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-07-18T20:35:29.161Z,1563482129.161 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-18T20:35:29.171Z,1563482129.171 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-18T20:35:29.577Z,1563482129.577 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-18T20:35:29.578Z,1563482129.578 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-07-18T20:35:34.684Z,1563482134.684 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190718T172614/Express0091.lzma
2019-07-18T20:35:34.918Z,1563482134.918 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-18T20:35:34.982Z,1563482134.982 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:35:35.490Z,1563482135.490 [DataOverHttps](INFO): Moved sent file to Logs/20190718T172614/Express0091.lzma.bak
2019-07-18T20:35:35.491Z,1563482135.491 [DataOverHttps](INFO): SBD MOMSN=11454938
2019-07-18T20:35:45.451Z,1563482145.451 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-18T20:35:45.909Z,1563482145.909 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:35:48.336Z,1563482148.336 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190718T203100/Express0001.lzma
2019-07-18T20:35:49.142Z,1563482149.142 [DataOverHttps](INFO): Moved sent file to Logs/20190718T203100/Express0001.lzma.bak
2019-07-18T20:35:49.142Z,1563482149.142 [DataOverHttps](INFO): SBD MOMSN=11454940
2019-07-18T20:35:51.398Z,1563482151.398 [Startup:StartupSatComms:B](INFO): Timed out from 2019-07-18T20:34:51.3Z
2019-07-18T20:35:51.398Z,1563482151.398 [Startup:StartupSatComms:B] Stopped
2019-07-18T20:35:51.398Z,1563482151.398 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-07-18T20:35:51.398Z,1563482151.398 [Startup:StartupSatComms] Stopped
2019-07-18T20:35:51.398Z,1563482151.398 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-07-18T20:35:51.399Z,1563482151.399 [Startup](INFO): Completed Startup
2019-07-18T20:35:51.399Z,1563482151.399 [MissionManager](INFO): Startup is completed.
2019-07-18T20:35:51.400Z,1563482151.400 [MissionManager](INFO): Uninitializing Mission Startup
2019-07-18T20:35:51.400Z,1563482151.400 [Startup] Stopped
2019-07-18T20:35:51.400Z,1563482151.400 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-07-18T20:35:51.400Z,1563482151.400 [Startup:A.GoToSurface] Stopped
2019-07-18T20:35:51.400Z,1563482151.400 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-07-18T20:35:51.810Z,1563482151.810 [MissionManager](IMPORTANT): Started mission Default
2019-07-18T20:35:51.810Z,1563482151.810 [Default] Running Loop=1
2019-07-18T20:35:51.810Z,1563482151.810 [Default](DEBUG): Aggregate::initialize Default
2019-07-18T20:35:51.810Z,1563482151.810 [Default:B.GoToSurface] Running Loop=1
2019-07-18T20:35:51.810Z,1563482151.810 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-07-18T20:35:51.810Z,1563482151.810 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-07-18T20:35:51.811Z,1563482151.811 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-07-18T20:35:51.811Z,1563482151.811 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-07-18T20:35:51.811Z,1563482151.811 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-07-18T20:35:51.812Z,1563482151.812 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-07-18T20:35:51.812Z,1563482151.812 [Default:A.Wait] Running Loop=1
2019-07-18T20:35:51.812Z,1563482151.812 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-07-18T20:35:56.742Z,1563482156.742 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-18T20:35:56.814Z,1563482156.814 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:36:02.250Z,1563482162.250 [DataOverHttps](INFO): Sending 901 bytes from file Logs/20190718T203218/Express0001.lzma
2019-07-18T20:36:03.054Z,1563482163.054 [DataOverHttps](INFO): Moved sent file to Logs/20190718T203218/Express0001.lzma.bak
2019-07-18T20:36:03.054Z,1563482163.054 [DataOverHttps](INFO): SBD MOMSN=11454943
2019-07-18T20:36:05.133Z,1563482165.133 [Default:A.Wait](INFO): Done Waiting.
2019-07-18T20:36:05.133Z,1563482165.133 [Default:A.Wait] Stopped
2019-07-18T20:36:05.133Z,1563482165.133 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-07-18T20:36:05.538Z,1563482165.538 [Default:CheckIn] Running Loop=1
2019-07-18T20:36:05.539Z,1563482165.539 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-18T20:36:05.539Z,1563482165.539 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-18T20:36:05.963Z,1563482165.963 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-07-18T20:36:07.654Z,1563482167.654 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-18T20:36:07.727Z,1563482167.727 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:36:18.123Z,1563482178.123 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-18T20:36:18.552Z,1563482178.552 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:36:28.650Z,1563482188.650 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-18T20:36:28.712Z,1563482188.712 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:36:39.538Z,1563482199.538 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-18T20:36:39.608Z,1563482199.608 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:36:50.451Z,1563482210.451 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-18T20:36:50.846Z,1563482210.846 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:37:01.369Z,1563482221.369 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-18T20:37:01.746Z,1563482221.746 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:37:12.336Z,1563482232.336 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:37:12.675Z,1563482232.675 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-18T20:37:23.156Z,1563482243.156 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:37:23.583Z,1563482243.583 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-18T20:37:34.056Z,1563482254.056 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-18T20:37:34.135Z,1563482254.135 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:37:45.075Z,1563482265.075 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-18T20:37:45.215Z,1563482265.215 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:37:55.903Z,1563482275.903 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-18T20:37:55.985Z,1563482275.985 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:38:06.824Z,1563482286.824 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-18T20:38:06.895Z,1563482286.895 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:38:10.335Z,1563482290.335 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-07-18T20:38:11.157Z,1563482291.157 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:38:15.197Z,1563482295.197 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:38:17.739Z,1563482297.739 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-18T20:38:17.809Z,1563482297.809 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:38:18.425Z,1563482298.425 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:38:21.253Z,1563482301.253 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:38:24.085Z,1563482304.085 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:38:27.317Z,1563482307.317 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:38:28.203Z,1563482308.203 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:38:28.606Z,1563482308.606 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-18T20:38:29.786Z,1563482309.786 [BPC1](ERROR): Failed to receive data from all battery packs.
2019-07-18T20:38:29.786Z,1563482309.786 [BPC1] Communications Fault, FailCount= 1
2019-07-18T20:38:29.786Z,1563482309.786 [BPC1](ERROR): Communications Fault
2019-07-18T20:38:29.802Z,1563482309.802 [CBIT](ERROR): Communications Fault in component: BPC1
2019-07-18T20:38:30.145Z,1563482310.145 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:38:30.169Z,1563482310.169 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2019-07-18T20:38:30.169Z,1563482310.169 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-18T20:38:30.179Z,1563482310.179 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-18T20:38:30.581Z,1563482310.581 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-18T20:38:30.581Z,1563482310.581 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2019-07-18T20:38:33.377Z,1563482313.377 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:38:36.201Z,1563482316.201 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:38:39.433Z,1563482319.433 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:38:42.277Z,1563482322.277 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:38:45.097Z,1563482325.097 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:38:48.325Z,1563482328.325 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:38:51.153Z,1563482331.153 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:38:54.385Z,1563482334.385 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:38:57.213Z,1563482337.213 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:39:00.445Z,1563482340.445 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:39:03.273Z,1563482343.273 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:39:06.097Z,1563482346.097 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:39:09.333Z,1563482349.333 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:39:12.157Z,1563482352.157 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:39:15.389Z,1563482355.389 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:39:18.217Z,1563482358.217 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:39:21.045Z,1563482361.045 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:39:23.069Z,1563482363.069 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:39:25.089Z,1563482365.089 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:39:28.323Z,1563482368.323 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:39:31.149Z,1563482371.149 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:39:34.377Z,1563482374.377 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:39:37.209Z,1563482377.209 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:39:40.441Z,1563482380.441 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:39:43.269Z,1563482383.269 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:39:46.093Z,1563482386.093 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:39:49.325Z,1563482389.325 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:39:52.153Z,1563482392.153 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:39:55.385Z,1563482395.385 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:39:58.221Z,1563482398.221 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:40:01.045Z,1563482401.045 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:40:03.065Z,1563482403.065 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:40:05.085Z,1563482405.085 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:40:08.317Z,1563482408.317 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:40:11.145Z,1563482411.145 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:40:14.373Z,1563482414.373 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:40:17.205Z,1563482417.205 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:40:20.437Z,1563482420.437 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:40:23.269Z,1563482423.269 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:40:26.093Z,1563482426.093 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:40:29.321Z,1563482429.321 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:40:32.149Z,1563482432.149 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:40:35.381Z,1563482435.381 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:40:38.212Z,1563482438.212 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:40:41.041Z,1563482441.041 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:40:43.057Z,1563482443.057 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:40:45.081Z,1563482445.081 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:40:47.101Z,1563482447.101 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:40:50.333Z,1563482450.333 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:40:53.157Z,1563482453.157 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:40:56.389Z,1563482456.389 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:40:59.217Z,1563482459.217 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:41:02.053Z,1563482462.053 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:41:04.069Z,1563482464.069 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:41:05.722Z,1563482465.722 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-07-18T20:36:05.5Z
2019-07-18T20:41:05.722Z,1563482465.722 [Default:CheckIn:Read_GPS] Stopped
2019-07-18T20:41:05.722Z,1563482465.722 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-18T20:41:06.089Z,1563482466.089 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:41:06.121Z,1563482466.121 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-07-18T20:41:09.321Z,1563482469.321 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:41:11.528Z,1563482471.528 [DataOverHttps](INFO): Sending 175 bytes from file Logs/20190718T203218/Express0005.lzma
2019-07-18T20:41:12.145Z,1563482472.145 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:41:12.334Z,1563482472.334 [DataOverHttps](INFO): Moved sent file to Logs/20190718T203218/Express0005.lzma.bak
2019-07-18T20:41:12.334Z,1563482472.334 [DataOverHttps](INFO): SBD MOMSN=11454975
2019-07-18T20:41:12.992Z,1563482472.992 [Default:CheckIn:Read_Iridium] Stopped
2019-07-18T20:41:12.992Z,1563482472.992 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-18T20:41:12.992Z,1563482472.992 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-18T20:41:15.393Z,1563482475.393 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:41:18.205Z,1563482478.205 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:41:21.441Z,1563482481.441 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:41:24.269Z,1563482484.269 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:41:27.101Z,1563482487.101 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:41:30.325Z,1563482490.325 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:41:31.176Z,1563482491.176 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2019-07-18T20:41:31.176Z,1563482491.176 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-18T20:41:31.187Z,1563482491.187 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-18T20:41:31.573Z,1563482491.573 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-18T20:41:31.573Z,1563482491.573 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2019-07-18T20:41:33.161Z,1563482493.161 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:41:36.401Z,1563482496.401 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:41:39.233Z,1563482499.233 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:41:42.057Z,1563482502.057 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:41:44.093Z,1563482504.093 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:41:46.086Z,1563482506.086 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:41:49.333Z,1563482509.333 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:41:52.149Z,1563482512.149 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:41:52.986Z,1563482512.986 [RDI_Pathfinder](ERROR): Failed to parse:
:BD,        +0.00,        +0.00,        +0.00,   0.00,549.99
2019-07-18T20:41:55.389Z,1563482515.389 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:41:58.222Z,1563482518.222 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:42:01.045Z,1563482521.045 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:42:03.053Z,1563482523.053 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:42:05.089Z,1563482525.089 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:42:08.321Z,1563482528.321 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:42:11.145Z,1563482531.145 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:42:14.381Z,1563482534.381 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:42:17.206Z,1563482537.206 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:42:20.437Z,1563482540.437 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:42:23.268Z,1563482543.268 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:42:26.085Z,1563482546.085 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:42:29.317Z,1563482549.317 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:42:32.141Z,1563482552.141 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:42:35.393Z,1563482555.393 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:42:38.217Z,1563482558.217 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:42:41.049Z,1563482561.049 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:42:43.065Z,1563482563.065 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:42:45.089Z,1563482565.089 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:42:48.322Z,1563482568.322 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:42:51.153Z,1563482571.153 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:42:54.381Z,1563482574.381 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:42:57.209Z,1563482577.209 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:43:00.449Z,1563482580.449 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:43:03.269Z,1563482583.269 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:43:06.101Z,1563482586.101 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:43:09.315Z,1563482589.315 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-07-18T20:43:09.315Z,1563482589.315 [NAL9602] Data Fault, FailCount= 1
2019-07-18T20:43:09.315Z,1563482589.315 [NAL9602](ERROR): Data Fault
2019-07-18T20:43:09.354Z,1563482589.354 [CBIT](ERROR): Data Fault in component: NAL9602
2019-07-18T20:43:09.739Z,1563482589.739 [NAL9602](INFO): Powering down
2019-07-18T20:43:10.590Z,1563482590.590 [CBIT](INFO): Clearing failed state for component NAL9602
2019-07-18T20:43:10.590Z,1563482590.590 [NAL9602] No Fault, FailCount= 1
2019-07-18T20:43:40.016Z,1563482620.016 [NAL9602](INFO): Powering up NAL9602
2019-07-18T20:43:50.955Z,1563482630.955 [NAL9602](INFO): NAL9602 initialized
2019-07-18T20:43:51.750Z,1563482631.750 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:43:54.981Z,1563482634.981 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:43:57.809Z,1563482637.809 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:44:01.037Z,1563482641.037 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:44:03.877Z,1563482643.877 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:44:06.693Z,1563482646.693 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:44:08.717Z,1563482648.717 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:44:10.738Z,1563482650.738 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:44:13.969Z,1563482653.969 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:44:16.805Z,1563482656.805 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:44:20.029Z,1563482660.029 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:44:22.857Z,1563482662.857 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:44:26.097Z,1563482666.097 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:44:28.921Z,1563482668.921 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:44:31.745Z,1563482671.745 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:44:32.182Z,1563482672.182 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2019-07-18T20:44:32.182Z,1563482672.182 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-18T20:44:32.203Z,1563482672.203 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-18T20:44:32.664Z,1563482672.664 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-18T20:44:32.664Z,1563482672.664 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2019-07-18T20:44:34.982Z,1563482674.982 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:44:37.809Z,1563482677.809 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:44:41.037Z,1563482681.037 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:44:43.865Z,1563482683.865 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:44:47.105Z,1563482687.105 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:44:49.925Z,1563482689.925 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:44:52.749Z,1563482692.749 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:44:53.611Z,1563482693.611 [RDI_Pathfinder](ERROR): Failed to parse:
68,-32768,-32768,V
2019-07-18T20:44:55.985Z,1563482695.985 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:44:58.813Z,1563482698.813 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:45:02.045Z,1563482702.045 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:45:04.881Z,1563482704.881 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:45:07.709Z,1563482707.709 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:45:09.721Z,1563482709.721 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:45:09.774Z,1563482709.774 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-07-18T20:45:09.774Z,1563482709.774 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19071813550754,35.0, -0.1,   0.0,1448.RA,  0.00,   0.00,   0.00,   0.00,   0.00
2019-07-18T20:45:12.961Z,1563482712.961 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:45:15.793Z,1563482715.793 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:45:19.021Z,1563482719.021 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:45:21.841Z,1563482721.841 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:45:25.088Z,1563482725.088 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:45:27.909Z,1563482727.909 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:45:30.737Z,1563482730.737 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:45:32.745Z,1563482732.745 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:45:35.990Z,1563482735.990 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:45:38.809Z,1563482738.809 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:45:42.041Z,1563482742.041 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:45:44.869Z,1563482744.869 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:45:47.706Z,1563482747.706 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:45:49.722Z,1563482749.722 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:45:52.961Z,1563482752.961 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:45:55.777Z,1563482755.777 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:45:59.029Z,1563482759.029 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:46:01.849Z,1563482761.849 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:46:05.077Z,1563482765.077 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:46:07.897Z,1563482767.897 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:46:10.738Z,1563482770.738 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:46:12.757Z,1563482772.757 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:46:13.645Z,1563482773.645 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-18T20:46:13.645Z,1563482773.645 [Default:CheckIn:C.Wait] Stopped
2019-07-18T20:46:13.645Z,1563482773.645 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-18T20:46:13.646Z,1563482773.646 [Default:CheckIn:D] Running Loop=1
2019-07-18T20:46:13.974Z,1563482773.974 [Default:CheckIn:D] Stopped
2019-07-18T20:46:13.974Z,1563482773.974 [Default:CheckIn:E] Running Loop=1
2019-07-18T20:46:14.382Z,1563482774.382 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.369400 min 
2019-07-18T20:46:14.382Z,1563482774.382 [Default:CheckIn:E] Stopped
2019-07-18T20:46:14.383Z,1563482774.383 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-18T20:46:14.383Z,1563482774.383 [Default:CheckIn] Stopped
2019-07-18T20:46:14.383Z,1563482774.383 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-18T20:46:14.383Z,1563482774.383 [Default:CheckIn](INFO): Running loop #2
2019-07-18T20:46:14.383Z,1563482774.383 [Default:CheckIn] Running Loop=2
2019-07-18T20:46:14.383Z,1563482774.383 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-18T20:46:14.383Z,1563482774.383 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-18T20:46:15.989Z,1563482775.989 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:46:18.806Z,1563482778.806 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:46:22.049Z,1563482782.049 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:46:24.869Z,1563482784.869 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:46:27.705Z,1563482787.705 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:46:29.725Z,1563482789.725 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:46:31.737Z,1563482791.737 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:46:34.969Z,1563482794.969 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:46:37.797Z,1563482797.797 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:46:41.029Z,1563482801.029 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:46:43.857Z,1563482803.857 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:46:46.681Z,1563482806.681 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:46:48.713Z,1563482808.713 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:46:50.733Z,1563482810.733 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:46:52.741Z,1563482812.741 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:46:55.989Z,1563482815.989 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:46:58.801Z,1563482818.801 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:47:02.049Z,1563482822.049 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:47:04.861Z,1563482824.861 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:47:07.701Z,1563482827.701 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:47:09.709Z,1563482829.709 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:47:11.733Z,1563482831.733 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:47:13.761Z,1563482833.761 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:47:16.981Z,1563482836.981 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:47:19.809Z,1563482839.809 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:47:23.041Z,1563482843.041 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:47:25.869Z,1563482845.869 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:47:28.701Z,1563482848.701 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:47:29.977Z,1563482849.977 [CBIT](INFO): Clearing failed state for component DropWeight
2019-07-18T20:47:29.977Z,1563482849.977 [DropWeight] No Fault, FailCount= 1
2019-07-18T20:47:30.737Z,1563482850.737 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:47:32.737Z,1563482852.737 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:47:33.177Z,1563482853.177 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2019-07-18T20:47:33.177Z,1563482853.177 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-18T20:47:33.203Z,1563482853.203 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-18T20:47:33.652Z,1563482853.652 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-18T20:47:33.652Z,1563482853.652 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2019-07-18T20:47:35.981Z,1563482855.981 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:47:38.798Z,1563482858.798 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:47:42.045Z,1563482862.045 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:47:44.861Z,1563482864.861 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:47:48.101Z,1563482868.101 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:47:50.929Z,1563482870.929 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:47:53.749Z,1563482873.749 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:47:56.977Z,1563482876.977 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:47:59.805Z,1563482879.805 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:48:03.041Z,1563482883.041 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:48:05.869Z,1563482885.869 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:48:09.101Z,1563482889.101 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:48:11.957Z,1563482891.957 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:48:14.769Z,1563482894.769 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:48:17.989Z,1563482897.989 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:48:20.817Z,1563482900.817 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:48:23.645Z,1563482903.645 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:48:26.473Z,1563482906.473 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:48:28.493Z,1563482908.493 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:48:31.029Z,1563482911.029 [CBIT](INFO): Clearing failed state for component BPC1
2019-07-18T20:48:31.030Z,1563482911.030 [BPC1] No Fault, FailCount= 1
2019-07-18T20:48:31.725Z,1563482911.725 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:48:34.556Z,1563482914.556 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:48:37.785Z,1563482917.785 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:48:40.609Z,1563482920.609 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:48:43.845Z,1563482923.845 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:48:46.673Z,1563482926.673 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:48:49.501Z,1563482929.501 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:48:51.957Z,1563482931.957 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:48:54.753Z,1563482934.753 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:48:57.985Z,1563482937.985 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:49:00.813Z,1563482940.813 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:49:03.645Z,1563482943.645 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:49:06.478Z,1563482946.478 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:49:08.485Z,1563482948.485 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:49:11.729Z,1563482951.729 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:49:14.550Z,1563482954.550 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:49:17.781Z,1563482957.781 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:49:20.621Z,1563482960.621 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:49:23.841Z,1563482963.841 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:49:26.665Z,1563482966.665 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:49:29.501Z,1563482969.501 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:49:32.741Z,1563482972.741 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:49:35.561Z,1563482975.561 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:49:38.789Z,1563482978.789 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:49:41.617Z,1563482981.617 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:49:44.845Z,1563482984.845 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:49:47.687Z,1563482987.687 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:49:49.843Z,1563482989.843 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:49:50.509Z,1563482990.509 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:49:53.737Z,1563482993.737 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:49:54.973Z,1563482994.973 [RDI_Pathfinder](ERROR): only read 1 of 4 data items
2019-07-18T20:49:54.973Z,1563482994.973 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,

2019-07-18T20:49:56.597Z,1563482996.597 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:49:59.797Z,1563482999.797 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:50:02.625Z,1563483002.625 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:50:05.449Z,1563483005.449 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:50:07.485Z,1563483007.485 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:50:09.897Z,1563483009.897 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:50:12.725Z,1563483012.725 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:50:15.957Z,1563483015.957 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:50:18.781Z,1563483018.781 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:50:21.613Z,1563483021.613 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:50:24.437Z,1563483024.437 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:50:26.462Z,1563483026.462 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:50:28.481Z,1563483028.481 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:50:31.721Z,1563483031.721 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:50:34.145Z,1563483034.145 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2019-07-18T20:50:34.145Z,1563483034.145 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-18T20:50:34.185Z,1563483034.185 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-18T20:50:34.537Z,1563483034.537 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:50:34.614Z,1563483034.614 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-18T20:50:34.614Z,1563483034.614 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2019-07-18T20:50:34.962Z,1563483034.962 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-07-18T20:50:34.962Z,1563483034.962 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19071814003254,35.0, -0.1,   0.0,1448.9,,  0.00,   0.00,   0.00,   0.00,   0.00
2019-07-18T20:50:37.773Z,1563483037.773 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:50:40.673Z,1563483040.673 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:50:43.505Z,1563483043.505 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:50:45.937Z,1563483045.937 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:50:48.761Z,1563483048.761 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:50:51.706Z,1563483051.706 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:50:51.989Z,1563483051.989 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:50:54.817Z,1563483054.817 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:50:57.657Z,1563483057.657 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:51:00.473Z,1563483060.473 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:51:02.517Z,1563483062.517 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:51:02.725Z,1563483062.725 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:51:05.725Z,1563483065.725 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:51:08.549Z,1563483068.549 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:51:11.793Z,1563483071.793 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:51:13.644Z,1563483073.644 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:51:14.629Z,1563483074.629 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:51:14.707Z,1563483074.707 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-07-18T20:46:14.4Z
2019-07-18T20:51:14.707Z,1563483074.707 [Default:CheckIn:Read_GPS] Stopped
2019-07-18T20:51:14.708Z,1563483074.708 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-18T20:51:17.793Z,1563483077.793 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:51:20.621Z,1563483080.621 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:51:22.863Z,1563483082.863 [DataOverHttps](INFO): Sending 171 bytes from file Logs/20190718T203218/Express0008.lzma
2019-07-18T20:51:23.449Z,1563483083.449 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:51:23.678Z,1563483083.678 [DataOverHttps](INFO): Moved sent file to Logs/20190718T203218/Express0008.lzma.bak
2019-07-18T20:51:23.679Z,1563483083.679 [DataOverHttps](INFO): SBD MOMSN=11455047
2019-07-18T20:51:24.478Z,1563483084.478 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-18T20:51:24.510Z,1563483084.510 [Default:CheckIn:Read_Iridium] Stopped
2019-07-18T20:51:24.510Z,1563483084.510 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-18T20:51:24.510Z,1563483084.510 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-18T20:51:25.481Z,1563483085.481 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:51:27.893Z,1563483087.893 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:51:29.107Z,1563483089.107 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-18T20:51:30.817Z,1563483090.817 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:51:32.130Z,1563483092.130 [CommandLine](IMPORTANT): got command quit
2019-07-18T20:51:33.149Z,1563483093.149 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-18T20:51:33.150Z,1563483093.150 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-07-18T20:51:33.238Z,1563483093.238 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-07-18T20:51:33.238Z,1563483093.238 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-07-18T20:51:33.239Z,1563483093.239 [CommandLine](INFO): Join timeout helper Thread ID is 938
2019-07-18T20:51:33.240Z,1563483093.240 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-07-18T20:51:33.241Z,1563483093.241 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-07-18T20:51:33.245Z,1563483093.245 [NavChartDb](INFO): Join timeout helper Thread ID is 939
2019-07-18T20:51:33.337Z,1563483093.337 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-18T20:51:33.337Z,1563483093.337 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-07-18T20:51:33.345Z,1563483093.345 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2019-07-18T20:51:33.345Z,1563483093.345 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-07-18T20:51:33.345Z,1563483093.345 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 940
2019-07-18T20:51:33.649Z,1563483093.649 [NAL9602](DEBUG): Fix Requested
2019-07-18T20:51:33.673Z,1563483093.673 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-18T20:51:33.673Z,1563483093.673 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-07-18T20:51:33.674Z,1563483093.674 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-07-18T20:51:33.681Z,1563483093.681 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-07-18T20:51:33.681Z,1563483093.681 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-07-18T20:51:33.681Z,1563483093.681 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 941
2019-07-18T20:51:33.845Z,1563483093.845 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-18T20:51:33.845Z,1563483093.845 [CTD_NeilBrown](INFO): Powering down
2019-07-18T20:51:33.857Z,1563483093.857 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-07-18T20:51:33.873Z,1563483093.873 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-07-18T20:51:33.873Z,1563483093.873 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-07-18T20:51:33.873Z,1563483093.873 [Radio_Surface](INFO): Join timeout helper Thread ID is 942
2019-07-18T20:51:34.137Z,1563483094.137 [Radio_Surface](INFO): Powering down
2019-07-18T20:51:34.138Z,1563483094.138 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-18T20:51:34.138Z,1563483094.138 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-07-18T20:51:34.142Z,1563483094.142 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-07-18T20:51:34.142Z,1563483094.142 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-07-18T20:51:34.142Z,1563483094.142 [DataOverHttps](INFO): Join timeout helper Thread ID is 943
2019-07-18T20:51:35.015Z,1563483095.015 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-18T20:51:35.019Z,1563483095.019 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-07-18T20:51:35.034Z,1563483095.034 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-07-18T20:51:35.034Z,1563483095.034 [logger ThreadHandler](INFO): Thread cancelled.
2019-07-18T20:51:35.034Z,1563483095.034 [logger](INFO): Join timeout helper Thread ID is 944
2019-07-18T20:51:35.081Z,1563483095.081 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-18T20:51:35.081Z,1563483095.081 [logger ThreadHandler](INFO): Thread cancelled.
2019-07-18T20:51:35.093Z,1563483095.093 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-07-18T20:51:35.093Z,1563483095.093 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-07-18T20:51:35.094Z,1563483095.094 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-07-18T20:51:35.094Z,1563483095.094 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-07-18T20:51:35.094Z,1563483095.094 [controlThread](INFO): Join timeout helper Thread ID is 945
2019-07-18T20:51:35.237Z,1563483095.237 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-18T20:51:35.237Z,1563483095.237 [controlThread](DEBUG): Uninitializing ControlThread
2019-07-18T20:51:35.237Z,1563483095.237 [AHRS_M2](INFO): Powering down
2019-07-18T20:51:35.309Z,1563483095.309 [DUSBL_Hydroid](INFO): Powering down
2019-07-18T20:51:35.401Z,1563483095.401 [Micromodem](INFO): Powering down
2019-07-18T20:51:35.497Z,1563483095.497 [NAL9602](INFO): Powering down
2019-07-18T20:51:35.569Z,1563483095.569 [RDI_Pathfinder](INFO): Powering down
2019-07-18T20:51:35.570Z,1563483095.570 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-07-18T20:51:35.571Z,1563483095.571 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-07-18T20:51:35.572Z,1563483095.572 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-07-18T20:51:35.572Z,1563483095.572 [MissionManager](INFO): Uninitializing Mission Default
2019-07-18T20:51:35.572Z,1563483095.572 [Default] Stopped
2019-07-18T20:51:35.572Z,1563483095.572 [Default](DEBUG): Aggregate::uninitialize Default
2019-07-18T20:51:35.572Z,1563483095.572 [Default:B.GoToSurface] Stopped
2019-07-18T20:51:35.573Z,1563483095.573 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-07-18T20:51:35.573Z,1563483095.573 [Default:CheckIn] Stopped
2019-07-18T20:51:35.573Z,1563483095.573 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-18T20:51:35.573Z,1563483095.573 [Default:CheckIn:C.Wait] Stopped
2019-07-18T20:51:35.573Z,1563483095.573 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-18T20:51:35.575Z,1563483095.575 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-07-18T20:51:35.576Z,1563483095.576 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-07-18T20:51:35.576Z,1563483095.576 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-07-18T20:51:35.576Z,1563483095.576 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-07-18T20:51:35.577Z,1563483095.577 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-07-18T20:51:35.577Z,1563483095.577 [BuoyancyServo](INFO): Powering down
2019-07-18T20:51:35.589Z,1563483095.589 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-07-18T20:51:35.589Z,1563483095.589 [ElevatorServo](INFO): Powering down
2019-07-18T20:51:35.590Z,1563483095.590 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-07-18T20:51:35.590Z,1563483095.590 [MassServo](INFO): Powering down
2019-07-18T20:51:35.590Z,1563483095.590 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-07-18T20:51:35.591Z,1563483095.591 [RudderServo](INFO): Powering down
2019-07-18T20:51:35.591Z,1563483095.591 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-07-18T20:51:35.591Z,1563483095.591 [ThrusterServo](INFO): Powering down
2019-07-18T20:51:35.592Z,1563483095.592 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-07-18T20:51:35.593Z,1563483095.593 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-07-18T20:51:35.593Z,1563483095.593 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-07-18T20:51:35.593Z,1563483095.593 [CBIT](DEBUG): Powering off loads.
2019-07-18T20:51:35.604Z,1563483095.604 [CBIT](DEBUG): Disabling WDT.
2019-07-18T20:51:35.616Z,1563483095.616 [CBIT](DEBUG): Opening all GF detection circuits.
2019-07-18T20:51:35.617Z,1563483095.617 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-07-18T20:51:35.677Z,1563483095.677 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-07-18T20:51:35.686Z,1563483095.686 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-07-18T20:51:35.728Z,1563483095.728 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-07-18T20:51:35.731Z,1563483095.731 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-07-18T20:51:35.803Z,1563483095.803 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-07-18T20:51:35.861Z,1563483095.861 [logger ThreadHandler](INFO): Thread cancelled.