2018-10-08T16:45:00.537Z,1539017100.537 [Supervisor](DEBUG): Initializing supervisor. 2018-10-08T16:45:00.540Z,1539017100.540 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2018-10-08T16:45:00.541Z,1539017100.541 [SyncHandler](INFO): Protected caller Thread ID is 7667 2018-10-08T16:45:00.542Z,1539017100.542 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2018-10-08T16:45:00.543Z,1539017100.543 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2018-10-08T16:45:00.543Z,1539017100.543 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 7668 2018-10-08T16:45:00.547Z,1539017100.547 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2018-10-08T16:45:00.559Z,1539017100.559 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2018-10-08T16:45:00.560Z,1539017100.560 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2018-10-08T16:45:00.561Z,1539017100.561 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 7669 2018-10-08T16:45:00.561Z,1539017100.561 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2018-10-08T16:45:00.562Z,1539017100.562 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2018-10-08T16:45:00.563Z,1539017100.563 [logger ThreadHandler](INFO): Protected caller Thread ID is 7670 2018-10-08T16:45:00.565Z,1539017100.565 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2018-10-08T16:45:00.565Z,1539017100.565 [Supervisor](INFO): Looking for Config files in directory: Config/ 2018-10-08T16:45:00.567Z,1539017100.567 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2018-10-08T16:45:00.761Z,1539017100.761 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2018-10-08T16:45:00.761Z,1539017100.761 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2018-10-08T16:45:00.907Z,1539017100.907 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2018-10-08T16:45:00.907Z,1539017100.907 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2018-10-08T16:45:01.264Z,1539017101.264 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2018-10-08T16:45:01.265Z,1539017101.265 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2018-10-08T16:45:01.405Z,1539017101.405 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2018-10-08T16:45:01.406Z,1539017101.406 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2018-10-08T16:45:01.487Z,1539017101.487 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2018-10-08T16:45:01.693Z,1539017101.693 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2018-10-08T16:45:01.694Z,1539017101.694 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2018-10-08T16:45:01.794Z,1539017101.794 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2018-10-08T16:45:01.794Z,1539017101.794 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2018-10-08T16:45:02.148Z,1539017102.148 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2018-10-08T16:45:02.148Z,1539017102.148 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2018-10-08T16:45:02.636Z,1539017102.636 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2018-10-08T16:45:02.637Z,1539017102.637 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2018-10-08T16:45:02.960Z,1539017102.960 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2018-10-08T16:45:02.960Z,1539017102.960 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2018-10-08T16:45:03.475Z,1539017103.475 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2018-10-08T16:45:03.476Z,1539017103.476 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2018-10-08T16:45:03.689Z,1539017103.689 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2018-10-08T16:45:03.690Z,1539017103.690 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2018-10-08T16:45:03.790Z,1539017103.790 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2018-10-08T16:45:03.790Z,1539017103.790 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2018-10-08T16:45:04.312Z,1539017104.312 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2018-10-08T16:45:04.313Z,1539017104.313 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2018-10-08T16:45:04.425Z,1539017104.425 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2018-10-08T16:45:04.427Z,1539017104.427 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/ 2018-10-08T16:45:04.428Z,1539017104.428 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg 2018-10-08T16:45:04.661Z,1539017104.661 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2018-10-08T16:45:04.662Z,1539017104.662 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg 2018-10-08T16:45:04.763Z,1539017104.763 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg 2018-10-08T16:45:04.858Z,1539017104.858 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg 2018-10-08T16:45:04.964Z,1539017104.964 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg 2018-10-08T16:45:05.051Z,1539017105.051 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg 2018-10-08T16:45:05.217Z,1539017105.217 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg 2018-10-08T16:45:05.390Z,1539017105.390 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg 2018-10-08T16:45:05.503Z,1539017105.503 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg 2018-10-08T16:45:05.604Z,1539017105.604 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg 2018-10-08T16:45:05.689Z,1539017105.689 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg 2018-10-08T16:45:05.887Z,1539017105.887 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/root/ 2018-10-08T16:45:05.887Z,1539017105.887 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2018-10-08T16:45:05.896Z,1539017105.896 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2018-10-08T16:45:06.030Z,1539017106.030 [SBIT](DEBUG): Construct Startup Built In Test. 2018-10-08T16:45:06.062Z,1539017106.062 [SBIT] Loaded 2018-10-08T16:45:06.062Z,1539017106.062 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2018-10-08T16:45:06.063Z,1539017106.063 [IBIT](DEBUG): Construct Initiated Built In Test. 2018-10-08T16:45:06.091Z,1539017106.091 [IBIT] Loaded 2018-10-08T16:45:06.091Z,1539017106.091 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2018-10-08T16:45:06.094Z,1539017106.094 [CBIT](DEBUG): Construct Continuous Built In Test. 2018-10-08T16:45:06.253Z,1539017106.253 [CBIT] Loaded 2018-10-08T16:45:06.254Z,1539017106.254 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2018-10-08T16:45:06.254Z,1539017106.254 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2018-10-08T16:45:06.255Z,1539017106.255 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2018-10-08T16:45:06.325Z,1539017106.325 [VerticalControl](DEBUG): Construct VerticalControl. 2018-10-08T16:45:06.428Z,1539017106.428 [VerticalControl] Loaded 2018-10-08T16:45:06.428Z,1539017106.428 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2018-10-08T16:45:06.429Z,1539017106.429 [HorizontalControl](DEBUG): Construct HorizontalControl. 2018-10-08T16:45:06.637Z,1539017106.637 [HorizontalControl] Loaded 2018-10-08T16:45:06.637Z,1539017106.637 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2018-10-08T16:45:06.638Z,1539017106.638 [SpeedControl](DEBUG): Construct SpeedControl. 2018-10-08T16:45:06.643Z,1539017106.643 [SpeedControl] Loaded 2018-10-08T16:45:06.644Z,1539017106.644 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2018-10-08T16:45:06.644Z,1539017106.644 [LoopControl](DEBUG): Construct LoopControl. 2018-10-08T16:45:06.645Z,1539017106.645 [LoopControl] Loaded 2018-10-08T16:45:06.645Z,1539017106.645 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2018-10-08T16:45:06.646Z,1539017106.646 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2018-10-08T16:45:06.646Z,1539017106.646 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2018-10-08T16:45:06.690Z,1539017106.690 [DepthRateCalculator] Loaded 2018-10-08T16:45:06.690Z,1539017106.690 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2018-10-08T16:45:06.696Z,1539017106.696 [PitchRateCalculator] Loaded 2018-10-08T16:45:06.696Z,1539017106.696 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2018-10-08T16:45:06.712Z,1539017106.712 [SpeedCalculator] Loaded 2018-10-08T16:45:06.713Z,1539017106.713 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2018-10-08T16:45:06.734Z,1539017106.734 [TempGradientCalculator] Loaded 2018-10-08T16:45:06.734Z,1539017106.734 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2018-10-08T16:45:06.740Z,1539017106.740 [YawRateCalculator] Loaded 2018-10-08T16:45:06.740Z,1539017106.740 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2018-10-08T16:45:06.770Z,1539017106.770 [ElevatorOffsetCalculator] Loaded 2018-10-08T16:45:06.770Z,1539017106.770 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2018-10-08T16:45:06.770Z,1539017106.770 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2018-10-08T16:45:06.771Z,1539017106.771 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2018-10-08T16:45:06.841Z,1539017106.841 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2018-10-08T16:45:06.841Z,1539017106.841 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2018-10-08T16:45:07.094Z,1539017107.094 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2018-10-08T16:45:07.094Z,1539017107.094 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2018-10-08T16:45:07.194Z,1539017107.194 [DeadReckonUsingMultipleVelocitySources] Loaded 2018-10-08T16:45:07.195Z,1539017107.195 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2018-10-08T16:45:07.250Z,1539017107.250 [DeadReckonUsingSpeedCalculator] Loaded 2018-10-08T16:45:07.250Z,1539017107.250 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2018-10-08T16:45:07.267Z,1539017107.267 [NavChart] Loaded 2018-10-08T16:45:07.267Z,1539017107.267 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2018-10-08T16:45:07.272Z,1539017107.272 [UniversalFixResidualReporter] Loaded 2018-10-08T16:45:07.272Z,1539017107.272 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2018-10-08T16:45:07.272Z,1539017107.272 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2018-10-08T16:45:07.273Z,1539017107.273 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2018-10-08T16:45:07.287Z,1539017107.287 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2018-10-08T16:45:07.288Z,1539017107.288 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2018-10-08T16:45:07.524Z,1539017107.524 [Aanderaa_O2] Loaded 2018-10-08T16:45:07.525Z,1539017107.525 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2018-10-08T16:45:07.605Z,1539017107.605 [CTD_NeilBrown] Loaded 2018-10-08T16:45:07.605Z,1539017107.605 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2018-10-08T16:45:07.607Z,1539017107.607 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 406DB4E0 2018-10-08T16:45:07.607Z,1539017107.607 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 7749 2018-10-08T16:45:07.653Z,1539017107.653 [WetLabsSeaOWL_UV_A] Loaded 2018-10-08T16:45:07.654Z,1539017107.654 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread. 2018-10-08T16:45:07.655Z,1539017107.655 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 4070B4E0 2018-10-08T16:45:07.655Z,1539017107.655 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 7750 2018-10-08T16:45:07.655Z,1539017107.655 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2018-10-08T16:45:07.656Z,1539017107.656 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2018-10-08T16:45:07.976Z,1539017107.976 [AHRS_M2] Loaded 2018-10-08T16:45:07.977Z,1539017107.977 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2018-10-08T16:45:08.047Z,1539017108.047 [DataOverHttps] Loaded 2018-10-08T16:45:08.048Z,1539017108.048 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2018-10-08T16:45:08.061Z,1539017108.061 [Depth_Keller] Loaded 2018-10-08T16:45:08.061Z,1539017108.061 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2018-10-08T16:45:08.066Z,1539017108.066 [DropWeight] Loaded 2018-10-08T16:45:08.067Z,1539017108.067 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2018-10-08T16:45:08.160Z,1539017108.160 [NAL9602] Loaded 2018-10-08T16:45:08.160Z,1539017108.160 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2018-10-08T16:45:08.166Z,1539017108.166 [Onboard] Loaded 2018-10-08T16:45:08.166Z,1539017108.166 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2018-10-08T16:45:08.173Z,1539017108.173 [Radio_Surface] Loaded 2018-10-08T16:45:08.173Z,1539017108.173 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2018-10-08T16:45:08.175Z,1539017108.175 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4096C4E0 2018-10-08T16:45:08.175Z,1539017108.175 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 7751 2018-10-08T16:45:08.204Z,1539017108.204 [RDI_Pathfinder] Loaded 2018-10-08T16:45:08.204Z,1539017108.204 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread. 2018-10-08T16:45:08.211Z,1539017108.211 [SCPI] Loaded 2018-10-08T16:45:08.211Z,1539017108.211 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread. 2018-10-08T16:45:08.236Z,1539017108.236 [BPC1](INFO): BPC1A: got serial number for stick 1: 0165 2018-10-08T16:45:08.237Z,1539017108.237 [BPC1](INFO): BPC1A: got serial number for stick 2: 0135 2018-10-08T16:45:08.238Z,1539017108.238 [BPC1](INFO): BPC1A: got serial number for stick 3: 0149 2018-10-08T16:45:08.239Z,1539017108.239 [BPC1](INFO): BPC1A: got serial number for stick 4: 0146 2018-10-08T16:45:08.240Z,1539017108.240 [BPC1](INFO): BPC1A: got serial number for stick 5: 013D 2018-10-08T16:45:08.241Z,1539017108.241 [BPC1](INFO): BPC1A: got serial number for stick 6: 014D 2018-10-08T16:45:08.241Z,1539017108.241 [BPC1](INFO): BPC1A: got serial number for stick 7: 0156 2018-10-08T16:45:08.242Z,1539017108.242 [BPC1](INFO): BPC1A: got serial number for stick 8: 0133 2018-10-08T16:45:08.243Z,1539017108.243 [BPC1](INFO): BPC1A: marked stick 8 as reserve. 2018-10-08T16:45:08.243Z,1539017108.243 [BPC1](INFO): BPC1A: got serial number for stick 9: 0131 2018-10-08T16:45:08.244Z,1539017108.244 [BPC1](INFO): BPC1A: got serial number for stick 10: 0145 2018-10-08T16:45:08.245Z,1539017108.245 [BPC1](INFO): BPC1A: got serial number for stick 11: 014A 2018-10-08T16:45:08.246Z,1539017108.246 [BPC1](INFO): BPC1A: got serial number for stick 12: 013C 2018-10-08T16:45:08.247Z,1539017108.247 [BPC1](INFO): BPC1A: got serial number for stick 13: 013B 2018-10-08T16:45:08.247Z,1539017108.247 [BPC1](INFO): BPC1A: got serial number for stick 14: 0132 2018-10-08T16:45:08.248Z,1539017108.248 [BPC1](INFO): BPC1A: got serial number for stick 15: 0134 2018-10-08T16:45:08.249Z,1539017108.249 [BPC1](INFO): BPC1A: got serial number for stick 16: 0153 2018-10-08T16:45:08.249Z,1539017108.249 [BPC1](INFO): BPC1A: marked stick 16 as reserve. 2018-10-08T16:45:08.250Z,1539017108.250 [BPC1](INFO): BPC1A: got serial number for stick 17: 014B 2018-10-08T16:45:08.251Z,1539017108.251 [BPC1](INFO): BPC1A: got serial number for stick 18: 013A 2018-10-08T16:45:08.252Z,1539017108.252 [BPC1](INFO): BPC1A: got serial number for stick 19: 0136 2018-10-08T16:45:08.253Z,1539017108.253 [BPC1](INFO): BPC1A: got serial number for stick 20: 014F 2018-10-08T16:45:08.253Z,1539017108.253 [BPC1](INFO): BPC1A: got serial number for stick 21: 014E 2018-10-08T16:45:08.254Z,1539017108.254 [BPC1](INFO): BPC1A: got serial number for stick 22: 013F 2018-10-08T16:45:08.255Z,1539017108.255 [BPC1](INFO): BPC1A: got serial number for stick 23: 0152 2018-10-08T16:45:08.256Z,1539017108.256 [BPC1](INFO): BPC1A: got serial number for stick 24: 014C 2018-10-08T16:45:08.256Z,1539017108.256 [BPC1](INFO): BPC1A: marked stick 24 as reserve. 2018-10-08T16:45:08.257Z,1539017108.257 [BPC1](INFO): BPC1A: got serial number for stick 25: 016B 2018-10-08T16:45:08.258Z,1539017108.258 [BPC1](INFO): BPC1A: got serial number for stick 26: 0141 2018-10-08T16:45:08.258Z,1539017108.258 [BPC1](INFO): BPC1A: got serial number for stick 27: 0139 2018-10-08T16:45:08.259Z,1539017108.259 [BPC1](INFO): BPC1A: got serial number for stick 28: 0137 2018-10-08T16:45:08.260Z,1539017108.260 [BPC1](INFO): BPC1A: got serial number for stick 29: 0142 2018-10-08T16:45:08.261Z,1539017108.261 [BPC1](INFO): BPC1A: got serial number for stick 30: 013E 2018-10-08T16:45:08.262Z,1539017108.262 [BPC1](INFO): BPC1A: got serial number for stick 31: 0147 2018-10-08T16:45:08.263Z,1539017108.263 [BPC1](INFO): BPC1B: got serial number for stick 32: 0140 2018-10-08T16:45:08.264Z,1539017108.264 [BPC1](INFO): BPC1B: got serial number for stick 33: 0163 2018-10-08T16:45:08.265Z,1539017108.265 [BPC1](INFO): BPC1B: got serial number for stick 34: 0157 2018-10-08T16:45:08.266Z,1539017108.266 [BPC1](INFO): BPC1B: got serial number for stick 35: 0159 2018-10-08T16:45:08.267Z,1539017108.267 [BPC1](INFO): BPC1B: got serial number for stick 36: 016E 2018-10-08T16:45:08.267Z,1539017108.267 [BPC1](INFO): BPC1B: got serial number for stick 37: 0160 2018-10-08T16:45:08.268Z,1539017108.268 [BPC1](INFO): BPC1B: got serial number for stick 38: 015C 2018-10-08T16:45:08.269Z,1539017108.269 [BPC1](INFO): BPC1B: got serial number for stick 39: 016D 2018-10-08T16:45:08.269Z,1539017108.269 [BPC1](INFO): BPC1B: marked stick 39 as reserve. 2018-10-08T16:45:08.270Z,1539017108.270 [BPC1](INFO): BPC1B: got serial number for stick 40: 012D 2018-10-08T16:45:08.271Z,1539017108.271 [BPC1](INFO): BPC1B: got serial number for stick 41: 015E 2018-10-08T16:45:08.272Z,1539017108.272 [BPC1](INFO): BPC1B: got serial number for stick 42: 0164 2018-10-08T16:45:08.273Z,1539017108.273 [BPC1](INFO): BPC1B: got serial number for stick 43: 015B 2018-10-08T16:45:08.273Z,1539017108.273 [BPC1](INFO): BPC1B: got serial number for stick 44: 0172 2018-10-08T16:45:08.274Z,1539017108.274 [BPC1](INFO): BPC1B: got serial number for stick 45: 0166 2018-10-08T16:45:08.275Z,1539017108.275 [BPC1](INFO): BPC1B: got serial number for stick 46: 0170 2018-10-08T16:45:08.276Z,1539017108.276 [BPC1](INFO): BPC1B: got serial number for stick 47: 0148 2018-10-08T16:45:08.276Z,1539017108.276 [BPC1](INFO): BPC1B: marked stick 47 as reserve. 2018-10-08T16:45:08.277Z,1539017108.277 [BPC1](INFO): BPC1B: got serial number for stick 48: 0130 2018-10-08T16:45:08.278Z,1539017108.278 [BPC1](INFO): BPC1B: got serial number for stick 49: 0169 2018-10-08T16:45:08.279Z,1539017108.279 [BPC1](INFO): BPC1B: got serial number for stick 50: 0158 2018-10-08T16:45:08.279Z,1539017108.279 [BPC1](INFO): BPC1B: got serial number for stick 51: 0162 2018-10-08T16:45:08.280Z,1539017108.280 [BPC1](INFO): BPC1B: got serial number for stick 52: 0150 2018-10-08T16:45:08.281Z,1539017108.281 [BPC1](INFO): BPC1B: got serial number for stick 53: 015F 2018-10-08T16:45:08.282Z,1539017108.282 [BPC1](INFO): BPC1B: got serial number for stick 54: 0171 2018-10-08T16:45:08.283Z,1539017108.283 [BPC1](INFO): BPC1B: got serial number for stick 55: 0143 2018-10-08T16:45:08.283Z,1539017108.283 [BPC1](INFO): BPC1B: marked stick 55 as reserve. 2018-10-08T16:45:08.284Z,1539017108.284 [BPC1](INFO): BPC1B: got serial number for stick 56: 0144 2018-10-08T16:45:08.285Z,1539017108.285 [BPC1](INFO): BPC1B: got serial number for stick 57: 016A 2018-10-08T16:45:08.285Z,1539017108.285 [BPC1](INFO): BPC1B: got serial number for stick 58: 0155 2018-10-08T16:45:08.286Z,1539017108.286 [BPC1](INFO): BPC1B: got serial number for stick 59: 0151 2018-10-08T16:45:08.287Z,1539017108.287 [BPC1](INFO): BPC1B: got serial number for stick 60: 0154 2018-10-08T16:45:08.288Z,1539017108.288 [BPC1](INFO): BPC1B: got serial number for stick 61: 0161 2018-10-08T16:45:08.289Z,1539017108.289 [BPC1](INFO): BPC1B: got serial number for stick 62: 0138 2018-10-08T16:45:10.486Z,1539017110.486 [BPC1] Loaded 2018-10-08T16:45:10.486Z,1539017110.486 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2018-10-08T16:45:10.487Z,1539017110.487 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2018-10-08T16:45:10.487Z,1539017110.487 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2018-10-08T16:45:10.592Z,1539017110.592 [BuoyancyServo] Loaded 2018-10-08T16:45:10.592Z,1539017110.592 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2018-10-08T16:45:10.604Z,1539017110.604 [ElevatorServo] Loaded 2018-10-08T16:45:10.604Z,1539017110.604 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2018-10-08T16:45:10.615Z,1539017110.615 [MassServo] Loaded 2018-10-08T16:45:10.616Z,1539017110.616 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2018-10-08T16:45:10.627Z,1539017110.627 [RudderServo] Loaded 2018-10-08T16:45:10.627Z,1539017110.627 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2018-10-08T16:45:10.639Z,1539017110.639 [ThrusterServo] Loaded 2018-10-08T16:45:10.639Z,1539017110.639 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2018-10-08T16:45:10.639Z,1539017110.639 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2018-10-08T16:45:10.640Z,1539017110.640 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2018-10-08T16:45:10.746Z,1539017110.746 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2018-10-08T16:45:10.746Z,1539017110.746 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2018-10-08T16:45:10.772Z,1539017110.772 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2018-10-08T16:45:10.775Z,1539017110.775 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2018-10-08T16:45:10.776Z,1539017110.776 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2018-10-08T16:45:10.783Z,1539017110.783 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2018-10-08T16:45:10.784Z,1539017110.784 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A154E0 2018-10-08T16:45:10.785Z,1539017110.785 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 7752 2018-10-08T16:45:10.789Z,1539017110.789 [Supervisor](INFO): Main Thread ID is 796 2018-10-08T16:45:10.790Z,1539017110.790 [Supervisor](DEBUG): Running supervisor. 2018-10-08T16:45:10.790Z,1539017110.790 [CommandLine ThreadHandler](INFO): Handler Thread ID is 7753 2018-10-08T16:45:10.793Z,1539017110.793 [controlThread ThreadHandler](INFO): Handler Thread ID is 7754 2018-10-08T16:45:10.793Z,1539017110.793 [controlThread](DEBUG): Initializing ControlThread 2018-10-08T16:45:10.794Z,1539017110.794 [SBIT](INFO): Initialize SBIT Component. 2018-10-08T16:45:10.795Z,1539017110.795 [SBIT](IMPORTANT): git: 2018-09-26-9-g14f2005 2018-10-08T16:45:10.795Z,1539017110.795 [SBIT](INFO): git hash: 14f2005f6a70b793a05ede5ccfbd62015cc8442d 2018-10-08T16:45:10.795Z,1539017110.795 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2018-10-08T16:45:10.795Z,1539017110.795 [SBIT](IMPORTANT): Kernel Version:#2 PREEMPT Thu Jan 11 20:13:48 PST 2018 2018-10-08T16:45:10.797Z,1539017110.797 [SBIT](INFO): Beginning SBIT in 28.000000 seconds. 2018-10-08T16:45:10.797Z,1539017110.797 [IBIT](INFO): Initialize IBIT Component. 2018-10-08T16:45:10.798Z,1539017110.798 [CBIT](DEBUG): Initialize CBIT Component. 2018-10-08T16:45:10.798Z,1539017110.798 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET. 2018-10-08T16:45:10.799Z,1539017110.799 [logger ThreadHandler](INFO): Handler Thread ID is 7755 2018-10-08T16:45:10.825Z,1539017110.825 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 7756 2018-10-08T16:45:10.826Z,1539017110.826 [CTD_NeilBrown](INFO): Powering down 2018-10-08T16:45:10.855Z,1539017110.855 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 7757 2018-10-08T16:45:10.856Z,1539017110.856 [WetLabsSeaOWL_UV_A](INFO): Powering down 2018-10-08T16:45:10.881Z,1539017110.881 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 7758 2018-10-08T16:45:10.887Z,1539017110.887 [Radio_Surface](INFO): Powering up 2018-10-08T16:45:10.905Z,1539017110.905 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2018-10-08T16:45:10.907Z,1539017110.907 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2018-10-08T16:45:10.908Z,1539017110.908 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2018-10-08T16:45:10.908Z,1539017110.908 [LoopControl](DEBUG): Initialize LoopControlComponent. 2018-10-08T16:45:10.908Z,1539017110.908 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2018-10-08T16:45:10.909Z,1539017110.909 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2018-10-08T16:45:10.909Z,1539017110.909 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2018-10-08T16:45:10.910Z,1539017110.910 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2018-10-08T16:45:10.910Z,1539017110.910 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2018-10-08T16:45:10.911Z,1539017110.911 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2018-10-08T16:45:10.911Z,1539017110.911 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2018-10-08T16:45:10.912Z,1539017110.912 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2018-10-08T16:45:10.912Z,1539017110.912 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2018-10-08T16:45:10.913Z,1539017110.913 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-10-08T16:45:10.913Z,1539017110.913 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-10-08T16:45:10.914Z,1539017110.914 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-10-08T16:45:10.914Z,1539017110.914 [NavChart](DEBUG): Initialize NavChart Navigation. 2018-10-08T16:45:10.914Z,1539017110.914 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2018-10-08T16:45:10.922Z,1539017110.922 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2018-10-08T16:45:10.929Z,1539017110.929 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 7759 2018-10-08T16:45:10.933Z,1539017110.933 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2018-10-08T16:45:10.933Z,1539017110.933 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2018-10-08T16:45:10.933Z,1539017110.933 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2018-10-08T16:45:10.933Z,1539017110.933 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2018-10-08T16:45:10.934Z,1539017110.934 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2018-10-08T16:45:10.934Z,1539017110.934 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2018-10-08T16:45:10.934Z,1539017110.934 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2018-10-08T16:45:10.934Z,1539017110.934 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2018-10-08T16:45:10.934Z,1539017110.934 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2018-10-08T16:45:10.935Z,1539017110.935 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2018-10-08T16:45:10.935Z,1539017110.935 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2018-10-08T16:45:10.935Z,1539017110.935 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2018-10-08T16:45:10.935Z,1539017110.935 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2018-10-08T16:45:10.935Z,1539017110.935 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2018-10-08T16:45:10.936Z,1539017110.936 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2018-10-08T16:45:10.936Z,1539017110.936 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2018-10-08T16:45:10.966Z,1539017110.966 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2018-10-08T16:45:11.014Z,1539017111.014 [MissionManager](DEBUG): 2018-10-08T16:45:11.015Z,1539017111.015 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2018-10-08T16:45:11.094Z,1539017111.094 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2018-10-08T16:45:11.095Z,1539017111.095 [Default:A.Wait](DEBUG): Construct Wait. 2018-10-08T16:45:11.113Z,1539017111.113 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2018-10-08T16:45:11.139Z,1539017111.139 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2018-10-08T16:45:11.142Z,1539017111.142 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2018-10-08T16:45:11.160Z,1539017111.160 [Default:E.Execute](DEBUG): Construct Execute. 2018-10-08T16:45:11.163Z,1539017111.163 [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 2018-10-08T16:45:11.173Z,1539017111.173 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,AHRS_M2,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,RDI_Pathfinder,SCPI,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2018-10-08T16:45:11.233Z,1539017111.233 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2018-10-08T16:45:11.293Z,1539017111.293 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2018-10-08T16:45:11.321Z,1539017111.321 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar 2018-10-08T16:45:11.517Z,1539017111.517 [DepthRateCalculator](ERROR): Depth measurement is not active 2018-10-08T16:45:11.593Z,1539017111.593 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-10-08T16:45:11.618Z,1539017111.618 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-10-08T16:45:11.717Z,1539017111.717 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2018-10-08T16:45:11.725Z,1539017111.725 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2018-10-08T16:45:11.747Z,1539017111.747 [ElevatorServo](DEBUG): Initializing EZServoServo. 2018-10-08T16:45:11.753Z,1539017111.753 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2018-10-08T16:45:11.767Z,1539017111.767 [MassServo](DEBUG): Initializing EZServoServo. 2018-10-08T16:45:11.773Z,1539017111.773 [MassServo](DEBUG): Initializing MassServo. 2018-10-08T16:45:11.779Z,1539017111.779 [RudderServo](DEBUG): Initializing EZServoServo. 2018-10-08T16:45:11.798Z,1539017111.798 [RudderServo](DEBUG): Initializing RudderServo. 2018-10-08T16:45:11.818Z,1539017111.818 [ThrusterServo](DEBUG): Initializing EZServoServo. 2018-10-08T16:45:11.837Z,1539017111.837 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2018-10-08T16:45:11.878Z,1539017111.878 [CommandLine](FAULT): Scheduling is paused 2018-10-08T16:45:11.878Z,1539017111.878 [CBIT](INFO): Critical error at 20181008T164510 2018-10-08T16:45:11.879Z,1539017111.879 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2018-10-08T16:45:12.060Z,1539017112.060 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-10-08T16:45:12.061Z,1539017112.061 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-10-08T16:45:12.357Z,1539017112.357 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-10-08T16:45:12.358Z,1539017112.358 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-10-08T16:45:12.681Z,1539017112.681 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout 2018-10-08T16:45:12.681Z,1539017112.681 [BuoyancyServo](FAULT): Buoyancy failed to initialize 2018-10-08T16:45:12.681Z,1539017112.681 [BuoyancyServo] Communications Fault, FailCount= 1 2018-10-08T16:45:12.681Z,1539017112.681 [BuoyancyServo](ERROR): Communications Fault 2018-10-08T16:45:12.893Z,1539017112.893 [CBIT](ERROR): Communications Fault in component: BuoyancyServo 2018-10-08T16:45:12.929Z,1539017112.929 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-10-08T16:45:12.930Z,1539017112.930 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-10-08T16:45:12.947Z,1539017112.947 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2018-10-08T16:45:12.947Z,1539017112.947 [BuoyancyServo](INFO): Powering down 2018-10-08T16:45:13.343Z,1539017113.343 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-10-08T16:45:13.344Z,1539017113.344 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-10-08T16:45:13.736Z,1539017113.736 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-10-08T16:45:13.737Z,1539017113.737 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-10-08T16:45:14.128Z,1539017114.128 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-10-08T16:45:14.130Z,1539017114.130 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-10-08T16:45:14.621Z,1539017114.621 [Aanderaa_O2](INFO): Powering down 2018-10-08T16:45:14.740Z,1539017114.740 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-10-08T16:45:14.741Z,1539017114.741 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-10-08T16:45:14.965Z,1539017114.965 [AHRS_M2](ERROR): Read RFS packet UART error: serial timeout 2018-10-08T16:45:15.008Z,1539017115.008 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-10-08T16:45:15.010Z,1539017115.010 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-10-08T16:45:15.058Z,1539017115.058 [CBIT](INFO): Clearing failed state for component BuoyancyServo 2018-10-08T16:45:15.058Z,1539017115.058 [BuoyancyServo] No Fault, FailCount= 1 2018-10-08T16:45:15.345Z,1539017115.345 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2018-10-08T16:45:15.466Z,1539017115.466 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2018-10-08T16:45:24.584Z,1539017124.584 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder 2018-10-08T16:45:38.559Z,1539017138.559 [NAL9602](INFO): Powering up NAL9602 2018-10-08T16:45:39.383Z,1539017139.383 [SBIT](IMPORTANT): Beginning Startup BIT 2018-10-08T16:45:39.388Z,1539017139.388 [CBIT](IMPORTANT): Beginning ground fault scan 2018-10-08T16:45:49.471Z,1539017149.471 [NAL9602](INFO): NAL9602 initialized 2018-10-08T16:45:50.410Z,1539017150.410 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.009757 CHAN A1 (24V): 0.003584 CHAN A2 (12V): -0.007298 CHAN A3 (5V): -0.002239 CHAN B0 (3.3V): 0.000260 CHAN B1 (3.15aV): 0.000560 CHAN B2 (3.15bV): 0.000211 CHAN B3 (GND): 0.002534 OPEN: 0.005068 Full Scale Calc: 4.765 mA, -1.589 mA 2018-10-08T16:46:12.525Z,1539017172.525 [BPC1](INFO): BPC1A: initialized. 2018-10-08T16:46:12.537Z,1539017172.537 [BPC1](INFO): BPC1B: initialized. 2018-10-08T16:46:13.707Z,1539017173.707 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T16:46:14.117Z,1539017174.117 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T16:46:18.116Z,1539017178.116 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T16:46:18.150Z,1539017178.150 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:46:18.150Z,1539017178.150 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2018-10-08T16:46:18.516Z,1539017178.516 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T16:46:18.564Z,1539017178.564 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:46:18.565Z,1539017178.565 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2018-10-08T16:46:18.573Z,1539017178.573 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T16:46:18.932Z,1539017178.932 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T16:46:19.325Z,1539017179.325 [BPC1](INFO): BPC1B: initialized. 2018-10-08T16:46:19.765Z,1539017179.765 [BPC1](INFO): BPC1A: initialized. 2018-10-08T16:46:26.266Z,1539017186.266 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T16:46:27.457Z,1539017187.457 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T16:46:31.064Z,1539017191.064 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T16:46:31.142Z,1539017191.142 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:46:31.142Z,1539017191.142 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2018-10-08T16:46:31.483Z,1539017191.483 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T16:46:31.887Z,1539017191.887 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T16:46:31.970Z,1539017191.970 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:46:31.971Z,1539017191.971 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2018-10-08T16:46:32.284Z,1539017192.284 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T16:46:32.301Z,1539017192.301 [BPC1](INFO): BPC1B: initialized. 2018-10-08T16:46:33.113Z,1539017193.113 [BPC1](INFO): BPC1A: initialized. 2018-10-08T16:46:33.508Z,1539017193.508 [SBIT](IMPORTANT): SBIT PASSED 2018-10-08T16:46:33.601Z,1539017193.601 [CommandLine](IMPORTANT): got command configSet list 2018-10-08T16:46:33.602Z,1539017193.602 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2018-10-08T16:46:33.603Z,1539017193.603 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=1 minute; 2018-10-08T16:46:33.603Z,1539017193.603 [CommandLine](IMPORTANT): CTD_NeilBrown.minSalinityBound=-10 practical_salinity_unit; 2018-10-08T16:46:33.603Z,1539017193.603 [CommandLine](IMPORTANT): Express linearApproximation concentration_of_colored_dissolved_organic_matter_in_sea_water_expressed_as_equivalent_mass_fraction_of_quinine_sulfate_dihydrate 1.000000 part_per_billion; 2018-10-08T16:46:33.603Z,1539017193.603 [CommandLine](IMPORTANT): IBIT.batteryVoltageThreshold=13.7 volt; 2018-10-08T16:46:33.603Z,1539017193.603 [CommandLine](IMPORTANT): NAL9602.gpsFailTimeout=10 minute; 2018-10-08T16:46:33.603Z,1539017193.603 [CommandLine](IMPORTANT): RDI_PathfinderUp.loadAtStartup=0 bool; 2018-10-08T16:46:33.603Z,1539017193.603 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=200 cubic_centimeter; 2018-10-08T16:46:33.604Z,1539017193.604 [CommandLine](IMPORTANT): VerticalControl.massDefault=2 millimeter; 2018-10-08T16:46:33.915Z,1539017193.915 [MissionManager](IMPORTANT): Started mission Startup 2018-10-08T16:46:33.915Z,1539017193.915 [Startup] Running Loop=1 2018-10-08T16:46:33.915Z,1539017193.915 [Startup](DEBUG): Aggregate::initialize Startup 2018-10-08T16:46:33.916Z,1539017193.916 [Startup:A.GoToSurface] Running Loop=1 2018-10-08T16:46:33.916Z,1539017193.916 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2018-10-08T16:46:33.916Z,1539017193.916 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2018-10-08T16:46:33.917Z,1539017193.917 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2018-10-08T16:46:33.917Z,1539017193.917 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2018-10-08T16:46:33.918Z,1539017193.918 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2018-10-08T16:46:33.918Z,1539017193.918 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2018-10-08T16:46:33.938Z,1539017193.938 [Startup:StartupSatComms] Running Loop=1 2018-10-08T16:46:33.939Z,1539017193.939 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2018-10-08T16:46:33.939Z,1539017193.939 [Startup:StartupSatComms:A] Running Loop=1 2018-10-08T16:46:34.309Z,1539017194.309 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2018-10-08T16:46:39.490Z,1539017199.490 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T16:46:40.688Z,1539017200.688 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T16:46:44.278Z,1539017204.278 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T16:46:44.351Z,1539017204.351 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:46:44.352Z,1539017204.352 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2018-10-08T16:46:44.729Z,1539017204.729 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T16:46:45.463Z,1539017205.463 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T16:46:45.566Z,1539017205.566 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:46:45.567Z,1539017205.567 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2018-10-08T16:46:45.581Z,1539017205.581 [BPC1](INFO): BPC1B: initialized. 2018-10-08T16:46:45.895Z,1539017205.895 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T16:46:46.701Z,1539017206.701 [BPC1](INFO): BPC1A: initialized. 2018-10-08T16:46:53.067Z,1539017213.067 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T16:46:54.281Z,1539017214.281 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T16:46:57.867Z,1539017217.867 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T16:46:57.963Z,1539017217.963 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:46:57.964Z,1539017217.964 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2018-10-08T16:46:58.280Z,1539017218.280 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T16:46:59.076Z,1539017219.076 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T16:46:59.148Z,1539017219.148 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:46:59.148Z,1539017219.148 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2018-10-08T16:46:59.161Z,1539017219.161 [BPC1](INFO): BPC1B: initialized. 2018-10-08T16:46:59.479Z,1539017219.479 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T16:47:00.297Z,1539017220.297 [BPC1](INFO): BPC1A: initialized. 2018-10-08T16:47:06.681Z,1539017226.681 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T16:47:07.887Z,1539017227.887 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T16:47:11.471Z,1539017231.471 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T16:47:11.554Z,1539017231.554 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:47:11.554Z,1539017231.554 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2018-10-08T16:47:11.896Z,1539017231.896 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T16:47:12.257Z,1539017232.257 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T16:47:12.342Z,1539017232.342 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:47:12.343Z,1539017232.343 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2018-10-08T16:47:12.689Z,1539017232.689 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T16:47:12.701Z,1539017232.701 [BPC1](INFO): BPC1B: initialized. 2018-10-08T16:47:13.489Z,1539017233.489 [BPC1](INFO): BPC1A: initialized. 2018-10-08T16:47:19.910Z,1539017239.910 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T16:47:21.079Z,1539017241.079 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T16:47:25.075Z,1539017245.075 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T16:47:25.159Z,1539017245.159 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:47:25.160Z,1539017245.160 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2018-10-08T16:47:25.498Z,1539017245.498 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T16:47:25.898Z,1539017245.898 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T16:47:25.989Z,1539017245.989 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:47:25.990Z,1539017245.990 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2018-10-08T16:47:26.299Z,1539017246.299 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T16:47:26.313Z,1539017246.313 [BPC1](INFO): BPC1B: initialized. 2018-10-08T16:47:27.089Z,1539017247.089 [BPC1](INFO): BPC1A: initialized. 2018-10-08T16:47:36.330Z,1539017256.330 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T16:47:36.331Z,1539017256.331 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T16:47:36.340Z,1539017256.340 [Startup:StartupSatComms:A](INFO): Timed out from 2018-10-08T16:46:33.9Z 2018-10-08T16:47:36.340Z,1539017256.340 [Startup:StartupSatComms:A] Stopped 2018-10-08T16:47:36.340Z,1539017256.340 [Startup:StartupSatComms:B] Running Loop=1 2018-10-08T16:47:36.495Z,1539017256.495 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2018-10-08T16:47:37.218Z,1539017257.218 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.014668 2018-10-08T16:47:41.269Z,1539017261.269 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T16:47:41.342Z,1539017261.342 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:47:41.342Z,1539017261.342 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2018-10-08T16:47:41.343Z,1539017261.343 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T16:47:41.423Z,1539017261.423 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:47:41.423Z,1539017261.423 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2018-10-08T16:47:41.505Z,1539017261.505 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20181008T163006/Courier0007.lzma 2018-10-08T16:47:41.560Z,1539017261.560 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T16:47:41.578Z,1539017261.578 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T16:47:42.256Z,1539017262.256 [DataOverHttps](INFO): Moved sent file to Logs/20181008T163006/Courier0007.lzma.bak 2018-10-08T16:47:42.256Z,1539017262.256 [DataOverHttps](INFO): SBD MOMSN=8614071 2018-10-08T16:47:42.337Z,1539017262.337 [BPC1](INFO): BPC1A: initialized. 2018-10-08T16:47:42.349Z,1539017262.349 [BPC1](INFO): BPC1B: initialized. 2018-10-08T16:47:51.240Z,1539017271.240 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T16:47:51.240Z,1539017271.240 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T16:47:51.326Z,1539017271.326 [DataOverHttps](INFO): Sending 99 bytes from file Logs/20181008T164500/Courier0000.lzma 2018-10-08T16:47:52.104Z,1539017272.104 [DataOverHttps](INFO): Moved sent file to Logs/20181008T164500/Courier0000.lzma.bak 2018-10-08T16:47:52.104Z,1539017272.104 [DataOverHttps](INFO): SBD MOMSN=8614073 2018-10-08T16:47:56.510Z,1539017276.510 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T16:47:56.594Z,1539017276.594 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:47:56.594Z,1539017276.594 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2018-10-08T16:47:56.595Z,1539017276.595 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T16:47:56.695Z,1539017276.695 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:47:56.695Z,1539017276.695 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2018-10-08T16:47:56.839Z,1539017276.839 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T16:47:56.856Z,1539017276.856 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T16:47:57.625Z,1539017277.625 [BPC1](INFO): BPC1A: initialized. 2018-10-08T16:47:57.637Z,1539017277.637 [BPC1](INFO): BPC1B: initialized. 2018-10-08T16:48:01.614Z,1539017281.614 [DataOverHttps](INFO): Sending 256 bytes from file Logs/20181008T163006/Express0008.lzma 2018-10-08T16:48:02.408Z,1539017282.408 [DataOverHttps](INFO): Moved sent file to Logs/20181008T163006/Express0008.lzma.bak 2018-10-08T16:48:02.408Z,1539017282.408 [DataOverHttps](INFO): SBD MOMSN=8614076 2018-10-08T16:48:06.812Z,1539017286.812 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T16:48:06.812Z,1539017286.812 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T16:48:11.742Z,1539017291.742 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T16:48:11.823Z,1539017291.823 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:48:11.823Z,1539017291.823 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2018-10-08T16:48:11.824Z,1539017291.824 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T16:48:11.903Z,1539017291.903 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:48:11.903Z,1539017291.903 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2018-10-08T16:48:11.919Z,1539017291.919 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-10-08T16:48:11.919Z,1539017291.919 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2018-10-08T16:48:11.919Z,1539017291.919 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2018-10-08T16:48:11.921Z,1539017291.921 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-10-08T16:48:11.921Z,1539017291.921 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1 2018-10-08T16:48:11.921Z,1539017291.921 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2018-10-08T16:48:11.941Z,1539017291.941 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2018-10-08T16:48:11.941Z,1539017291.941 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2018-10-08T16:48:12.011Z,1539017292.011 [DataOverHttps](INFO): Sending 1017 bytes from file Logs/20181008T164500/Express0001.lzma 2018-10-08T16:48:12.086Z,1539017292.086 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T16:48:12.098Z,1539017292.098 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T16:48:12.153Z,1539017292.153 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2018-10-08T16:48:12.153Z,1539017292.153 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2018-10-08T16:48:12.154Z,1539017292.154 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2018-10-08T16:48:12.154Z,1539017292.154 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1 2018-10-08T16:48:12.440Z,1539017292.440 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2018-10-08T16:48:12.440Z,1539017292.440 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2018-10-08T16:48:12.440Z,1539017292.440 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2018-10-08T16:48:12.441Z,1539017292.441 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-10-08T16:48:12.441Z,1539017292.441 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-10-08T16:48:12.442Z,1539017292.442 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-10-08T16:48:12.756Z,1539017292.756 [DataOverHttps](INFO): Moved sent file to Logs/20181008T164500/Express0001.lzma.bak 2018-10-08T16:48:12.756Z,1539017292.756 [DataOverHttps](INFO): SBD MOMSN=8614078 2018-10-08T16:48:12.818Z,1539017292.818 [BPC1](INFO): BPC1A: initialized. 2018-10-08T16:48:12.829Z,1539017292.829 [BPC1](INFO): BPC1B: initialized. 2018-10-08T16:48:13.892Z,1539017293.892 [Startup:StartupSatComms:B] Stopped 2018-10-08T16:48:13.893Z,1539017293.893 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2018-10-08T16:48:13.893Z,1539017293.893 [Startup:StartupSatComms] Stopped 2018-10-08T16:48:13.894Z,1539017293.894 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2018-10-08T16:48:13.896Z,1539017293.896 [Startup](INFO): Completed Startup 2018-10-08T16:48:13.896Z,1539017293.896 [MissionManager](INFO): Startup is completed. 2018-10-08T16:48:13.896Z,1539017293.896 [MissionManager](INFO): Uninitializing Mission Startup 2018-10-08T16:48:13.897Z,1539017293.897 [Startup] Stopped 2018-10-08T16:48:13.897Z,1539017293.897 [Startup](DEBUG): Aggregate::uninitialize Startup 2018-10-08T16:48:13.897Z,1539017293.897 [Startup:A.GoToSurface] Stopped 2018-10-08T16:48:13.898Z,1539017293.898 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2018-10-08T16:48:14.033Z,1539017294.033 [MissionManager](IMPORTANT): Started mission Default 2018-10-08T16:48:14.034Z,1539017294.034 [Default] Running Loop=1 2018-10-08T16:48:14.034Z,1539017294.034 [Default](DEBUG): Aggregate::initialize Default 2018-10-08T16:48:14.034Z,1539017294.034 [Default:B.GoToSurface] Running Loop=1 2018-10-08T16:48:14.034Z,1539017294.034 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2018-10-08T16:48:14.034Z,1539017294.034 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2018-10-08T16:48:14.035Z,1539017294.035 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2018-10-08T16:48:14.035Z,1539017294.035 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2018-10-08T16:48:14.035Z,1539017294.035 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2018-10-08T16:48:14.036Z,1539017294.036 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2018-10-08T16:48:14.036Z,1539017294.036 [Default:A.Wait] Running Loop=1 2018-10-08T16:48:14.036Z,1539017294.036 [Default:A.Wait](DEBUG): Initialize Wait Component. 2018-10-08T16:48:17.160Z,1539017297.160 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-32768,-32768,-32768,V 2018-10-08T16:48:20.077Z,1539017300.077 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T16:48:20.077Z,1539017300.077 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T16:48:24.888Z,1539017304.888 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T16:48:24.977Z,1539017304.977 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:48:24.978Z,1539017304.978 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2018-10-08T16:48:24.978Z,1539017304.978 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T16:48:25.063Z,1539017305.063 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:48:25.063Z,1539017305.063 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2018-10-08T16:48:25.285Z,1539017305.285 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T16:48:25.305Z,1539017305.305 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T16:48:26.081Z,1539017306.081 [BPC1](INFO): BPC1A: initialized. 2018-10-08T16:48:26.093Z,1539017306.093 [BPC1](INFO): BPC1B: initialized. 2018-10-08T16:48:27.306Z,1539017307.306 [Default:A.Wait](INFO): Done Waiting. 2018-10-08T16:48:27.306Z,1539017307.306 [Default:A.Wait] Stopped 2018-10-08T16:48:27.306Z,1539017307.306 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2018-10-08T16:48:27.713Z,1539017307.713 [Default:CheckIn] Running Loop=1 2018-10-08T16:48:27.713Z,1539017307.713 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-10-08T16:48:27.713Z,1539017307.713 [Default:CheckIn:Read_GPS] Running Loop=1 2018-10-08T16:48:28.102Z,1539017308.102 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2018-10-08T16:48:33.297Z,1539017313.297 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T16:48:33.297Z,1539017313.297 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T16:48:38.084Z,1539017318.084 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T16:48:38.160Z,1539017318.160 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:48:38.161Z,1539017318.161 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2018-10-08T16:48:38.161Z,1539017318.161 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T16:48:38.247Z,1539017318.247 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:48:38.249Z,1539017318.249 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2018-10-08T16:48:38.518Z,1539017318.518 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T16:48:38.551Z,1539017318.551 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T16:48:39.298Z,1539017319.298 [BPC1](INFO): BPC1A: initialized. 2018-10-08T16:48:39.309Z,1539017319.309 [BPC1](INFO): BPC1B: initialized. 2018-10-08T16:48:46.490Z,1539017326.490 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T16:48:46.907Z,1539017326.907 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T16:48:52.495Z,1539017332.495 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T16:48:52.581Z,1539017332.581 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:48:52.582Z,1539017332.582 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2018-10-08T16:48:52.582Z,1539017332.582 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T16:48:52.667Z,1539017332.667 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:48:52.668Z,1539017332.668 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2018-10-08T16:48:52.788Z,1539017332.788 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T16:48:52.803Z,1539017332.803 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T16:48:53.569Z,1539017333.569 [BPC1](INFO): BPC1A: initialized. 2018-10-08T16:48:53.581Z,1539017333.581 [BPC1](INFO): BPC1B: initialized. 2018-10-08T16:49:00.748Z,1539017340.748 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T16:49:00.748Z,1539017340.748 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T16:49:05.540Z,1539017345.540 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T16:49:05.625Z,1539017345.625 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:49:05.626Z,1539017345.626 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2018-10-08T16:49:05.626Z,1539017345.626 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T16:49:05.738Z,1539017345.738 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:49:05.738Z,1539017345.738 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2018-10-08T16:49:05.963Z,1539017345.963 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T16:49:05.979Z,1539017345.979 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T16:49:06.765Z,1539017346.765 [BPC1](INFO): BPC1A: initialized. 2018-10-08T16:49:06.777Z,1539017346.777 [BPC1](INFO): BPC1B: initialized. 2018-10-08T16:49:13.551Z,1539017353.551 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T16:49:14.355Z,1539017354.355 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T16:49:18.347Z,1539017358.347 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T16:49:18.421Z,1539017358.421 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:49:18.421Z,1539017358.421 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2018-10-08T16:49:18.773Z,1539017358.773 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T16:49:19.161Z,1539017359.161 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T16:49:19.231Z,1539017359.231 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:49:19.231Z,1539017359.231 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2018-10-08T16:49:19.575Z,1539017359.575 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T16:49:19.961Z,1539017359.961 [BPC1](INFO): BPC1A: initialized. 2018-10-08T16:49:20.353Z,1539017360.353 [BPC1](INFO): BPC1B: initialized. 2018-10-08T16:49:27.558Z,1539017367.558 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T16:49:27.559Z,1539017367.559 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T16:49:32.095Z,1539017372.095 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T16:49:32.177Z,1539017372.177 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:49:32.177Z,1539017372.177 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2018-10-08T16:49:32.484Z,1539017372.484 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T16:49:32.489Z,1539017372.489 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T16:49:32.594Z,1539017372.594 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:49:32.595Z,1539017372.595 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2018-10-08T16:49:32.945Z,1539017372.945 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T16:49:33.293Z,1539017373.293 [BPC1](INFO): BPC1A: initialized. 2018-10-08T16:49:33.689Z,1539017373.689 [BPC1](INFO): BPC1B: initialized. 2018-10-08T16:49:40.487Z,1539017380.487 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T16:49:40.888Z,1539017380.888 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T16:49:45.294Z,1539017385.294 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T16:49:45.373Z,1539017385.373 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:49:45.373Z,1539017385.373 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2018-10-08T16:49:45.720Z,1539017385.720 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T16:49:45.720Z,1539017385.720 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T16:49:45.838Z,1539017385.838 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:49:45.838Z,1539017385.838 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2018-10-08T16:49:46.101Z,1539017386.101 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T16:49:46.485Z,1539017386.485 [BPC1](INFO): BPC1A: initialized. 2018-10-08T16:49:46.901Z,1539017386.901 [BPC1](INFO): BPC1B: initialized. 2018-10-08T16:49:54.087Z,1539017394.087 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T16:49:54.088Z,1539017394.088 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T16:49:58.892Z,1539017398.892 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T16:49:58.979Z,1539017398.979 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:49:58.980Z,1539017398.980 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2018-10-08T16:49:58.980Z,1539017398.980 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T16:49:59.074Z,1539017399.074 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:49:59.074Z,1539017399.074 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2018-10-08T16:49:59.291Z,1539017399.291 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T16:49:59.323Z,1539017399.323 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T16:50:02.921Z,1539017402.921 [BPC1](INFO): BPC1A: initialized. 2018-10-08T16:50:02.933Z,1539017402.933 [BPC1](INFO): BPC1B: initialized. 2018-10-08T16:50:04.215Z,1539017404.215 [RDI_Pathfinder](ERROR): Failed to parse: 2018-10-08T16:50:09.834Z,1539017409.834 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T16:50:10.210Z,1539017410.210 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T16:50:14.615Z,1539017414.615 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T16:50:14.716Z,1539017414.716 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:50:14.716Z,1539017414.716 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2018-10-08T16:50:15.017Z,1539017415.017 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T16:50:15.017Z,1539017415.017 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T16:50:15.136Z,1539017415.136 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:50:15.137Z,1539017415.137 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2018-10-08T16:50:15.437Z,1539017415.437 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T16:50:15.837Z,1539017415.837 [BPC1](INFO): BPC1A: initialized. 2018-10-08T16:50:16.233Z,1539017416.233 [BPC1](INFO): BPC1B: initialized. 2018-10-08T16:50:23.030Z,1539017423.030 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T16:50:23.427Z,1539017423.427 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T16:50:27.834Z,1539017427.834 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T16:50:27.925Z,1539017427.925 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:50:27.925Z,1539017427.925 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2018-10-08T16:50:27.926Z,1539017427.926 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T16:50:28.051Z,1539017428.051 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:50:28.052Z,1539017428.052 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2018-10-08T16:50:28.222Z,1539017428.222 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T16:50:28.238Z,1539017428.238 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T16:50:28.967Z,1539017428.967 [CommandLine](IMPORTANT): got command get platform_battery_voltage 2018-10-08T16:50:28.967Z,1539017428.967 [CommandLine](FAULT): Element has no value 2018-10-08T16:50:29.049Z,1539017429.049 [BPC1](INFO): BPC1A: initialized. 2018-10-08T16:50:29.433Z,1539017429.433 [BPC1](INFO): BPC1B: initialized. 2018-10-08T16:50:38.336Z,1539017438.336 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T16:50:38.336Z,1539017438.336 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T16:50:41.260Z,1539017441.260 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T16:50:41.342Z,1539017441.342 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:50:41.342Z,1539017441.342 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2018-10-08T16:50:41.343Z,1539017441.343 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T16:50:41.431Z,1539017441.431 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:50:41.431Z,1539017441.431 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2018-10-08T16:50:41.693Z,1539017441.693 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T16:50:41.717Z,1539017441.717 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T16:50:42.465Z,1539017442.465 [BPC1](INFO): BPC1A: initialized. 2018-10-08T16:50:42.481Z,1539017442.481 [BPC1](INFO): BPC1B: initialized. 2018-10-08T16:50:49.690Z,1539017449.690 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T16:50:49.691Z,1539017449.691 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T16:50:52.435Z,1539017452.435 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-10-08T16:50:54.479Z,1539017454.479 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T16:50:54.584Z,1539017454.584 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:50:54.584Z,1539017454.584 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2018-10-08T16:50:54.585Z,1539017454.585 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T16:50:54.680Z,1539017454.680 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:50:54.681Z,1539017454.681 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2018-10-08T16:50:54.898Z,1539017454.898 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T16:50:54.906Z,1539017454.906 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T16:50:55.685Z,1539017455.685 [BPC1](INFO): BPC1A: initialized. 2018-10-08T16:50:55.701Z,1539017455.701 [BPC1](INFO): BPC1B: initialized. 2018-10-08T16:50:58.251Z,1539017458.251 [CommandLine](IMPORTANT): got command get BPC1.platform_battery_voltage 2018-10-08T16:50:58.251Z,1539017458.251 [CommandLine](IMPORTANT): BPC1.platform_battery_voltage nan V 2018-10-08T16:51:03.313Z,1539017463.313 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T16:51:03.313Z,1539017463.313 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T16:51:08.079Z,1539017468.079 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T16:51:08.202Z,1539017468.202 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:51:08.203Z,1539017468.203 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2018-10-08T16:51:08.203Z,1539017468.203 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T16:51:08.359Z,1539017468.359 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:51:08.360Z,1539017468.360 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2018-10-08T16:51:08.584Z,1539017468.584 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T16:51:08.608Z,1539017468.608 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T16:51:09.293Z,1539017469.293 [BPC1](INFO): BPC1A: initialized. 2018-10-08T16:51:09.305Z,1539017469.305 [BPC1](INFO): BPC1B: initialized. 2018-10-08T16:51:14.808Z,1539017474.808 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-10-08T16:51:14.808Z,1539017474.808 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2018-10-08T16:51:14.808Z,1539017474.808 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2018-10-08T16:51:14.810Z,1539017474.810 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-10-08T16:51:14.810Z,1539017474.810 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2 2018-10-08T16:51:14.811Z,1539017474.811 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2018-10-08T16:51:14.824Z,1539017474.824 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2018-10-08T16:51:14.824Z,1539017474.824 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2018-10-08T16:51:14.989Z,1539017474.989 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2018-10-08T16:51:14.989Z,1539017474.989 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2018-10-08T16:51:14.990Z,1539017474.990 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2018-10-08T16:51:14.990Z,1539017474.990 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2 2018-10-08T16:51:15.298Z,1539017475.298 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2018-10-08T16:51:15.298Z,1539017475.298 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2018-10-08T16:51:15.298Z,1539017475.298 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2018-10-08T16:51:15.299Z,1539017475.299 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-10-08T16:51:15.299Z,1539017475.299 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-10-08T16:51:15.300Z,1539017475.300 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-10-08T16:51:16.485Z,1539017476.485 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T16:51:16.897Z,1539017476.897 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T16:51:21.707Z,1539017481.707 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T16:51:21.780Z,1539017481.780 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:51:21.780Z,1539017481.780 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2018-10-08T16:51:21.781Z,1539017481.781 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T16:51:21.865Z,1539017481.865 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:51:21.865Z,1539017481.865 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2018-10-08T16:51:22.095Z,1539017482.095 [RDI_Pathfinder](ERROR): only read 2 of 5 data items 2018-10-08T16:51:22.096Z,1539017482.096 [RDI_Pathfinder](ERROR): Failed to parse: :BI,-32768,2768,V 2018-10-08T16:51:22.135Z,1539017482.135 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T16:51:22.143Z,1539017482.143 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T16:51:22.925Z,1539017482.925 [BPC1](INFO): BPC1A: initialized. 2018-10-08T16:51:22.937Z,1539017482.937 [BPC1](INFO): BPC1B: initialized. 2018-10-08T16:51:30.079Z,1539017490.079 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T16:51:30.080Z,1539017490.080 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T16:51:34.885Z,1539017494.885 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T16:51:34.975Z,1539017494.975 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:51:34.975Z,1539017494.975 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2018-10-08T16:51:34.976Z,1539017494.976 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T16:51:35.059Z,1539017495.059 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:51:35.059Z,1539017495.059 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2018-10-08T16:51:35.280Z,1539017495.280 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T16:51:35.297Z,1539017495.297 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T16:51:36.101Z,1539017496.101 [BPC1](INFO): BPC1A: initialized. 2018-10-08T16:51:36.115Z,1539017496.115 [BPC1](INFO): BPC1B: initialized. 2018-10-08T16:51:43.267Z,1539017503.267 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T16:51:43.676Z,1539017503.676 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T16:51:48.495Z,1539017508.495 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T16:51:48.599Z,1539017508.599 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:51:48.599Z,1539017508.599 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2018-10-08T16:51:48.600Z,1539017508.600 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T16:51:48.684Z,1539017508.684 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:51:48.684Z,1539017508.684 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2018-10-08T16:51:48.827Z,1539017508.827 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T16:51:48.837Z,1539017508.837 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T16:51:49.587Z,1539017509.587 [RDI_Pathfinder](ERROR): Failed to parse: :BI,-32768,-32768,-32768,-32768,V 2018-10-08T16:51:49.601Z,1539017509.601 [BPC1](INFO): BPC1A: initialized. 2018-10-08T16:51:49.614Z,1539017509.614 [BPC1](INFO): BPC1B: initialized. 2018-10-08T16:51:56.792Z,1539017516.792 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T16:51:57.171Z,1539017517.171 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T16:52:01.983Z,1539017521.983 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T16:52:02.067Z,1539017522.067 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:52:02.068Z,1539017522.068 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2018-10-08T16:52:02.068Z,1539017522.068 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T16:52:02.152Z,1539017522.152 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:52:02.152Z,1539017522.152 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2018-10-08T16:52:02.395Z,1539017522.395 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T16:52:02.402Z,1539017522.402 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T16:52:03.197Z,1539017523.197 [BPC1](INFO): BPC1A: initialized. 2018-10-08T16:52:03.210Z,1539017523.210 [BPC1](INFO): BPC1B: initialized. 2018-10-08T16:52:10.367Z,1539017530.367 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T16:52:10.367Z,1539017530.367 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T16:52:15.178Z,1539017535.178 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T16:52:15.254Z,1539017535.254 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:52:15.254Z,1539017535.254 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2018-10-08T16:52:15.599Z,1539017535.599 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T16:52:15.600Z,1539017535.600 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T16:52:15.712Z,1539017535.712 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:52:15.713Z,1539017535.713 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2018-10-08T16:52:15.981Z,1539017535.981 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T16:52:16.373Z,1539017536.373 [BPC1](INFO): BPC1A: initialized. 2018-10-08T16:52:16.817Z,1539017536.817 [BPC1](INFO): BPC1B: initialized. 2018-10-08T16:52:23.801Z,1539017543.801 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T16:52:23.802Z,1539017543.802 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T16:52:26.735Z,1539017546.735 [CommandLine](IMPORTANT): got command get BPC1.BattStatus_1 2018-10-08T16:52:26.735Z,1539017546.735 [CommandLine](IMPORTANT): BPC1.BattStatus_1 224.000000 n/a 2018-10-08T16:52:28.267Z,1539017548.267 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T16:52:28.343Z,1539017548.343 [BPC1](INFO): BPC1B: got 7 stick msg (1596 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:52:28.344Z,1539017548.344 [BPC1](INFO): BPC1B: got valid message (1596 bytes). 2018-10-08T16:52:28.688Z,1539017548.688 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T16:52:28.772Z,1539017548.772 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:52:28.773Z,1539017548.773 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2018-10-08T16:52:28.781Z,1539017548.781 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T16:52:29.084Z,1539017549.084 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T16:52:29.509Z,1539017549.509 [BPC1](INFO): BPC1B: initialized. 2018-10-08T16:52:29.917Z,1539017549.917 [BPC1](INFO): BPC1A: initialized. 2018-10-08T16:52:30.684Z,1539017550.684 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T16:52:31.474Z,1539017551.474 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T16:52:34.669Z,1539017554.669 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T16:52:34.711Z,1539017554.711 [BPC1](INFO): BPC1B: got 7 stick msg (1596 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:52:34.711Z,1539017554.711 [BPC1](INFO): BPC1B: got valid message (1596 bytes). 2018-10-08T16:52:35.082Z,1539017555.082 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T16:52:35.114Z,1539017555.114 [BPC1](INFO): BPC1A: got 7 stick msg (1596 bytes) with SHORT_IBPS_MENU. 2018-10-08T16:52:35.114Z,1539017555.114 [BPC1](INFO): BPC1A: got valid message (1596 bytes). 2018-10-08T16:52:35.121Z,1539017555.121 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T16:52:35.499Z,1539017555.499 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T16:52:35.515Z,1539017555.515 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2018-10-08T16:53:27.997Z,1539017607.997 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-10-08T16:48:27.7Z 2018-10-08T16:53:27.997Z,1539017607.997 [Default:CheckIn:Read_GPS] Stopped 2018-10-08T16:53:27.997Z,1539017607.997 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-10-08T16:53:28.403Z,1539017608.403 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2018-10-08T16:53:32.478Z,1539017612.478 [DataOverHttps](INFO): Sending 190 bytes from file Logs/20181008T164500/Courier0004.lzma 2018-10-08T16:53:33.244Z,1539017613.244 [DataOverHttps](INFO): Moved sent file to Logs/20181008T164500/Courier0004.lzma.bak 2018-10-08T16:53:33.244Z,1539017613.244 [DataOverHttps](INFO): SBD MOMSN=8614084 2018-10-08T16:53:43.354Z,1539017623.354 [DataOverHttps](INFO): Sending 300 bytes from file Logs/20181008T164500/Express0005.lzma 2018-10-08T16:53:46.179Z,1539017626.179 [CommandLine](IMPORTANT): got command report mod platform_battery_voltage 2018-10-08T16:53:52.379Z,1539017632.379 [DataOverHttps](INFO): Moved sent file to Logs/20181008T164500/Express0005.lzma.bak 2018-10-08T16:53:52.379Z,1539017632.379 [DataOverHttps](INFO): SBD MOMSN=8614086 2018-10-08T16:53:53.292Z,1539017633.292 [Default:CheckIn:Read_Iridium] Stopped 2018-10-08T16:53:53.292Z,1539017633.292 [Default:CheckIn:C.Wait] Running Loop=1 2018-10-08T16:53:53.292Z,1539017633.292 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-10-08T16:54:03.079Z,1539017643.079 [CommandLine](IMPORTANT): got command get platform_battery_voltage 2018-10-08T16:54:03.079Z,1539017643.079 [CommandLine](FAULT): Element has no value 2018-10-08T16:54:15.631Z,1539017655.631 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-10-08T16:54:15.631Z,1539017655.631 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2018-10-08T16:54:15.631Z,1539017655.631 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2018-10-08T16:54:15.633Z,1539017655.633 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-10-08T16:54:15.633Z,1539017655.633 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3 2018-10-08T16:54:15.634Z,1539017655.634 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2018-10-08T16:54:15.647Z,1539017655.647 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2018-10-08T16:54:15.647Z,1539017655.647 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2018-10-08T16:54:16.035Z,1539017656.035 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2018-10-08T16:54:16.035Z,1539017656.035 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2018-10-08T16:54:16.036Z,1539017656.036 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2018-10-08T16:54:16.036Z,1539017656.036 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3 2018-10-08T16:54:16.430Z,1539017656.430 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2018-10-08T16:54:16.430Z,1539017656.430 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2018-10-08T16:54:16.430Z,1539017656.430 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2018-10-08T16:54:16.431Z,1539017656.431 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-10-08T16:54:16.431Z,1539017656.431 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-10-08T16:54:16.432Z,1539017656.432 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-10-08T16:54:19.177Z,1539017659.177 [CommandLine](IMPORTANT): got command get BPC1.platform_battery_voltage 2018-10-08T16:54:19.178Z,1539017659.178 [CommandLine](IMPORTANT): BPC1.platform_battery_voltage 16.285463 V 2018-10-08T16:55:34.918Z,1539017734.918 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2018-10-08T16:55:34.919Z,1539017734.919 [RDI_Pathfinder](ERROR): Failed to parse: :TS,18100810003911,35.0, -0.1, 0.0,144 2018-10-08T16:55:50.619Z,1539017750.619 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-10-08T16:55:50.619Z,1539017750.619 [NAL9602] Data Fault, FailCount= 1 2018-10-08T16:55:50.619Z,1539017750.619 [NAL9602](ERROR): Data Fault 2018-10-08T16:55:50.720Z,1539017750.720 [CBIT](ERROR): Data Fault in component: NAL9602 2018-10-08T16:55:51.019Z,1539017751.019 [NAL9602](INFO): Powering down 2018-10-08T16:55:51.894Z,1539017751.894 [CBIT](INFO): Clearing failed state for component NAL9602 2018-10-08T16:55:51.894Z,1539017751.894 [NAL9602] No Fault, FailCount= 1 2018-10-08T16:56:21.103Z,1539017781.103 [NAL9602](INFO): Powering up NAL9602 2018-10-08T16:56:31.899Z,1539017791.899 [NAL9602](INFO): NAL9602 initialized 2018-10-08T16:57:16.647Z,1539017836.647 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-10-08T16:57:16.647Z,1539017836.647 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2018-10-08T16:57:16.647Z,1539017836.647 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2018-10-08T16:57:16.653Z,1539017836.653 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-10-08T16:57:16.653Z,1539017836.653 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 4 2018-10-08T16:57:16.653Z,1539017836.653 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2018-10-08T16:57:16.675Z,1539017836.675 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2018-10-08T16:57:16.676Z,1539017836.676 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2018-10-08T16:57:17.062Z,1539017837.062 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2018-10-08T16:57:17.062Z,1539017837.062 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2018-10-08T16:57:17.062Z,1539017837.062 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2018-10-08T16:57:17.062Z,1539017837.062 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 4 2018-10-08T16:57:17.439Z,1539017837.439 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2018-10-08T16:57:17.439Z,1539017837.439 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2018-10-08T16:57:17.440Z,1539017837.440 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2018-10-08T16:57:17.440Z,1539017837.440 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-10-08T16:57:17.441Z,1539017837.441 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-10-08T16:57:17.441Z,1539017837.441 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-10-08T16:58:53.440Z,1539017933.440 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-10-08T16:58:53.441Z,1539017933.441 [Default:CheckIn:C.Wait] Stopped 2018-10-08T16:58:53.442Z,1539017933.442 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-10-08T16:58:53.442Z,1539017933.442 [Default:CheckIn:D] Running Loop=1 2018-10-08T16:58:53.833Z,1539017933.833 [Default:CheckIn:D] Stopped 2018-10-08T16:58:53.833Z,1539017933.833 [Default:CheckIn:E] Running Loop=1 2018-10-08T16:58:54.224Z,1539017934.224 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.663289 min 2018-10-08T16:58:54.239Z,1539017934.239 [Default:CheckIn:E] Stopped 2018-10-08T16:58:54.239Z,1539017934.239 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-10-08T16:58:54.239Z,1539017934.239 [Default:CheckIn] Stopped 2018-10-08T16:58:54.239Z,1539017934.239 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-10-08T16:58:54.239Z,1539017934.239 [Default:CheckIn](INFO): Running loop #2 2018-10-08T16:58:54.239Z,1539017934.239 [Default:CheckIn] Running Loop=2 2018-10-08T16:58:54.239Z,1539017934.239 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-10-08T16:58:54.239Z,1539017934.239 [Default:CheckIn:Read_GPS] Running Loop=1 2018-10-08T17:00:17.622Z,1539018017.622 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-10-08T17:00:17.622Z,1539018017.622 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2018-10-08T17:00:17.622Z,1539018017.622 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2018-10-08T17:00:17.624Z,1539018017.624 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-10-08T17:00:17.624Z,1539018017.624 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 5 2018-10-08T17:00:17.624Z,1539018017.624 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2018-10-08T17:00:17.649Z,1539018017.649 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2018-10-08T17:00:17.650Z,1539018017.650 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2018-10-08T17:00:18.036Z,1539018018.036 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2018-10-08T17:00:18.036Z,1539018018.036 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2018-10-08T17:00:18.041Z,1539018018.041 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2018-10-08T17:00:18.041Z,1539018018.041 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 5 2018-10-08T17:00:18.430Z,1539018018.430 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2018-10-08T17:00:18.430Z,1539018018.430 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2018-10-08T17:00:18.431Z,1539018018.431 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2018-10-08T17:00:18.431Z,1539018018.431 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-10-08T17:00:18.431Z,1539018018.431 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-10-08T17:00:18.432Z,1539018018.432 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-10-08T17:00:35.736Z,1539018035.736 [RDI_Pathfinder](ERROR): only read -1 of 1 data item for altitude 2018-10-08T17:00:35.737Z,1539018035.737 [RDI_Pathfinder](ERROR): Failed to parse: :BD, +0.00, +0.00, +0.00, 2018-10-08T17:01:32.235Z,1539018092.235 [CommandLine](IMPORTANT): got command get platform_battery_voltage 2018-10-08T17:01:32.235Z,1539018092.235 [CommandLine](FAULT): Element has no value 2018-10-08T17:01:44.567Z,1539018104.567 [CommandLine](IMPORTANT): got command get BPC1.platform_battery_voltage 2018-10-08T17:01:44.567Z,1539018104.567 [CommandLine](IMPORTANT): BPC1.platform_battery_voltage 16.285463 V 2018-10-08T17:03:27.407Z,1539018207.407 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-10-08T17:03:27.407Z,1539018207.407 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2018-10-08T17:03:27.407Z,1539018207.407 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2018-10-08T17:03:27.409Z,1539018207.409 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-10-08T17:03:27.441Z,1539018207.441 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 6 2018-10-08T17:03:27.441Z,1539018207.441 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2018-10-08T17:03:27.516Z,1539018207.516 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2018-10-08T17:03:27.517Z,1539018207.517 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2018-10-08T17:03:27.817Z,1539018207.817 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2018-10-08T17:03:27.818Z,1539018207.818 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2018-10-08T17:03:27.818Z,1539018207.818 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2018-10-08T17:03:27.818Z,1539018207.818 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 6 2018-10-08T17:03:27.996Z,1539018207.996 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2018-10-08T17:03:27.996Z,1539018207.996 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2018-10-08T17:03:28.009Z,1539018208.009 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2018-10-08T17:03:28.010Z,1539018208.010 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-10-08T17:03:28.010Z,1539018208.010 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-10-08T17:03:28.011Z,1539018208.011 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-10-08T17:03:37.226Z,1539018217.226 [Reporter](INFO): platform_battery_voltage 16.285463 V 2018-10-08T17:03:37.993Z,1539018217.993 [BPC1](INFO): BPC1A: initialized. 2018-10-08T17:03:38.005Z,1539018218.005 [BPC1](INFO): BPC1B: initialized. 2018-10-08T17:03:39.605Z,1539018219.605 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T17:03:39.605Z,1539018219.605 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T17:03:43.994Z,1539018223.994 [BPC1](INFO): BPC1A: validating data format. 2018-10-08T17:03:44.044Z,1539018224.044 [BPC1](INFO): BPC1A: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T17:03:44.044Z,1539018224.044 [BPC1](INFO): BPC1A: got valid message (1824 bytes). 2018-10-08T17:03:44.045Z,1539018224.045 [BPC1](INFO): BPC1B: validating data format. 2018-10-08T17:03:44.061Z,1539018224.061 [BPC1](INFO): BPC1B: got 8 stick msg (1824 bytes) with SHORT_IBPS_MENU. 2018-10-08T17:03:44.061Z,1539018224.061 [BPC1](INFO): BPC1B: got valid message (1824 bytes). 2018-10-08T17:03:44.407Z,1539018224.407 [BPC1](INFO): BPC1A: data parsed. 2018-10-08T17:03:44.423Z,1539018224.423 [BPC1](INFO): BPC1B: data parsed. 2018-10-08T17:03:45.217Z,1539018225.217 [BPC1](INFO): BPC1A: initialized. 2018-10-08T17:03:45.229Z,1539018225.229 [BPC1](INFO): BPC1B: initialized. 2018-10-08T17:03:52.768Z,1539018232.768 [BPC1](INFO): BPC1A: sending IBPS break. 2018-10-08T17:03:52.768Z,1539018232.768 [BPC1](INFO): BPC1B: sending IBPS break. 2018-10-08T17:03:53.691Z,1539018233.691 [CommandLine](IMPORTANT): got command restart application 2018-10-08T17:03:54.704Z,1539018234.704 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2018-10-08T17:03:54.704Z,1539018234.704 [CommandLine ThreadHandler](INFO): Thread cancelled. 2018-10-08T17:03:54.713Z,1539018234.713 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2018-10-08T17:03:54.713Z,1539018234.713 [CommandLine ThreadHandler](INFO): Thread cancelled. 2018-10-08T17:03:54.714Z,1539018234.714 [CommandLine](INFO): Join timeout helper Thread ID is 7803 2018-10-08T17:03:54.725Z,1539018234.725 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2018-10-08T17:03:54.725Z,1539018234.725 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2018-10-08T17:03:54.725Z,1539018234.725 [NavChartDb](INFO): Join timeout helper Thread ID is 7804 2018-10-08T17:03:55.057Z,1539018235.057 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2018-10-08T17:03:55.057Z,1539018235.057 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2018-10-08T17:03:55.061Z,1539018235.061 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2018-10-08T17:03:55.061Z,1539018235.061 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2018-10-08T17:03:55.061Z,1539018235.061 [Radio_Surface](INFO): Join timeout helper Thread ID is 7805 2018-10-08T17:03:55.298Z,1539018235.298 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2018-10-08T17:03:55.299Z,1539018235.299 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2018-10-08T17:03:55.309Z,1539018235.309 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler 2018-10-08T17:03:55.309Z,1539018235.309 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2018-10-08T17:03:55.309Z,1539018235.309 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 7806 2018-10-08T17:03:55.321Z,1539018235.321 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread. 2018-10-08T17:03:55.321Z,1539018235.321 [WetLabsSeaOWL_UV_A](INFO): Powering down 2018-10-08T17:03:55.322Z,1539018235.322 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2018-10-08T17:03:55.323Z,1539018235.323 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler 2018-10-08T17:03:55.323Z,1539018235.323 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2018-10-08T17:03:55.323Z,1539018235.323 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 7807 2018-10-08T17:03:55.353Z,1539018235.353 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread. 2018-10-08T17:03:55.353Z,1539018235.353 [CTD_NeilBrown](INFO): Powering down 2018-10-08T17:03:55.354Z,1539018235.354 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2018-10-08T17:03:55.370Z,1539018235.370 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2018-10-08T17:03:55.370Z,1539018235.370 [logger ThreadHandler](INFO): Thread cancelled. 2018-10-08T17:03:55.370Z,1539018235.370 [logger](INFO): Join timeout helper Thread ID is 7808 2018-10-08T17:03:55.381Z,1539018235.381 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2018-10-08T17:03:55.381Z,1539018235.381 [logger ThreadHandler](INFO): Thread cancelled. 2018-10-08T17:03:55.382Z,1539018235.382 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2018-10-08T17:03:55.383Z,1539018235.383 [CommandLine ThreadHandler](INFO): Thread cancelled. 2018-10-08T17:03:55.383Z,1539018235.383 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2018-10-08T17:03:55.383Z,1539018235.383 [controlThread ThreadHandler](INFO): Thread cancelled. 2018-10-08T17:03:55.383Z,1539018235.383 [controlThread](INFO): Join timeout helper Thread ID is 7809 2018-10-08T17:03:56.435Z,1539018236.435 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-10-08T16:58:54.2Z 2018-10-08T17:03:56.435Z,1539018236.435 [Default:CheckIn:Read_GPS] Stopped 2018-10-08T17:03:56.435Z,1539018236.435 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-10-08T17:03:56.448Z,1539018236.448 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2018-10-08T17:03:56.449Z,1539018236.449 [controlThread](DEBUG): Uninitializing ControlThread 2018-10-08T17:03:56.449Z,1539018236.449 [Aanderaa_O2](INFO): Powering down 2018-10-08T17:03:56.450Z,1539018236.450 [AHRS_M2](INFO): Powering down 2018-10-08T17:03:56.524Z,1539018236.524 [NAL9602](INFO): Powering down 2018-10-08T17:03:56.597Z,1539018236.597 [RDI_Pathfinder](INFO): Powering down 2018-10-08T17:03:56.599Z,1539018236.599 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2018-10-08T17:03:56.600Z,1539018236.600 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2018-10-08T17:03:56.600Z,1539018236.600 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2018-10-08T17:03:56.601Z,1539018236.601 [MissionManager](INFO): Uninitializing Mission Default 2018-10-08T17:03:56.601Z,1539018236.601 [Default] Stopped 2018-10-08T17:03:56.602Z,1539018236.602 [Default](DEBUG): Aggregate::uninitialize Default 2018-10-08T17:03:56.602Z,1539018236.602 [Default:B.GoToSurface] Stopped 2018-10-08T17:03:56.602Z,1539018236.602 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2018-10-08T17:03:56.602Z,1539018236.602 [Default:CheckIn] Stopped 2018-10-08T17:03:56.602Z,1539018236.602 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-10-08T17:03:56.602Z,1539018236.602 [Default:CheckIn:Read_Iridium] Stopped 2018-10-08T17:03:56.605Z,1539018236.605 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2018-10-08T17:03:56.606Z,1539018236.606 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2018-10-08T17:03:56.606Z,1539018236.606 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2018-10-08T17:03:56.606Z,1539018236.606 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2018-10-08T17:03:56.607Z,1539018236.607 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2018-10-08T17:03:56.607Z,1539018236.607 [BuoyancyServo](INFO): Powering down 2018-10-08T17:03:56.621Z,1539018236.621 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2018-10-08T17:03:56.621Z,1539018236.621 [ElevatorServo](INFO): Powering down 2018-10-08T17:03:56.622Z,1539018236.622 [MassServo](DEBUG): Uninitialize Mass Servo. 2018-10-08T17:03:56.622Z,1539018236.622 [MassServo](INFO): Powering down 2018-10-08T17:03:56.623Z,1539018236.623 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2018-10-08T17:03:56.623Z,1539018236.623 [RudderServo](INFO): Powering down 2018-10-08T17:03:56.624Z,1539018236.624 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2018-10-08T17:03:56.624Z,1539018236.624 [ThrusterServo](INFO): Powering down 2018-10-08T17:03:56.625Z,1539018236.625 [SBIT](DEBUG): Uninitialize SBIT Component. 2018-10-08T17:03:56.626Z,1539018236.626 [IBIT](DEBUG): Uninitialize IBIT Component. 2018-10-08T17:03:56.626Z,1539018236.626 [CBIT](DEBUG): Uninitialize CBIT Component. 2018-10-08T17:03:56.627Z,1539018236.627 [controlThread ThreadHandler](INFO): Thread cancelled. 2018-10-08T17:03:56.714Z,1539018236.714 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2018-10-08T17:03:56.717Z,1539018236.717 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2018-10-08T17:03:56.779Z,1539018236.779 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2018-10-08T17:03:56.830Z,1539018236.830 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2018-10-08T17:03:56.886Z,1539018236.886 [logger ThreadHandler](INFO): Thread cancelled.