2019-01-10T14:24:54.513Z,1547130294.513 [Supervisor](DEBUG): Initializing supervisor. 2019-01-10T14:24:54.516Z,1547130294.516 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2019-01-10T14:24:54.517Z,1547130294.517 [SyncHandler](INFO): Protected caller Thread ID is 800 2019-01-10T14:24:54.517Z,1547130294.517 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2019-01-10T14:24:54.518Z,1547130294.518 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2019-01-10T14:24:54.518Z,1547130294.518 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 801 2019-01-10T14:24:54.521Z,1547130294.521 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2019-01-10T14:24:54.533Z,1547130294.533 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2019-01-10T14:24:54.534Z,1547130294.534 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2019-01-10T14:24:54.535Z,1547130294.535 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 802 2019-01-10T14:24:54.535Z,1547130294.535 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2019-01-10T14:24:54.536Z,1547130294.536 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2019-01-10T14:24:54.537Z,1547130294.537 [logger ThreadHandler](INFO): Protected caller Thread ID is 803 2019-01-10T14:24:54.539Z,1547130294.539 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2019-01-10T14:24:54.539Z,1547130294.539 [Supervisor](INFO): Looking for Config files in directory: Config/ 2019-01-10T14:24:54.543Z,1547130294.543 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2019-01-10T14:24:54.643Z,1547130294.643 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2019-01-10T14:24:54.645Z,1547130294.645 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2019-01-10T14:24:54.748Z,1547130294.748 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2019-01-10T14:24:54.750Z,1547130294.750 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2019-01-10T14:24:54.961Z,1547130294.961 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2019-01-10T14:24:54.963Z,1547130294.963 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2019-01-10T14:24:55.348Z,1547130295.348 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2019-01-10T14:24:55.350Z,1547130295.350 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2019-01-10T14:24:55.701Z,1547130295.701 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2019-01-10T14:24:55.703Z,1547130295.703 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2019-01-10T14:24:56.191Z,1547130296.191 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2019-01-10T14:24:56.193Z,1547130296.193 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2019-01-10T14:24:56.702Z,1547130296.702 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2019-01-10T14:24:56.704Z,1547130296.704 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2019-01-10T14:24:57.186Z,1547130297.186 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2019-01-10T14:24:57.187Z,1547130297.187 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2019-01-10T14:24:57.270Z,1547130297.270 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2019-01-10T14:24:57.600Z,1547130297.600 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2019-01-10T14:24:57.602Z,1547130297.602 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2019-01-10T14:24:57.756Z,1547130297.756 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2019-01-10T14:24:57.757Z,1547130297.757 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2019-01-10T14:24:57.992Z,1547130297.992 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2019-01-10T14:24:57.993Z,1547130297.993 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2019-01-10T14:24:58.581Z,1547130298.581 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2019-01-10T14:24:58.582Z,1547130298.582 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2019-01-10T14:24:58.712Z,1547130298.712 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2019-01-10T14:24:58.713Z,1547130298.713 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2019-01-10T14:24:58.867Z,1547130298.867 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2019-01-10T14:24:58.869Z,1547130298.869 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2019-01-10T14:24:58.872Z,1547130298.872 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2019-01-10T14:24:59.115Z,1547130299.115 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2019-01-10T14:24:59.117Z,1547130299.117 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2019-01-10T14:24:59.226Z,1547130299.226 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2019-01-10T14:24:59.387Z,1547130299.387 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2019-01-10T14:24:59.484Z,1547130299.484 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2019-01-10T14:24:59.572Z,1547130299.572 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2019-01-10T14:24:59.741Z,1547130299.741 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2019-01-10T14:24:59.958Z,1547130299.958 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2019-01-10T14:25:00.060Z,1547130300.060 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2019-01-10T14:25:00.158Z,1547130300.158 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2019-01-10T14:25:00.259Z,1547130300.259 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2019-01-10T14:25:00.343Z,1547130300.343 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2019-01-10T14:25:00.355Z,1547130300.355 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2019-01-10T14:25:00.484Z,1547130300.484 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2019-01-10T14:25:00.485Z,1547130300.485 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2019-01-10T14:25:00.509Z,1547130300.509 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2019-01-10T14:25:00.509Z,1547130300.509 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2019-01-10T14:25:00.565Z,1547130300.565 [DepthRateCalculator] Loaded 2019-01-10T14:25:00.566Z,1547130300.566 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2019-01-10T14:25:00.572Z,1547130300.572 [PitchRateCalculator] Loaded 2019-01-10T14:25:00.572Z,1547130300.572 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2019-01-10T14:25:00.588Z,1547130300.588 [SpeedCalculator] Loaded 2019-01-10T14:25:00.588Z,1547130300.588 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2019-01-10T14:25:00.609Z,1547130300.609 [TempGradientCalculator] Loaded 2019-01-10T14:25:00.609Z,1547130300.609 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2019-01-10T14:25:00.615Z,1547130300.615 [YawRateCalculator] Loaded 2019-01-10T14:25:00.616Z,1547130300.616 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2019-01-10T14:25:00.656Z,1547130300.656 [ElevatorOffsetCalculator] Loaded 2019-01-10T14:25:00.656Z,1547130300.656 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2019-01-10T14:25:00.656Z,1547130300.656 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2019-01-10T14:25:00.657Z,1547130300.657 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2019-01-10T14:25:00.698Z,1547130300.698 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2019-01-10T14:25:00.698Z,1547130300.698 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2019-01-10T14:25:12.362Z,1547130312.362 [AcousticModem_Benthos_ATM900] Loaded 2019-01-10T14:25:12.362Z,1547130312.362 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread. 2019-01-10T14:25:12.498Z,1547130312.498 [DataOverHttps] Loaded 2019-01-10T14:25:12.499Z,1547130312.499 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2019-01-10T14:25:12.513Z,1547130312.513 [Depth_Keller] Loaded 2019-01-10T14:25:12.513Z,1547130312.513 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2019-01-10T14:25:12.924Z,1547130312.924 [GobyModem] Loaded 2019-01-10T14:25:12.924Z,1547130312.924 [ComponentRegistry](DEBUG): SyncComponent "GobyModem" handled in the control thread. 2019-01-10T14:25:13.022Z,1547130313.022 [NAL9602] Loaded 2019-01-10T14:25:13.023Z,1547130313.023 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2019-01-10T14:25:13.038Z,1547130313.038 [Onboard] Loaded 2019-01-10T14:25:13.039Z,1547130313.039 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2019-01-10T14:25:13.049Z,1547130313.049 [Radio_Surface] Loaded 2019-01-10T14:25:13.049Z,1547130313.049 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2019-01-10T14:25:13.050Z,1547130313.050 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 419E84E0 2019-01-10T14:25:13.051Z,1547130313.051 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 883 2019-01-10T14:25:13.098Z,1547130313.098 [PNI_TCM] Loaded 2019-01-10T14:25:13.098Z,1547130313.098 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread. 2019-01-10T14:25:13.159Z,1547130313.159 [Rowe_600LCM] Loaded 2019-01-10T14:25:13.159Z,1547130313.159 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread. 2019-01-10T14:25:13.160Z,1547130313.160 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 41A184E0 2019-01-10T14:25:13.160Z,1547130313.160 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 884 2019-01-10T14:25:14.925Z,1547130314.925 [BPC1] Loaded 2019-01-10T14:25:14.926Z,1547130314.926 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2019-01-10T14:25:14.926Z,1547130314.926 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2019-01-10T14:25:14.927Z,1547130314.927 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2019-01-10T14:25:15.089Z,1547130315.089 [SBIT](DEBUG): Construct Startup Built In Test. 2019-01-10T14:25:15.113Z,1547130315.113 [SBIT] Loaded 2019-01-10T14:25:15.113Z,1547130315.113 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2019-01-10T14:25:15.114Z,1547130315.114 [IBIT](DEBUG): Construct Initiated Built In Test. 2019-01-10T14:25:15.125Z,1547130315.125 [IBIT] Loaded 2019-01-10T14:25:15.126Z,1547130315.126 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2019-01-10T14:25:15.129Z,1547130315.129 [CBIT](DEBUG): Construct Continuous Built In Test. 2019-01-10T14:25:15.270Z,1547130315.270 [CBIT] Loaded 2019-01-10T14:25:15.270Z,1547130315.270 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2019-01-10T14:25:15.271Z,1547130315.271 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2019-01-10T14:25:15.271Z,1547130315.271 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2019-01-10T14:25:15.506Z,1547130315.506 [ESPComponent] Loaded 2019-01-10T14:25:15.507Z,1547130315.507 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2019-01-10T14:25:15.521Z,1547130315.521 [PAR_Licor] Loaded 2019-01-10T14:25:15.521Z,1547130315.521 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2019-01-10T14:25:15.571Z,1547130315.571 [WetLabsBB2FL] Loaded 2019-01-10T14:25:15.572Z,1547130315.572 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2019-01-10T14:25:15.573Z,1547130315.573 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 41AF84E0 2019-01-10T14:25:15.573Z,1547130315.573 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 885 2019-01-10T14:25:15.574Z,1547130315.574 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2019-01-10T14:25:15.574Z,1547130315.574 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2019-01-10T14:25:15.857Z,1547130315.857 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2019-01-10T14:25:15.858Z,1547130315.858 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2019-01-10T14:25:15.945Z,1547130315.945 [VerticalControl](DEBUG): Construct VerticalControl. 2019-01-10T14:25:16.041Z,1547130316.041 [VerticalControl] Loaded 2019-01-10T14:25:16.041Z,1547130316.041 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2019-01-10T14:25:16.042Z,1547130316.042 [HorizontalControl](DEBUG): Construct HorizontalControl. 2019-01-10T14:25:16.103Z,1547130316.103 [HorizontalControl] Loaded 2019-01-10T14:25:16.103Z,1547130316.103 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2019-01-10T14:25:16.104Z,1547130316.104 [SpeedControl](DEBUG): Construct SpeedControl. 2019-01-10T14:25:16.109Z,1547130316.109 [SpeedControl] Loaded 2019-01-10T14:25:16.109Z,1547130316.109 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2019-01-10T14:25:16.110Z,1547130316.110 [LoopControl](DEBUG): Construct LoopControl. 2019-01-10T14:25:16.110Z,1547130316.110 [LoopControl] Loaded 2019-01-10T14:25:16.111Z,1547130316.111 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2019-01-10T14:25:16.111Z,1547130316.111 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2019-01-10T14:25:16.112Z,1547130316.112 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2019-01-10T14:25:16.215Z,1547130316.215 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2019-01-10T14:25:16.216Z,1547130316.216 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2019-01-10T14:25:16.339Z,1547130316.339 [BuoyancyServo] Loaded 2019-01-10T14:25:16.339Z,1547130316.339 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2019-01-10T14:25:16.351Z,1547130316.351 [ElevatorServo] Loaded 2019-01-10T14:25:16.351Z,1547130316.351 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2019-01-10T14:25:16.362Z,1547130316.362 [MassServo] Loaded 2019-01-10T14:25:16.362Z,1547130316.362 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2019-01-10T14:25:16.374Z,1547130316.374 [RudderServo] Loaded 2019-01-10T14:25:16.374Z,1547130316.374 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2019-01-10T14:25:16.385Z,1547130316.385 [ThrusterServo] Loaded 2019-01-10T14:25:16.385Z,1547130316.385 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2019-01-10T14:25:16.386Z,1547130316.386 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2019-01-10T14:25:16.386Z,1547130316.386 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2019-01-10T14:25:16.501Z,1547130316.501 [DeadReckonUsingSpeedCalculator] Loaded 2019-01-10T14:25:16.501Z,1547130316.501 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2019-01-10T14:25:16.518Z,1547130316.518 [NavChart] Loaded 2019-01-10T14:25:16.518Z,1547130316.518 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2019-01-10T14:25:16.522Z,1547130316.522 [UniversalFixResidualReporter] Loaded 2019-01-10T14:25:16.522Z,1547130316.522 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2019-01-10T14:25:16.523Z,1547130316.523 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2019-01-10T14:25:16.526Z,1547130316.526 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2019-01-10T14:25:16.527Z,1547130316.527 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2019-01-10T14:25:16.534Z,1547130316.534 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2019-01-10T14:25:16.535Z,1547130316.535 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 41C524E0 2019-01-10T14:25:16.535Z,1547130316.535 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 886 2019-01-10T14:25:16.540Z,1547130316.540 [Supervisor](INFO): Main Thread ID is 796 2019-01-10T14:25:16.540Z,1547130316.540 [Supervisor](DEBUG): Running supervisor. 2019-01-10T14:25:16.541Z,1547130316.541 [CommandLine ThreadHandler](INFO): Handler Thread ID is 887 2019-01-10T14:25:16.543Z,1547130316.543 [controlThread ThreadHandler](INFO): Handler Thread ID is 888 2019-01-10T14:25:16.543Z,1547130316.543 [controlThread](DEBUG): Initializing ControlThread 2019-01-10T14:25:16.544Z,1547130316.544 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2019-01-10T14:25:16.545Z,1547130316.545 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2019-01-10T14:25:16.545Z,1547130316.545 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2019-01-10T14:25:16.545Z,1547130316.545 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2019-01-10T14:25:16.546Z,1547130316.546 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2019-01-10T14:25:16.546Z,1547130316.546 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2019-01-10T14:25:16.567Z,1547130316.567 [logger ThreadHandler](INFO): Handler Thread ID is 889 2019-01-10T14:25:16.595Z,1547130316.595 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 890 2019-01-10T14:25:16.601Z,1547130316.601 [Radio_Surface](INFO): Powering up 2019-01-10T14:25:16.615Z,1547130316.615 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 891 2019-01-10T14:25:16.616Z,1547130316.616 [Rowe_600LCM](INFO): Initializing 2019-01-10T14:25:16.737Z,1547130316.737 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 892 2019-01-10T14:25:16.739Z,1547130316.739 [WetLabsBB2FL](INFO): Powering down 2019-01-10T14:25:16.881Z,1547130316.881 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 893 2019-01-10T14:25:17.022Z,1547130317.022 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2019-01-10T14:25:17.022Z,1547130317.022 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2019-01-10T14:25:17.022Z,1547130317.022 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2019-01-10T14:25:17.022Z,1547130317.022 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2019-01-10T14:25:17.023Z,1547130317.023 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2019-01-10T14:25:17.023Z,1547130317.023 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2019-01-10T14:25:17.023Z,1547130317.023 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2019-01-10T14:25:17.023Z,1547130317.023 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2019-01-10T14:25:17.023Z,1547130317.023 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2019-01-10T14:25:17.024Z,1547130317.024 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2019-01-10T14:25:17.024Z,1547130317.024 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2019-01-10T14:25:17.024Z,1547130317.024 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2019-01-10T14:25:17.024Z,1547130317.024 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2019-01-10T14:25:17.024Z,1547130317.024 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2019-01-10T14:25:17.025Z,1547130317.025 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2019-01-10T14:25:17.025Z,1547130317.025 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2019-01-10T14:25:17.183Z,1547130317.183 [Rowe_600LCM](INFO): Powering up 2019-01-10T14:25:21.032Z,1547130321.032 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2019-01-10T14:25:21.113Z,1547130321.113 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null & 2019-01-10T14:26:48.424Z,1547130408.424 [GobyModem](CRITICAL): exception at startup: Failed to startup. 2019-01-10T14:26:48.485Z,1547130408.485 [SBIT](INFO): Initialize SBIT Component. 2019-01-10T14:26:48.485Z,1547130408.485 [SBIT](IMPORTANT): git: 2018-12-19-33-g7a9485f 2019-01-10T14:26:48.486Z,1547130408.486 [SBIT](INFO): git hash: 7a9485f35819a7024d1a01c3daca1d5dca0e188a 2019-01-10T14:26:48.486Z,1547130408.486 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2019-01-10T14:26:48.487Z,1547130408.487 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 Kernel Reported: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018 2019-01-10T14:26:48.488Z,1547130408.488 [SBIT](INFO): Beginning SBIT in 24.000000 seconds. 2019-01-10T14:26:48.489Z,1547130408.489 [IBIT](INFO): Initialize IBIT Component. 2019-01-10T14:26:48.489Z,1547130408.489 [CBIT](DEBUG): Initialize CBIT Component. 2019-01-10T14:26:48.519Z,1547130408.519 [CBIT](DEBUG): Initialized mux pins. 2019-01-10T14:26:48.519Z,1547130408.519 [CBIT](DEBUG): Initializing the watchdog timer. 2019-01-10T14:26:48.543Z,1547130408.543 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2019-01-10T14:26:48.543Z,1547130408.543 [CBIT](DEBUG): Initializing heartbeat. 2019-01-10T14:26:48.614Z,1547130408.614 [CBIT](DEBUG): Deactivating GF circuits. 2019-01-10T14:26:48.615Z,1547130408.615 [CBIT](DEBUG): Deactivating emergency mode. 2019-01-10T14:26:48.652Z,1547130408.652 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2019-01-10T14:26:48.671Z,1547130408.671 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2019-01-10T14:26:48.672Z,1547130408.672 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2019-01-10T14:26:48.672Z,1547130408.672 [LoopControl](DEBUG): Initialize LoopControlComponent. 2019-01-10T14:26:48.674Z,1547130408.674 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-01-10T14:26:48.680Z,1547130408.680 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2019-01-10T14:26:48.680Z,1547130408.680 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2019-01-10T14:26:48.681Z,1547130408.681 [NavChart](DEBUG): Initialize NavChart Navigation. 2019-01-10T14:26:48.681Z,1547130408.681 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2019-01-10T14:26:48.687Z,1547130408.687 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2019-01-10T14:26:48.740Z,1547130408.740 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2019-01-10T14:26:48.751Z,1547130408.751 [MissionManager](DEBUG): 2019-01-10T14:26:48.752Z,1547130408.752 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2019-01-10T14:26:48.819Z,1547130408.819 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2019-01-10T14:26:48.820Z,1547130408.820 [Default:A.Wait](DEBUG): Construct Wait. 2019-01-10T14:26:48.821Z,1547130408.821 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2019-01-10T14:26:48.844Z,1547130408.844 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2019-01-10T14:26:48.859Z,1547130408.859 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2019-01-10T14:26:48.865Z,1547130408.865 [Default:E.Execute](DEBUG): Construct Execute. 2019-01-10T14:26:48.868Z,1547130408.868 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2019-01-10T14:26:48.884Z,1547130408.884 [controlThread](DEBUG): Component order: CycleStarter,AcousticModem_Benthos_ATM900,DataOverHttps,Depth_Keller,GobyModem,NAL9602,Onboard,PNI_TCM,BPC1,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2019-01-10T14:26:48.900Z,1547130408.900 [AcousticModem_Benthos_ATM900](INFO): Powering up 2019-01-10T14:26:48.900Z,1547130408.900 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900. 2019-01-10T14:26:48.923Z,1547130408.923 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2019-01-10T14:26:48.933Z,1547130408.933 [Depth_Keller](ERROR): Pressure reading out of range: 1895.684326 decibar 2019-01-10T14:26:48.953Z,1547130408.953 [NAL9602](INFO): Powering up NAL9602 2019-01-10T14:26:49.031Z,1547130409.031 [ESPComponent](INFO): powering down ESP 2019-01-10T14:26:49.278Z,1547130409.278 [DepthRateCalculator](ERROR): Depth measurement is not active 2019-01-10T14:26:49.499Z,1547130409.499 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2019-01-10T14:26:49.507Z,1547130409.507 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2019-01-10T14:26:49.513Z,1547130409.513 [ElevatorServo](DEBUG): Initializing EZServoServo. 2019-01-10T14:26:49.519Z,1547130409.519 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2019-01-10T14:26:49.525Z,1547130409.525 [MassServo](DEBUG): Initializing EZServoServo. 2019-01-10T14:26:49.531Z,1547130409.531 [MassServo](DEBUG): Initializing MassServo. 2019-01-10T14:26:49.536Z,1547130409.536 [RudderServo](DEBUG): Initializing EZServoServo. 2019-01-10T14:26:49.543Z,1547130409.543 [RudderServo](DEBUG): Initializing RudderServo. 2019-01-10T14:26:49.549Z,1547130409.549 [ThrusterServo](DEBUG): Initializing EZServoServo. 2019-01-10T14:26:49.555Z,1547130409.555 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2019-01-10T14:26:49.589Z,1547130409.589 [CommandLine](FAULT): Scheduling is paused 2019-01-10T14:26:49.590Z,1547130409.590 [CBIT](INFO): Critical error at 20190110T142648 2019-01-10T14:26:49.590Z,1547130409.590 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2019-01-10T14:26:50.463Z,1547130410.463 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout 2019-01-10T14:26:50.463Z,1547130410.463 [BuoyancyServo](FAULT): Buoyancy failed to initialize 2019-01-10T14:26:50.463Z,1547130410.463 [BuoyancyServo] Communications Fault, FailCount= 1 2019-01-10T14:26:50.463Z,1547130410.463 [BuoyancyServo](ERROR): Communications Fault 2019-01-10T14:26:50.696Z,1547130410.696 [CBIT](ERROR): Communications Fault in component: BuoyancyServo 2019-01-10T14:26:52.808Z,1547130412.808 [CBIT](INFO): Clearing failed state for component BuoyancyServo 2019-01-10T14:26:52.808Z,1547130412.808 [BuoyancyServo] No Fault, FailCount= 1 2019-01-10T14:26:53.173Z,1547130413.173 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2019-01-10T14:26:53.288Z,1547130413.288 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2019-01-10T14:26:58.689Z,1547130418.689 [CBIT](CRITICAL): Environmental Failure. Press:14.773009 PSI. Humidity:35%. Temp:24 C. ABORTING MISSION 2019-01-10T14:26:58.961Z,1547130418.961 [CBIT](INFO): Critical error at 20190110T142658 2019-01-10T14:27:01.477Z,1547130421.477 [NAL9602](INFO): NAL9602 initialized 2019-01-10T14:27:09.072Z,1547130429.072 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize; deviceResponse_ loaded: , available: hos 2019-01-10T14:27:09.072Z,1547130429.072 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 1 2019-01-10T14:27:09.072Z,1547130429.072 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault 2019-01-10T14:27:09.178Z,1547130429.178 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900 2019-01-10T14:27:09.471Z,1547130429.471 [AcousticModem_Benthos_ATM900](INFO): Powering down 2019-01-10T14:27:10.346Z,1547130430.346 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900 2019-01-10T14:27:10.346Z,1547130430.346 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 1 2019-01-10T14:27:12.672Z,1547130432.672 [AcousticModem_Benthos_ATM900](INFO): Powering up 2019-01-10T14:27:12.673Z,1547130432.673 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900. 2019-01-10T14:27:13.125Z,1547130433.125 [SBIT](IMPORTANT): Beginning Startup BIT 2019-01-10T14:27:13.129Z,1547130433.129 [CBIT](IMPORTANT): Beginning ground fault scan 2019-01-10T14:27:24.504Z,1547130444.504 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.008923 CHAN A1 (24V): -0.013899 CHAN A2 (12V): -0.005463 CHAN A3 (5V): -0.002686 CHAN B0 (3.3V): -0.001026 CHAN B1 (3.15aV): -0.001097 CHAN B2 (3.15bV): -0.000846 CHAN B3 (GND): 0.000215 OPEN: 0.004114 Full Scale Calc: 4.765 mA, -1.589 mA 2019-01-10T14:27:32.999Z,1547130452.999 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface 2019-01-10T14:27:32.000Z,1547130453.000 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 2 2019-01-10T14:27:32.000Z,1547130453.000 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault 2019-01-10T14:27:33.176Z,1547130453.176 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900 2019-01-10T14:27:33.399Z,1547130453.399 [AcousticModem_Benthos_ATM900](INFO): Powering down 2019-01-10T14:27:34.439Z,1547130454.439 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900 2019-01-10T14:27:34.439Z,1547130454.439 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 2 2019-01-10T14:27:36.599Z,1547130456.599 [AcousticModem_Benthos_ATM900](INFO): Powering up 2019-01-10T14:27:36.600Z,1547130456.600 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900. 2019-01-10T14:27:54.430Z,1547130474.430 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004476 2019-01-10T14:27:56.968Z,1547130476.968 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface 2019-01-10T14:27:56.968Z,1547130476.968 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 3 2019-01-10T14:27:56.968Z,1547130476.968 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault 2019-01-10T14:27:57.156Z,1547130477.156 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900 2019-01-10T14:27:57.368Z,1547130477.368 [AcousticModem_Benthos_ATM900](INFO): Powering down 2019-01-10T14:27:58.396Z,1547130478.396 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900 2019-01-10T14:27:58.396Z,1547130478.396 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 3 2019-01-10T14:28:00.567Z,1547130480.567 [AcousticModem_Benthos_ATM900](INFO): Powering up 2019-01-10T14:28:00.568Z,1547130480.568 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900. 2019-01-10T14:28:07.428Z,1547130487.428 [SBIT](IMPORTANT): SBIT PASSED 2019-01-10T14:28:07.473Z,1547130487.473 [CommandLine](IMPORTANT): got command configSet list 2019-01-10T14:28:07.474Z,1547130487.474 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2019-01-10T14:28:07.474Z,1547130487.474 [CommandLine](IMPORTANT): Aanderaa_O2.loadAtStartup=0 bool; 2019-01-10T14:28:07.475Z,1547130487.475 [CommandLine](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool; 2019-01-10T14:28:07.475Z,1547130487.475 [CommandLine](IMPORTANT): DropWeight.loadAtStartup=0 bool; 2019-01-10T14:28:07.475Z,1547130487.475 [CommandLine](IMPORTANT): PAR_Licor.loadAtStartup=1 bool; 2019-01-10T14:28:07.475Z,1547130487.475 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=1 bool; 2019-01-10T14:28:07.877Z,1547130487.877 [MissionManager](IMPORTANT): Started mission Startup 2019-01-10T14:28:07.878Z,1547130487.878 [Startup] Running Loop=1 2019-01-10T14:28:07.878Z,1547130487.878 [Startup](DEBUG): Aggregate::initialize Startup 2019-01-10T14:28:07.878Z,1547130487.878 [Startup:A.GoToSurface] Running Loop=1 2019-01-10T14:28:07.878Z,1547130487.878 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-01-10T14:28:07.879Z,1547130487.879 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-01-10T14:28:07.879Z,1547130487.879 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-01-10T14:28:07.880Z,1547130487.880 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-01-10T14:28:07.880Z,1547130487.880 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-01-10T14:28:07.880Z,1547130487.880 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-01-10T14:28:07.894Z,1547130487.894 [Startup:StartupSatComms] Running Loop=1 2019-01-10T14:28:07.894Z,1547130487.894 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2019-01-10T14:28:07.894Z,1547130487.894 [Startup:StartupSatComms:A] Running Loop=1 2019-01-10T14:28:08.235Z,1547130488.235 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2019-01-10T14:28:20.967Z,1547130500.967 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface 2019-01-10T14:28:20.967Z,1547130500.967 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 4 2019-01-10T14:28:20.967Z,1547130500.967 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault 2019-01-10T14:28:21.060Z,1547130501.060 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900 2019-01-10T14:28:21.367Z,1547130501.367 [AcousticModem_Benthos_ATM900](INFO): Powering down 2019-01-10T14:28:22.223Z,1547130502.223 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900 2019-01-10T14:28:22.223Z,1547130502.223 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 4 2019-01-10T14:28:24.567Z,1547130504.567 [AcousticModem_Benthos_ATM900](INFO): Powering up 2019-01-10T14:28:24.568Z,1547130504.568 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900. 2019-01-10T14:28:44.968Z,1547130524.968 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface 2019-01-10T14:28:44.968Z,1547130524.968 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 5 2019-01-10T14:28:44.968Z,1547130524.968 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault 2019-01-10T14:28:45.058Z,1547130525.058 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900 2019-01-10T14:28:45.373Z,1547130525.373 [AcousticModem_Benthos_ATM900](INFO): Powering down 2019-01-10T14:28:46.237Z,1547130526.237 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900 2019-01-10T14:28:46.237Z,1547130526.237 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 5 2019-01-10T14:28:48.567Z,1547130528.567 [AcousticModem_Benthos_ATM900](INFO): Powering up 2019-01-10T14:28:48.568Z,1547130528.568 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900. 2019-01-10T14:29:08.111Z,1547130548.111 [Startup:StartupSatComms:A](INFO): Timed out from 2019-01-10T14:28:07.9Z 2019-01-10T14:29:08.112Z,1547130548.112 [Startup:StartupSatComms:A] Stopped 2019-01-10T14:29:08.112Z,1547130548.112 [Startup:StartupSatComms:B] Running Loop=1 2019-01-10T14:29:08.515Z,1547130548.515 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-01-10T14:29:08.853Z,1547130548.853 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize; deviceResponse_ loaded: , available: :41:45]@¼# 2019-01-10T14:29:08.854Z,1547130548.854 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 6 2019-01-10T14:29:08.854Z,1547130548.854 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault 2019-01-10T14:29:11.774Z,1547130551.774 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900 2019-01-10T14:29:11.782Z,1547130551.782 [AcousticModem_Benthos_ATM900](INFO): Powering down 2019-01-10T14:29:15.257Z,1547130555.257 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190110T140709/Courier0007.lzma 2019-01-10T14:29:15.400Z,1547130555.400 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900 2019-01-10T14:29:15.400Z,1547130555.400 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 6 2019-01-10T14:29:15.655Z,1547130555.655 [AcousticModem_Benthos_ATM900](INFO): Powering up 2019-01-10T14:29:15.656Z,1547130555.656 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900. 2019-01-10T14:29:16.057Z,1547130556.057 [DataOverHttps](INFO): Moved sent file to Logs/20190110T140709/Courier0007.lzma.bak 2019-01-10T14:29:16.057Z,1547130556.057 [DataOverHttps](INFO): SBD MOMSN=9162423 2019-01-10T14:29:27.263Z,1547130567.263 [DataOverHttps](INFO): Sending 193 bytes from file Logs/20190110T142454/Courier0000.lzma 2019-01-10T14:29:28.061Z,1547130568.061 [DataOverHttps](INFO): Moved sent file to Logs/20190110T142454/Courier0000.lzma.bak 2019-01-10T14:29:28.061Z,1547130568.061 [DataOverHttps](INFO): SBD MOMSN=9162425 2019-01-10T14:29:35.270Z,1547130575.270 [BPC1](FAULT): Failed to parse data from all battery packs. 2019-01-10T14:29:35.270Z,1547130575.270 [BPC1] Data Fault, FailCount= 1 2019-01-10T14:29:35.270Z,1547130575.270 [BPC1](ERROR): Data Fault 2019-01-10T14:29:35.323Z,1547130575.323 [CBIT](ERROR): Data Fault in component: BPC1 2019-01-10T14:29:35.968Z,1547130575.968 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface 2019-01-10T14:29:35.968Z,1547130575.968 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 7 2019-01-10T14:29:35.968Z,1547130575.968 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault 2019-01-10T14:29:36.147Z,1547130576.147 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900 2019-01-10T14:29:36.368Z,1547130576.368 [AcousticModem_Benthos_ATM900](INFO): Powering down 2019-01-10T14:29:41.355Z,1547130581.355 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900 2019-01-10T14:29:41.355Z,1547130581.355 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 7 2019-01-10T14:29:41.362Z,1547130581.362 [AcousticModem_Benthos_ATM900](INFO): Powering up 2019-01-10T14:29:41.362Z,1547130581.362 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900. 2019-01-10T14:29:41.396Z,1547130581.396 [DataOverHttps](INFO): Sending 335 bytes from file Logs/20190110T140709/Express0008.lzma 2019-01-10T14:29:42.165Z,1547130582.165 [DataOverHttps](INFO): Moved sent file to Logs/20190110T140709/Express0008.lzma.bak 2019-01-10T14:29:42.165Z,1547130582.165 [DataOverHttps](INFO): SBD MOMSN=9162430 2019-01-10T14:29:49.223Z,1547130589.223 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = 1000175.183353 2019-01-10T14:29:49.224Z,1547130589.224 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1 2019-01-10T14:29:49.224Z,1547130589.224 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2019-01-10T14:29:49.235Z,1547130589.235 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2019-01-10T14:29:49.388Z,1547130589.388 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2019-01-10T14:29:49.389Z,1547130589.389 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1 2019-01-10T14:29:49.710Z,1547130589.710 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-01-10T14:29:49.710Z,1547130589.710 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2019-01-10T14:29:49.710Z,1547130589.710 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2019-01-10T14:29:54.925Z,1547130594.925 [CommandLine](IMPORTANT): got command help configSet 2019-01-10T14:29:55.111Z,1547130595.111 [DataOverHttps](INFO): Sending 841 bytes from file Logs/20190110T142454/Express0001.lzma 2019-01-10T14:29:55.902Z,1547130595.902 [DataOverHttps](INFO): Moved sent file to Logs/20190110T142454/Express0001.lzma.bak 2019-01-10T14:29:55.903Z,1547130595.903 [DataOverHttps](INFO): SBD MOMSN=9162448 2019-01-10T14:29:59.243Z,1547130599.243 [Startup:StartupSatComms:B] Stopped 2019-01-10T14:29:59.244Z,1547130599.244 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2019-01-10T14:29:59.244Z,1547130599.244 [Startup:StartupSatComms] Stopped 2019-01-10T14:29:59.244Z,1547130599.244 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2019-01-10T14:29:59.245Z,1547130599.245 [Startup](INFO): Completed Startup 2019-01-10T14:29:59.245Z,1547130599.245 [MissionManager](INFO): Startup is completed. 2019-01-10T14:29:59.245Z,1547130599.245 [MissionManager](INFO): Uninitializing Mission Startup 2019-01-10T14:29:59.245Z,1547130599.245 [Startup] Stopped 2019-01-10T14:29:59.245Z,1547130599.245 [Startup](DEBUG): Aggregate::uninitialize Startup 2019-01-10T14:29:59.245Z,1547130599.245 [Startup:A.GoToSurface] Stopped 2019-01-10T14:29:59.245Z,1547130599.245 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-01-10T14:29:59.378Z,1547130599.378 [MissionManager](IMPORTANT): Started mission Default 2019-01-10T14:29:59.378Z,1547130599.378 [Default] Running Loop=1 2019-01-10T14:29:59.378Z,1547130599.378 [Default](DEBUG): Aggregate::initialize Default 2019-01-10T14:29:59.378Z,1547130599.378 [Default:B.GoToSurface] Running Loop=1 2019-01-10T14:29:59.382Z,1547130599.382 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-01-10T14:29:59.383Z,1547130599.383 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-01-10T14:29:59.383Z,1547130599.383 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-01-10T14:29:59.383Z,1547130599.383 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-01-10T14:29:59.384Z,1547130599.384 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-01-10T14:29:59.384Z,1547130599.384 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-01-10T14:29:59.384Z,1547130599.384 [Default:A.Wait] Running Loop=1 2019-01-10T14:29:59.384Z,1547130599.384 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-01-10T14:30:02.823Z,1547130602.823 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize; deviceResponse_ loaded: , available: ttery lo¼# 2019-01-10T14:30:02.823Z,1547130602.823 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 8 2019-01-10T14:30:02.823Z,1547130602.823 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault 2019-01-10T14:30:02.983Z,1547130602.983 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900 2019-01-10T14:30:02.984Z,1547130602.984 [CBIT](FAULT): Communications Fault in component: AcousticModem_Benthos_ATM900 2019-01-10T14:30:03.224Z,1547130603.224 [AcousticModem_Benthos_ATM900](INFO): Powering down 2019-01-10T14:30:03.877Z,1547130603.877 [CommandLine](IMPORTANT): got command configSet reload 2019-01-10T14:30:03.877Z,1547130603.877 [CommandLine](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg 2019-01-10T14:30:12.468Z,1547130612.468 [Default:A.Wait](INFO): Done Waiting. 2019-01-10T14:30:12.468Z,1547130612.468 [Default:A.Wait] Stopped 2019-01-10T14:30:12.468Z,1547130612.468 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-01-10T14:30:12.868Z,1547130612.868 [Default:CheckIn] Running Loop=1 2019-01-10T14:30:12.869Z,1547130612.869 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-01-10T14:30:12.869Z,1547130612.869 [Default:CheckIn:Read_GPS] Running Loop=1 2019-01-10T14:30:13.286Z,1547130613.286 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2019-01-10T14:30:16.433Z,1547130616.433 [CommandLine](IMPORTANT): got command show variable ATM900 2019-01-10T14:30:16.626Z,1547130616.626 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.loadAtStartup (bool) 2019-01-10T14:30:16.627Z,1547130616.627 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.simulateHardware (bool) 2019-01-10T14:30:16.627Z,1547130616.627 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.localAddress (count) 2019-01-10T14:30:16.627Z,1547130616.627 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.verbosity (count) 2019-01-10T14:30:16.648Z,1547130616.648 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.loadControl (none) 2019-01-10T14:30:16.649Z,1547130616.649 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.uart (none) 2019-01-10T14:30:16.651Z,1547130616.651 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.baud (bit_per_second) 2019-01-10T14:30:17.033Z,1547130617.033 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.acoustic_wakeup (count) 2019-01-10T14:30:17.034Z,1547130617.034 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.acoustic_receive_time (epoch_second) 2019-01-10T14:30:17.039Z,1547130617.039 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.acoustic_transmit_time (epoch_second) 2019-01-10T14:30:17.039Z,1547130617.039 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.range_request (count) 2019-01-10T14:30:17.040Z,1547130617.040 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.remote_address (count) 2019-01-10T14:30:17.040Z,1547130617.040 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.local_address (count) 2019-01-10T14:30:17.041Z,1547130617.041 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.range (meter) 2019-01-10T14:30:17.385Z,1547130617.385 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.durationOfLastRun (second) 2019-01-10T14:30:17.408Z,1547130617.408 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.component_voltage (volt) 2019-01-10T14:30:17.408Z,1547130617.408 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.component_avgVoltage (volt) 2019-01-10T14:30:17.408Z,1547130617.408 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.component_current (milliampere) 2019-01-10T14:30:17.409Z,1547130617.409 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.component_avgCurrent (milliampere) 2019-01-10T14:30:31.946Z,1547130631.946 [CommandLine](IMPORTANT): got command get AcousticModem_Benthos_ATM900.loadAtStartup 2019-01-10T14:30:31.947Z,1547130631.947 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.loadAtStartup 1 bool 2019-01-10T14:30:58.532Z,1547130658.532 [CommandLine](IMPORTANT): got command set AcousticModem_Benthos_ATM900.loadAtStartup 0.000000 bool 2019-01-10T14:32:04.421Z,1547130724.421 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-01-10T14:32:50.073Z,1547130770.073 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = 1000356.033214 2019-01-10T14:32:50.073Z,1547130770.073 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2 2019-01-10T14:32:50.073Z,1547130770.073 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2019-01-10T14:32:50.119Z,1547130770.119 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2019-01-10T14:32:50.492Z,1547130770.492 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2019-01-10T14:32:50.492Z,1547130770.492 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2 2019-01-10T14:32:50.884Z,1547130770.884 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-01-10T14:32:50.885Z,1547130770.885 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2019-01-10T14:32:50.885Z,1547130770.885 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2019-01-10T14:33:07.935Z,1547130787.935 [CommandLine](IMPORTANT): got command show state 2019-01-10T14:33:07.936Z,1547130787.936 [CommandLine](IMPORTANT): Mission State: 2019-01-10T14:33:07.936Z,1547130787.936 [CommandLine](INFO): Startup->null/0 2019-01-10T14:33:07.936Z,1547130787.936 [CommandLine](INFO): Startup:StartupSatComms->null/0 2019-01-10T14:33:07.937Z,1547130787.937 [CommandLine](INFO): Default->Default:CheckIn/0 2019-01-10T14:33:07.937Z,1547130787.937 [CommandLine](INFO): Default:CheckIn->Default:CheckIn:Read_GPS/0 2019-01-10T14:33:18.132Z,1547130798.132 [CommandLine](IMPORTANT): got command show stack 2019-01-10T14:33:18.132Z,1547130798.132 [CommandLine](IMPORTANT): Behavior Stack: 2019-01-10T14:33:18.133Z,1547130798.133 [Default](IMPORTANT): Priority 0: Default:B.GoToSurface 2019-01-10T14:33:18.133Z,1547130798.133 [Default:CheckIn](IMPORTANT): Priority 1: Default:CheckIn:Read_GPS 2019-01-10T14:34:00.245Z,1547130840.245 [CommandLine](IMPORTANT): got command run ./Missions/Demo/senddata_direct_test.xml 2019-01-10T14:34:00.246Z,1547130840.246 [MissionManager](INFO): Loading Mission: ./Missions/Demo/senddata_direct_test.xml 2019-01-10T14:34:00.387Z,1547130840.387 [MissionManager](DEBUG): 2019-01-10T14:34:00.397Z,1547130840.397 [CommandLine](IMPORTANT): Running ./Missions/Demo/senddata_direct_test.xml 2019-01-10T14:34:03.606Z,1547130843.606 [Default] Stopped 2019-01-10T14:34:03.606Z,1547130843.606 [Default](DEBUG): Aggregate::uninitialize Default 2019-01-10T14:34:03.606Z,1547130843.606 [Default:B.GoToSurface] Stopped 2019-01-10T14:34:03.606Z,1547130843.606 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-01-10T14:34:03.606Z,1547130843.606 [Default:CheckIn] Stopped 2019-01-10T14:34:03.607Z,1547130843.607 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-01-10T14:34:03.607Z,1547130843.607 [Default:CheckIn:Read_GPS] Stopped 2019-01-10T14:34:03.607Z,1547130843.607 [MissionManager](IMPORTANT): Started mission senddata_direct_test 2019-01-10T14:34:03.607Z,1547130843.607 [senddata_direct_test] Running Loop=1 2019-01-10T14:34:03.607Z,1547130843.607 [senddata_direct_test](DEBUG): Aggregate::initialize senddata_direct_test 2019-01-10T14:34:03.607Z,1547130843.607 [senddata_direct_test:A] Running Loop=1 2019-01-10T14:34:03.609Z,1547130843.609 [senddata_direct_test:A] Stopped 2019-01-10T14:34:03.609Z,1547130843.609 [senddata_direct_test:B] Running Loop=1 2019-01-10T14:34:03.685Z,1547130843.685 [GobyModem](INFO): modem://1: set _.pressure 102287.789062 pascal 2019-01-10T14:34:03.816Z,1547130843.816 [senddata_direct_test:B] Stopped 2019-01-10T14:34:03.816Z,1547130843.816 [senddata_direct_test:C] Running Loop=1 2019-01-10T14:34:04.039Z,1547130844.039 [GobyModem](INFO): modem://1: set _.temperature 23.856684 celsius 2019-01-10T14:34:04.116Z,1547130844.116 [senddata_direct_test:C] Stopped 2019-01-10T14:34:04.117Z,1547130844.117 [senddata_direct_test](INFO): Completed senddata_direct_test 2019-01-10T14:34:04.117Z,1547130844.117 [MissionManager](INFO): senddata_direct_test is completed. 2019-01-10T14:34:04.117Z,1547130844.117 [MissionManager](INFO): Uninitializing Mission senddata_direct_test 2019-01-10T14:34:04.117Z,1547130844.117 [senddata_direct_test] Stopped 2019-01-10T14:34:04.117Z,1547130844.117 [senddata_direct_test](DEBUG): Aggregate::uninitialize senddata_direct_test 2019-01-10T14:34:04.437Z,1547130844.437 [GobyModem](INFO): modem://1: set _.humidity 35.081188 percent 2019-01-10T14:34:04.509Z,1547130844.509 [MissionManager](IMPORTANT): Started mission Default 2019-01-10T14:34:04.510Z,1547130844.510 [Default] Running Loop=1 2019-01-10T14:34:04.510Z,1547130844.510 [Default](DEBUG): Aggregate::initialize Default 2019-01-10T14:34:04.510Z,1547130844.510 [Default:B.GoToSurface] Running Loop=1 2019-01-10T14:34:04.510Z,1547130844.510 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-01-10T14:34:04.510Z,1547130844.510 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-01-10T14:34:04.511Z,1547130844.511 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-01-10T14:34:04.511Z,1547130844.511 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-01-10T14:34:04.511Z,1547130844.511 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-01-10T14:34:04.512Z,1547130844.512 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-01-10T14:34:04.512Z,1547130844.512 [Default:A.Wait] Running Loop=1 2019-01-10T14:34:04.512Z,1547130844.512 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-01-10T14:34:17.684Z,1547130857.684 [Default:A.Wait](INFO): Done Waiting. 2019-01-10T14:34:17.684Z,1547130857.684 [Default:A.Wait] Stopped 2019-01-10T14:34:17.684Z,1547130857.684 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-01-10T14:34:18.084Z,1547130858.084 [Default:CheckIn] Running Loop=1 2019-01-10T14:34:18.084Z,1547130858.084 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-01-10T14:34:18.084Z,1547130858.084 [Default:CheckIn:Read_GPS] Running Loop=1 2019-01-10T14:35:03.810Z,1547130903.810 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900 2019-01-10T14:35:03.810Z,1547130903.810 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 8 2019-01-10T14:35:03.817Z,1547130903.817 [AcousticModem_Benthos_ATM900](INFO): Powering up 2019-01-10T14:35:03.817Z,1547130903.817 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900. 2019-01-10T14:35:12.621Z,1547130912.621 [AcousticModem_Benthos_ATM900](DEBUG): d 2019-01-10T14:35:14.029Z,1547130914.029 [CommandLine](IMPORTANT): got command run ./Missions/Demo/senddata_direct_test.xml 2019-01-10T14:35:14.029Z,1547130914.029 [MissionManager](INFO): Loading Mission: ./Missions/Demo/senddata_direct_test.xml 2019-01-10T14:35:14.045Z,1547130914.045 [MissionManager](DEBUG): 2019-01-10T14:35:14.047Z,1547130914.047 [CommandLine](IMPORTANT): Running ./Missions/Demo/senddata_direct_test.xml 2019-01-10T14:35:14.293Z,1547130914.293 [Default] Stopped 2019-01-10T14:35:14.293Z,1547130914.293 [Default](DEBUG): Aggregate::uninitialize Default 2019-01-10T14:35:14.293Z,1547130914.293 [Default:B.GoToSurface] Stopped 2019-01-10T14:35:14.293Z,1547130914.293 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-01-10T14:35:14.294Z,1547130914.294 [Default:CheckIn] Stopped 2019-01-10T14:35:14.294Z,1547130914.294 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-01-10T14:35:14.294Z,1547130914.294 [Default:CheckIn:Read_GPS] Stopped 2019-01-10T14:35:14.294Z,1547130914.294 [MissionManager](IMPORTANT): Started mission senddata_direct_test 2019-01-10T14:35:14.294Z,1547130914.294 [senddata_direct_test] Running Loop=1 2019-01-10T14:35:14.294Z,1547130914.294 [senddata_direct_test](DEBUG): Aggregate::initialize senddata_direct_test 2019-01-10T14:35:14.295Z,1547130914.295 [senddata_direct_test:A] Running Loop=1 2019-01-10T14:35:14.296Z,1547130914.296 [senddata_direct_test:A] Stopped 2019-01-10T14:35:14.296Z,1547130914.296 [senddata_direct_test:B] Running Loop=1 2019-01-10T14:35:14.637Z,1547130914.637 [GobyModem](INFO): modem://1: set _.pressure 102518.054688 pascal 2019-01-10T14:35:14.690Z,1547130914.690 [senddata_direct_test:B] Stopped 2019-01-10T14:35:14.691Z,1547130914.691 [senddata_direct_test:C] Running Loop=1 2019-01-10T14:35:15.032Z,1547130915.032 [GobyModem](INFO): modem://1: set _.temperature 23.816370 celsius 2019-01-10T14:35:15.088Z,1547130915.088 [senddata_direct_test:C] Stopped 2019-01-10T14:35:15.088Z,1547130915.088 [senddata_direct_test](INFO): Completed senddata_direct_test 2019-01-10T14:35:15.088Z,1547130915.088 [MissionManager](INFO): senddata_direct_test is completed. 2019-01-10T14:35:15.088Z,1547130915.088 [MissionManager](INFO): Uninitializing Mission senddata_direct_test 2019-01-10T14:35:15.089Z,1547130915.089 [senddata_direct_test] Stopped 2019-01-10T14:35:15.089Z,1547130915.089 [senddata_direct_test](DEBUG): Aggregate::uninitialize senddata_direct_test 2019-01-10T14:35:15.429Z,1547130915.429 [GobyModem](INFO): modem://1: set _.humidity 35.056770 percent 2019-01-10T14:35:15.541Z,1547130915.541 [MissionManager](IMPORTANT): Started mission Default 2019-01-10T14:35:15.541Z,1547130915.541 [Default] Running Loop=1 2019-01-10T14:35:15.541Z,1547130915.541 [Default](DEBUG): Aggregate::initialize Default 2019-01-10T14:35:15.541Z,1547130915.541 [Default:B.GoToSurface] Running Loop=1 2019-01-10T14:35:15.541Z,1547130915.541 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-01-10T14:35:15.542Z,1547130915.542 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-01-10T14:35:15.542Z,1547130915.542 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-01-10T14:35:15.542Z,1547130915.542 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-01-10T14:35:15.543Z,1547130915.543 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-01-10T14:35:15.543Z,1547130915.543 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-01-10T14:35:15.543Z,1547130915.543 [Default:A.Wait] Running Loop=1 2019-01-10T14:35:15.543Z,1547130915.543 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-01-10T14:35:23.820Z,1547130923.820 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize; deviceResponse_ loaded: d , available: Sta 2019-01-10T14:35:23.820Z,1547130923.820 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 1 2019-01-10T14:35:23.820Z,1547130923.820 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault 2019-01-10T14:35:23.925Z,1547130923.925 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900 2019-01-10T14:35:24.219Z,1547130924.219 [AcousticModem_Benthos_ATM900](INFO): Powering down 2019-01-10T14:35:25.092Z,1547130925.092 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900 2019-01-10T14:35:25.092Z,1547130925.092 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 1 2019-01-10T14:35:27.420Z,1547130927.420 [AcousticModem_Benthos_ATM900](INFO): Powering up 2019-01-10T14:35:27.421Z,1547130927.421 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900. 2019-01-10T14:35:28.691Z,1547130928.691 [Default:A.Wait](INFO): Done Waiting. 2019-01-10T14:35:28.691Z,1547130928.691 [Default:A.Wait] Stopped 2019-01-10T14:35:28.691Z,1547130928.691 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-01-10T14:35:29.088Z,1547130929.088 [Default:CheckIn] Running Loop=1 2019-01-10T14:35:29.088Z,1547130929.088 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-01-10T14:35:29.088Z,1547130929.088 [Default:CheckIn:Read_GPS] Running Loop=1 2019-01-10T14:35:38.956Z,1547130938.956 [CommandLine](IMPORTANT): got command show variable Goby 2019-01-10T14:35:38.987Z,1547130938.987 [CommandLine](IMPORTANT): GobyModem.loadAtStartup (bool) 2019-01-10T14:35:38.988Z,1547130938.988 [CommandLine](IMPORTANT): GobyModem.simulateHardware (bool) 2019-01-10T14:35:38.988Z,1547130938.988 [CommandLine](IMPORTANT): GobyModem.modemType (none) 2019-01-10T14:35:38.988Z,1547130938.988 [CommandLine](IMPORTANT): GobyModem.networkIds (none) 2019-01-10T14:35:38.989Z,1547130938.989 [CommandLine](IMPORTANT): GobyModem.maxDistance (kilometer) 2019-01-10T14:35:38.989Z,1547130938.989 [CommandLine](IMPORTANT): GobyModem.transBaud (bit_per_second) 2019-01-10T14:35:39.006Z,1547130939.006 [CommandLine](IMPORTANT): GobyModem.loadControl (none) 2019-01-10T14:35:39.007Z,1547130939.007 [CommandLine](IMPORTANT): GobyModem.uart (none) 2019-01-10T14:35:39.007Z,1547130939.007 [CommandLine](IMPORTANT): GobyModem.baud (bit_per_second) 2019-01-10T14:35:39.009Z,1547130939.009 [CommandLine](IMPORTANT): GobyModem.platform_conversation (bool) 2019-01-10T14:35:39.123Z,1547130939.123 [CommandLine](IMPORTANT): GobyModem.durationOfLastRun (second) 2019-01-10T14:35:47.819Z,1547130947.819 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface 2019-01-10T14:35:47.819Z,1547130947.819 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 2 2019-01-10T14:35:47.820Z,1547130947.820 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault 2019-01-10T14:35:47.890Z,1547130947.890 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900 2019-01-10T14:35:48.219Z,1547130948.219 [AcousticModem_Benthos_ATM900](INFO): Powering down 2019-01-10T14:35:49.099Z,1547130949.099 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900 2019-01-10T14:35:49.099Z,1547130949.099 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 2 2019-01-10T14:35:51.061Z,1547130951.061 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = 1000537.020778 2019-01-10T14:35:51.061Z,1547130951.061 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3 2019-01-10T14:35:51.061Z,1547130951.061 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2019-01-10T14:35:51.131Z,1547130951.131 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2019-01-10T14:35:51.422Z,1547130951.422 [AcousticModem_Benthos_ATM900](INFO): Powering up 2019-01-10T14:35:51.422Z,1547130951.422 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900. 2019-01-10T14:35:51.587Z,1547130951.587 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2019-01-10T14:35:51.587Z,1547130951.587 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3 2019-01-10T14:35:51.861Z,1547130951.861 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-01-10T14:35:51.861Z,1547130951.861 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2019-01-10T14:35:51.862Z,1547130951.862 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2019-01-10T14:35:56.416Z,1547130956.416 [CommandLine](IMPORTANT): got command get GobyModem.modemType 2019-01-10T14:35:56.417Z,1547130956.417 [CommandLine](IMPORTANT): GobyModem.modemType benthos_atm900 2019-01-10T14:36:11.644Z,1547130971.644 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface 2019-01-10T14:36:11.644Z,1547130971.644 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 3 2019-01-10T14:36:11.644Z,1547130971.644 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault 2019-01-10T14:36:11.736Z,1547130971.736 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900 2019-01-10T14:36:12.040Z,1547130972.040 [AcousticModem_Benthos_ATM900](INFO): Powering down 2019-01-10T14:36:12.917Z,1547130972.917 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900 2019-01-10T14:36:12.917Z,1547130972.917 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 3 2019-01-10T14:36:14.804Z,1547130974.804 [CommandLine](IMPORTANT): got command quit 2019-01-10T14:36:15.241Z,1547130975.241 [AcousticModem_Benthos_ATM900](INFO): Powering up 2019-01-10T14:36:15.242Z,1547130975.242 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900. 2019-01-10T14:36:15.811Z,1547130975.811 [Supervisor](INFO): Stop Mission called by Supervisor::terminate 2019-01-10T14:36:15.814Z,1547130975.814 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2019-01-10T14:36:15.814Z,1547130975.814 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-01-10T14:36:16.002Z,1547130976.002 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2019-01-10T14:36:16.003Z,1547130976.003 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-01-10T14:36:16.003Z,1547130976.003 [CommandLine](INFO): Join timeout helper Thread ID is 936 2019-01-10T14:36:16.004Z,1547130976.004 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2019-01-10T14:36:16.004Z,1547130976.004 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-01-10T14:36:16.004Z,1547130976.004 [NavChartDb](INFO): Join timeout helper Thread ID is 937 2019-01-10T14:36:16.187Z,1547130976.187 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2019-01-10T14:36:16.187Z,1547130976.187 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-01-10T14:36:16.203Z,1547130976.203 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2019-01-10T14:36:16.203Z,1547130976.203 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-01-10T14:36:16.203Z,1547130976.203 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 938 2019-01-10T14:36:16.328Z,1547130976.328 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2019-01-10T14:36:16.328Z,1547130976.328 [WetLabsBB2FL](INFO): Powering down 2019-01-10T14:36:16.329Z,1547130976.329 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-01-10T14:36:16.343Z,1547130976.343 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler 2019-01-10T14:36:16.343Z,1547130976.343 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled. 2019-01-10T14:36:16.343Z,1547130976.343 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 939 2019-01-10T14:36:16.499Z,1547130976.499 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread. 2019-01-10T14:36:16.499Z,1547130976.499 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2019-01-10T14:36:16.701Z,1547130976.701 [Rowe_600LCM](INFO): Powering down 2019-01-10T14:36:16.702Z,1547130976.702 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled. 2019-01-10T14:36:16.707Z,1547130976.707 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2019-01-10T14:36:16.707Z,1547130976.707 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-01-10T14:36:16.708Z,1547130976.708 [Radio_Surface](INFO): Join timeout helper Thread ID is 941