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.