2019-04-26T00:05:23.358Z,1556237123.358 [Supervisor](DEBUG): Initializing supervisor. 2019-04-26T00:05:23.361Z,1556237123.361 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2019-04-26T00:05:23.361Z,1556237123.361 [SyncHandler](INFO): Protected caller Thread ID is 809 2019-04-26T00:05:23.362Z,1556237123.362 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2019-04-26T00:05:23.362Z,1556237123.362 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2019-04-26T00:05:23.363Z,1556237123.363 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 810 2019-04-26T00:05:23.365Z,1556237123.365 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2019-04-26T00:05:23.377Z,1556237123.377 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2019-04-26T00:05:23.378Z,1556237123.378 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2019-04-26T00:05:23.378Z,1556237123.378 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 811 2019-04-26T00:05:23.379Z,1556237123.379 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2019-04-26T00:05:23.380Z,1556237123.380 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2019-04-26T00:05:23.380Z,1556237123.380 [logger ThreadHandler](INFO): Protected caller Thread ID is 812 2019-04-26T00:05:23.382Z,1556237123.382 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2019-04-26T00:05:23.383Z,1556237123.383 [Supervisor](INFO): Looking for Config files in directory: Config/ 2019-04-26T00:05:23.387Z,1556237123.387 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2019-04-26T00:05:23.821Z,1556237123.821 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2019-04-26T00:05:23.823Z,1556237123.823 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2019-04-26T00:05:23.921Z,1556237123.921 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2019-04-26T00:05:23.923Z,1556237123.923 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2019-04-26T00:05:24.252Z,1556237124.252 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2019-04-26T00:05:24.254Z,1556237124.254 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2019-04-26T00:05:24.398Z,1556237124.398 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2019-04-26T00:05:24.398Z,1556237124.398 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2019-04-26T00:05:24.591Z,1556237124.591 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2019-04-26T00:05:24.593Z,1556237124.593 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2019-04-26T00:05:25.055Z,1556237125.055 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2019-04-26T00:05:25.056Z,1556237125.056 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2019-04-26T00:05:25.270Z,1556237125.270 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2019-04-26T00:05:25.272Z,1556237125.272 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2019-04-26T00:05:25.418Z,1556237125.418 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2019-04-26T00:05:25.419Z,1556237125.419 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2019-04-26T00:05:25.615Z,1556237125.615 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2019-04-26T00:05:25.617Z,1556237125.617 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2019-04-26T00:05:25.713Z,1556237125.713 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2019-04-26T00:05:25.715Z,1556237125.715 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2019-04-26T00:05:26.037Z,1556237126.037 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2019-04-26T00:05:26.039Z,1556237126.039 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2019-04-26T00:05:26.120Z,1556237126.120 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2019-04-26T00:05:26.332Z,1556237126.332 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2019-04-26T00:05:26.745Z,1556237126.745 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2019-04-26T00:05:27.355Z,1556237127.355 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2019-04-26T00:05:27.356Z,1556237127.356 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2019-04-26T00:05:27.752Z,1556237127.752 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2019-04-26T00:05:27.754Z,1556237127.754 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/ 2019-04-26T00:05:27.757Z,1556237127.757 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg 2019-04-26T00:05:27.962Z,1556237127.962 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg 2019-04-26T00:05:28.064Z,1556237128.064 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg 2019-04-26T00:05:28.166Z,1556237128.166 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg 2019-04-26T00:05:28.397Z,1556237128.397 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2019-04-26T00:05:28.397Z,1556237128.397 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg 2019-04-26T00:05:28.483Z,1556237128.483 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg 2019-04-26T00:05:28.577Z,1556237128.577 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg 2019-04-26T00:05:28.676Z,1556237128.676 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg 2019-04-26T00:05:28.759Z,1556237128.759 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg 2019-04-26T00:05:28.868Z,1556237128.868 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg 2019-04-26T00:05:29.040Z,1556237129.040 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg 2019-04-26T00:05:29.171Z,1556237129.171 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2019-04-26T00:05:29.189Z,1556237129.189 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2019-04-26T00:05:29.807Z,1556237129.807 [AHRS_M2] Loaded 2019-04-26T00:05:29.808Z,1556237129.808 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2019-04-26T00:05:29.947Z,1556237129.947 [DataOverHttps] Loaded 2019-04-26T00:05:29.948Z,1556237129.948 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2019-04-26T00:05:29.949Z,1556237129.949 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4075A4E0 2019-04-26T00:05:29.949Z,1556237129.949 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 891 2019-04-26T00:05:29.964Z,1556237129.964 [Depth_Keller] Loaded 2019-04-26T00:05:29.964Z,1556237129.964 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2019-04-26T00:05:29.969Z,1556237129.969 [DropWeight] Loaded 2019-04-26T00:05:29.969Z,1556237129.969 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2019-04-26T00:05:30.027Z,1556237130.027 [DUSBL_Hydroid] Loaded 2019-04-26T00:05:30.028Z,1556237130.028 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread. 2019-04-26T00:05:30.069Z,1556237130.069 [Micromodem] Loaded 2019-04-26T00:05:30.069Z,1556237130.069 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread. 2019-04-26T00:05:30.170Z,1556237130.170 [NAL9602] Loaded 2019-04-26T00:05:30.171Z,1556237130.171 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2019-04-26T00:05:30.187Z,1556237130.187 [Onboard] Loaded 2019-04-26T00:05:30.187Z,1556237130.187 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2019-04-26T00:05:30.194Z,1556237130.194 [PowerOnly] Loaded 2019-04-26T00:05:30.194Z,1556237130.194 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread. 2019-04-26T00:05:30.201Z,1556237130.201 [Radio_Surface] Loaded 2019-04-26T00:05:30.201Z,1556237130.201 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2019-04-26T00:05:30.202Z,1556237130.202 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4078A4E0 2019-04-26T00:05:30.202Z,1556237130.202 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 892 2019-04-26T00:05:30.248Z,1556237130.248 [RDI_Pathfinder] Loaded 2019-04-26T00:05:30.248Z,1556237130.248 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread. 2019-04-26T00:05:31.802Z,1556237131.802 [BPC1] Loaded 2019-04-26T00:05:31.802Z,1556237131.802 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2019-04-26T00:05:31.802Z,1556237131.802 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2019-04-26T00:05:31.803Z,1556237131.803 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2019-04-26T00:05:31.847Z,1556237131.847 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2019-04-26T00:05:32.446Z,1556237132.446 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2019-04-26T00:05:32.582Z,1556237132.582 [DeadReckonUsingMultipleVelocitySources] Loaded 2019-04-26T00:05:32.582Z,1556237132.582 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2019-04-26T00:05:32.604Z,1556237132.604 [NavChart] Loaded 2019-04-26T00:05:32.604Z,1556237132.604 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2019-04-26T00:05:32.608Z,1556237132.608 [UniversalFixResidualReporter] Loaded 2019-04-26T00:05:32.608Z,1556237132.608 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2019-04-26T00:05:32.609Z,1556237132.609 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2019-04-26T00:05:32.609Z,1556237132.609 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2019-04-26T00:05:32.746Z,1556237132.746 [BuoyancyServo] Loaded 2019-04-26T00:05:32.746Z,1556237132.746 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2019-04-26T00:05:32.761Z,1556237132.761 [ElevatorServo] Loaded 2019-04-26T00:05:32.762Z,1556237132.762 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2019-04-26T00:05:32.762Z,1556237132.762 [Module Loader](CRITICAL): Could not find element LineCaptureServo.loadAtStartup 2019-04-26T00:05:32.777Z,1556237132.777 [MassServo] Loaded 2019-04-26T00:05:32.777Z,1556237132.777 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2019-04-26T00:05:32.793Z,1556237132.793 [RudderServo] Loaded 2019-04-26T00:05:32.793Z,1556237132.793 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2019-04-26T00:05:32.808Z,1556237132.808 [ThrusterServo] Loaded 2019-04-26T00:05:32.808Z,1556237132.808 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2019-04-26T00:05:32.808Z,1556237132.808 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2019-04-26T00:05:32.809Z,1556237132.809 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2019-04-26T00:05:33.142Z,1556237133.142 [CTD_NeilBrown] Loaded 2019-04-26T00:05:33.142Z,1556237133.142 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2019-04-26T00:05:33.143Z,1556237133.143 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408CC4E0 2019-04-26T00:05:33.144Z,1556237133.144 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 893 2019-04-26T00:05:33.190Z,1556237133.190 [WetLabsSeaOWL_UV_A] Loaded 2019-04-26T00:05:33.190Z,1556237133.190 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread. 2019-04-26T00:05:33.191Z,1556237133.191 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 408FC4E0 2019-04-26T00:05:33.191Z,1556237133.191 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 894 2019-04-26T00:05:33.192Z,1556237133.192 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2019-04-26T00:05:33.193Z,1556237133.193 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2019-04-26T00:05:33.552Z,1556237133.552 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2019-04-26T00:05:33.552Z,1556237133.552 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2019-04-26T00:05:33.610Z,1556237133.610 [DepthRateCalculator] Loaded 2019-04-26T00:05:33.611Z,1556237133.611 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2019-04-26T00:05:33.616Z,1556237133.616 [PitchRateCalculator] Loaded 2019-04-26T00:05:33.617Z,1556237133.617 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2019-04-26T00:05:33.629Z,1556237133.629 [SpeedCalculator] Loaded 2019-04-26T00:05:33.630Z,1556237133.630 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2019-04-26T00:05:33.651Z,1556237133.651 [TempGradientCalculator] Loaded 2019-04-26T00:05:33.651Z,1556237133.651 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2019-04-26T00:05:33.657Z,1556237133.657 [YawRateCalculator] Loaded 2019-04-26T00:05:33.657Z,1556237133.657 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2019-04-26T00:05:33.699Z,1556237133.699 [ElevatorOffsetCalculator] Loaded 2019-04-26T00:05:33.699Z,1556237133.699 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2019-04-26T00:05:33.699Z,1556237133.699 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2019-04-26T00:05:33.700Z,1556237133.700 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2019-04-26T00:05:33.869Z,1556237133.869 [SBIT](DEBUG): Construct Startup Built In Test. 2019-04-26T00:05:33.892Z,1556237133.892 [SBIT] Loaded 2019-04-26T00:05:33.892Z,1556237133.892 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2019-04-26T00:05:33.893Z,1556237133.893 [IBIT](DEBUG): Construct Initiated Built In Test. 2019-04-26T00:05:33.905Z,1556237133.905 [IBIT] Loaded 2019-04-26T00:05:33.905Z,1556237133.905 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2019-04-26T00:05:33.908Z,1556237133.908 [CBIT](DEBUG): Construct Continuous Built In Test. 2019-04-26T00:05:34.050Z,1556237134.050 [CBIT] Loaded 2019-04-26T00:05:34.050Z,1556237134.050 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2019-04-26T00:05:34.051Z,1556237134.051 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2019-04-26T00:05:34.051Z,1556237134.051 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2019-04-26T00:05:34.165Z,1556237134.165 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2019-04-26T00:05:34.167Z,1556237134.167 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2019-04-26T00:05:34.302Z,1556237134.302 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2019-04-26T00:05:34.302Z,1556237134.302 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2019-04-26T00:05:34.393Z,1556237134.393 [VerticalControl](DEBUG): Construct VerticalControl. 2019-04-26T00:05:34.478Z,1556237134.478 [VerticalControl] Loaded 2019-04-26T00:05:34.479Z,1556237134.479 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2019-04-26T00:05:34.479Z,1556237134.479 [HorizontalControl](DEBUG): Construct HorizontalControl. 2019-04-26T00:05:34.539Z,1556237134.539 [HorizontalControl] Loaded 2019-04-26T00:05:34.539Z,1556237134.539 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2019-04-26T00:05:34.540Z,1556237134.540 [SpeedControl](DEBUG): Construct SpeedControl. 2019-04-26T00:05:34.542Z,1556237134.542 [SpeedControl] Loaded 2019-04-26T00:05:34.542Z,1556237134.542 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2019-04-26T00:05:34.543Z,1556237134.543 [LoopControl](DEBUG): Construct LoopControl. 2019-04-26T00:05:34.543Z,1556237134.543 [LoopControl] Loaded 2019-04-26T00:05:34.543Z,1556237134.543 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2019-04-26T00:05:34.544Z,1556237134.544 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2019-04-26T00:05:34.544Z,1556237134.544 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2019-04-26T00:05:34.588Z,1556237134.588 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2019-04-26T00:05:34.592Z,1556237134.592 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2019-04-26T00:05:34.592Z,1556237134.592 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2019-04-26T00:05:34.599Z,1556237134.599 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2019-04-26T00:05:34.600Z,1556237134.600 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AD34E0 2019-04-26T00:05:34.600Z,1556237134.600 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 895 2019-04-26T00:05:34.605Z,1556237134.605 [Supervisor](INFO): Main Thread ID is 805 2019-04-26T00:05:34.605Z,1556237134.605 [Supervisor](DEBUG): Running supervisor. 2019-04-26T00:05:34.606Z,1556237134.606 [CommandLine ThreadHandler](INFO): Handler Thread ID is 896 2019-04-26T00:05:34.608Z,1556237134.608 [controlThread ThreadHandler](INFO): Handler Thread ID is 897 2019-04-26T00:05:34.608Z,1556237134.608 [controlThread](DEBUG): Initializing ControlThread 2019-04-26T00:05:34.615Z,1556237134.615 [NavChart](DEBUG): Initialize NavChart Navigation. 2019-04-26T00:05:34.615Z,1556237134.615 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2019-04-26T00:05:34.616Z,1556237134.616 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2019-04-26T00:05:34.617Z,1556237134.617 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2019-04-26T00:05:34.617Z,1556237134.617 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2019-04-26T00:05:34.617Z,1556237134.617 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2019-04-26T00:05:34.618Z,1556237134.618 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2019-04-26T00:05:34.618Z,1556237134.618 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2019-04-26T00:05:34.619Z,1556237134.619 [SBIT](INFO): Initialize SBIT Component. 2019-04-26T00:05:34.619Z,1556237134.619 [SBIT](IMPORTANT): git: 2019-04-10-14-g08d638a 2019-04-26T00:05:34.619Z,1556237134.619 [SBIT](INFO): git hash: 08d638a599400f5b89d801042872eecc619e609b 2019-04-26T00:05:34.620Z,1556237134.620 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2019-04-26T00:05:34.621Z,1556237134.621 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019 2019-04-26T00:05:34.622Z,1556237134.622 [SBIT](INFO): Beginning SBIT in 44.000000 seconds. 2019-04-26T00:05:34.622Z,1556237134.622 [IBIT](INFO): Initialize IBIT Component. 2019-04-26T00:05:34.623Z,1556237134.623 [CBIT](DEBUG): Initialize CBIT Component. 2019-04-26T00:05:34.624Z,1556237134.624 [logger ThreadHandler](INFO): Handler Thread ID is 898 2019-04-26T00:05:34.636Z,1556237134.636 [CBIT](DEBUG): Initialized mux pins. 2019-04-26T00:05:34.636Z,1556237134.636 [CBIT](DEBUG): Initializing the watchdog timer. 2019-04-26T00:05:34.644Z,1556237134.644 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 899 2019-04-26T00:05:34.645Z,1556237134.645 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2019-04-26T00:05:34.656Z,1556237134.656 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 900 2019-04-26T00:05:34.660Z,1556237134.660 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2019-04-26T00:05:34.660Z,1556237134.660 [CBIT](DEBUG): Initializing heartbeat. 2019-04-26T00:05:34.668Z,1556237134.668 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 901 2019-04-26T00:05:34.669Z,1556237134.669 [CTD_NeilBrown](INFO): Powering down 2019-04-26T00:05:34.696Z,1556237134.696 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 902 2019-04-26T00:05:34.697Z,1556237134.697 [WetLabsSeaOWL_UV_A](INFO): Powering down 2019-04-26T00:05:34.729Z,1556237134.729 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 903 2019-04-26T00:05:34.732Z,1556237134.732 [CBIT](DEBUG): Deactivating GF circuits. 2019-04-26T00:05:34.732Z,1556237134.732 [CBIT](DEBUG): Deactivating emergency mode. 2019-04-26T00:05:34.737Z,1556237134.737 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2019-04-26T00:05:34.737Z,1556237134.737 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2019-04-26T00:05:34.738Z,1556237134.738 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2019-04-26T00:05:34.738Z,1556237134.738 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2019-04-26T00:05:34.738Z,1556237134.738 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2019-04-26T00:05:34.738Z,1556237134.738 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2019-04-26T00:05:34.738Z,1556237134.738 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2019-04-26T00:05:34.738Z,1556237134.738 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2019-04-26T00:05:34.739Z,1556237134.739 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2019-04-26T00:05:34.739Z,1556237134.739 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2019-04-26T00:05:34.739Z,1556237134.739 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2019-04-26T00:05:34.739Z,1556237134.739 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2019-04-26T00:05:34.739Z,1556237134.739 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2019-04-26T00:05:34.739Z,1556237134.739 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2019-04-26T00:05:34.740Z,1556237134.740 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2019-04-26T00:05:34.740Z,1556237134.740 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2019-04-26T00:05:34.768Z,1556237134.768 [CBIT](DEBUG): Backplane powered. 2019-04-26T00:05:34.768Z,1556237134.768 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2019-04-26T00:05:34.770Z,1556237134.770 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2019-04-26T00:05:34.771Z,1556237134.771 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2019-04-26T00:05:34.771Z,1556237134.771 [LoopControl](DEBUG): Initialize LoopControlComponent. 2019-04-26T00:05:34.772Z,1556237134.772 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2019-04-26T00:05:34.807Z,1556237134.807 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2019-04-26T00:05:34.826Z,1556237134.826 [MissionManager](DEBUG): 2019-04-26T00:05:34.827Z,1556237134.827 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2019-04-26T00:05:34.918Z,1556237134.918 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2019-04-26T00:05:34.919Z,1556237134.919 [Default:A.Wait](DEBUG): Construct Wait. 2019-04-26T00:05:34.931Z,1556237134.931 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2019-04-26T00:05:34.950Z,1556237134.950 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2019-04-26T00:05:34.983Z,1556237134.983 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2019-04-26T00:05:35.005Z,1556237135.005 [Default:E.Execute](DEBUG): Construct Execute. 2019-04-26T00:05:35.009Z,1556237135.009 [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-04-26T00:05:35.028Z,1556237135.028 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2019-04-26T00:05:35.033Z,1556237135.033 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-04-26T00:05:35.060Z,1556237135.060 [Radio_Surface](INFO): Powering up 2019-04-26T00:05:35.241Z,1556237135.241 [DUSBL_Hydroid](INFO): Powering up 2019-04-26T00:05:35.241Z,1556237135.241 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid. 2019-04-26T00:05:35.330Z,1556237135.330 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2019-04-26T00:05:35.332Z,1556237135.332 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2019-04-26T00:05:35.333Z,1556237135.333 [ElevatorServo](DEBUG): Initializing EZServoServo. 2019-04-26T00:05:35.340Z,1556237135.340 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2019-04-26T00:05:35.341Z,1556237135.341 [MassServo](DEBUG): Initializing EZServoServo. 2019-04-26T00:05:35.348Z,1556237135.348 [MassServo](DEBUG): Initializing MassServo. 2019-04-26T00:05:35.349Z,1556237135.349 [RudderServo](DEBUG): Initializing EZServoServo. 2019-04-26T00:05:35.356Z,1556237135.356 [RudderServo](DEBUG): Initializing RudderServo. 2019-04-26T00:05:35.357Z,1556237135.357 [ThrusterServo](DEBUG): Initializing EZServoServo. 2019-04-26T00:05:35.364Z,1556237135.364 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2019-04-26T00:05:35.366Z,1556237135.366 [CommandLine](FAULT): Scheduling is paused 2019-04-26T00:05:35.367Z,1556237135.367 [CBIT](INFO): Critical error at 20190426T000532 2019-04-26T00:05:35.367Z,1556237135.367 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2019-04-26T00:05:35.485Z,1556237135.485 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar 2019-04-26T00:05:35.486Z,1556237135.486 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2019-04-26T00:05:35.486Z,1556237135.486 [DropWeight] Hardware Fault, FailCount= 1 2019-04-26T00:05:35.486Z,1556237135.486 [DropWeight](ERROR): Hardware Fault 2019-04-26T00:05:35.487Z,1556237135.487 [Micromodem](INFO): Powering up 2019-04-26T00:05:35.496Z,1556237135.496 [Micromodem](DEBUG): Initializing Micromodem. 2019-04-26T00:05:35.567Z,1556237135.567 [CBIT](INFO): Critical error at 20190426T000535 2019-04-26T00:05:35.570Z,1556237135.570 [CBIT](ERROR): Hardware Fault in component: DropWeight 2019-04-26T00:05:35.570Z,1556237135.570 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2019-04-26T00:05:36.212Z,1556237136.212 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2019-04-26T00:05:36.212Z,1556237136.212 [RudderServo](FAULT): Rudder failed to initialize 2019-04-26T00:05:36.212Z,1556237136.212 [RudderServo] Communications Fault, FailCount= 1 2019-04-26T00:05:36.212Z,1556237136.212 [RudderServo](ERROR): Communications Fault 2019-04-26T00:05:36.381Z,1556237136.381 [CBIT](INFO): Critical error at 20190426T000535 2019-04-26T00:05:36.384Z,1556237136.384 [CBIT](ERROR): Communications Fault in component: RudderServo 2019-04-26T00:05:36.553Z,1556237136.553 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-04-26T00:05:36.553Z,1556237136.553 [RudderServo](INFO): Powering down 2019-04-26T00:05:37.228Z,1556237137.228 [RudderServo](DEBUG): Initializing EZServoServo. 2019-04-26T00:05:37.349Z,1556237137.349 [RudderServo](DEBUG): Initializing RudderServo. 2019-04-26T00:05:37.353Z,1556237137.353 [CBIT](INFO): Clearing failed state for component RudderServo 2019-04-26T00:05:37.353Z,1556237137.353 [RudderServo] No Fault, FailCount= 1 2019-04-26T00:05:38.732Z,1556237138.732 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-04-26T00:05:39.136Z,1556237139.136 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-04-26T00:05:39.640Z,1556237139.640 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-04-26T00:05:40.236Z,1556237140.236 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-04-26T00:05:40.700Z,1556237140.700 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-04-26T00:05:41.216Z,1556237141.216 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-04-26T00:05:41.712Z,1556237141.712 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-04-26T00:05:44.912Z,1556237144.912 [CBIT](CRITICAL): Environmental Failure. Press:14.771316 PSI. Humidity:34%. Temp:26 C. ABORTING MISSION 2019-04-26T00:05:45.338Z,1556237145.338 [CBIT](INFO): Critical error at 20190426T000544 2019-04-26T00:05:46.514Z,1556237146.514 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004646 2019-04-26T00:05:55.313Z,1556237155.313 [DUSBL_Hydroid](FAULT): failed to initialize; deviceResponse_ loaded: , available: 0 2019-04-26T00:05:55.313Z,1556237155.313 [DUSBL_Hydroid] Communications Fault, FailCount= 1 2019-04-26T00:05:55.314Z,1556237155.314 [DUSBL_Hydroid](ERROR): Communications Fault 2019-04-26T00:05:55.381Z,1556237155.381 [CBIT](ERROR): Communications Fault in component: DUSBL_Hydroid 2019-04-26T00:05:55.717Z,1556237155.717 [DUSBL_Hydroid](INFO): Powering down 2019-04-26T00:05:56.564Z,1556237156.564 [CBIT](INFO): Clearing failed state for component DUSBL_Hydroid 2019-04-26T00:05:56.564Z,1556237156.564 [DUSBL_Hydroid] No Fault, FailCount= 1 2019-04-26T00:05:56.924Z,1556237156.924 [AHRS_M2](FAULT): Failed to acquire valid data within timeout. 2019-04-26T00:05:56.924Z,1556237156.924 [AHRS_M2] Data Fault, FailCount= 1 2019-04-26T00:05:56.924Z,1556237156.924 [AHRS_M2](ERROR): Data Fault 2019-04-26T00:05:56.988Z,1556237156.988 [CBIT](ERROR): Data Fault in component: AHRS_M2 2019-04-26T00:05:57.316Z,1556237157.316 [AHRS_M2](INFO): Powering down 2019-04-26T00:05:57.417Z,1556237157.417 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing 2019-04-26T00:05:57.417Z,1556237157.417 [RDI_Pathfinder] Communications Fault, FailCount= 1 2019-04-26T00:05:57.417Z,1556237157.417 [RDI_Pathfinder](ERROR): Communications Fault 2019-04-26T00:05:57.457Z,1556237157.457 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder 2019-04-26T00:05:57.824Z,1556237157.824 [RDI_Pathfinder](INFO): Powering down 2019-04-26T00:05:58.160Z,1556237158.160 [CBIT](INFO): Clearing failed state for component AHRS_M2 2019-04-26T00:05:58.160Z,1556237158.160 [AHRS_M2] No Fault, FailCount= 1 2019-04-26T00:05:58.528Z,1556237158.528 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-04-26T00:05:58.575Z,1556237158.575 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder 2019-04-26T00:05:58.575Z,1556237158.575 [RDI_Pathfinder] No Fault, FailCount= 1 2019-04-26T00:05:58.937Z,1556237158.937 [DUSBL_Hydroid](INFO): Powering up 2019-04-26T00:05:58.937Z,1556237158.937 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid. 2019-04-26T00:06:00.555Z,1556237160.555 [NAL9602](INFO): Powering up NAL9602 2019-04-26T00:06:02.084Z,1556237162.084 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:02.480Z,1556237162.480 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:02.884Z,1556237162.884 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:03.296Z,1556237163.296 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:03.700Z,1556237163.700 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:04.112Z,1556237164.112 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:04.528Z,1556237164.528 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:04.920Z,1556237164.920 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:05.316Z,1556237165.316 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:05.720Z,1556237165.720 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:06.124Z,1556237166.124 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:06.528Z,1556237166.528 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:06.928Z,1556237166.928 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:07.340Z,1556237167.340 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:07.744Z,1556237167.744 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:08.156Z,1556237168.156 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:08.544Z,1556237168.544 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:08.944Z,1556237168.944 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:09.356Z,1556237169.356 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:09.760Z,1556237169.760 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:10.164Z,1556237170.164 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:10.568Z,1556237170.568 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:10.972Z,1556237170.972 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:11.396Z,1556237171.396 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:11.396Z,1556237171.396 [AHRS_M2](FAULT): Failed to initialize within timeout. 2019-04-26T00:06:11.396Z,1556237171.396 [AHRS_M2] Communications Fault, FailCount= 2 2019-04-26T00:06:11.396Z,1556237171.396 [AHRS_M2](ERROR): Communications Fault 2019-04-26T00:06:11.402Z,1556237171.402 [NAL9602](INFO): NAL9602 initialized 2019-04-26T00:06:11.432Z,1556237171.432 [CBIT](ERROR): Communications Fault in component: AHRS_M2 2019-04-26T00:06:11.456Z,1556237171.456 [AHRS_M2](INFO): Powering down 2019-04-26T00:06:11.880Z,1556237171.880 [NAL9602](DEBUG): Fix Requested 2019-04-26T00:06:12.328Z,1556237172.328 [CBIT](INFO): Clearing failed state for component AHRS_M2 2019-04-26T00:06:12.328Z,1556237172.328 [AHRS_M2] No Fault, FailCount= 2 2019-04-26T00:06:12.668Z,1556237172.668 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-04-26T00:06:16.224Z,1556237176.224 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:16.628Z,1556237176.628 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:17.032Z,1556237177.032 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:17.436Z,1556237177.436 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:17.840Z,1556237177.840 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:18.260Z,1556237178.260 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:18.660Z,1556237178.660 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:19.044Z,1556237179.044 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:19.057Z,1556237179.057 [DUSBL_Hydroid](FAULT): failed to initialize; deviceResponse_ loaded: , available: 0 2019-04-26T00:06:19.057Z,1556237179.057 [DUSBL_Hydroid] Communications Fault, FailCount= 2 2019-04-26T00:06:19.058Z,1556237179.058 [DUSBL_Hydroid](ERROR): Communications Fault 2019-04-26T00:06:19.125Z,1556237179.125 [SBIT](IMPORTANT): Beginning Startup BIT 2019-04-26T00:06:19.133Z,1556237179.133 [CBIT](ERROR): Communications Fault in component: DUSBL_Hydroid 2019-04-26T00:06:19.134Z,1556237179.134 [CBIT](IMPORTANT): Beginning ground fault scan 2019-04-26T00:06:19.464Z,1556237179.464 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:19.469Z,1556237179.469 [DUSBL_Hydroid](INFO): Powering down 2019-04-26T00:06:19.996Z,1556237179.996 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:20.424Z,1556237180.424 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:20.517Z,1556237180.517 [CBIT](INFO): Clearing failed state for component DUSBL_Hydroid 2019-04-26T00:06:20.517Z,1556237180.517 [DUSBL_Hydroid] No Fault, FailCount= 2 2019-04-26T00:06:20.872Z,1556237180.872 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:21.488Z,1556237181.488 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:21.535Z,1556237181.535 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing 2019-04-26T00:06:21.536Z,1556237181.536 [RDI_Pathfinder] Communications Fault, FailCount= 2 2019-04-26T00:06:21.536Z,1556237181.536 [RDI_Pathfinder](ERROR): Communications Fault 2019-04-26T00:06:22.049Z,1556237182.049 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder 2019-04-26T00:06:22.380Z,1556237182.380 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:22.480Z,1556237182.480 [RDI_Pathfinder](INFO): Powering down 2019-04-26T00:06:23.040Z,1556237183.040 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:23.045Z,1556237183.045 [DUSBL_Hydroid](INFO): Powering up 2019-04-26T00:06:23.045Z,1556237183.045 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid. 2019-04-26T00:06:23.620Z,1556237183.620 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:23.725Z,1556237183.725 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder 2019-04-26T00:06:23.725Z,1556237183.725 [RDI_Pathfinder] No Fault, FailCount= 2 2019-04-26T00:06:24.148Z,1556237184.148 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:24.696Z,1556237184.696 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:25.116Z,1556237185.116 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:25.648Z,1556237185.648 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:25.648Z,1556237185.648 [AHRS_M2](FAULT): Failed to initialize within timeout. 2019-04-26T00:06:25.648Z,1556237185.648 [AHRS_M2] Communications Fault, FailCount= 3 2019-04-26T00:06:25.648Z,1556237185.648 [AHRS_M2](ERROR): Communications Fault 2019-04-26T00:06:25.753Z,1556237185.753 [CBIT](ERROR): Communications Fault in component: AHRS_M2 2019-04-26T00:06:25.763Z,1556237185.763 [AHRS_M2](INFO): Powering down 2019-04-26T00:06:26.637Z,1556237186.637 [CBIT](INFO): Clearing failed state for component AHRS_M2 2019-04-26T00:06:26.637Z,1556237186.637 [AHRS_M2] No Fault, FailCount= 3 2019-04-26T00:06:26.968Z,1556237186.968 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-04-26T00:06:30.512Z,1556237190.512 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:31.012Z,1556237191.012 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:31.196Z,1556237191.196 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.009836 CHAN A1 (24V): -0.028650 CHAN A2 (12V): -0.007179 CHAN A3 (5V): -0.002207 CHAN B0 (3.3V): 0.000044 CHAN B1 (3.15aV): -0.000266 CHAN B2 (3.15bV): 0.000411 CHAN B3 (GND): 0.002189 OPEN: -0.000709 Full Scale Calc: 4.765 mA, -1.589 mA 2019-04-26T00:06:31.520Z,1556237191.520 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:31.920Z,1556237191.920 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:32.332Z,1556237192.332 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:32.736Z,1556237192.736 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:33.148Z,1556237193.148 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:33.568Z,1556237193.568 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:33.944Z,1556237193.944 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:34.356Z,1556237194.356 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:35.236Z,1556237195.236 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:35.716Z,1556237195.716 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:36.188Z,1556237196.188 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:36.696Z,1556237196.696 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:37.208Z,1556237197.208 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:37.668Z,1556237197.668 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:38.136Z,1556237198.136 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:38.588Z,1556237198.588 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:39.064Z,1556237199.064 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:39.528Z,1556237199.528 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:40.020Z,1556237200.020 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:40.020Z,1556237200.020 [AHRS_M2](FAULT): Failed to initialize within timeout. 2019-04-26T00:06:40.020Z,1556237200.020 [AHRS_M2] Communications Fault, FailCount= 4 2019-04-26T00:06:40.020Z,1556237200.020 [AHRS_M2](ERROR): Communications Fault 2019-04-26T00:06:40.273Z,1556237200.273 [CBIT](ERROR): Communications Fault in component: AHRS_M2 2019-04-26T00:06:40.278Z,1556237200.278 [AHRS_M2](INFO): Powering down 2019-04-26T00:06:41.123Z,1556237201.123 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-26T00:06:41.209Z,1556237201.209 [CBIT](INFO): Clearing failed state for component AHRS_M2 2019-04-26T00:06:41.210Z,1556237201.210 [AHRS_M2] No Fault, FailCount= 4 2019-04-26T00:06:41.488Z,1556237201.488 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-04-26T00:06:43.115Z,1556237203.115 [DUSBL_Hydroid](FAULT): failed to initialize; deviceResponse_ loaded: , available: 0 2019-04-26T00:06:43.115Z,1556237203.115 [DUSBL_Hydroid] Communications Fault, FailCount= 3 2019-04-26T00:06:43.115Z,1556237203.115 [DUSBL_Hydroid](ERROR): Communications Fault 2019-04-26T00:06:43.201Z,1556237203.201 [CBIT](ERROR): Communications Fault in component: DUSBL_Hydroid 2019-04-26T00:06:43.513Z,1556237203.513 [DUSBL_Hydroid](INFO): Powering down 2019-04-26T00:06:44.401Z,1556237204.401 [CBIT](INFO): Clearing failed state for component DUSBL_Hydroid 2019-04-26T00:06:44.401Z,1556237204.401 [DUSBL_Hydroid] No Fault, FailCount= 3 2019-04-26T00:06:45.044Z,1556237205.044 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:45.448Z,1556237205.448 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:45.868Z,1556237205.868 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:46.296Z,1556237206.296 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:46.330Z,1556237206.330 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing 2019-04-26T00:06:46.330Z,1556237206.330 [RDI_Pathfinder] Communications Fault, FailCount= 3 2019-04-26T00:06:46.330Z,1556237206.330 [RDI_Pathfinder](ERROR): Communications Fault 2019-04-26T00:06:46.409Z,1556237206.409 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder 2019-04-26T00:06:46.409Z,1556237206.409 [CBIT](CRITICAL): Communications Fault in component: RDI_Pathfinder 2019-04-26T00:06:46.732Z,1556237206.732 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:46.737Z,1556237206.737 [DUSBL_Hydroid](INFO): Powering up 2019-04-26T00:06:46.737Z,1556237206.737 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid. 2019-04-26T00:06:46.852Z,1556237206.852 [RDI_Pathfinder](INFO): Powering down 2019-04-26T00:06:46.919Z,1556237206.919 [CBIT](INFO): Critical error at 20190426T000646 2019-04-26T00:06:47.244Z,1556237207.244 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:47.664Z,1556237207.664 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:48.076Z,1556237208.076 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:48.484Z,1556237208.484 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:48.900Z,1556237208.900 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:49.312Z,1556237209.312 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:49.800Z,1556237209.800 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:50.204Z,1556237210.204 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:50.608Z,1556237210.608 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:50.643Z,1556237210.643 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-26T00:06:51.013Z,1556237211.013 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:51.408Z,1556237211.408 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:51.812Z,1556237211.812 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:52.216Z,1556237212.216 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:52.628Z,1556237212.628 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:53.032Z,1556237213.032 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:53.444Z,1556237213.444 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:53.860Z,1556237213.860 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:54.246Z,1556237214.246 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:54.648Z,1556237214.648 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-04-26T00:06:54.648Z,1556237214.648 [AHRS_M2](FAULT): Failed to initialize within timeout. 2019-04-26T00:06:54.648Z,1556237214.648 [AHRS_M2] Communications Fault, FailCount= 5 2019-04-26T00:06:54.649Z,1556237214.649 [AHRS_M2](ERROR): Communications Fault 2019-04-26T00:06:54.713Z,1556237214.713 [CBIT](ERROR): Communications Fault in component: AHRS_M2 2019-04-26T00:06:54.713Z,1556237214.713 [CBIT](CRITICAL): Communications Fault in component: AHRS_M2 2019-04-26T00:06:54.728Z,1556237214.728 [AHRS_M2](INFO): Powering down 2019-04-26T00:06:54.837Z,1556237214.837 [CBIT](INFO): Critical error at 20190426T000654 2019-04-26T00:07:00.827Z,1556237220.827 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-26T00:07:06.953Z,1556237226.953 [DUSBL_Hydroid](FAULT): failed to initialize; deviceResponse_ loaded: , available: 0 2019-04-26T00:07:06.953Z,1556237226.953 [DUSBL_Hydroid] Communications Fault, FailCount= 4 2019-04-26T00:07:06.953Z,1556237226.953 [DUSBL_Hydroid](ERROR): Communications Fault 2019-04-26T00:07:07.037Z,1556237227.037 [CBIT](ERROR): Communications Fault in component: DUSBL_Hydroid 2019-04-26T00:07:07.363Z,1556237227.363 [DUSBL_Hydroid](INFO): Powering down 2019-04-26T00:07:08.209Z,1556237228.209 [CBIT](INFO): Clearing failed state for component DUSBL_Hydroid 2019-04-26T00:07:08.209Z,1556237228.209 [DUSBL_Hydroid] No Fault, FailCount= 4 2019-04-26T00:07:10.593Z,1556237230.593 [DUSBL_Hydroid](INFO): Powering up 2019-04-26T00:07:10.594Z,1556237230.594 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid. 2019-04-26T00:07:10.624Z,1556237230.624 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-26T00:07:12.639Z,1556237232.639 [SBIT](IMPORTANT): SBIT PASSED 2019-04-26T00:07:12.712Z,1556237232.712 [CommandLine](IMPORTANT): got command configSet list 2019-04-26T00:07:12.713Z,1556237232.713 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2019-04-26T00:07:12.713Z,1556237232.713 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=3 hour; 2019-04-26T00:07:12.714Z,1556237232.714 [CommandLine](IMPORTANT): BPC1.loadAtStartup=1 bool; 2019-04-26T00:07:12.714Z,1556237232.714 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold=90 count; 2019-04-26T00:07:12.714Z,1556237232.714 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.range 2.000000 meter; 2019-04-26T00:07:12.714Z,1556237232.714 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.xAngle 2.000000 angular_degree; 2019-04-26T00:07:12.714Z,1556237232.714 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.BottomVelocityFlag 0.000000 count; 2019-04-26T00:07:12.714Z,1556237232.714 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.height_above_sea_floor 2.000000 meter; 2019-04-26T00:07:12.714Z,1556237232.714 [CommandLine](IMPORTANT): Express none TrackAcousticContact.contact_latitude; 2019-04-26T00:07:12.714Z,1556237232.714 [CommandLine](IMPORTANT): Express none TrackAcousticContact.contact_longitude; 2019-04-26T00:07:12.715Z,1556237232.715 [CommandLine](IMPORTANT): Express linearApproximation acoustic_contact_range 1.000000 meter; 2019-04-26T00:07:12.715Z,1556237232.715 [CommandLine](IMPORTANT): NAL9602.fastGPSFix=1 bool; 2019-04-26T00:07:12.715Z,1556237232.715 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=190 cubic_centimeter; 2019-04-26T00:07:12.715Z,1556237232.715 [CommandLine](IMPORTANT): VerticalControl.massDefault=6 millimeter; 2019-04-26T00:07:13.040Z,1556237233.040 [MissionManager](IMPORTANT): Started mission Startup 2019-04-26T00:07:13.040Z,1556237233.040 [Startup] Running Loop=1 2019-04-26T00:07:13.040Z,1556237233.040 [Startup](DEBUG): Aggregate::initialize Startup 2019-04-26T00:07:13.041Z,1556237233.041 [Startup:A.GoToSurface] Running Loop=1 2019-04-26T00:07:13.041Z,1556237233.041 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-04-26T00:07:13.041Z,1556237233.041 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-04-26T00:07:13.042Z,1556237233.042 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-04-26T00:07:13.042Z,1556237233.042 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-04-26T00:07:13.042Z,1556237233.042 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-04-26T00:07:13.043Z,1556237233.043 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-04-26T00:07:13.045Z,1556237233.045 [Startup:StartupSatComms] Running Loop=1 2019-04-26T00:07:13.045Z,1556237233.045 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2019-04-26T00:07:13.045Z,1556237233.045 [Startup:StartupSatComms:A] Running Loop=1 2019-04-26T00:07:13.448Z,1556237233.448 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2019-04-26T00:07:20.709Z,1556237240.709 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-26T00:07:30.789Z,1556237250.789 [DUSBL_Hydroid](FAULT): failed to initialize; deviceResponse_ loaded: , available: 0 2019-04-26T00:07:30.789Z,1556237250.789 [DUSBL_Hydroid] Communications Fault, FailCount= 5 2019-04-26T00:07:30.789Z,1556237250.789 [DUSBL_Hydroid](ERROR): Communications Fault 2019-04-26T00:07:30.806Z,1556237250.806 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-26T00:07:30.829Z,1556237250.829 [CBIT](ERROR): Communications Fault in component: DUSBL_Hydroid 2019-04-26T00:07:31.198Z,1556237251.198 [DUSBL_Hydroid](INFO): Powering down 2019-04-26T00:07:32.055Z,1556237252.055 [CBIT](INFO): Clearing failed state for component DUSBL_Hydroid 2019-04-26T00:07:32.055Z,1556237252.055 [DUSBL_Hydroid] No Fault, FailCount= 5 2019-04-26T00:07:34.426Z,1556237254.426 [DUSBL_Hydroid](INFO): Powering up 2019-04-26T00:07:34.427Z,1556237254.427 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid. 2019-04-26T00:07:34.863Z,1556237254.863 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-04-26T00:07:34.863Z,1556237254.863 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2019-04-26T00:07:34.863Z,1556237254.863 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-04-26T00:07:34.874Z,1556237254.874 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-04-26T00:07:35.272Z,1556237255.272 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-04-26T00:07:35.272Z,1556237255.272 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2019-04-26T00:07:40.497Z,1556237260.497 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-26T00:07:50.201Z,1556237270.201 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-26T00:07:54.629Z,1556237274.629 [DUSBL_Hydroid](FAULT): failed to initialize; deviceResponse_ loaded: , available: 0 2019-04-26T00:07:54.629Z,1556237274.629 [DUSBL_Hydroid] Communications Fault, FailCount= 6 2019-04-26T00:07:54.629Z,1556237274.629 [DUSBL_Hydroid](ERROR): Communications Fault 2019-04-26T00:07:54.659Z,1556237274.659 [CBIT](ERROR): Communications Fault in component: DUSBL_Hydroid 2019-04-26T00:07:55.029Z,1556237275.029 [DUSBL_Hydroid](INFO): Powering down 2019-04-26T00:07:55.882Z,1556237275.882 [CBIT](INFO): Clearing failed state for component DUSBL_Hydroid 2019-04-26T00:07:55.882Z,1556237275.882 [DUSBL_Hydroid] No Fault, FailCount= 6 2019-04-26T00:07:58.261Z,1556237278.261 [DUSBL_Hydroid](INFO): Powering up 2019-04-26T00:07:58.261Z,1556237278.261 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid. 2019-04-26T00:07:59.897Z,1556237279.897 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-26T00:08:09.599Z,1556237289.599 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-26T00:08:13.234Z,1556237293.234 [Startup:StartupSatComms:A](INFO): Timed out from 2019-04-26T00:07:13.0Z 2019-04-26T00:08:13.234Z,1556237293.234 [Startup:StartupSatComms:A] Stopped 2019-04-26T00:08:13.234Z,1556237293.234 [Startup:StartupSatComms:B] Running Loop=1 2019-04-26T00:08:13.639Z,1556237293.639 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-04-26T00:08:18.465Z,1556237298.465 [DUSBL_Hydroid](FAULT): failed to initialize; deviceResponse_ loaded: , available: 0 2019-04-26T00:08:18.465Z,1556237298.465 [DUSBL_Hydroid] Communications Fault, FailCount= 7 2019-04-26T00:08:18.465Z,1556237298.465 [DUSBL_Hydroid](ERROR): Communications Fault 2019-04-26T00:08:18.501Z,1556237298.501 [CBIT](ERROR): Communications Fault in component: DUSBL_Hydroid 2019-04-26T00:08:18.869Z,1556237298.869 [DUSBL_Hydroid](INFO): Powering down 2019-04-26T00:08:19.706Z,1556237299.706 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-26T00:08:19.733Z,1556237299.733 [CBIT](INFO): Clearing failed state for component DUSBL_Hydroid 2019-04-26T00:08:19.733Z,1556237299.733 [DUSBL_Hydroid] No Fault, FailCount= 7 2019-04-26T00:08:22.097Z,1556237302.097 [DUSBL_Hydroid](INFO): Powering up 2019-04-26T00:08:22.097Z,1556237302.097 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid. 2019-04-26T00:08:23.968Z,1556237303.968 [DataOverHttps](INFO): Sending 326 bytes from file Logs/20190426T000523/Courier0000.lzma 2019-04-26T00:08:24.773Z,1556237304.773 [DataOverHttps](INFO): Moved sent file to Logs/20190426T000523/Courier0000.lzma.bak 2019-04-26T00:08:24.774Z,1556237304.774 [DataOverHttps](INFO): SBD MOMSN=10796333 2019-04-26T00:08:29.803Z,1556237309.803 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-26T00:08:35.173Z,1556237315.173 [DataOverHttps](INFO): Sending 1224 bytes from file Logs/20190426T000523/Express0001.lzma 2019-04-26T00:08:35.977Z,1556237315.977 [DataOverHttps](INFO): Moved sent file to Logs/20190426T000523/Express0001.lzma.bak 2019-04-26T00:08:35.977Z,1556237315.977 [DataOverHttps](INFO): SBD MOMSN=10796343 2019-04-26T00:08:36.686Z,1556237316.686 [Startup:StartupSatComms:B] Stopped 2019-04-26T00:08:36.687Z,1556237316.687 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2019-04-26T00:08:36.687Z,1556237316.687 [Startup:StartupSatComms] Stopped 2019-04-26T00:08:36.687Z,1556237316.687 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2019-04-26T00:08:36.687Z,1556237316.687 [Startup](INFO): Completed Startup 2019-04-26T00:08:36.688Z,1556237316.688 [MissionManager](INFO): Startup is completed. 2019-04-26T00:08:36.688Z,1556237316.688 [MissionManager](INFO): Uninitializing Mission Startup 2019-04-26T00:08:36.688Z,1556237316.688 [Startup] Stopped 2019-04-26T00:08:36.688Z,1556237316.688 [Startup](DEBUG): Aggregate::uninitialize Startup 2019-04-26T00:08:36.688Z,1556237316.688 [Startup:A.GoToSurface] Stopped 2019-04-26T00:08:36.688Z,1556237316.688 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-04-26T00:08:37.092Z,1556237317.092 [MissionManager](IMPORTANT): Started mission Default 2019-04-26T00:08:37.092Z,1556237317.092 [Default] Running Loop=1 2019-04-26T00:08:37.092Z,1556237317.092 [Default](DEBUG): Aggregate::initialize Default 2019-04-26T00:08:37.092Z,1556237317.092 [Default:B.GoToSurface] Running Loop=1 2019-04-26T00:08:37.092Z,1556237317.092 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-04-26T00:08:37.093Z,1556237317.093 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-04-26T00:08:37.093Z,1556237317.093 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-04-26T00:08:37.093Z,1556237317.093 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-04-26T00:08:37.094Z,1556237317.094 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-04-26T00:08:37.094Z,1556237317.094 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-04-26T00:08:37.094Z,1556237317.094 [Default:A.Wait] Running Loop=1 2019-04-26T00:08:37.094Z,1556237317.094 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-04-26T00:08:42.297Z,1556237322.297 [DUSBL_Hydroid](FAULT): failed to initialize; deviceResponse_ loaded: , available: 0 2019-04-26T00:08:42.297Z,1556237322.297 [DUSBL_Hydroid] Communications Fault, FailCount= 8 2019-04-26T00:08:42.297Z,1556237322.297 [DUSBL_Hydroid](ERROR): Communications Fault 2019-04-26T00:08:42.326Z,1556237322.326 [CBIT](ERROR): Communications Fault in component: DUSBL_Hydroid 2019-04-26T00:08:42.326Z,1556237322.326 [CBIT](CRITICAL): Communications Fault in component: DUSBL_Hydroid 2019-04-26T00:08:42.701Z,1556237322.701 [DUSBL_Hydroid](INFO): Powering down 2019-04-26T00:08:42.813Z,1556237322.813 [CBIT](INFO): Critical error at 20190426T000842 2019-04-26T00:08:50.405Z,1556237330.405 [Default:A.Wait](INFO): Done Waiting. 2019-04-26T00:08:50.405Z,1556237330.405 [Default:A.Wait] Stopped 2019-04-26T00:08:50.405Z,1556237330.405 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-04-26T00:08:50.826Z,1556237330.826 [Default:CheckIn] Running Loop=1 2019-04-26T00:08:50.826Z,1556237330.826 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-04-26T00:08:50.826Z,1556237330.826 [Default:CheckIn:Read_GPS] Running Loop=1 2019-04-26T00:08:51.232Z,1556237331.232 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2019-04-26T00:09:35.658Z,1556237375.658 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-04-26T00:09:35.658Z,1556237375.658 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2019-04-26T00:09:35.658Z,1556237375.658 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-04-26T00:09:35.669Z,1556237375.669 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-04-26T00:09:36.123Z,1556237376.123 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-04-26T00:09:36.123Z,1556237376.123 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2019-04-26T00:09:46.567Z,1556237386.567 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder 2019-04-26T00:09:46.567Z,1556237386.567 [RDI_Pathfinder] No Fault, FailCount= 3 2019-04-26T00:09:59.492Z,1556237399.492 [RDI_Pathfinder](FAULT): DVL failed to acquire valid data within timeout. 2019-04-26T00:09:59.493Z,1556237399.493 [RDI_Pathfinder] Data Fault, FailCount= 1 2019-04-26T00:09:59.493Z,1556237399.493 [RDI_Pathfinder](ERROR): Data Fault 2019-04-26T00:09:59.517Z,1556237399.517 [CBIT](ERROR): Data Fault in component: RDI_Pathfinder 2019-04-26T00:09:59.976Z,1556237399.976 [RDI_Pathfinder](INFO): Powering down 2019-04-26T00:10:00.707Z,1556237400.707 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder 2019-04-26T00:10:00.707Z,1556237400.707 [RDI_Pathfinder] No Fault, FailCount= 1 2019-04-26T00:10:23.319Z,1556237423.319 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing 2019-04-26T00:10:23.319Z,1556237423.319 [RDI_Pathfinder] Communications Fault, FailCount= 2 2019-04-26T00:10:23.320Z,1556237423.320 [RDI_Pathfinder](ERROR): Communications Fault 2019-04-26T00:10:23.342Z,1556237423.342 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder 2019-04-26T00:10:23.792Z,1556237423.792 [RDI_Pathfinder](INFO): Powering down 2019-04-26T00:10:24.561Z,1556237424.561 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder 2019-04-26T00:10:24.562Z,1556237424.562 [RDI_Pathfinder] No Fault, FailCount= 2 2019-04-26T00:10:47.162Z,1556237447.162 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing 2019-04-26T00:10:47.162Z,1556237447.162 [RDI_Pathfinder] Communications Fault, FailCount= 3 2019-04-26T00:10:47.163Z,1556237447.163 [RDI_Pathfinder](ERROR): Communications Fault 2019-04-26T00:10:47.178Z,1556237447.178 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder 2019-04-26T00:10:47.178Z,1556237447.178 [CBIT](CRITICAL): Communications Fault in component: RDI_Pathfinder 2019-04-26T00:10:47.640Z,1556237447.640 [RDI_Pathfinder](INFO): Powering down 2019-04-26T00:10:47.670Z,1556237447.670 [CBIT](INFO): Critical error at 20190426T001047 2019-04-26T00:11:01.296Z,1556237461.296 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-26T00:11:10.988Z,1556237470.988 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-26T00:11:14.607Z,1556237474.607 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-04-26T00:11:15.432Z,1556237475.432 [NAL9602](DEBUG): Fix Requested 2019-04-26T00:11:19.468Z,1556237479.468 [NAL9602](DEBUG): Fix Requested 2019-04-26T00:11:21.089Z,1556237481.089 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-26T00:11:21.488Z,1556237481.488 [NAL9602](DEBUG): Fix Requested 2019-04-26T00:11:24.720Z,1556237484.720 [NAL9602](DEBUG): Fix Requested 2019-04-26T00:11:27.548Z,1556237487.548 [NAL9602](DEBUG): Fix Requested 2019-04-26T00:11:30.784Z,1556237490.784 [NAL9602](DEBUG): Fix Requested 2019-04-26T00:11:30.799Z,1556237490.799 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-26T00:11:33.604Z,1556237493.604 [NAL9602](DEBUG): Fix Requested 2019-04-26T00:11:36.840Z,1556237496.840 [NAL9602](DEBUG): Fix Requested 2019-04-26T00:11:36.863Z,1556237496.863 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-04-26T00:11:36.863Z,1556237496.863 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2019-04-26T00:11:36.863Z,1556237496.863 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-04-26T00:11:36.874Z,1556237496.874 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-04-26T00:11:37.277Z,1556237497.277 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMu