2019-07-01T15:48:40.073Z,1561996120.073 [Supervisor](DEBUG): Initializing supervisor. 2019-07-01T15:48:40.076Z,1561996120.076 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2019-07-01T15:48:40.076Z,1561996120.076 [SyncHandler](INFO): Protected caller Thread ID is 2527 2019-07-01T15:48:40.077Z,1561996120.077 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2019-07-01T15:48:40.078Z,1561996120.078 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2019-07-01T15:48:40.078Z,1561996120.078 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2528 2019-07-01T15:48:40.081Z,1561996120.081 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2019-07-01T15:48:40.092Z,1561996120.092 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2019-07-01T15:48:40.093Z,1561996120.093 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2019-07-01T15:48:40.094Z,1561996120.094 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2529 2019-07-01T15:48:40.094Z,1561996120.094 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2019-07-01T15:48:40.095Z,1561996120.095 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2019-07-01T15:48:40.096Z,1561996120.096 [logger ThreadHandler](INFO): Protected caller Thread ID is 2530 2019-07-01T15:48:40.098Z,1561996120.098 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2019-07-01T15:48:40.098Z,1561996120.098 [Supervisor](INFO): Looking for Config files in directory: Config/ 2019-07-01T15:48:40.100Z,1561996120.100 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2019-07-01T15:48:40.534Z,1561996120.534 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2019-07-01T15:48:40.534Z,1561996120.534 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2019-07-01T15:48:40.633Z,1561996120.633 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2019-07-01T15:48:40.633Z,1561996120.633 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2019-07-01T15:48:40.944Z,1561996120.944 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2019-07-01T15:48:40.944Z,1561996120.944 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2019-07-01T15:48:41.084Z,1561996121.084 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2019-07-01T15:48:41.084Z,1561996121.084 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2019-07-01T15:48:41.274Z,1561996121.274 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2019-07-01T15:48:41.274Z,1561996121.274 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2019-07-01T15:48:41.714Z,1561996121.714 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2019-07-01T15:48:41.715Z,1561996121.715 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2019-07-01T15:48:41.917Z,1561996121.917 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2019-07-01T15:48:41.918Z,1561996121.918 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2019-07-01T15:48:42.061Z,1561996122.061 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2019-07-01T15:48:42.062Z,1561996122.062 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2019-07-01T15:48:42.253Z,1561996122.253 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2019-07-01T15:48:42.253Z,1561996122.253 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2019-07-01T15:48:42.350Z,1561996122.350 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2019-07-01T15:48:42.350Z,1561996122.350 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2019-07-01T15:48:42.644Z,1561996122.644 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2019-07-01T15:48:42.644Z,1561996122.644 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2019-07-01T15:48:42.726Z,1561996122.726 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2019-07-01T15:48:42.829Z,1561996122.829 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2019-07-01T15:48:42.829Z,1561996122.829 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2019-07-01T15:48:43.406Z,1561996123.406 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2019-07-01T15:48:43.407Z,1561996123.407 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2019-07-01T15:48:43.792Z,1561996123.792 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2019-07-01T15:48:43.794Z,1561996123.794 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/ 2019-07-01T15:48:43.795Z,1561996123.795 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg 2019-07-01T15:48:44.334Z,1561996124.334 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg 2019-07-01T15:48:45.088Z,1561996125.088 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg 2019-07-01T15:48:45.188Z,1561996125.188 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg 2019-07-01T15:48:45.499Z,1561996125.499 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2019-07-01T15:48:45.500Z,1561996125.500 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg 2019-07-01T15:48:45.588Z,1561996125.588 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg 2019-07-01T15:48:45.681Z,1561996125.681 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg 2019-07-01T15:48:45.778Z,1561996125.778 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg 2019-07-01T15:48:45.862Z,1561996125.862 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg 2019-07-01T15:48:45.969Z,1561996125.969 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg 2019-07-01T15:48:46.144Z,1561996126.144 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg 2019-07-01T15:48:46.272Z,1561996126.272 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2019-07-01T15:48:46.276Z,1561996126.276 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2019-07-01T15:48:47.015Z,1561996127.015 [AHRS_M2] Loaded 2019-07-01T15:48:47.016Z,1561996127.016 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2019-07-01T15:48:47.110Z,1561996127.110 [DataOverHttps] Loaded 2019-07-01T15:48:47.111Z,1561996127.111 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2019-07-01T15:48:47.112Z,1561996127.112 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407654E0 2019-07-01T15:48:47.112Z,1561996127.112 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 2610 2019-07-01T15:48:47.125Z,1561996127.125 [Depth_Keller] Loaded 2019-07-01T15:48:47.125Z,1561996127.125 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2019-07-01T15:48:47.130Z,1561996127.130 [DropWeight] Loaded 2019-07-01T15:48:47.130Z,1561996127.130 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2019-07-01T15:48:47.185Z,1561996127.185 [DUSBL_Hydroid] Loaded 2019-07-01T15:48:47.185Z,1561996127.185 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread. 2019-07-01T15:48:47.285Z,1561996127.285 [NAL9602] Loaded 2019-07-01T15:48:47.285Z,1561996127.285 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2019-07-01T15:48:47.300Z,1561996127.300 [Onboard] Loaded 2019-07-01T15:48:47.301Z,1561996127.301 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2019-07-01T15:48:47.306Z,1561996127.306 [PowerOnly] Loaded 2019-07-01T15:48:47.307Z,1561996127.307 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread. 2019-07-01T15:48:47.313Z,1561996127.313 [Radio_Surface] Loaded 2019-07-01T15:48:47.313Z,1561996127.313 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2019-07-01T15:48:47.314Z,1561996127.314 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407954E0 2019-07-01T15:48:47.314Z,1561996127.314 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2611 2019-07-01T15:48:47.356Z,1561996127.356 [RDI_Pathfinder] Loaded 2019-07-01T15:48:47.357Z,1561996127.357 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread. 2019-07-01T15:48:48.798Z,1561996128.798 [BPC1] Loaded 2019-07-01T15:48:48.798Z,1561996128.798 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2019-07-01T15:48:48.799Z,1561996128.799 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2019-07-01T15:48:48.799Z,1561996128.799 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2019-07-01T15:48:48.823Z,1561996128.823 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2019-07-01T15:48:48.823Z,1561996128.823 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2019-07-01T15:48:48.948Z,1561996128.948 [DeadReckonUsingMultipleVelocitySources] Loaded 2019-07-01T15:48:48.948Z,1561996128.948 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2019-07-01T15:48:48.968Z,1561996128.968 [NavChart] Loaded 2019-07-01T15:48:48.968Z,1561996128.968 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2019-07-01T15:48:48.972Z,1561996128.972 [UniversalFixResidualReporter] Loaded 2019-07-01T15:48:48.972Z,1561996128.972 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2019-07-01T15:48:48.972Z,1561996128.972 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2019-07-01T15:48:48.973Z,1561996128.973 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2019-07-01T15:48:49.100Z,1561996129.100 [BuoyancyServo] Loaded 2019-07-01T15:48:49.100Z,1561996129.100 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2019-07-01T15:48:49.115Z,1561996129.115 [ElevatorServo] Loaded 2019-07-01T15:48:49.115Z,1561996129.115 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2019-07-01T15:48:49.129Z,1561996129.129 [MassServo] Loaded 2019-07-01T15:48:49.130Z,1561996129.130 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2019-07-01T15:48:49.144Z,1561996129.144 [RudderServo] Loaded 2019-07-01T15:48:49.144Z,1561996129.144 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2019-07-01T15:48:49.158Z,1561996129.158 [ThrusterServo] Loaded 2019-07-01T15:48:49.159Z,1561996129.159 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2019-07-01T15:48:49.159Z,1561996129.159 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2019-07-01T15:48:49.160Z,1561996129.160 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2019-07-01T15:48:49.752Z,1561996129.752 [CTD_NeilBrown] Loaded 2019-07-01T15:48:49.752Z,1561996129.752 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2019-07-01T15:48:49.754Z,1561996129.754 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408E04E0 2019-07-01T15:48:49.754Z,1561996129.754 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 2612 2019-07-01T15:48:49.797Z,1561996129.797 [WetLabsSeaOWL_UV_A] Loaded 2019-07-01T15:48:49.797Z,1561996129.797 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread. 2019-07-01T15:48:49.798Z,1561996129.798 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409104E0 2019-07-01T15:48:49.798Z,1561996129.798 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 2613 2019-07-01T15:48:49.799Z,1561996129.799 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2019-07-01T15:48:49.799Z,1561996129.799 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2019-07-01T15:48:50.141Z,1561996130.141 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2019-07-01T15:48:50.142Z,1561996130.142 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2019-07-01T15:48:50.196Z,1561996130.196 [DepthRateCalculator] Loaded 2019-07-01T15:48:50.196Z,1561996130.196 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2019-07-01T15:48:50.202Z,1561996130.202 [PitchRateCalculator] Loaded 2019-07-01T15:48:50.202Z,1561996130.202 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2019-07-01T15:48:50.214Z,1561996130.214 [SpeedCalculator] Loaded 2019-07-01T15:48:50.214Z,1561996130.214 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2019-07-01T15:48:50.234Z,1561996130.234 [TempGradientCalculator] Loaded 2019-07-01T15:48:50.235Z,1561996130.235 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2019-07-01T15:48:50.240Z,1561996130.240 [YawRateCalculator] Loaded 2019-07-01T15:48:50.240Z,1561996130.240 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2019-07-01T15:48:50.279Z,1561996130.279 [ElevatorOffsetCalculator] Loaded 2019-07-01T15:48:50.279Z,1561996130.279 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2019-07-01T15:48:50.280Z,1561996130.280 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2019-07-01T15:48:50.280Z,1561996130.280 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2019-07-01T15:48:50.440Z,1561996130.440 [SBIT](DEBUG): Construct Startup Built In Test. 2019-07-01T15:48:50.461Z,1561996130.461 [SBIT] Loaded 2019-07-01T15:48:50.461Z,1561996130.461 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2019-07-01T15:48:50.462Z,1561996130.462 [IBIT](DEBUG): Construct Initiated Built In Test. 2019-07-01T15:48:50.473Z,1561996130.473 [IBIT] Loaded 2019-07-01T15:48:50.474Z,1561996130.474 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2019-07-01T15:48:50.477Z,1561996130.477 [CBIT](DEBUG): Construct Continuous Built In Test. 2019-07-01T15:48:50.611Z,1561996130.611 [CBIT] Loaded 2019-07-01T15:48:50.611Z,1561996130.611 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2019-07-01T15:48:50.612Z,1561996130.612 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2019-07-01T15:48:50.612Z,1561996130.612 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2019-07-01T15:48:50.739Z,1561996130.739 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2019-07-01T15:48:50.740Z,1561996130.740 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2019-07-01T15:48:50.862Z,1561996130.862 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2019-07-01T15:48:50.862Z,1561996130.862 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2019-07-01T15:48:50.950Z,1561996130.950 [VerticalControl](DEBUG): Construct VerticalControl. 2019-07-01T15:48:51.031Z,1561996131.031 [VerticalControl] Loaded 2019-07-01T15:48:51.032Z,1561996131.032 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2019-07-01T15:48:51.032Z,1561996131.032 [HorizontalControl](DEBUG): Construct HorizontalControl. 2019-07-01T15:48:51.088Z,1561996131.088 [HorizontalControl] Loaded 2019-07-01T15:48:51.088Z,1561996131.088 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2019-07-01T15:48:51.089Z,1561996131.089 [SpeedControl](DEBUG): Construct SpeedControl. 2019-07-01T15:48:51.091Z,1561996131.091 [SpeedControl] Loaded 2019-07-01T15:48:51.091Z,1561996131.091 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2019-07-01T15:48:51.092Z,1561996131.092 [LoopControl](DEBUG): Construct LoopControl. 2019-07-01T15:48:51.092Z,1561996131.092 [LoopControl] Loaded 2019-07-01T15:48:51.092Z,1561996131.092 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2019-07-01T15:48:51.093Z,1561996131.093 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2019-07-01T15:48:51.093Z,1561996131.093 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2019-07-01T15:48:51.141Z,1561996131.141 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2019-07-01T15:48:51.145Z,1561996131.145 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2019-07-01T15:48:51.146Z,1561996131.146 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2019-07-01T15:48:51.153Z,1561996131.153 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2019-07-01T15:48:51.154Z,1561996131.154 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AEC4E0 2019-07-01T15:48:51.154Z,1561996131.154 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2614 2019-07-01T15:48:51.159Z,1561996131.159 [Supervisor](INFO): Main Thread ID is 2526 2019-07-01T15:48:51.159Z,1561996131.159 [Supervisor](DEBUG): Running supervisor. 2019-07-01T15:48:51.160Z,1561996131.160 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2615 2019-07-01T15:48:51.162Z,1561996131.162 [controlThread ThreadHandler](INFO): Handler Thread ID is 2616 2019-07-01T15:48:51.163Z,1561996131.163 [controlThread](DEBUG): Initializing ControlThread 2019-07-01T15:48:51.168Z,1561996131.168 [NavChart](DEBUG): Initialize NavChart Navigation. 2019-07-01T15:48:51.168Z,1561996131.168 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2019-07-01T15:48:51.170Z,1561996131.170 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2019-07-01T15:48:51.170Z,1561996131.170 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2019-07-01T15:48:51.170Z,1561996131.170 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2019-07-01T15:48:51.170Z,1561996131.170 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2019-07-01T15:48:51.171Z,1561996131.171 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2019-07-01T15:48:51.171Z,1561996131.171 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2019-07-01T15:48:51.172Z,1561996131.172 [SBIT](INFO): Initialize SBIT Component. 2019-07-01T15:48:51.172Z,1561996131.172 [SBIT](IMPORTANT): git: 2019-07-01 2019-07-01T15:48:51.172Z,1561996131.172 [SBIT](INFO): git hash: 66ee1f914ed66d399bd38d45ccca9e12ca50b60d 2019-07-01T15:48:51.173Z,1561996131.173 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2019-07-01T15:48:51.174Z,1561996131.174 [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-01T15:48:51.175Z,1561996131.175 [SBIT](INFO): Beginning SBIT in 28.000000 seconds. 2019-07-01T15:48:51.176Z,1561996131.176 [IBIT](INFO): Initialize IBIT Component. 2019-07-01T15:48:51.177Z,1561996131.177 [CBIT](DEBUG): Initialize CBIT Component. 2019-07-01T15:48:51.178Z,1561996131.178 [logger ThreadHandler](INFO): Handler Thread ID is 2617 2019-07-01T15:48:51.189Z,1561996131.189 [CBIT](DEBUG): Initialized mux pins. 2019-07-01T15:48:51.189Z,1561996131.189 [CBIT](DEBUG): Initializing the watchdog timer. 2019-07-01T15:48:51.202Z,1561996131.202 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 2618 2019-07-01T15:48:51.203Z,1561996131.203 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2019-07-01T15:48:51.210Z,1561996131.210 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2619 2019-07-01T15:48:51.213Z,1561996131.213 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2019-07-01T15:48:51.213Z,1561996131.213 [CBIT](DEBUG): Initializing heartbeat. 2019-07-01T15:48:51.221Z,1561996131.221 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 2620 2019-07-01T15:48:51.222Z,1561996131.222 [CTD_NeilBrown](INFO): Powering down 2019-07-01T15:48:51.249Z,1561996131.249 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 2621 2019-07-01T15:48:51.250Z,1561996131.250 [WetLabsSeaOWL_UV_A](INFO): Powering down 2019-07-01T15:48:51.285Z,1561996131.285 [CBIT](DEBUG): Deactivating GF circuits. 2019-07-01T15:48:51.285Z,1561996131.285 [CBIT](DEBUG): Deactivating emergency mode. 2019-07-01T15:48:51.286Z,1561996131.286 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2622 2019-07-01T15:48:51.291Z,1561996131.291 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2019-07-01T15:48:51.291Z,1561996131.291 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2019-07-01T15:48:51.291Z,1561996131.291 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2019-07-01T15:48:51.292Z,1561996131.292 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2019-07-01T15:48:51.292Z,1561996131.292 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2019-07-01T15:48:51.292Z,1561996131.292 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2019-07-01T15:48:51.292Z,1561996131.292 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2019-07-01T15:48:51.292Z,1561996131.292 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2019-07-01T15:48:51.293Z,1561996131.293 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2019-07-01T15:48:51.293Z,1561996131.293 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2019-07-01T15:48:51.293Z,1561996131.293 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2019-07-01T15:48:51.293Z,1561996131.293 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2019-07-01T15:48:51.293Z,1561996131.293 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2019-07-01T15:48:51.294Z,1561996131.294 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2019-07-01T15:48:51.294Z,1561996131.294 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2019-07-01T15:48:51.294Z,1561996131.294 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2019-07-01T15:48:51.321Z,1561996131.321 [CBIT](DEBUG): Backplane powered. 2019-07-01T15:48:51.321Z,1561996131.321 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2019-07-01T15:48:51.323Z,1561996131.323 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2019-07-01T15:48:51.324Z,1561996131.324 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2019-07-01T15:48:51.324Z,1561996131.324 [LoopControl](DEBUG): Initialize LoopControlComponent. 2019-07-01T15:48:51.325Z,1561996131.325 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2019-07-01T15:48:51.346Z,1561996131.346 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2019-07-01T15:48:51.373Z,1561996131.373 [MissionManager](DEBUG): 2019-07-01T15:48:51.373Z,1561996131.373 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2019-07-01T15:48:51.453Z,1561996131.453 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2019-07-01T15:48:51.454Z,1561996131.454 [Default:A.Wait](DEBUG): Construct Wait. 2019-07-01T15:48:51.456Z,1561996131.456 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2019-07-01T15:48:51.475Z,1561996131.475 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2019-07-01T15:48:51.502Z,1561996131.502 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2019-07-01T15:48:51.508Z,1561996131.508 [Default:E.Execute](DEBUG): Construct Execute. 2019-07-01T15:48:51.527Z,1561996131.527 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2019-07-01T15:48:51.532Z,1561996131.532 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DUSBL_Hydroid,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-01T15:48:51.562Z,1561996131.562 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-07-01T15:48:51.613Z,1561996131.613 [Radio_Surface](INFO): Powering up 2019-07-01T15:48:51.811Z,1561996131.811 [Depth_Keller](ERROR): Pressure reading out of range: 957.962097 decibar 2019-07-01T15:48:51.814Z,1561996131.814 [DUSBL_Hydroid](INFO): Powering up 2019-07-01T15:48:51.814Z,1561996131.814 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid. 2019-07-01T15:48:51.893Z,1561996131.893 [DepthRateCalculator](ERROR): Depth measurement is not active 2019-07-01T15:48:51.947Z,1561996131.947 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2019-07-01T15:48:51.953Z,1561996131.953 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2019-07-01T15:48:51.954Z,1561996131.954 [ElevatorServo](DEBUG): Initializing EZServoServo. 2019-07-01T15:48:51.961Z,1561996131.961 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2019-07-01T15:48:51.962Z,1561996131.962 [MassServo](DEBUG): Initializing EZServoServo. 2019-07-01T15:48:51.969Z,1561996131.969 [MassServo](DEBUG): Initializing MassServo. 2019-07-01T15:48:51.970Z,1561996131.970 [RudderServo](DEBUG): Initializing EZServoServo. 2019-07-01T15:48:51.977Z,1561996131.977 [RudderServo](DEBUG): Initializing RudderServo. 2019-07-01T15:48:51.978Z,1561996131.978 [ThrusterServo](DEBUG): Initializing EZServoServo. 2019-07-01T15:48:51.985Z,1561996131.985 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2019-07-01T15:48:52.105Z,1561996132.105 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2019-07-01T15:48:52.105Z,1561996132.105 [DropWeight] Hardware Fault, FailCount= 1 2019-07-01T15:48:52.105Z,1561996132.105 [DropWeight](ERROR): Hardware Fault 2019-07-01T15:48:52.149Z,1561996132.149 [DepthRateCalculator](ERROR): Depth measurement is not active 2019-07-01T15:48:52.180Z,1561996132.180 [CommandLine](FAULT): Scheduling is paused 2019-07-01T15:48:52.181Z,1561996132.181 [CBIT](INFO): Critical error at 20190701T154852 2019-07-01T15:48:52.181Z,1561996132.181 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2019-07-01T15:48:52.183Z,1561996132.183 [CBIT](ERROR): Hardware Fault in component: DropWeight 2019-07-01T15:48:52.184Z,1561996132.184 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2019-07-01T15:48:52.433Z,1561996132.433 [CBIT](INFO): Critical error at 20190701T154852 2019-07-01T15:49:03.821Z,1561996143.821 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.098671 2019-07-01T15:49:05.360Z,1561996145.360 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder 2019-07-01T15:49:09.778Z,1561996149.778 [DUSBL_Hydroid](INFO): DUSBL Version:O 2019-07-01T15:49:17.454Z,1561996157.454 [NAL9602](INFO): Powering up NAL9602 2019-07-01T15:49:19.918Z,1561996159.918 [SBIT](IMPORTANT): Beginning Startup BIT 2019-07-01T15:49:19.923Z,1561996159.923 [CBIT](IMPORTANT): Beginning ground fault scan 2019-07-01T15:49:28.462Z,1561996168.462 [NAL9602](INFO): NAL9602 initialized 2019-07-01T15:49:29.277Z,1561996169.277 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:49:30.962Z,1561996170.962 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.009283 CHAN A1 (24V): -0.197461 CHAN A2 (12V): -0.007041 CHAN A3 (5V): -0.002339 CHAN B0 (3.3V): 0.000223 CHAN B1 (3.15aV): 0.000516 CHAN B2 (3.15bV): 0.000087 CHAN B3 (GND): 0.001721 OPEN: 0.005192 Full Scale Calc: 4.765 mA, -1.589 mA 2019-07-01T15:49:58.909Z,1561996198.909 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2019-07-01T15:50:13.574Z,1561996213.574 [SBIT](IMPORTANT): SBIT PASSED 2019-07-01T15:50:13.607Z,1561996213.607 [CommandLine](IMPORTANT): got command configSet list 2019-07-01T15:50:13.607Z,1561996213.607 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2019-07-01T15:50:13.608Z,1561996213.608 [CommandLine](IMPORTANT): Micromodem.loadAtStartup=0 bool; 2019-07-01T15:50:13.922Z,1561996213.922 [MissionManager](IMPORTANT): Started mission Startup 2019-07-01T15:50:13.922Z,1561996213.922 [Startup] Running Loop=1 2019-07-01T15:50:13.922Z,1561996213.922 [Startup](DEBUG): Aggregate::initialize Startup 2019-07-01T15:50:13.922Z,1561996213.922 [Startup:A.GoToSurface] Running Loop=1 2019-07-01T15:50:13.922Z,1561996213.922 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-07-01T15:50:13.923Z,1561996213.923 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-07-01T15:50:13.923Z,1561996213.923 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-07-01T15:50:13.924Z,1561996213.924 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-07-01T15:50:13.924Z,1561996213.924 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-07-01T15:50:13.925Z,1561996213.925 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-07-01T15:50:13.926Z,1561996213.926 [Startup:StartupSatComms] Running Loop=1 2019-07-01T15:50:13.926Z,1561996213.926 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2019-07-01T15:50:13.926Z,1561996213.926 [Startup:StartupSatComms:A] Running Loop=1 2019-07-01T15:50:14.338Z,1561996214.338 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2019-07-01T15:51:08.898Z,1561996268.898 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2019-07-01T15:51:14.102Z,1561996274.102 [Startup:StartupSatComms:A](INFO): Timed out from 2019-07-01T15:50:13.9Z 2019-07-01T15:51:14.102Z,1561996274.102 [Startup:StartupSatComms:A] Stopped 2019-07-01T15:51:14.102Z,1561996274.102 [Startup:StartupSatComms:B] Running Loop=1 2019-07-01T15:51:14.524Z,1561996274.524 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-07-01T15:51:16.827Z,1561996276.827 [DataOverHttps](INFO): Sending 287 bytes from file Logs/20190624T232945/Courier0000.lzma 2019-07-01T15:51:17.638Z,1561996277.638 [DataOverHttps](INFO): Moved sent file to Logs/20190624T232945/Courier0000.lzma.bak 2019-07-01T15:51:17.639Z,1561996277.639 [DataOverHttps](INFO): SBD MOMSN=11416427 2019-07-01T15:51:29.362Z,1561996289.362 [DataOverHttps](INFO): Sending 199 bytes from file Logs/20190624T233715/Courier0000.lzma 2019-07-01T15:51:30.166Z,1561996290.166 [DataOverHttps](INFO): Moved sent file to Logs/20190624T233715/Courier0000.lzma.bak 2019-07-01T15:51:30.167Z,1561996290.167 [DataOverHttps](INFO): SBD MOMSN=11416435 2019-07-01T15:51:41.196Z,1561996301.196 [DataOverHttps](INFO): Sending 133 bytes from file Logs/20190701T154840/Courier0000.lzma 2019-07-01T15:51:42.002Z,1561996302.002 [DataOverHttps](INFO): Moved sent file to Logs/20190701T154840/Courier0000.lzma.bak 2019-07-01T15:51:42.002Z,1561996302.002 [DataOverHttps](INFO): SBD MOMSN=11416441 2019-07-01T15:51:51.409Z,1561996311.409 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2019-07-01T15:51:51.409Z,1561996311.409 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-01T15:51:51.451Z,1561996311.451 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-01T15:51:51.802Z,1561996311.802 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-01T15:51:51.802Z,1561996311.802 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2019-07-01T15:51:53.530Z,1561996313.530 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2019-07-01T15:51:54.203Z,1561996314.203 [DataOverHttps](INFO): Sending 193 bytes from file Logs/20190624T231536/Express0005.lzma 2019-07-01T15:51:55.006Z,1561996315.006 [DataOverHttps](INFO): Moved sent file to Logs/20190624T231536/Express0005.lzma.bak 2019-07-01T15:51:55.007Z,1561996315.007 [DataOverHttps](INFO): SBD MOMSN=11416446 2019-07-01T15:52:12.630Z,1561996332.630 [DataOverHttps](INFO): Sending 659 bytes from file Logs/20190624T232024/Express0001.lzma 2019-07-01T15:52:14.025Z,1561996334.025 [DataOverHttps](INFO): Moved sent file to Logs/20190624T232024/Express0001.lzma.bak 2019-07-01T15:52:14.026Z,1561996334.026 [DataOverHttps](INFO): SBD MOMSN=11416454 2019-07-01T15:52:14.496Z,1561996334.496 [Startup:StartupSatComms:B](INFO): Timed out from 2019-07-01T15:51:14.1Z 2019-07-01T15:52:14.496Z,1561996334.496 [Startup:StartupSatComms:B] Stopped 2019-07-01T15:52:14.496Z,1561996334.496 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2019-07-01T15:52:14.496Z,1561996334.496 [Startup:StartupSatComms] Stopped 2019-07-01T15:52:14.496Z,1561996334.496 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2019-07-01T15:52:14.505Z,1561996334.505 [Startup](INFO): Completed Startup 2019-07-01T15:52:14.506Z,1561996334.506 [MissionManager](INFO): Startup is completed. 2019-07-01T15:52:14.506Z,1561996334.506 [MissionManager](INFO): Uninitializing Mission Startup 2019-07-01T15:52:14.506Z,1561996334.506 [Startup] Stopped 2019-07-01T15:52:14.506Z,1561996334.506 [Startup](DEBUG): Aggregate::uninitialize Startup 2019-07-01T15:52:14.506Z,1561996334.506 [Startup:A.GoToSurface] Stopped 2019-07-01T15:52:14.506Z,1561996334.506 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-07-01T15:52:14.886Z,1561996334.886 [MissionManager](IMPORTANT): Started mission Default 2019-07-01T15:52:14.886Z,1561996334.886 [Default] Running Loop=1 2019-07-01T15:52:14.886Z,1561996334.886 [Default](DEBUG): Aggregate::initialize Default 2019-07-01T15:52:14.887Z,1561996334.887 [Default:B.GoToSurface] Running Loop=1 2019-07-01T15:52:14.887Z,1561996334.887 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-07-01T15:52:14.887Z,1561996334.887 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-07-01T15:52:14.887Z,1561996334.887 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-07-01T15:52:14.888Z,1561996334.888 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-07-01T15:52:14.888Z,1561996334.888 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-07-01T15:52:14.888Z,1561996334.888 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-07-01T15:52:14.888Z,1561996334.888 [Default:A.Wait] Running Loop=1 2019-07-01T15:52:14.889Z,1561996334.889 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-07-01T15:52:28.203Z,1561996348.203 [Default:A.Wait](INFO): Done Waiting. 2019-07-01T15:52:28.203Z,1561996348.203 [Default:A.Wait] Stopped 2019-07-01T15:52:28.203Z,1561996348.203 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-07-01T15:52:28.575Z,1561996348.575 [Default:CheckIn] Running Loop=1 2019-07-01T15:52:28.576Z,1561996348.576 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-07-01T15:52:28.576Z,1561996348.576 [Default:CheckIn:Read_GPS] Running Loop=1 2019-07-01T15:52:28.980Z,1561996348.980 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2019-07-01T15:52:57.418Z,1561996377.418 [DataOverHttps](INFO): Sending 435 bytes from file Logs/20190624T232303/Express0001.lzma 2019-07-01T15:52:59.092Z,1561996379.092 [DataOverHttps](INFO): Moved sent file to Logs/20190624T232303/Express0001.lzma.bak 2019-07-01T15:52:59.093Z,1561996379.093 [DataOverHttps](INFO): SBD MOMSN=11416470 2019-07-01T15:53:10.284Z,1561996390.284 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2019-07-01T15:54:04.884Z,1561996444.884 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2019-07-01T15:54:31.770Z,1561996471.770 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-07-01T15:54:32.593Z,1561996472.593 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:54:35.421Z,1561996475.421 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:54:38.649Z,1561996478.649 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:54:41.480Z,1561996481.480 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:54:44.717Z,1561996484.717 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:54:47.541Z,1561996487.541 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:54:50.777Z,1561996490.777 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:54:52.405Z,1561996492.405 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2019-07-01T15:54:52.405Z,1561996492.405 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-01T15:54:52.442Z,1561996492.442 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-01T15:54:52.818Z,1561996492.818 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-01T15:54:52.818Z,1561996492.818 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2019-07-01T15:54:53.597Z,1561996493.597 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:54:56.429Z,1561996496.429 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:54:59.657Z,1561996499.657 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:55:02.489Z,1561996502.489 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:55:05.721Z,1561996505.721 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:55:08.556Z,1561996508.556 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:55:11.784Z,1561996511.784 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:55:12.682Z,1561996512.682 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2019-07-01T15:55:14.609Z,1561996514.609 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:55:17.433Z,1561996517.433 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:55:20.669Z,1561996520.669 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:55:23.497Z,1561996523.497 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:55:26.729Z,1561996526.729 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:55:29.553Z,1561996529.553 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:55:32.381Z,1561996532.381 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:55:35.613Z,1561996535.613 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:55:38.445Z,1561996538.445 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:55:41.685Z,1561996541.685 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:55:44.505Z,1561996544.505 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:55:47.733Z,1561996547.733 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:55:50.561Z,1561996550.561 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:55:53.389Z,1561996553.389 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:55:56.621Z,1561996556.621 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:55:59.453Z,1561996559.453 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:56:02.685Z,1561996562.685 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:56:05.525Z,1561996565.525 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:56:08.749Z,1561996568.749 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:56:11.573Z,1561996571.573 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:56:14.401Z,1561996574.401 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:56:17.633Z,1561996577.633 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:56:20.465Z,1561996580.465 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:56:22.518Z,1561996582.518 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2019-07-01T15:56:22.522Z,1561996582.522 [BPC1](INFO): Received data from all battery sticks. 2019-07-01T15:56:23.689Z,1561996583.689 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:56:26.517Z,1561996586.517 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:56:29.753Z,1561996589.753 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:56:32.581Z,1561996592.581 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:56:35.405Z,1561996595.405 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:56:38.637Z,1561996598.637 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:56:41.469Z,1561996601.469 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:56:44.709Z,1561996604.709 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:56:45.463Z,1561996605.463 [CommandLine](IMPORTANT): got command burn on 2019-07-01T15:56:45.463Z,1561996605.463 [CommandLine](IMPORTANT): Activating dropweight wire 2019-07-01T15:56:47.525Z,1561996607.525 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:56:50.757Z,1561996610.757 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:56:53.585Z,1561996613.585 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:56:56.417Z,1561996616.417 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:56:59.649Z,1561996619.649 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:57:02.473Z,1561996622.473 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:57:05.705Z,1561996625.705 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:57:08.541Z,1561996628.541 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:57:11.773Z,1561996631.773 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:57:14.593Z,1561996634.593 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:57:17.421Z,1561996637.421 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:57:20.665Z,1561996640.665 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:57:23.489Z,1561996643.489 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:57:26.713Z,1561996646.713 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:57:28.758Z,1561996648.758 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-07-01T15:52:28.6Z 2019-07-01T15:57:28.758Z,1561996648.758 [Default:CheckIn:Read_GPS] Stopped 2019-07-01T15:57:28.758Z,1561996648.758 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-07-01T15:57:29.169Z,1561996649.169 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-07-01T15:57:29.541Z,1561996649.541 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:57:32.773Z,1561996652.773 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:57:34.616Z,1561996654.616 [DataOverHttps](INFO): Sending 186 bytes from file Logs/20190701T154840/Courier0004.lzma 2019-07-01T15:57:35.424Z,1561996655.424 [DataOverHttps](INFO): Moved sent file to Logs/20190701T154840/Courier0004.lzma.bak 2019-07-01T15:57:35.424Z,1561996655.424 [DataOverHttps](INFO): SBD MOMSN=11416482 2019-07-01T15:57:35.601Z,1561996655.601 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:57:38.429Z,1561996658.429 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:57:41.661Z,1561996661.661 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:57:44.489Z,1561996664.489 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:57:47.483Z,1561996667.483 [DataOverHttps](INFO): Sending 716 bytes from file Logs/20190624T232630/Express0001.lzma 2019-07-01T15:57:47.729Z,1561996667.729 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:57:48.286Z,1561996668.286 [DataOverHttps](INFO): Moved sent file to Logs/20190624T232630/Express0001.lzma.bak 2019-07-01T15:57:48.287Z,1561996668.287 [DataOverHttps](INFO): SBD MOMSN=11416484 2019-07-01T15:57:50.549Z,1561996670.549 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:57:52.767Z,1561996672.767 [CommandLine](IMPORTANT): got command burn off 2019-07-01T15:57:52.767Z,1561996672.767 [CommandLine](IMPORTANT): Deactivating dropweight wire 2019-07-01T15:57:53.405Z,1561996673.405 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2019-07-01T15:57:53.405Z,1561996673.405 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-01T15:57:53.472Z,1561996673.472 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-01T15:57:53.781Z,1561996673.781 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:57:53.862Z,1561996673.862 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-01T15:57:53.862Z,1561996673.862 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2019-07-01T15:57:56.620Z,1561996676.620 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:57:59.441Z,1561996679.441 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:58:00.410Z,1561996680.410 [DataOverHttps](INFO): Sending 124 bytes from file Logs/20190624T232630/Express0005.lzma 2019-07-01T15:58:01.214Z,1561996681.214 [DataOverHttps](INFO): Moved sent file to Logs/20190624T232630/Express0005.lzma.bak 2019-07-01T15:58:01.214Z,1561996681.214 [DataOverHttps](INFO): SBD MOMSN=11416505 2019-07-01T15:58:02.669Z,1561996682.669 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:58:05.501Z,1561996685.501 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:58:08.729Z,1561996688.729 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:58:11.557Z,1561996691.557 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:58:13.223Z,1561996693.223 [DataOverHttps](INFO): Sending 959 bytes from file Logs/20190624T232945/Express0001.lzma 2019-07-01T15:58:14.026Z,1561996694.026 [DataOverHttps](INFO): Moved sent file to Logs/20190624T232945/Express0001.lzma.bak 2019-07-01T15:58:14.027Z,1561996694.027 [DataOverHttps](INFO): SBD MOMSN=11416514 2019-07-01T15:58:14.789Z,1561996694.789 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:58:17.617Z,1561996697.617 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:58:20.445Z,1561996700.445 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:58:23.677Z,1561996703.677 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:58:26.366Z,1561996706.366 [DataOverHttps](INFO): Sending 376 bytes from file Logs/20190624T233715/Express0001.lzma 2019-07-01T15:58:26.505Z,1561996706.505 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:58:27.170Z,1561996707.170 [DataOverHttps](INFO): Moved sent file to Logs/20190624T233715/Express0001.lzma.bak 2019-07-01T15:58:27.171Z,1561996707.171 [DataOverHttps](INFO): SBD MOMSN=11416606 2019-07-01T15:58:29.741Z,1561996709.741 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:58:32.569Z,1561996712.569 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:58:35.801Z,1561996715.801 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:58:38.629Z,1561996718.629 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:58:41.465Z,1561996721.465 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:56:46.575Z,1561996606.575 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:56:49.402Z,1561996609.402 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:56:52.635Z,1561996612.635 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:56:55.462Z,1561996615.462 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:56:58.694Z,1561996618.694 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:57:01.526Z,1561996621.526 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:57:01.896Z,1561996621.896 [CommandLine](IMPORTANT): got command restart system 2019-07-01T15:57:03.951Z,1561996623.951 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-01T15:57:03.951Z,1561996623.951 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-07-01T15:57:03.991Z,1561996623.991 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2019-07-01T15:57:03.992Z,1561996623.992 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-07-01T15:57:03.993Z,1561996623.993 [CommandLine](INFO): Join timeout helper Thread ID is 2673 2019-07-01T15:57:03.994Z,1561996623.994 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2019-07-01T15:57:03.994Z,1561996623.994 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-07-01T15:57:04.019Z,1561996624.019 [NavChartDb](INFO): Join timeout helper Thread ID is 2674 2019-07-01T15:57:04.231Z,1561996624.231 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-01T15:57:04.231Z,1561996624.231 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-07-01T15:57:04.235Z,1561996624.235 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler 2019-07-01T15:57:04.235Z,1561996624.235 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2019-07-01T15:57:04.235Z,1561996624.235 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 2675 2019-07-01T15:57:04.351Z,1561996624.351 [NAL9602](DEBUG): Fix Requested 2019-07-01T15:57:04.502Z,1561996624.502 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected calle