2019-10-04T20:03:22.551Z,1570219402.551 [Supervisor](DEBUG): Initializing supervisor.
2019-10-04T20:03:22.554Z,1570219402.554 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-10-04T20:03:22.554Z,1570219402.554 [SyncHandler](INFO): Protected caller Thread ID is 1023
2019-10-04T20:03:22.555Z,1570219402.555 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-10-04T20:03:22.556Z,1570219402.556 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-10-04T20:03:22.556Z,1570219402.556 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1024
2019-10-04T20:03:22.559Z,1570219402.559 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-10-04T20:03:22.570Z,1570219402.570 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-10-04T20:03:22.571Z,1570219402.571 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-10-04T20:03:22.571Z,1570219402.571 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1025
2019-10-04T20:03:22.572Z,1570219402.572 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-10-04T20:03:22.573Z,1570219402.573 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-10-04T20:03:22.573Z,1570219402.573 [logger ThreadHandler](INFO): Protected caller Thread ID is 1026
2019-10-04T20:03:22.575Z,1570219402.575 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-10-04T20:03:22.575Z,1570219402.575 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-10-04T20:03:22.577Z,1570219402.577 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-10-04T20:03:22.989Z,1570219402.989 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-10-04T20:03:22.990Z,1570219402.990 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-10-04T20:03:23.086Z,1570219403.086 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-10-04T20:03:23.087Z,1570219403.087 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-10-04T20:03:23.396Z,1570219403.396 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-10-04T20:03:23.396Z,1570219403.396 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-10-04T20:03:23.534Z,1570219403.534 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-10-04T20:03:23.535Z,1570219403.535 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-10-04T20:03:23.723Z,1570219403.723 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-10-04T20:03:23.723Z,1570219403.723 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-10-04T20:03:24.161Z,1570219404.161 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-10-04T20:03:24.162Z,1570219404.162 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-10-04T20:03:24.364Z,1570219404.364 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-10-04T20:03:24.365Z,1570219404.365 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-10-04T20:03:24.510Z,1570219404.510 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-10-04T20:03:24.511Z,1570219404.511 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-10-04T20:03:24.700Z,1570219404.700 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-10-04T20:03:24.701Z,1570219404.701 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-10-04T20:03:24.795Z,1570219404.795 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-10-04T20:03:24.796Z,1570219404.796 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-10-04T20:03:25.089Z,1570219405.089 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-10-04T20:03:25.090Z,1570219405.090 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-10-04T20:03:25.169Z,1570219405.169 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-10-04T20:03:25.271Z,1570219405.271 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-10-04T20:03:25.272Z,1570219405.272 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-10-04T20:03:25.850Z,1570219405.850 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-10-04T20:03:25.850Z,1570219405.850 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-10-04T20:03:26.242Z,1570219406.242 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-10-04T20:03:26.244Z,1570219406.244 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2019-10-04T20:03:26.245Z,1570219406.245 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2019-10-04T20:03:26.448Z,1570219406.448 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2019-10-04T20:03:26.551Z,1570219406.551 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2019-10-04T20:03:26.746Z,1570219406.746 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2019-10-04T20:03:27.349Z,1570219407.349 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-10-04T20:03:27.349Z,1570219407.349 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2019-10-04T20:03:27.534Z,1570219407.534 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2019-10-04T20:03:27.626Z,1570219407.626 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2019-10-04T20:03:27.721Z,1570219407.721 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2019-10-04T20:03:27.803Z,1570219407.803 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2019-10-04T20:03:27.910Z,1570219407.910 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2019-10-04T20:03:28.089Z,1570219408.089 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2019-10-04T20:03:28.220Z,1570219408.220 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/root/
2019-10-04T20:03:28.220Z,1570219408.220 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-10-04T20:03:28.224Z,1570219408.224 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-10-04T20:03:28.613Z,1570219408.613 [AHRS_M2] Loaded
2019-10-04T20:03:28.613Z,1570219408.613 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-10-04T20:03:28.687Z,1570219408.687 [DataOverHttps] Loaded
2019-10-04T20:03:28.688Z,1570219408.688 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-10-04T20:03:28.689Z,1570219408.689 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407664E0
2019-10-04T20:03:28.689Z,1570219408.689 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1105
2019-10-04T20:03:28.702Z,1570219408.702 [Depth_Keller] Loaded
2019-10-04T20:03:28.702Z,1570219408.702 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-10-04T20:03:28.707Z,1570219408.707 [DropWeight] Loaded
2019-10-04T20:03:28.707Z,1570219408.707 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-10-04T20:03:28.757Z,1570219408.757 [Micromodem] Loaded
2019-10-04T20:03:28.757Z,1570219408.757 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2019-10-04T20:03:28.853Z,1570219408.853 [NAL9602] Loaded
2019-10-04T20:03:28.854Z,1570219408.854 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-10-04T20:03:28.869Z,1570219408.869 [Onboard] Loaded
2019-10-04T20:03:28.870Z,1570219408.870 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-10-04T20:03:28.875Z,1570219408.875 [PowerOnly] Loaded
2019-10-04T20:03:28.876Z,1570219408.876 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2019-10-04T20:03:28.882Z,1570219408.882 [Radio_Surface] Loaded
2019-10-04T20:03:28.882Z,1570219408.882 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-10-04T20:03:28.883Z,1570219408.883 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407964E0
2019-10-04T20:03:28.884Z,1570219408.884 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1106
2019-10-04T20:03:28.927Z,1570219408.927 [RDI_Pathfinder] Loaded
2019-10-04T20:03:28.927Z,1570219408.927 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2019-10-04T20:03:30.396Z,1570219410.396 [BPC1] Loaded
2019-10-04T20:03:30.396Z,1570219410.396 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-10-04T20:03:30.397Z,1570219410.397 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-10-04T20:03:30.397Z,1570219410.397 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-10-04T20:03:30.410Z,1570219410.410 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-10-04T20:03:30.411Z,1570219410.411 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-10-04T20:03:30.514Z,1570219410.514 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-10-04T20:03:30.515Z,1570219410.515 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-10-04T20:03:30.535Z,1570219410.535 [NavChart] Loaded
2019-10-04T20:03:30.535Z,1570219410.535 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-10-04T20:03:30.539Z,1570219410.539 [UniversalFixResidualReporter] Loaded
2019-10-04T20:03:30.539Z,1570219410.539 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-10-04T20:03:30.539Z,1570219410.539 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-10-04T20:03:30.540Z,1570219410.540 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-10-04T20:03:30.647Z,1570219410.647 [BuoyancyServo] Loaded
2019-10-04T20:03:30.647Z,1570219410.647 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-10-04T20:03:30.662Z,1570219410.662 [ElevatorServo] Loaded
2019-10-04T20:03:30.663Z,1570219410.663 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-10-04T20:03:30.677Z,1570219410.677 [MassServo] Loaded
2019-10-04T20:03:30.678Z,1570219410.678 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-10-04T20:03:30.692Z,1570219410.692 [RudderServo] Loaded
2019-10-04T20:03:30.692Z,1570219410.692 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-10-04T20:03:30.707Z,1570219410.707 [ThrusterServo] Loaded
2019-10-04T20:03:30.707Z,1570219410.707 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-10-04T20:03:30.707Z,1570219410.707 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-10-04T20:03:30.708Z,1570219410.708 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-10-04T20:03:30.886Z,1570219410.886 [PAR_Licor] Loaded
2019-10-04T20:03:30.886Z,1570219410.886 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-10-04T20:03:30.931Z,1570219410.931 [WetLabsSeaOWL_UV_A] Loaded
2019-10-04T20:03:30.931Z,1570219410.931 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2019-10-04T20:03:30.932Z,1570219410.932 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 408E14E0
2019-10-04T20:03:30.932Z,1570219410.932 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 1107
2019-10-04T20:03:30.933Z,1570219410.933 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-10-04T20:03:30.934Z,1570219410.934 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-10-04T20:03:31.224Z,1570219411.224 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-10-04T20:03:31.225Z,1570219411.225 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-10-04T20:03:31.266Z,1570219411.266 [DepthRateCalculator] Loaded
2019-10-04T20:03:31.266Z,1570219411.266 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-10-04T20:03:31.271Z,1570219411.271 [PitchRateCalculator] Loaded
2019-10-04T20:03:31.272Z,1570219411.272 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-10-04T20:03:31.284Z,1570219411.284 [SpeedCalculator] Loaded
2019-10-04T20:03:31.284Z,1570219411.284 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-10-04T20:03:31.305Z,1570219411.305 [TempGradientCalculator] Loaded
2019-10-04T20:03:31.305Z,1570219411.305 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-10-04T20:03:31.311Z,1570219411.311 [YawRateCalculator] Loaded
2019-10-04T20:03:31.311Z,1570219411.311 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-10-04T20:03:31.350Z,1570219411.350 [ElevatorOffsetCalculator] Loaded
2019-10-04T20:03:31.350Z,1570219411.350 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-10-04T20:03:31.351Z,1570219411.351 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-10-04T20:03:31.351Z,1570219411.351 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-10-04T20:03:31.482Z,1570219411.482 [SBIT](DEBUG): Construct Startup Built In Test.
2019-10-04T20:03:31.504Z,1570219411.504 [SBIT] Loaded
2019-10-04T20:03:31.504Z,1570219411.504 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-10-04T20:03:31.505Z,1570219411.505 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-10-04T20:03:31.516Z,1570219411.516 [IBIT] Loaded
2019-10-04T20:03:31.517Z,1570219411.517 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-10-04T20:03:31.520Z,1570219411.520 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-10-04T20:03:31.656Z,1570219411.656 [CBIT] Loaded
2019-10-04T20:03:31.656Z,1570219411.656 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-10-04T20:03:31.657Z,1570219411.657 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-10-04T20:03:31.657Z,1570219411.657 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-10-04T20:03:31.900Z,1570219411.900 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-10-04T20:03:31.901Z,1570219411.901 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-10-04T20:03:32.093Z,1570219412.093 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-10-04T20:03:32.094Z,1570219412.094 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-10-04T20:03:32.160Z,1570219412.160 [VerticalControl](DEBUG): Construct VerticalControl.
2019-10-04T20:03:32.243Z,1570219412.243 [VerticalControl] Loaded
2019-10-04T20:03:32.243Z,1570219412.243 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-10-04T20:03:32.244Z,1570219412.244 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-10-04T20:03:32.300Z,1570219412.300 [HorizontalControl] Loaded
2019-10-04T20:03:32.300Z,1570219412.300 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-10-04T20:03:32.301Z,1570219412.301 [SpeedControl](DEBUG): Construct SpeedControl.
2019-10-04T20:03:32.303Z,1570219412.303 [SpeedControl] Loaded
2019-10-04T20:03:32.303Z,1570219412.303 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-10-04T20:03:32.304Z,1570219412.304 [LoopControl](DEBUG): Construct LoopControl.
2019-10-04T20:03:32.304Z,1570219412.304 [LoopControl] Loaded
2019-10-04T20:03:32.305Z,1570219412.305 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-10-04T20:03:32.305Z,1570219412.305 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-10-04T20:03:32.306Z,1570219412.306 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-10-04T20:03:32.338Z,1570219412.338 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-10-04T20:03:32.342Z,1570219412.342 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-10-04T20:03:32.343Z,1570219412.343 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-10-04T20:03:32.349Z,1570219412.349 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-10-04T20:03:32.350Z,1570219412.350 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40ABD4E0
2019-10-04T20:03:32.350Z,1570219412.350 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1108
2019-10-04T20:03:32.355Z,1570219412.355 [Supervisor](INFO): Main Thread ID is 803
2019-10-04T20:03:32.355Z,1570219412.355 [Supervisor](DEBUG): Running supervisor.
2019-10-04T20:03:32.356Z,1570219412.356 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1109
2019-10-04T20:03:32.359Z,1570219412.359 [controlThread ThreadHandler](INFO): Handler Thread ID is 1110
2019-10-04T20:03:32.360Z,1570219412.360 [controlThread](DEBUG): Initializing ControlThread
2019-10-04T20:03:32.368Z,1570219412.368 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-10-04T20:03:32.368Z,1570219412.368 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-10-04T20:03:32.373Z,1570219412.373 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-10-04T20:03:32.373Z,1570219412.373 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-10-04T20:03:32.374Z,1570219412.374 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-10-04T20:03:32.374Z,1570219412.374 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-10-04T20:03:32.375Z,1570219412.375 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-10-04T20:03:32.375Z,1570219412.375 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-10-04T20:03:32.375Z,1570219412.375 [SBIT](INFO): Initialize SBIT Component.
2019-10-04T20:03:32.376Z,1570219412.376 [SBIT](IMPORTANT): git: 2019-08-24A
2019-10-04T20:03:32.376Z,1570219412.376 [SBIT](INFO): git hash: 1cd70827f152bddb570e5fcd117087690803f3ad
2019-10-04T20:03:32.376Z,1570219412.376 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-10-04T20:03:32.378Z,1570219412.378 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #2 PREEMPT Wed May 15 08:34:03 PDT 2019
2019-10-04T20:03:32.379Z,1570219412.379 [SBIT](INFO): Beginning SBIT in 28.000000 seconds.
2019-10-04T20:03:32.379Z,1570219412.379 [IBIT](INFO): Initialize IBIT Component.
2019-10-04T20:03:32.380Z,1570219412.380 [CBIT](DEBUG): Initialize CBIT Component.
2019-10-04T20:03:32.381Z,1570219412.381 [logger ThreadHandler](INFO): Handler Thread ID is 1111
2019-10-04T20:03:32.393Z,1570219412.393 [CBIT](DEBUG): Initialized mux pins.
2019-10-04T20:03:32.393Z,1570219412.393 [CBIT](DEBUG): Initializing the watchdog timer.
2019-10-04T20:03:32.401Z,1570219412.401 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1112
2019-10-04T20:03:32.402Z,1570219412.402 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-10-04T20:03:32.413Z,1570219412.413 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1113
2019-10-04T20:03:32.417Z,1570219412.417 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2019-10-04T20:03:32.417Z,1570219412.417 [CBIT](DEBUG): Initializing heartbeat.
2019-10-04T20:03:32.425Z,1570219412.425 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 1114
2019-10-04T20:03:32.426Z,1570219412.426 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-10-04T20:03:32.453Z,1570219412.453 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1115
2019-10-04T20:03:32.456Z,1570219412.456 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-10-04T20:03:32.456Z,1570219412.456 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-10-04T20:03:32.457Z,1570219412.457 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-10-04T20:03:32.457Z,1570219412.457 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-10-04T20:03:32.458Z,1570219412.458 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-10-04T20:03:32.458Z,1570219412.458 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-10-04T20:03:32.458Z,1570219412.458 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-10-04T20:03:32.458Z,1570219412.458 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-10-04T20:03:32.458Z,1570219412.458 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-10-04T20:03:32.458Z,1570219412.458 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-10-04T20:03:32.459Z,1570219412.459 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-10-04T20:03:32.459Z,1570219412.459 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-10-04T20:03:32.459Z,1570219412.459 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-10-04T20:03:32.459Z,1570219412.459 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-10-04T20:03:32.459Z,1570219412.459 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-10-04T20:03:32.460Z,1570219412.460 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-10-04T20:03:32.489Z,1570219412.489 [CBIT](DEBUG): Deactivating GF circuits.
2019-10-04T20:03:32.489Z,1570219412.489 [CBIT](DEBUG): Deactivating emergency mode.
2019-10-04T20:03:32.525Z,1570219412.525 [CBIT](DEBUG): Backplane powered.
2019-10-04T20:03:32.525Z,1570219412.525 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-10-04T20:03:32.527Z,1570219412.527 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-10-04T20:03:32.528Z,1570219412.528 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-10-04T20:03:32.528Z,1570219412.528 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-10-04T20:03:32.529Z,1570219412.529 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-10-04T20:03:32.540Z,1570219412.540 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-10-04T20:03:32.566Z,1570219412.566 [MissionManager](DEBUG):
2019-10-04T20:03:32.567Z,1570219412.567 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-10-04T20:03:32.640Z,1570219412.640 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-10-04T20:03:32.641Z,1570219412.641 [Default:A.Wait](DEBUG): Construct Wait.
2019-10-04T20:03:32.643Z,1570219412.643 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-10-04T20:03:32.690Z,1570219412.690 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-10-04T20:03:32.692Z,1570219412.692 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-10-04T20:03:32.718Z,1570219412.718 [Default:E.Execute](DEBUG): Construct Execute.
2019-10-04T20:03:32.737Z,1570219412.737 [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-10-04T20:03:32.742Z,1570219412.742 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-10-04T20:03:32.753Z,1570219412.753 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-10-04T20:03:32.817Z,1570219412.817 [Radio_Surface](INFO): Powering up
2019-10-04T20:03:32.899Z,1570219412.899 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-10-04T20:03:32.905Z,1570219412.905 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-10-04T20:03:32.906Z,1570219412.906 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-10-04T20:03:32.929Z,1570219412.929 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-10-04T20:03:32.930Z,1570219412.930 [MassServo](DEBUG): Initializing EZServoServo.
2019-10-04T20:03:32.937Z,1570219412.937 [MassServo](DEBUG): Initializing MassServo.
2019-10-04T20:03:32.938Z,1570219412.938 [RudderServo](DEBUG): Initializing EZServoServo.
2019-10-04T20:03:32.945Z,1570219412.945 [RudderServo](DEBUG): Initializing RudderServo.
2019-10-04T20:03:32.946Z,1570219412.946 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-10-04T20:03:32.953Z,1570219412.953 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-10-04T20:03:32.955Z,1570219412.955 [CommandLine](FAULT): Scheduling is paused
2019-10-04T20:03:32.955Z,1570219412.955 [CBIT](INFO): Critical error at 20191004T200332
2019-10-04T20:03:32.956Z,1570219412.956 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-10-04T20:03:33.168Z,1570219413.168 [Micromodem](INFO): Powering up
2019-10-04T20:03:33.169Z,1570219413.169 [Micromodem](DEBUG): Initializing Micromodem.
2019-10-04T20:03:38.039Z,1570219418.039 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33
2019-10-04T20:03:46.112Z,1570219426.112 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-10-04T20:03:49.318Z,1570219429.318 [Micromodem](ERROR): Nmea resend: $CCCFG,ALL,0*33
2019-10-04T20:03:51.755Z,1570219431.755 [Micromodem](INFO): Nmea in: $CATMG,2019-10-04T20:03:50.798764Z,RTC,RTC*58
2019-10-04T20:03:51.755Z,1570219431.755 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2019-10-04T20:03:50.798764Z,RTC,RTC*58
2019-10-04T20:03:59.011Z,1570219439.011 [NAL9602](INFO): Powering up NAL9602
2019-10-04T20:04:00.631Z,1570219440.631 [Micromodem](ERROR): Nmea resend: $CCCFG,ALL,0*33
2019-10-04T20:04:01.031Z,1570219441.031 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31
2019-10-04T20:04:01.031Z,1570219441.031 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31
2019-10-04T20:04:01.126Z,1570219441.126 [SBIT](IMPORTANT): Beginning Startup BIT
2019-10-04T20:04:01.134Z,1570219441.134 [CBIT](IMPORTANT): Beginning ground fault scan
2019-10-04T20:04:01.435Z,1570219441.435 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33
2019-10-04T20:04:01.435Z,1570219441.435 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64
2019-10-04T20:04:01.843Z,1570219441.843 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66
2019-10-04T20:04:01.843Z,1570219441.843 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F
2019-10-04T20:04:02.243Z,1570219442.243 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D
2019-10-04T20:04:02.243Z,1570219442.243 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E
2019-10-04T20:04:02.647Z,1570219442.647 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C
2019-10-04T20:04:02.647Z,1570219442.647 [Micromodem](INFO): Nmea out: $CCCFG,FC0,10000*46
2019-10-04T20:04:03.051Z,1570219443.051 [Micromodem](INFO): Nmea in: $CACFG,FC0,10000*44
2019-10-04T20:04:03.051Z,1570219443.051 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63
2019-10-04T20:04:03.614Z,1570219443.614 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61
2019-10-04T20:04:03.614Z,1570219443.614 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A
2019-10-04T20:04:04.027Z,1570219444.027 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38
2019-10-04T20:04:04.027Z,1570219444.027 [Micromodem](INFO): Nmea out: $CCCLK,2019,10,04,20,04,05*48
2019-10-04T20:04:04.447Z,1570219444.447 [Micromodem](INFO): Nmea in: $CACLK,2019,10,4,20,4,5*7A
2019-10-04T20:04:04.457Z,1570219444.457 [Micromodem](INFO): Nmea in: $CATMS,0,2019-10-04T20:04:06Z*79
2019-10-04T20:04:04.458Z,1570219444.458 [Micromodem](INFO): Nmea in: $CATMG,2019-10-04T20:04:06.026130Z,USER_CMD,RTC*18
2019-10-04T20:04:10.076Z,1570219450.076 [NAL9602](INFO): NAL9602 initialized
2019-10-04T20:04:10.897Z,1570219450.897 [NAL9602](DEBUG): Fix Requested
2019-10-04T20:04:12.206Z,1570219452.206 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.010316
CHAN A1 (24V): -0.014495
CHAN A2 (12V): -0.001603
CHAN A3 (5V): -0.001268
CHAN B0 (3.3V): 0.000455
CHAN B1 (3.15aV): 0.000543
CHAN B2 (3.15bV): 0.000466
CHAN B3 (GND): 0.000349
OPEN: 0.005133
Full Scale Calc: 4.765 mA, -1.589 mA
2019-10-04T20:04:54.736Z,1570219494.736 [SBIT](IMPORTANT): SBIT PASSED
2019-10-04T20:04:54.803Z,1570219494.803 [CommandLine](IMPORTANT): got command configSet list
2019-10-04T20:04:54.803Z,1570219494.803 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-10-04T20:04:54.804Z,1570219494.804 [CommandLine](IMPORTANT): Aanderaa_O2.loadAtStartup=0 bool;
2019-10-04T20:04:54.804Z,1570219494.804 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup=0 bool;
2019-10-04T20:04:55.148Z,1570219495.148 [MissionManager](IMPORTANT): Started mission Startup
2019-10-04T20:04:55.149Z,1570219495.149 [Startup] Running Loop=1
2019-10-04T20:04:55.149Z,1570219495.149 [Startup](DEBUG): Aggregate::initialize Startup
2019-10-04T20:04:55.149Z,1570219495.149 [Startup:A.GoToSurface] Running Loop=1
2019-10-04T20:04:55.149Z,1570219495.149 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-10-04T20:04:55.150Z,1570219495.150 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-10-04T20:04:55.150Z,1570219495.150 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-10-04T20:04:55.151Z,1570219495.151 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-10-04T20:04:55.151Z,1570219495.151 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-10-04T20:04:55.151Z,1570219495.151 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-10-04T20:04:55.153Z,1570219495.153 [Startup:StartupSatComms] Running Loop=1
2019-10-04T20:04:55.153Z,1570219495.153 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-10-04T20:04:55.153Z,1570219495.153 [Startup:StartupSatComms:A] Running Loop=1
2019-10-04T20:04:55.547Z,1570219495.547 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-10-04T20:05:55.357Z,1570219555.357 [Startup:StartupSatComms:A](INFO): Timed out from 2019-10-04T20:04:55.2Z
2019-10-04T20:05:55.357Z,1570219555.357 [Startup:StartupSatComms:A] Stopped
2019-10-04T20:05:55.357Z,1570219555.357 [Startup:StartupSatComms:B] Running Loop=1
2019-10-04T20:05:55.736Z,1570219555.736 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-10-04T20:05:57.791Z,1570219557.791 [Micromodem](INFO): Outgoing frame #1, 64 bytes: 8AA5975D000000005D00000400530000000000000000151D80030C5669BF31555EAE1409A708CE248A10F23557EC54120F3A0E55408627066FB016FDEF03627E
2019-10-04T20:05:57.791Z,1570219557.791 [Micromodem](INFO): Outgoing frame #2, 43 bytes: 108DBFC567A507BC012F83E67930CF24AA6DD154CCBB8FDCD74EC2206C39567813E263631F973B971E8EE4
2019-10-04T20:05:57.791Z,1570219557.791 [Micromodem](INFO): Nmea out: $CCCYC,0,1,9,1,0,2*52
2019-10-04T20:05:57.934Z,1570219557.934 [Micromodem](INFO): Nmea in: $CACYC,0,1,9,1,0,2*50
2019-10-04T20:05:58.275Z,1570219558.275 [Micromodem](INFO): Nmea in: $CADRQ,200559,1,9,0,64,1*45
2019-10-04T20:05:58.275Z,1570219558.275 [Micromodem](INFO): Nmea out: $CCTXD,1,9,1,8AA5975D000000005D00000400530000000000000000151D80030C5669BF31555EAE1409A708CE248A10F23557EC54120F3A0E55408627066FB016FDEF03627E*70
2019-10-04T20:05:58.672Z,1570219558.672 [Micromodem](INFO): Nmea in: $CATXD,1,9,1,64*71
2019-10-04T20:05:59.079Z,1570219559.079 [Micromodem](INFO): Nmea in: $CADRQ,200600,1,9,0,64,2*49
2019-10-04T20:05:59.079Z,1570219559.079 [Micromodem](INFO): Nmea out: $CCTXD,1,9,1,108DBFC567A507BC012F83E67930CF24AA6DD154CCBB8FDCD74EC2206C39567813E263631F973B971E8EE4*78
2019-10-04T20:05:59.479Z,1570219559.479 [Micromodem](INFO): Nmea in: $CATXD,1,9,1,43*74
2019-10-04T20:05:59.887Z,1570219559.887 [Micromodem](INFO): Nmea in: $CATXP,107*44
2019-10-04T20:06:02.315Z,1570219562.315 [Micromodem](INFO): Nmea in: $CATXF,107*52
2019-10-04T20:06:03.531Z,1570219563.531 [Micromodem](INFO): Nmea in: $CAXST,6,20191004,200601.105074,3,0,200,4000,10000,1,1,9,1,2,2,3,107*41
2019-10-04T20:06:04.740Z,1570219564.740 [Micromodem](INFO): Nmea in: $CAACK,9,1,1,1*43
2019-10-04T20:06:05.143Z,1570219565.143 [Micromodem](INFO): Nmea in: $CAACK,9,1,2,1*40
2019-10-04T20:06:05.144Z,1570219565.144 [Micromodem](INFO): Sent 99 bytes from file Logs/20191004T200322/Courier0000.lzma.parts
2019-10-04T20:06:05.144Z,1570219565.144 [Micromodem](INFO): Packets left to send: 0
2019-10-04T20:06:05.543Z,1570219565.543 [Micromodem](INFO): Nmea in: $CACST,6,0,20191004200605.664087,06,10554,40,0232,0150,07,00,00,00,00,1,009,001,0,4,1,0,150,-13.8,3.00,06,0.00,-01,0.02,79,10000,4000*63
2019-10-04T20:06:07.300Z,1570219567.300 [Startup:StartupSatComms:B] Stopped
2019-10-04T20:06:07.300Z,1570219567.300 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-10-04T20:06:07.300Z,1570219567.300 [Startup:StartupSatComms] Stopped
2019-10-04T20:06:07.300Z,1570219567.300 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-10-04T20:06:07.301Z,1570219567.301 [Startup](INFO): Completed Startup
2019-10-04T20:06:07.301Z,1570219567.301 [MissionManager](INFO): Startup is completed.
2019-10-04T20:06:07.301Z,1570219567.301 [MissionManager](INFO): Uninitializing Mission Startup
2019-10-04T20:06:07.301Z,1570219567.301 [Startup] Stopped
2019-10-04T20:06:07.301Z,1570219567.301 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-10-04T20:06:07.302Z,1570219567.302 [Startup:A.GoToSurface] Stopped
2019-10-04T20:06:07.302Z,1570219567.302 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-10-04T20:06:07.463Z,1570219567.463 [MissionManager](IMPORTANT): Started mission Default
2019-10-04T20:06:07.463Z,1570219567.463 [Default] Running Loop=1
2019-10-04T20:06:07.463Z,1570219567.463 [Default](DEBUG): Aggregate::initialize Default
2019-10-04T20:06:07.463Z,1570219567.463 [Default:B.GoToSurface] Running Loop=1
2019-10-04T20:06:07.463Z,1570219567.463 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-10-04T20:06:07.464Z,1570219567.464 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-10-04T20:06:07.464Z,1570219567.464 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-10-04T20:06:07.464Z,1570219567.464 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-10-04T20:06:07.469Z,1570219567.469 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-10-04T20:06:07.469Z,1570219567.469 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-10-04T20:06:07.470Z,1570219567.470 [Default:A.Wait] Running Loop=1
2019-10-04T20:06:07.470Z,1570219567.470 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-10-04T20:06:20.679Z,1570219580.679 [Default:A.Wait](INFO): Done Waiting.
2019-10-04T20:06:20.680Z,1570219580.680 [Default:A.Wait] Stopped
2019-10-04T20:06:20.680Z,1570219580.680 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-10-04T20:06:21.106Z,1570219581.106 [Default:CheckIn] Running Loop=1
2019-10-04T20:06:21.106Z,1570219581.106 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-04T20:06:21.106Z,1570219581.106 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-04T20:06:21.503Z,1570219581.503 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-10-04T20:06:32.398Z,1570219592.398 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-10-04T20:06:32.398Z,1570219592.398 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-10-04T20:06:32.408Z,1570219592.408 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-10-04T20:06:32.826Z,1570219592.826 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-10-04T20:06:32.826Z,1570219592.826 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-10-04T20:07:08.903Z,1570219628.903 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005115
2019-10-04T20:09:13.163Z,1570219753.163 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-10-04T20:09:13.981Z,1570219753.981 [NAL9602](DEBUG): Fix Requested
2019-10-04T20:09:18.033Z,1570219758.033 [NAL9602](DEBUG): Fix Requested
2019-10-04T20:09:18.417Z,1570219758.417 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200351.00,A,3648.16472,N,12147.28473,W,0.058,21.65,041019,,,A*4D
2019-10-04T20:09:18.420Z,1570219758.420 [NAL9602](INFO): GPS fix at 20191004T200351: (36.802745, -121.788079)
2019-10-04T20:09:18.445Z,1570219758.445 [Default:CheckIn:Read_GPS] Stopped
2019-10-04T20:09:18.445Z,1570219758.445 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-04T20:09:18.872Z,1570219758.872 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-10-04T20:09:23.381Z,1570219763.381 [Micromodem](INFO): Outgoing frame #1, 64 bytes: 8AA5975D040001005D00000400DB0100000000000000151D80030C5669BF3148E2FA22188B6A3173E6960F887FF8A99E669AC91D474B0DB47F940EC581E0D567
2019-10-04T20:09:23.382Z,1570219763.382 [Micromodem](INFO): Outgoing frame #2, 64 bytes: 266CC0E6F1A517638CB0C0B8BE350ABD5E397F52AE53832D140D6C9DFB363B4198799E9A8AFB747105202A27D85AB2F12AB943C7EC16791000AF650696E743B1
2019-10-04T20:09:23.382Z,1570219763.382 [Micromodem](INFO): Outgoing frame #3, 64 bytes: DB4AE6838C2B4FB0434159BC09B3FAED39F1E08164AB3142BD2797B48B06B81617ABB978824011E5A78E2A4A71DA923A05C3FD00484BD9B8DB16B7858B05A4E4
2019-10-04T20:09:23.383Z,1570219763.383 [Micromodem](INFO): Nmea out: $CCCYC,0,1,9,1,0,3*53
2019-10-04T20:09:24.149Z,1570219764.149 [Micromodem](INFO): Nmea in: $CACYC,0,1,9,1,0,3*51
2019-10-04T20:09:24.438Z,1570219764.438 [Micromodem](INFO): Nmea in: $CADRQ,200925,1,9,0,64,1*42
2019-10-04T20:09:24.438Z,1570219764.438 [Micromodem](INFO): Nmea out: $CCTXD,1,9,1,8AA5975D040001005D00000400DB0100000000000000151D80030C5669BF3148E2FA22188B6A3173E6960F887FF8A99E669AC91D474B0DB47F940EC581E0D567*7B
2019-10-04T20:09:24.830Z,1570219764.830 [Micromodem](INFO): Nmea in: $CATXD,1,9,1,64*71
2019-10-04T20:09:25.243Z,1570219765.243 [Micromodem](INFO): Nmea in: $CADRQ,200926,1,9,0,64,2*42
2019-10-04T20:09:25.243Z,1570219765.243 [Micromodem](INFO): Nmea out: $CCTXD,1,9,1,266CC0E6F1A517638CB0C0B8BE350ABD5E397F52AE53832D140D6C9DFB363B4198799E9A8AFB747105202A27D85AB2F12AB943C7EC16791000AF650696E743B1*7A
2019-10-04T20:09:25.634Z,1570219765.634 [Micromodem](INFO): Nmea in: $CATXD,1,9,1,64*71
2019-10-04T20:09:26.051Z,1570219766.051 [Micromodem](INFO): Nmea in: $CADRQ,200927,1,9,0,64,3*42
2019-10-04T20:09:26.051Z,1570219766.051 [Micromodem](INFO): Nmea out: $CCTXD,1,9,1,DB4AE6838C2B4FB0434159BC09B3FAED39F1E08164AB3142BD2797B48B06B81617ABB978824011E5A78E2A4A71DA923A05C3FD00484BD9B8DB16B7858B05A4E4*0E
2019-10-04T20:09:26.442Z,1570219766.442 [Micromodem](INFO): Nmea in: $CATXD,1,9,1,64*71
2019-10-04T20:09:26.846Z,1570219766.846 [Micromodem](INFO): Nmea in: $CATXP,192*48
2019-10-04T20:09:30.491Z,1570219770.491 [Micromodem](INFO): Nmea in: $CATXF,192*5E
2019-10-04T20:09:30.892Z,1570219770.892 [Micromodem](INFO): Nmea in: $CAXST,6,20191004,200928.109813,3,0,200,4000,10000,1,1,9,1,3,3,3,192*4C
2019-10-04T20:09:32.947Z,1570219772.947 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20191004T200322/Courier0004.lzma
2019-10-04T20:09:33.730Z,1570219773.730 [Micromodem](INFO): Nmea in: $CAACK,9,1,1,1*43
2019-10-04T20:09:33.747Z,1570219773.747 [DataOverHttps](INFO): Moved sent file to Logs/20191004T200322/Courier0004.lzma.bak
2019-10-04T20:09:33.747Z,1570219773.747 [DataOverHttps](INFO): SBD MOMSN=11850824
2019-10-04T20:09:34.123Z,1570219774.123 [Micromodem](INFO): Nmea in: $CAACK,9,1,2,1*40
2019-10-04T20:09:34.531Z,1570219774.531 [Micromodem](INFO): Nmea in: $CAACK,9,1,3,1*41
2019-10-04T20:09:34.531Z,1570219774.531 [Micromodem](INFO): Sent 184 bytes from file Logs/20191004T200322/Courier0004.lzma.parts
2019-10-04T20:09:34.531Z,1570219774.531 [Micromodem](INFO): Packets left to send: 1
2019-10-04T20:09:34.940Z,1570219774.940 [Micromodem](INFO): Nmea in: $CACST,6,0,20191004200934.520894,06,8292,39,0184,0150,07,00,00,00,00,1,009,001,0,4,1,0,150,-16.0,3.00,08,0.00,-01,-0.02,79,10000,4000*7D
2019-10-04T20:09:39.546Z,1570219779.546 [Default:CheckIn:Read_Iridium] Stopped
2019-10-04T20:09:39.546Z,1570219779.546 [Default:CheckIn:C.Wait] Running Loop=1
2019-10-04T20:09:39.546Z,1570219779.546 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-10-04T20:09:54.522Z,1570219794.522 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-04T20:10:21.473Z,1570219821.473 [DataOverHttps](INFO): Sending 446 bytes from file Logs/20191004T193816/Express0014.lzma
2019-10-04T20:10:22.278Z,1570219822.278 [DataOverHttps](INFO): Moved sent file to Logs/20191004T193816/Express0014.lzma.bak
2019-10-04T20:10:22.278Z,1570219822.278 [DataOverHttps](INFO): SBD MOMSN=11850828
2019-10-04T20:10:58.781Z,1570219858.781 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2019-10-04T20:10:58.784Z,1570219858.784 [BPC1](INFO): Received data from all battery sticks.
2019-10-04T20:12:32.390Z,1570219952.390 [CommandLine](IMPORTANT): got command failComponent
2019-10-04T20:12:32.390Z,1570219952.390 [CommandLine](IMPORTANT): Failed components:
2019-10-04T20:12:32.390Z,1570219952.390 [CommandLine](IMPORTANT): No failed Components.
2019-10-04T20:12:44.991Z,1570219964.991 [CommandLine](IMPORTANT): got command get platform_mass_position
2019-10-04T20:12:44.992Z,1570219964.992 [CommandLine](IMPORTANT): platform_mass_position 0.002000 m
2019-10-04T20:12:58.631Z,1570219978.631 [CommandLine](IMPORTANT): got command get VerticalControl.massDefault
2019-10-04T20:12:58.632Z,1570219978.632 [CommandLine](IMPORTANT): VerticalControl.massDefault 0.200000 cm
2019-10-04T20:13:12.481Z,1570219992.481 [CommandLine](IMPORTANT): got command get VerticalControl.massPositionLimitAft
2019-10-04T20:13:12.481Z,1570219992.481 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitAft -22.000000 mm
2019-10-04T20:13:19.710Z,1570219999.710 [CommandLine](IMPORTANT): got command get VerticalControl.massPositionLimitFwd
2019-10-04T20:13:19.711Z,1570219999.711 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitFwd 33.000000 mm
2019-10-04T20:14:39.785Z,1570220079.785 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-10-04T20:14:39.785Z,1570220079.785 [Default:CheckIn:C.Wait] Stopped
2019-10-04T20:14:39.785Z,1570220079.785 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-10-04T20:14:39.785Z,1570220079.785 [Default:CheckIn:D] Running Loop=1
2019-10-04T20:14:39.922Z,1570220079.922 [CommandLine](IMPORTANT): got command restart system
2019-10-04T20:14:40.198Z,1570220080.198 [Default:CheckIn:D] Stopped
2019-10-04T20:14:40.198Z,1570220080.198 [Default:CheckIn:E] Running Loop=1
2019-10-04T20:14:40.597Z,1570220080.597 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 8.545585 min
2019-10-04T20:14:40.597Z,1570220080.597 [Default:CheckIn:E] Stopped
2019-10-04T20:14:40.598Z,1570220080.598 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-10-04T20:14:40.598Z,1570220080.598 [Default:CheckIn] Stopped
2019-10-04T20:14:40.598Z,1570220080.598 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-04T20:14:40.598Z,1570220080.598 [Default:CheckIn](INFO): Running loop #2
2019-10-04T20:14:40.598Z,1570220080.598 [Default:CheckIn] Running Loop=2
2019-10-04T20:14:40.598Z,1570220080.598 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-04T20:14:40.598Z,1570220080.598 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-04T20:14:42.089Z,1570220082.089 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-04T20:14:42.089Z,1570220082.089 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-10-04T20:14:42.181Z,1570220082.181 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2019-10-04T20:14:42.181Z,1570220082.181 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-10-04T20:14:42.182Z,1570220082.182 [CommandLine](INFO): Join timeout helper Thread ID is 1155
2019-10-04T20:14:42.182Z,1570220082.182 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-10-04T20:14:42.182Z,1570220082.182 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-10-04T20:14:42.183Z,1570220082.183 [NavChartDb](INFO): Join timeout helper Thread ID is 1156
2019-10-04T20:14:42.193Z,1570220082.193 [NAL9602](DEBUG): Fix Requested
2019-10-04T20:14:42.477Z,1570220082.477 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-04T20:14:42.477Z,1570220082.477 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-10-04T20:14:42.481Z,1570220082.481 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2019-10-04T20:14:42.481Z,1570220082.481 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-10-04T20:14:42.481Z,1570220082.481 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 1157
2019-10-04T20:14:42.580Z,1570220082.580 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200916.00,A,3648.16640,N,12147.28540,W,0.039,140.33,041019,,,A*74
2019-10-04T20:14:42.583Z,1570220082.583 [NAL9602](INFO): GPS fix at 20191004T200916: (36.802773, -121.788090)
2019-10-04T20:14:42.614Z,1570220082.614 [Default:CheckIn:Read_GPS] Stopped
2019-10-04T20:14:42.614Z,1570220082.614 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-04T20:14:42.789Z,1570220082.789 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-04T20:14:42.789Z,1570220082.789 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-10-04T20:14:42.790Z,1570220082.790 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-10-04T20:14:42.805Z,1570220082.805 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-10-04T20:14:42.805Z,1570220082.805 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-10-04T20:14:42.805Z,1570220082.805 [Radio_Surface](INFO): Join timeout helper Thread ID is 1158
2019-10-04T20:14:43.141Z,1570220083.141 [Radio_Surface](INFO): Powering down
2019-10-04T20:14:43.142Z,1570220083.142 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-04T20:14:43.142Z,1570220083.142 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-10-04T20:14:43.149Z,1570220083.149 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-10-04T20:14:43.149Z,1570220083.149 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-10-04T20:14:43.149Z,1570220083.149 [DataOverHttps](INFO): Join timeout helper Thread ID is 1159
2019-10-04T20:14:43.313Z,1570220083.313 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-04T20:14:43.313Z,1570220083.313 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-10-04T20:14:43.318Z,1570220083.318 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-10-04T20:14:43.318Z,1570220083.318 [logger ThreadHandler](INFO): Thread cancelled.
2019-10-04T20:14:43.318Z,1570220083.318 [logger](INFO): Join timeout helper Thread ID is 1160
2019-10-04T20:14:43.377Z,1570220083.377 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-04T20:14:43.378Z,1570220083.378 [logger ThreadHandler](INFO): Thread cancelled.
2019-10-04T20:14:43.398Z,1570220083.398 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-10-04T20:14:43.398Z,1570220083.398 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-10-04T20:14:43.398Z,1570220083.398 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-10-04T20:14:43.398Z,1570220083.398 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-10-04T20:14:43.398Z,1570220083.398 [controlThread](INFO): Join timeout helper Thread ID is 1161
2019-10-04T20:14:45.056Z,1570220085.056 [Micromodem](INFO): Outgoing frame #1, 64 bytes: 8AA5975D070001005D00000400830100000000000000151D80030C5669BF3148E2FA22188B6A3173E5573572661C0BCBDFFAB423BD32D9A51E8904B0A920CE9A
2019-10-04T20:14:45.057Z,1570220085.057 [Micromodem](INFO): Outgoing frame #2, 64 bytes: EF9F66414C9B9FD6761AD008C3E3DC4FCA2E4E25B6359B14B772C1B04EB4F583E519D51AF9DE137BC93C430356E220B3E019742E5566D1FD82C072D312160B8C
2019-10-04T20:14:45.057Z,1570220085.057 [Micromodem](INFO): Outgoing frame #3, 64 bytes: F9F37D39BAF788F996DDA9312193435C488BC6D8FC7D883FA903387B9CC31232D570B6659E9AB4F79FD0AADAF36962E314421064F9F98CCD745FB26EFFCC1DA1
2019-10-04T20:14:45.058Z,1570220085.058 [Micromodem](INFO): Nmea out: $CCCYC,0,1,9,1,0,3*53
2019-10-04T20:14:45.130Z,1570220085.130 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-04T20:14:45.131Z,1570220085.131 [controlThread](DEBUG): Uninitializing ControlThread
2019-10-04T20:14:45.131Z,1570220085.131 [AHRS_M2](INFO): Powering down
2019-10-04T20:14:45.202Z,1570220085.202 [Micromodem](INFO): Powering down
2019-10-04T20:14:45.297Z,1570220085.297 [NAL9602](INFO): Powering down
2019-10-04T20:14:45.369Z,1570220085.369 [RDI_Pathfinder](INFO): Powering down
2019-10-04T20:14:45.371Z,1570220085.371 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-10-04T20:14:45.371Z,1570220085.371 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-10-04T20:14:45.372Z,1570220085.372 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-10-04T20:14:45.372Z,1570220085.372 [MissionManager](INFO): Uninitializing Mission Default
2019-10-04T20:14:45.373Z,1570220085.373 [Default] Stopped
2019-10-04T20:14:45.373Z,1570220085.373 [Default](DEBUG): Aggregate::uninitialize Default
2019-10-04T20:14:45.373Z,1570220085.373 [Default:B.GoToSurface] Stopped
2019-10-04T20:14:45.373Z,1570220085.373 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-10-04T20:14:45.373Z,1570220085.373 [Default:CheckIn] Stopped
2019-10-04T20:14:45.373Z,1570220085.373 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-04T20:14:45.373Z,1570220085.373 [Default:CheckIn:Read_Iridium] Stopped
2019-10-04T20:14:45.376Z,1570220085.376 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-10-04T20:14:45.376Z,1570220085.376 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-10-04T20:14:45.376Z,1570220085.376 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-10-04T20:14:45.377Z,1570220085.377 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-10-04T20:14:45.377Z,1570220085.377 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-10-04T20:14:45.377Z,1570220085.377 [BuoyancyServo](INFO): Powering down
2019-10-04T20:14:45.389Z,1570220085.389 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-10-04T20:14:45.389Z,1570220085.389 [ElevatorServo](INFO): Powering down
2019-10-04T20:14:45.390Z,1570220085.390 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-10-04T20:14:45.390Z,1570220085.390 [MassServo](INFO): Powering down
2019-10-04T20:14:45.391Z,1570220085.391 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-10-04T20:14:45.391Z,1570220085.391 [RudderServo](INFO): Powering down
2019-10-04T20:14:45.392Z,1570220085.392 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-10-04T20:14:45.392Z,1570220085.392 [ThrusterServo](INFO): Powering down
2019-10-04T20:14:45.393Z,1570220085.393 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-10-04T20:14:45.393Z,1570220085.393 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-10-04T20:14:45.393Z,1570220085.393 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-10-04T20:14:45.393Z,1570220085.393 [CBIT](DEBUG): Powering off loads.
2019-10-04T20:14:45.405Z,1570220085.405 [CBIT](DEBUG): Disabling WDT.
2019-10-04T20:14:45.417Z,1570220085.417 [CBIT](DEBUG): Opening all GF detection circuits.
2019-10-04T20:14:45.418Z,1570220085.418 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-10-04T20:14:45.467Z,1570220085.467 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-10-04T20:14:45.475Z,1570220085.475 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-10-04T20:14:45.518Z,1570220085.518 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-10-04T20:14:45.579Z,1570220085.579 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-10-04T20:14:45.653Z,1570220085.653 [logger ThreadHandler](INFO): Thread cancelled.