2019-01-02T18:42:34.207Z,1546454554.207 [Supervisor](DEBUG): Initializing supervisor. 2019-01-02T18:42:34.210Z,1546454554.210 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2019-01-02T18:42:34.210Z,1546454554.210 [SyncHandler](INFO): Protected caller Thread ID is 2027 2019-01-02T18:42:34.211Z,1546454554.211 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2019-01-02T18:42:34.212Z,1546454554.212 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2019-01-02T18:42:34.212Z,1546454554.212 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2028 2019-01-02T18:42:34.215Z,1546454554.215 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2019-01-02T18:42:34.226Z,1546454554.226 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2019-01-02T18:42:34.227Z,1546454554.227 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2019-01-02T18:42:34.228Z,1546454554.228 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2029 2019-01-02T18:42:34.228Z,1546454554.228 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2019-01-02T18:42:34.229Z,1546454554.229 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2019-01-02T18:42:34.230Z,1546454554.230 [logger ThreadHandler](INFO): Protected caller Thread ID is 2030 2019-01-02T18:42:34.232Z,1546454554.232 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2019-01-02T18:42:34.232Z,1546454554.232 [Supervisor](INFO): Looking for Config files in directory: Config/ 2019-01-02T18:42:34.233Z,1546454554.233 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2019-01-02T18:42:34.328Z,1546454554.328 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2019-01-02T18:42:34.328Z,1546454554.328 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2019-01-02T18:42:34.425Z,1546454554.425 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2019-01-02T18:42:34.426Z,1546454554.426 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2019-01-02T18:42:34.612Z,1546454554.612 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2019-01-02T18:42:34.612Z,1546454554.612 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2019-01-02T18:42:34.963Z,1546454554.963 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2019-01-02T18:42:34.964Z,1546454554.964 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2019-01-02T18:42:35.278Z,1546454555.278 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2019-01-02T18:42:35.278Z,1546454555.278 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2019-01-02T18:42:35.805Z,1546454555.805 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2019-01-02T18:42:35.806Z,1546454555.806 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2019-01-02T18:42:36.481Z,1546454556.481 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2019-01-02T18:42:36.482Z,1546454556.482 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2019-01-02T18:42:36.919Z,1546454556.919 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2019-01-02T18:42:36.919Z,1546454556.919 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2019-01-02T18:42:36.998Z,1546454556.998 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2019-01-02T18:42:37.296Z,1546454557.296 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2019-01-02T18:42:37.297Z,1546454557.297 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2019-01-02T18:42:37.440Z,1546454557.440 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2019-01-02T18:42:37.441Z,1546454557.441 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2019-01-02T18:42:37.651Z,1546454557.651 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2019-01-02T18:42:37.652Z,1546454557.652 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2019-01-02T18:42:37.850Z,1546454557.850 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2019-01-02T18:42:37.850Z,1546454557.850 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2019-01-02T18:42:37.945Z,1546454557.945 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2019-01-02T18:42:37.946Z,1546454557.946 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2019-01-02T18:42:38.086Z,1546454558.086 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2019-01-02T18:42:38.088Z,1546454558.088 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2019-01-02T18:42:38.089Z,1546454558.089 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2019-01-02T18:42:38.315Z,1546454558.315 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2019-01-02T18:42:38.316Z,1546454558.316 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2019-01-02T18:42:38.417Z,1546454558.417 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2019-01-02T18:42:38.562Z,1546454558.562 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2019-01-02T18:42:38.652Z,1546454558.652 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2019-01-02T18:42:38.734Z,1546454558.734 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2019-01-02T18:42:38.893Z,1546454558.893 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2019-01-02T18:42:39.088Z,1546454559.088 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2019-01-02T18:42:39.183Z,1546454559.183 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2019-01-02T18:42:39.276Z,1546454559.276 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2019-01-02T18:42:39.371Z,1546454559.371 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2019-01-02T18:42:39.452Z,1546454559.452 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/ 2019-01-02T18:42:39.453Z,1546454559.453 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2019-01-02T18:42:39.459Z,1546454559.459 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2019-01-02T18:42:39.555Z,1546454559.555 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2019-01-02T18:42:39.556Z,1546454559.556 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2019-01-02T18:42:39.569Z,1546454559.569 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2019-01-02T18:42:39.569Z,1546454559.569 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2019-01-02T18:42:39.612Z,1546454559.612 [DepthRateCalculator] Loaded 2019-01-02T18:42:39.612Z,1546454559.612 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2019-01-02T18:42:39.618Z,1546454559.618 [PitchRateCalculator] Loaded 2019-01-02T18:42:39.618Z,1546454559.618 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2019-01-02T18:42:39.634Z,1546454559.634 [SpeedCalculator] Loaded 2019-01-02T18:42:39.634Z,1546454559.634 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2019-01-02T18:42:39.654Z,1546454559.654 [TempGradientCalculator] Loaded 2019-01-02T18:42:39.655Z,1546454559.655 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2019-01-02T18:42:39.660Z,1546454559.660 [YawRateCalculator] Loaded 2019-01-02T18:42:39.661Z,1546454559.661 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2019-01-02T18:42:39.699Z,1546454559.699 [ElevatorOffsetCalculator] Loaded 2019-01-02T18:42:39.700Z,1546454559.700 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2019-01-02T18:42:39.700Z,1546454559.700 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2019-01-02T18:42:39.701Z,1546454559.701 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2019-01-02T18:42:39.726Z,1546454559.726 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2019-01-02T18:42:39.727Z,1546454559.727 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2019-01-02T18:42:42.494Z,1546454562.494 [DataOverHttps] Loaded 2019-01-02T18:42:42.494Z,1546454562.494 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2019-01-02T18:42:42.533Z,1546454562.533 [Depth_Keller] Loaded 2019-01-02T18:42:42.533Z,1546454562.533 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2019-01-02T18:42:42.542Z,1546454562.542 [GobyModem] Loaded 2019-01-02T18:42:42.542Z,1546454562.542 [ComponentRegistry](DEBUG): SyncComponent "GobyModem" handled in the control thread. 2019-01-02T18:42:42.637Z,1546454562.637 [NAL9602] Loaded 2019-01-02T18:42:42.638Z,1546454562.638 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2019-01-02T18:42:42.653Z,1546454562.653 [Onboard] Loaded 2019-01-02T18:42:42.653Z,1546454562.653 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2019-01-02T18:42:42.663Z,1546454562.663 [Radio_Surface] Loaded 2019-01-02T18:42:42.663Z,1546454562.663 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2019-01-02T18:42:42.664Z,1546454562.664 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 419E04E0 2019-01-02T18:42:42.665Z,1546454562.665 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2110 2019-01-02T18:42:42.712Z,1546454562.712 [PNI_TCM] Loaded 2019-01-02T18:42:42.712Z,1546454562.712 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread. 2019-01-02T18:42:44.443Z,1546454564.443 [BPC1] Loaded 2019-01-02T18:42:44.443Z,1546454564.443 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2019-01-02T18:42:44.443Z,1546454564.443 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2019-01-02T18:42:44.444Z,1546454564.444 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2019-01-02T18:42:44.575Z,1546454564.575 [SBIT](DEBUG): Construct Startup Built In Test. 2019-01-02T18:42:44.598Z,1546454564.598 [SBIT] Loaded 2019-01-02T18:42:44.598Z,1546454564.598 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2019-01-02T18:42:44.599Z,1546454564.599 [IBIT](DEBUG): Construct Initiated Built In Test. 2019-01-02T18:42:44.610Z,1546454564.610 [IBIT] Loaded 2019-01-02T18:42:44.610Z,1546454564.610 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2019-01-02T18:42:44.614Z,1546454564.614 [CBIT](DEBUG): Construct Continuous Built In Test. 2019-01-02T18:42:44.748Z,1546454564.748 [CBIT] Loaded 2019-01-02T18:42:44.748Z,1546454564.748 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2019-01-02T18:42:44.749Z,1546454564.749 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2019-01-02T18:42:44.749Z,1546454564.749 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2019-01-02T18:42:44.921Z,1546454564.921 [ESPComponent] Loaded 2019-01-02T18:42:44.921Z,1546454564.921 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2019-01-02T18:42:44.935Z,1546454564.935 [PAR_Licor] Loaded 2019-01-02T18:42:44.935Z,1546454564.935 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2019-01-02T18:42:44.983Z,1546454564.983 [WetLabsBB2FL] Loaded 2019-01-02T18:42:44.984Z,1546454564.984 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2019-01-02T18:42:44.985Z,1546454564.985 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 41AC04E0 2019-01-02T18:42:44.985Z,1546454564.985 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 2111 2019-01-02T18:42:44.986Z,1546454564.986 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2019-01-02T18:42:44.986Z,1546454564.986 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2019-01-02T18:42:45.218Z,1546454565.218 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2019-01-02T18:42:45.219Z,1546454565.219 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2019-01-02T18:42:45.284Z,1546454565.284 [VerticalControl](DEBUG): Construct VerticalControl. 2019-01-02T18:42:45.386Z,1546454565.386 [VerticalControl] Loaded 2019-01-02T18:42:45.387Z,1546454565.387 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2019-01-02T18:42:45.387Z,1546454565.387 [HorizontalControl](DEBUG): Construct HorizontalControl. 2019-01-02T18:42:45.446Z,1546454565.446 [HorizontalControl] Loaded 2019-01-02T18:42:45.446Z,1546454565.446 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2019-01-02T18:42:45.447Z,1546454565.447 [SpeedControl](DEBUG): Construct SpeedControl. 2019-01-02T18:42:45.452Z,1546454565.452 [SpeedControl] Loaded 2019-01-02T18:42:45.452Z,1546454565.452 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2019-01-02T18:42:45.453Z,1546454565.453 [LoopControl](DEBUG): Construct LoopControl. 2019-01-02T18:42:45.453Z,1546454565.453 [LoopControl] Loaded 2019-01-02T18:42:45.454Z,1546454565.454 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2019-01-02T18:42:45.454Z,1546454565.454 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2019-01-02T18:42:45.455Z,1546454565.455 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2019-01-02T18:42:45.517Z,1546454565.517 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2019-01-02T18:42:45.518Z,1546454565.518 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2019-01-02T18:42:45.612Z,1546454565.612 [BuoyancyServo] Loaded 2019-01-02T18:42:45.612Z,1546454565.612 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2019-01-02T18:42:45.624Z,1546454565.624 [ElevatorServo] Loaded 2019-01-02T18:42:45.624Z,1546454565.624 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2019-01-02T18:42:45.634Z,1546454565.634 [MassServo] Loaded 2019-01-02T18:42:45.635Z,1546454565.635 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2019-01-02T18:42:45.646Z,1546454565.646 [RudderServo] Loaded 2019-01-02T18:42:45.646Z,1546454565.646 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2019-01-02T18:42:45.656Z,1546454565.656 [ThrusterServo] Loaded 2019-01-02T18:42:45.657Z,1546454565.657 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2019-01-02T18:42:45.657Z,1546454565.657 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2019-01-02T18:42:45.658Z,1546454565.658 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2019-01-02T18:42:45.753Z,1546454565.753 [DeadReckonUsingSpeedCalculator] Loaded 2019-01-02T18:42:45.753Z,1546454565.753 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2019-01-02T18:42:45.770Z,1546454565.770 [NavChart] Loaded 2019-01-02T18:42:45.770Z,1546454565.770 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2019-01-02T18:42:45.774Z,1546454565.774 [UniversalFixResidualReporter] Loaded 2019-01-02T18:42:45.774Z,1546454565.774 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2019-01-02T18:42:45.775Z,1546454565.775 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2019-01-02T18:42:45.778Z,1546454565.778 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2019-01-02T18:42:45.779Z,1546454565.779 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2019-01-02T18:42:45.786Z,1546454565.786 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2019-01-02T18:42:45.787Z,1546454565.787 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 41C1A4E0 2019-01-02T18:42:45.787Z,1546454565.787 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2112 2019-01-02T18:42:45.791Z,1546454565.791 [Supervisor](INFO): Main Thread ID is 2026 2019-01-02T18:42:45.792Z,1546454565.792 [Supervisor](DEBUG): Running supervisor. 2019-01-02T18:42:45.792Z,1546454565.792 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2113 2019-01-02T18:42:45.795Z,1546454565.795 [controlThread ThreadHandler](INFO): Handler Thread ID is 2114 2019-01-02T18:42:45.795Z,1546454565.795 [controlThread](DEBUG): Initializing ControlThread 2019-01-02T18:42:45.796Z,1546454565.796 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2019-01-02T18:42:45.796Z,1546454565.796 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2019-01-02T18:42:45.797Z,1546454565.797 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2019-01-02T18:42:45.797Z,1546454565.797 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2019-01-02T18:42:45.798Z,1546454565.798 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2019-01-02T18:42:45.798Z,1546454565.798 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2019-01-02T18:42:45.819Z,1546454565.819 [logger ThreadHandler](INFO): Handler Thread ID is 2115 2019-01-02T18:42:45.847Z,1546454565.847 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2116 2019-01-02T18:42:45.853Z,1546454565.853 [Radio_Surface](INFO): Powering up 2019-01-02T18:42:45.867Z,1546454565.867 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 2117 2019-01-02T18:42:45.868Z,1546454565.868 [WetLabsBB2FL](INFO): Powering down 2019-01-02T18:42:45.907Z,1546454565.907 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2118 2019-01-02T18:42:45.910Z,1546454565.910 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2019-01-02T18:42:45.910Z,1546454565.910 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2019-01-02T18:42:45.910Z,1546454565.910 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2019-01-02T18:42:45.911Z,1546454565.911 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2019-01-02T18:42:45.911Z,1546454565.911 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2019-01-02T18:42:45.911Z,1546454565.911 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2019-01-02T18:42:45.911Z,1546454565.911 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2019-01-02T18:42:45.911Z,1546454565.911 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2019-01-02T18:42:45.911Z,1546454565.911 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2019-01-02T18:42:45.912Z,1546454565.912 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2019-01-02T18:42:45.912Z,1546454565.912 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2019-01-02T18:42:45.912Z,1546454565.912 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2019-01-02T18:42:45.912Z,1546454565.912 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2019-01-02T18:42:45.912Z,1546454565.912 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2019-01-02T18:42:45.913Z,1546454565.913 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2019-01-02T18:42:45.913Z,1546454565.913 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2019-01-02T18:43:14.840Z,1546454594.840 [GobyModem](CRITICAL): exception at startup: Failed to startup. 2019-01-02T18:43:14.845Z,1546454594.845 [SBIT](INFO): Initialize SBIT Component. 2019-01-02T18:43:14.845Z,1546454594.845 [SBIT](IMPORTANT): git: 2018-12-19 2019-01-02T18:43:14.846Z,1546454594.846 [SBIT](INFO): git hash: f0e90a53519ed2f91f39351bc58b7b0f50855756 2019-01-02T18:43:14.846Z,1546454594.846 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2019-01-02T18:43:14.847Z,1546454594.847 [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-02T18:43:14.848Z,1546454594.848 [SBIT](INFO): Beginning SBIT in 24.000000 seconds. 2019-01-02T18:43:14.849Z,1546454594.849 [IBIT](INFO): Initialize IBIT Component. 2019-01-02T18:43:14.850Z,1546454594.850 [CBIT](DEBUG): Initialize CBIT Component. 2019-01-02T18:43:14.862Z,1546454594.862 [CBIT](DEBUG): Initialized mux pins. 2019-01-02T18:43:14.862Z,1546454594.862 [CBIT](DEBUG): Initializing the watchdog timer. 2019-01-02T18:43:14.899Z,1546454594.899 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2019-01-02T18:43:14.899Z,1546454594.899 [CBIT](DEBUG): Initializing heartbeat. 2019-01-02T18:43:14.970Z,1546454594.970 [CBIT](DEBUG): Deactivating GF circuits. 2019-01-02T18:43:14.971Z,1546454594.971 [CBIT](DEBUG): Deactivating emergency mode. 2019-01-02T18:43:15.011Z,1546454595.011 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2019-01-02T18:43:15.013Z,1546454595.013 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2019-01-02T18:43:15.013Z,1546454595.013 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2019-01-02T18:43:15.014Z,1546454595.014 [LoopControl](DEBUG): Initialize LoopControlComponent. 2019-01-02T18:43:15.016Z,1546454595.016 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-01-02T18:43:15.016Z,1546454595.016 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2019-01-02T18:43:15.017Z,1546454595.017 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2019-01-02T18:43:15.017Z,1546454595.017 [NavChart](DEBUG): Initialize NavChart Navigation. 2019-01-02T18:43:15.018Z,1546454595.018 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2019-01-02T18:43:15.019Z,1546454595.019 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2019-01-02T18:43:15.038Z,1546454595.038 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2019-01-02T18:43:15.109Z,1546454595.109 [MissionManager](DEBUG): 2019-01-02T18:43:15.110Z,1546454595.110 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2019-01-02T18:43:15.186Z,1546454595.186 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2019-01-02T18:43:15.187Z,1546454595.187 [Default:A.Wait](DEBUG): Construct Wait. 2019-01-02T18:43:15.188Z,1546454595.188 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2019-01-02T18:43:15.243Z,1546454595.243 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2019-01-02T18:43:15.246Z,1546454595.246 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2019-01-02T18:43:15.267Z,1546454595.267 [Default:E.Execute](DEBUG): Construct Execute. 2019-01-02T18:43:15.271Z,1546454595.271 [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-02T18:43:15.282Z,1546454595.282 [controlThread](DEBUG): Component order: CycleStarter,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-02T18:43:15.307Z,1546454595.307 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2019-01-02T18:43:15.417Z,1546454595.417 [NAL9602](INFO): Powering up NAL9602 2019-01-02T18:43:15.516Z,1546454595.516 [ESPComponent](INFO): powering down ESP 2019-01-02T18:43:16.015Z,1546454596.015 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2019-01-02T18:43:16.023Z,1546454596.023 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2019-01-02T18:43:16.045Z,1546454596.045 [ElevatorServo](DEBUG): Initializing EZServoServo. 2019-01-02T18:43:16.051Z,1546454596.051 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2019-01-02T18:43:16.056Z,1546454596.056 [MassServo](DEBUG): Initializing EZServoServo. 2019-01-02T18:43:16.063Z,1546454596.063 [MassServo](DEBUG): Initializing MassServo. 2019-01-02T18:43:16.068Z,1546454596.068 [RudderServo](DEBUG): Initializing EZServoServo. 2019-01-02T18:43:16.079Z,1546454596.079 [RudderServo](DEBUG): Initializing RudderServo. 2019-01-02T18:43:16.100Z,1546454596.100 [ThrusterServo](DEBUG): Initializing EZServoServo. 2019-01-02T18:43:16.107Z,1546454596.107 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2019-01-02T18:43:16.155Z,1546454596.155 [CommandLine](FAULT): Scheduling is paused 2019-01-02T18:43:16.156Z,1546454596.156 [CBIT](INFO): Critical error at 20190102T184314 2019-01-02T18:43:16.156Z,1546454596.156 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2019-01-02T18:43:16.991Z,1546454596.991 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout 2019-01-02T18:43:16.991Z,1546454596.991 [BuoyancyServo](FAULT): Buoyancy failed to initialize 2019-01-02T18:43:16.991Z,1546454596.991 [BuoyancyServo] Communications Fault, FailCount= 1 2019-01-02T18:43:16.991Z,1546454596.991 [BuoyancyServo](ERROR): Communications Fault 2019-01-02T18:43:17.202Z,1546454597.202 [CBIT](ERROR): Communications Fault in component: BuoyancyServo 2019-01-02T18:43:19.375Z,1546454599.375 [CBIT](INFO): Clearing failed state for component BuoyancyServo 2019-01-02T18:43:19.375Z,1546454599.375 [BuoyancyServo] No Fault, FailCount= 1 2019-01-02T18:43:19.672Z,1546454599.672 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2019-01-02T18:43:19.787Z,1546454599.787 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2019-01-02T18:43:25.116Z,1546454605.116 [CBIT](CRITICAL): Environmental Failure. Press:14.883087 PSI. Humidity:19%. Temp:24 C. ABORTING MISSION 2019-01-02T18:43:25.293Z,1546454605.293 [CBIT](INFO): Critical error at 20190102T184325 2019-01-02T18:43:26.021Z,1546454606.021 [GobyModem](INFO): Added slot 1 2019-01-02T18:43:26.418Z,1546454606.418 [NAL9602](INFO): NAL9602 initialized 2019-01-02T18:43:39.263Z,1546454619.263 [SBIT](IMPORTANT): Beginning Startup BIT 2019-01-02T18:43:39.267Z,1546454619.267 [CBIT](IMPORTANT): Beginning ground fault scan 2019-01-02T18:43:50.267Z,1546454630.267 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.015695 CHAN A1 (24V): -0.019056 CHAN A2 (12V): -0.005260 CHAN A3 (5V): -0.002543 CHAN B0 (3.3V): -0.000981 CHAN B1 (3.15aV): -0.001597 CHAN B2 (3.15bV): -0.000707 CHAN B3 (GND): 0.000124 OPEN: 0.004034 Full Scale Calc: 4.765 mA, -1.589 mA 2019-01-02T18:43:58.132Z,1546454638.132 [CommandLine](IMPORTANT): got command failComponent 2019-01-02T18:43:58.132Z,1546454638.132 [CommandLine](IMPORTANT): Failed components: 2019-01-02T18:43:58.133Z,1546454638.133 [CommandLine](IMPORTANT): No failed Components. 2019-01-02T18:44:08.699Z,1546454648.699 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.latitude_fix 36.799999 degree 2019-01-02T18:44:08.701Z,1546454648.701 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.latitude_fix" handled in the control thread. 2019-01-02T18:44:08.701Z,1546454648.701 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.longitude_fix -121.900002 degree 2019-01-02T18:44:08.751Z,1546454648.751 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.longitude_fix" handled in the control thread. 2019-01-02T18:44:08.819Z,1546454648.819 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,GobyModem,NAL9602,Onboard,PNI_TCM,BPC1,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,Maintain_NAL9602.latitude_fix,Maintain_NAL9602.longitude_fix,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-02T18:44:09.169Z,1546454649.169 [DeadReckonUsingSpeedCalculator](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-01-02T18:44:09.169Z,1546454649.169 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1 2019-01-02T18:44:09.169Z,1546454649.169 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2019-01-02T18:44:09.312Z,1546454649.312 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2019-01-02T18:44:09.579Z,1546454649.579 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2019-01-02T18:44:09.579Z,1546454649.579 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1 2019-01-02T18:44:09.952Z,1546454649.952 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-01-02T18:44:09.953Z,1546454649.953 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2019-01-02T18:44:09.953Z,1546454649.953 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2019-01-02T18:44:10.362Z,1546454650.362 [DeadReckonUsingSpeedCalculator](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-01-02T18:44:10.362Z,1546454650.362 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2 2019-01-02T18:44:10.362Z,1546454650.362 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2019-01-02T18:44:10.374Z,1546454650.374 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2019-01-02T18:44:10.777Z,1546454650.777 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2019-01-02T18:44:10.777Z,1546454650.777 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2 2019-01-02T18:44:11.166Z,1546454651.166 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-01-02T18:44:11.166Z,1546454651.166 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2019-01-02T18:44:11.167Z,1546454651.167 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2019-01-02T18:44:11.573Z,1546454651.573 [DeadReckonUsingSpeedCalculator](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-01-02T18:44:11.573Z,1546454651.573 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3 2019-01-02T18:44:11.573Z,1546454651.573 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2019-01-02T18:44:11.586Z,1546454651.586 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2019-01-02T18:44:11.980Z,1546454651.980 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2019-01-02T18:44:11.980Z,1546454651.980 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3 2019-01-02T18:44:12.355Z,1546454652.355 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-01-02T18:44:12.356Z,1546454652.356 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2019-01-02T18:44:12.356Z,1546454652.356 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2019-01-02T18:44:12.766Z,1546454652.766 [DeadReckonUsingSpeedCalculator](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-01-02T18:44:12.766Z,1546454652.766 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 4 2019-01-02T18:44:12.766Z,1546454652.766 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2019-01-02T18:44:12.778Z,1546454652.778 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2019-01-02T18:44:13.173Z,1546454653.173 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2019-01-02T18:44:13.173Z,1546454653.173 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 4 2019-01-02T18:44:13.561Z,1546454653.561 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-01-02T18:44:13.561Z,1546454653.561 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2019-01-02T18:44:13.562Z,1546454653.562 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2019-01-02T18:44:13.965Z,1546454653.965 [DeadReckonUsingSpeedCalculator](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-01-02T18:44:13.965Z,1546454653.965 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 5 2019-01-02T18:44:13.965Z,1546454653.965 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2019-01-02T18:44:13.977Z,1546454653.977 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2019-01-02T18:44:14.384Z,1546454654.384 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2019-01-02T18:44:14.384Z,1546454654.384 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 5 2019-01-02T18:44:14.747Z,1546454654.747 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-01-02T18:44:14.748Z,1546454654.748 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2019-01-02T18:44:14.748Z,1546454654.748 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2019-01-02T18:44:15.154Z,1546454655.154 [DeadReckonUsingSpeedCalculator](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-01-02T18:44:15.179Z,1546454655.179 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 6 2019-01-02T18:44:15.180Z,1546454655.180 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2019-01-02T18:44:15.208Z,1546454655.208 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2019-01-02T18:44:15.596Z,1546454655.596 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2019-01-02T18:44:15.596Z,1546454655.596 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 6 2019-01-02T18:44:16.008Z,1546454656.008 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-01-02T18:44:16.008Z,1546454656.008 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2019-01-02T18:44:16.009Z,1546454656.009 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2019-01-02T18:44:16.439Z,1546454656.439 [DeadReckonUsingSpeedCalculator](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-01-02T18:44:16.439Z,1546454656.439 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 7 2019-01-02T18:44:16.439Z,1546454656.439 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2019-01-02T18:44:16.463Z,1546454656.463 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2019-01-02T18:44:16.835Z,1546454656.835 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2019-01-02T18:44:16.835Z,1546454656.835 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 7 2019-01-02T18:44:17.179Z,1546454657.179 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-01-02T18:44:17.179Z,1546454657.179 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2019-01-02T18:44:17.179Z,1546454657.179 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2019-01-02T18:44:17.566Z,1546454657.566 [DeadReckonUsingSpeedCalculator](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-01-02T18:44:17.566Z,1546454657.566 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 8 2019-01-02T18:44:17.566Z,1546454657.566 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2019-01-02T18:44:17.578Z,1546454657.578 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2019-01-02T18:44:17.976Z,1546454657.976 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2019-01-02T18:44:17.976Z,1546454657.976 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 8 2019-01-02T18:44:18.361Z,1546454658.361 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-01-02T18:44:18.361Z,1546454658.361 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2019-01-02T18:44:18.362Z,1546454658.362 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2019-01-02T18:44:18.770Z,1546454658.770 [DeadReckonUsingSpeedCalculator](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-01-02T18:44:18.770Z,1546454658.770 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 9 2019-01-02T18:44:18.770Z,1546454658.770 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2019-01-02T18:44:18.782Z,1546454658.782 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2019-01-02T18:44:19.181Z,1546454659.181 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2019-01-02T18:44:19.181Z,1546454659.181 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 9 2019-01-02T18:44:19.548Z,1546454659.548 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-01-02T18:44:19.549Z,1546454659.549 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2019-01-02T18:44:19.549Z,1546454659.549 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2019-01-02T18:44:19.957Z,1546454659.957 [DeadReckonUsingSpeedCalculator](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-01-02T18:44:19.957Z,1546454659.957 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 10 2019-01-02T18:44:19.957Z,1546454659.957 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2019-01-02T18:44:19.994Z,1546454659.994 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2019-01-02T18:44:20.383Z,1546454660.383 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2019-01-02T18:44:20.383Z,1546454660.383 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 10 2019-01-02T18:44:20.753Z,1546454660.753 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-01-02T18:44:20.753Z,1546454660.753 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2019-01-02T18:44:20.753Z,1546454660.753 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2019-01-02T18:44:21.189Z,1546454661.189 [DeadReckonUsingSpeedCalculator](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-01-02T18:44:21.189Z,1546454661.189 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 11 2019-01-02T18:44:21.189Z,1546454661.189 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2019-01-02T18:44:21.379Z,1546454661.379 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2019-01-02T18:44:22.036Z,1546454662.036 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2019-01-02T18:44:22.036Z,1546454662.036 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 11 2019-01-02T18:44:22.113Z,1546454662.113 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-01-02T18:44:22.113Z,1546454662.113 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2019-01-02T18:44:22.114Z,1546454662.114 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2019-01-02T18:44:22.526Z,1546454662.526 [DeadReckonUsingSpeedCalculator](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-01-02T18:44:22.526Z,1546454662.526 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 12 2019-01-02T18:44:22.526Z,1546454662.526 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2019-01-02T18:44:22.632Z,1546454662.632 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2019-01-02T18:44:23.008Z,1546454663.008 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2019-01-02T18:44:23.008Z,1546454663.008 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 12 2019-01-02T18:44:23.289Z,1546454663.289 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-01-02T18:44:23.289Z,1546454663.289 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2019-01-02T18:44:23.290Z,1546454663.290 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2019-01-02T18:44:23.702Z,1546454663.702 [DeadReckonUsingSpeedCalculator](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-01-02T18:44:23.702Z,1546454663.702 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 13 2019-01-02T18:44:23.702Z,1546454663.702 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2019-01-02T18:44:23.816Z,1546454663.816 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2019-01-02T18:44:24.297Z,1546454664.297 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2019-01-02T18:44:24.297Z,1546454664.297 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 13 2019-01-02T18:44:24.485Z,1546454664.485 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-01-02T18:44:24.486Z,1546454664.486 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2019-01-02T18:44:24.486Z,1546454664.486 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2019-01-02T18:44:24.908Z,1546454664.908 [DeadReckonUsingSpeedCalculator](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-01-02T18:44:24.908Z,1546454664.908 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 14 2019-01-02T18:44:24.908Z,1546454664.908 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2019-01-02T18:44:24.968Z,1546454664.968 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2019-01-02T18:44:25.344Z,1546454665.344 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2019-01-02T18:44:25.344Z,1546454665.344 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 14 2019-01-02T18:44:25.683Z,1546454665.683 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-01-02T18:44:25.684Z,1546454665.684 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2019-01-02T18:44:25.684Z,1546454665.684 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2019-01-02T18:44:26.086Z,1546454666.086 [DeadReckonUsingSpeedCalculator](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-01-02T18:44:26.086Z,1546454666.086 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 15 2019-01-02T18:44:26.086Z,1546454666.086 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2019-01-02T18:44:26.098Z,1546454666.098 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2019-01-02T18:44:26.537Z,1546454666.537 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2019-01-02T18:44:26.537Z,1546454666.537 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 15 2019-01-02T18:44:26.893Z,1546454666.893 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-01-02T18:44:26.894Z,1546454666.894 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2019-01-02T18:44:26.894Z,1546454666.894 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2019-01-02T18:44:27.296Z,1546454667.296 [DeadReckonUsingSpeedCalculator](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-01-02T18:44:27.296Z,1546454667.296 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 16 2019-01-02T18:44:27.296Z,1546454667.296 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2019-01-02T18:44:27.308Z,1546454667.308 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2019-01-02T18:44:27.738Z,1546454667.738 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2019-01-02T18:44:27.738Z,1546454667.738 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 16 2019-01-02T18:44:28.087Z,1546454668.087 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-01-02T18:44:28.088Z,1546454668.088 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2019-01-02T18:44:28.088Z,1546454668.088 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2019-01-02T18:44:28.487Z,1546454668.487 [DeadReckonUsingSpeedCalculator](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-01-02T18:44:28.487Z,1546454668.487 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 17 2019-01-02T18:44:28.487Z,1546454668.487 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2019-01-02T18:44:28.499Z,1546454668.499 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2019-01-02T18:44:28.913Z,1546454668.913 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2019-01-02T18:44:28.913Z,1546454668.913 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 17 2019-01-02T18:44:29.171Z,1546454669.171 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1546454656.000000 second 2019-01-02T18:44:29.293Z,1546454669.293 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-01-02T18:44:29.294Z,1546454669.294 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2019-01-02T18:44:29.298Z,1546454669.298 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2019-01-02T18:44:33.301Z,1546454673.301 [SBIT](IMPORTANT): SBIT PASSED 2019-01-02T18:44:33.372Z,1546454673.372 [CommandLine](IMPORTANT): got command configSet list 2019-01-02T18:44:33.372Z,1546454673.372 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2019-01-02T18:44:33.373Z,1546454673.373 [CommandLine](IMPORTANT): Aanderaa_O2.loadAtStartup=0 bool; 2019-01-02T18:44:33.373Z,1546454673.373 [CommandLine](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool; 2019-01-02T18:44:33.373Z,1546454673.373 [CommandLine](IMPORTANT): DropWeight.loadAtStartup=0 bool; 2019-01-02T18:44:33.373Z,1546454673.373 [CommandLine](IMPORTANT): PAR_Licor.loadAtStartup=1 bool; 2019-01-02T18:44:33.373Z,1546454673.373 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=0 bool; 2019-01-02T18:44:33.713Z,1546454673.713 [MissionManager](IMPORTANT): Started mission Startup 2019-01-02T18:44:33.714Z,1546454673.714 [Startup] Running Loop=1 2019-01-02T18:44:33.714Z,1546454673.714 [Startup](DEBUG): Aggregate::initialize Startup 2019-01-02T18:44:33.714Z,1546454673.714 [Startup:A.GoToSurface] Running Loop=1 2019-01-02T18:44:33.714Z,1546454673.714 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-01-02T18:44:33.715Z,1546454673.715 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-01-02T18:44:33.715Z,1546454673.715 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-01-02T18:44:33.715Z,1546454673.715 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-01-02T18:44:33.716Z,1546454673.716 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-01-02T18:44:33.716Z,1546454673.716 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-01-02T18:44:33.721Z,1546454673.721 [Startup:StartupSatComms] Running Loop=1 2019-01-02T18:44:33.722Z,1546454673.722 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2019-01-02T18:44:33.722Z,1546454673.722 [Startup:StartupSatComms:A] Running Loop=1 2019-01-02T18:44:34.169Z,1546454674.169 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2019-01-02T18:44:34.170Z,1546454674.170 [Startup:StartupSatComms:A] Stopped 2019-01-02T18:44:34.171Z,1546454674.171 [Startup:StartupSatComms:B] Running Loop=1 2019-01-02T18:44:34.504Z,1546454674.504 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-01-02T18:44:35.036Z,1546454675.036 [CommandLine](IMPORTANT): got command show stack 2019-01-02T18:44:35.036Z,1546454675.036 [CommandLine](IMPORTANT): Behavior Stack: 2019-01-02T18:44:35.037Z,1546454675.037 [Startup](IMPORTANT): Priority 0: Startup:A.GoToSurface 2019-01-02T18:44:35.037Z,1546454675.037 [Startup:StartupSatComms](IMPORTANT): Priority 1: Startup:StartupSatComms:B 2019-01-02T18:44:40.252Z,1546454680.252 [CommandLine](IMPORTANT): got command get latitude 2019-01-02T18:44:40.253Z,1546454680.253 [CommandLine](IMPORTANT): latitude 36.799999 arcdeg 2019-01-02T18:44:49.319Z,1546454689.319 [CommandLine](IMPORTANT): got command set NAL9602.platform_communications 1.000000 bool 2019-01-02T18:44:49.689Z,1546454689.689 [Startup:StartupSatComms:B] Stopped 2019-01-02T18:44:49.689Z,1546454689.689 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2019-01-02T18:44:49.689Z,1546454689.689 [Startup:StartupSatComms] Stopped 2019-01-02T18:44:49.689Z,1546454689.689 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2019-01-02T18:44:49.690Z,1546454689.690 [Startup](INFO): Completed Startup 2019-01-02T18:44:49.690Z,1546454689.690 [MissionManager](INFO): Startup is completed. 2019-01-02T18:44:49.691Z,1546454689.691 [MissionManager](INFO): Uninitializing Mission Startup 2019-01-02T18:44:49.691Z,1546454689.691 [Startup] Stopped 2019-01-02T18:44:49.691Z,1546454689.691 [Startup](DEBUG): Aggregate::uninitialize Startup 2019-01-02T18:44:49.691Z,1546454689.691 [Startup:A.GoToSurface] Stopped 2019-01-02T18:44:49.691Z,1546454689.691 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-01-02T18:44:50.096Z,1546454690.096 [MissionManager](IMPORTANT): Started mission Default 2019-01-02T18:44:50.097Z,1546454690.097 [Default] Running Loop=1 2019-01-02T18:44:50.097Z,1546454690.097 [Default](DEBUG): Aggregate::initialize Default 2019-01-02T18:44:50.097Z,1546454690.097 [Default:B.GoToSurface] Running Loop=1 2019-01-02T18:44:50.097Z,1546454690.097 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-01-02T18:44:50.097Z,1546454690.097 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-01-02T18:44:50.097Z,1546454690.097 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-01-02T18:44:50.098Z,1546454690.098 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-01-02T18:44:50.098Z,1546454690.098 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-01-02T18:44:50.099Z,1546454690.099 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-01-02T18:44:50.099Z,1546454690.099 [Default:A.Wait] Running Loop=1 2019-01-02T18:44:50.099Z,1546454690.099 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-01-02T18:45:00.820Z,1546454700.820 [CommandLine](IMPORTANT): got command run ./Missions/Demo/senddata_direct_test.xml 2019-01-02T18:45:00.821Z,1546454700.821 [MissionManager](INFO): Loading Mission: ./Missions/Demo/senddata_direct_test.xml 2019-01-02T18:45:00.871Z,1546454700.871 [MissionManager](DEBUG): 2019-01-02T18:45:00.899Z,1546454700.899 [CommandLine](IMPORTANT): Running ./Missions/Demo/senddata_direct_test.xml 2019-01-02T18:45:00.937Z,1546454700.937 [Default] Stopped 2019-01-02T18:45:00.937Z,1546454700.937 [Default](DEBUG): Aggregate::uninitialize Default 2019-01-02T18:45:00.937Z,1546454700.937 [Default:A.Wait] Stopped 2019-01-02T18:45:00.937Z,1546454700.937 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-01-02T18:45:00.938Z,1546454700.938 [Default:B.GoToSurface] Stopped 2019-01-02T18:45:00.938Z,1546454700.938 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-01-02T18:45:00.938Z,1546454700.938 [MissionManager](IMPORTANT): Started mission senddata_direct_test 2019-01-02T18:45:00.938Z,1546454700.938 [senddata_direct_test] Running Loop=1 2019-01-02T18:45:00.938Z,1546454700.938 [senddata_direct_test](DEBUG): Aggregate::initialize senddata_direct_test 2019-01-02T18:45:00.942Z,1546454700.942 [senddata_direct_test:A] Running Loop=1 2019-01-02T18:45:00.944Z,1546454700.944 [senddata_direct_test:A] Stopped 2019-01-02T18:45:00.944Z,1546454700.944 [senddata_direct_test:B] Running Loop=1 2019-01-02T18:45:01.248Z,1546454701.248 [GobyModem](INFO): modem://1: set _.pressure 102603.031250 pascal 2019-01-02T18:45:01.331Z,1546454701.331 [senddata_direct_test:B] Stopped 2019-01-02T18:45:01.331Z,1546454701.331 [senddata_direct_test:C] Running Loop=1 2019-01-02T18:45:01.651Z,1546454701.651 [GobyModem](INFO): modem://1: set _.temperature 23.292627 celsius 2019-01-02T18:45:01.718Z,1546454701.718 [senddata_direct_test:C] Stopped 2019-01-02T18:45:01.718Z,1546454701.718 [senddata_direct_test](INFO): Completed senddata_direct_test 2019-01-02T18:45:01.722Z,1546454701.722 [MissionManager](INFO): senddata_direct_test is completed. 2019-01-02T18:45:01.723Z,1546454701.723 [MissionManager](INFO): Uninitializing Mission senddata_direct_test 2019-01-02T18:45:01.723Z,1546454701.723 [senddata_direct_test] Stopped 2019-01-02T18:45:01.723Z,1546454701.723 [senddata_direct_test](DEBUG): Aggregate::uninitialize senddata_direct_test 2019-01-02T18:45:02.052Z,1546454702.052 [GobyModem](INFO): modem://1: set _.humidity 19.374924 percent 2019-01-02T18:45:02.114Z,1546454702.114 [MissionManager](IMPORTANT): Started mission Default 2019-01-02T18:45:02.114Z,1546454702.114 [Default] Running Loop=1 2019-01-02T18:45:02.114Z,1546454702.114 [Default](DEBUG): Aggregate::initialize Default 2019-01-02T18:45:02.114Z,1546454702.114 [Default:B.GoToSurface] Running Loop=1 2019-01-02T18:45:02.114Z,1546454702.114 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-01-02T18:45:02.119Z,1546454702.119 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-01-02T18:45:02.119Z,1546454702.119 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-01-02T18:45:02.119Z,1546454702.119 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-01-02T18:45:02.119Z,1546454702.119 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-01-02T18:45:02.120Z,1546454702.120 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-01-02T18:45:02.120Z,1546454702.120 [Default:A.Wait] Running Loop=1 2019-01-02T18:45:02.120Z,1546454702.120 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-01-02T18:45:15.292Z,1546454715.292 [Default:A.Wait](INFO): Done Waiting. 2019-01-02T18:45:15.292Z,1546454715.292 [Default:A.Wait] Stopped 2019-01-02T18:45:15.293Z,1546454715.293 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-01-02T18:45:15.699Z,1546454715.699 [Default:CheckIn] Running Loop=1 2019-01-02T18:45:15.699Z,1546454715.699 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-01-02T18:45:15.700Z,1546454715.700 [Default:CheckIn:Read_GPS] Running Loop=1 2019-01-02T18:45:15.912Z,1546454715.912 [CommandLine](IMPORTANT): got command show variable netowrkId 2019-01-02T18:45:16.112Z,1546454716.112 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2019-01-02T18:45:20.324Z,1546454720.324 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004054 2019-01-02T18:45:21.708Z,1546454721.708 [CommandLine](IMPORTANT): got command show variable netowrkID 2019-01-02T18:45:26.395Z,1546454726.395 [CommandLine](IMPORTANT): got command show variable goby 2019-01-02T18:45:26.435Z,1546454726.435 [CommandLine](IMPORTANT): GobyModem.loadAtStartup (bool) 2019-01-02T18:45:26.436Z,1546454726.436 [CommandLine](IMPORTANT): GobyModem.simulateHardware (bool) 2019-01-02T18:45:26.436Z,1546454726.436 [CommandLine](IMPORTANT): GobyModem.modemType (none) 2019-01-02T18:45:26.436Z,1546454726.436 [CommandLine](IMPORTANT): GobyModem.networkIds (none) 2019-01-02T18:45:26.437Z,1546454726.437 [CommandLine](IMPORTANT): GobyModem.maxDistance (kilometer) 2019-01-02T18:45:26.437Z,1546454726.437 [CommandLine](IMPORTANT): GobyModem.transBaud (bit_per_second) 2019-01-02T18:45:26.483Z,1546454726.483 [CommandLine](IMPORTANT): GobyModem.loadControl (none) 2019-01-02T18:45:26.484Z,1546454726.484 [CommandLine](IMPORTANT): GobyModem.uart (none) 2019-01-02T18:45:26.484Z,1546454726.484 [CommandLine](IMPORTANT): GobyModem.baud (bit_per_second) 2019-01-02T18:45:26.485Z,1546454726.485 [CommandLine](IMPORTANT): GobyModem.platform_conversation (bool) 2019-01-02T18:45:26.530Z,1546454726.530 [CommandLine](IMPORTANT): GobyModem.durationOfLastRun (second) 2019-01-02T18:45:34.787Z,1546454734.787 [CommandLine](IMPORTANT): got command get GobyModem.networkIds 2019-01-02T18:45:34.787Z,1546454734.787 [CommandLine](IMPORTANT): GobyModem.networkIds 0,1 2019-01-02T18:45:57.534Z,1546454757.534 [CommandLine](IMPORTANT): got command run ./Missions/Demo/senddata_direct_test.xml 2019-01-02T18:45:57.536Z,1546454757.536 [MissionManager](INFO): Loading Mission: ./Missions/Demo/senddata_direct_test.xml 2019-01-02T18:45:57.628Z,1546454757.628 [MissionManager](DEBUG): 2019-01-02T18:45:57.630Z,1546454757.630 [CommandLine](IMPORTANT): Running ./Missions/Demo/senddata_direct_test.xml 2019-01-02T18:45:57.985Z,1546454757.985 [Default] Stopped 2019-01-02T18:45:57.985Z,1546454757.985 [Default](DEBUG): Aggregate::uninitialize Default 2019-01-02T18:45:57.985Z,1546454757.985 [Default:B.GoToSurface] Stopped 2019-01-02T18:45:57.985Z,1546454757.985 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-01-02T18:45:57.985Z,1546454757.985 [Default:CheckIn] Stopped 2019-01-02T18:45:57.985Z,1546454757.985 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-01-02T18:45:57.985Z,1546454757.985 [Default:CheckIn:Read_GPS] Stopped 2019-01-02T18:45:57.985Z,1546454757.985 [MissionManager](IMPORTANT): Started mission senddata_direct_test 2019-01-02T18:45:57.986Z,1546454757.986 [senddata_direct_test] Running Loop=1 2019-01-02T18:45:57.986Z,1546454757.986 [senddata_direct_test](DEBUG): Aggregate::initialize senddata_direct_test 2019-01-02T18:45:57.986Z,1546454757.986 [senddata_direct_test:A] Running Loop=1 2019-01-02T18:45:57.987Z,1546454757.987 [senddata_direct_test:A] Stopped 2019-01-02T18:45:57.987Z,1546454757.987 [senddata_direct_test:B] Running Loop=1 2019-01-02T18:45:58.324Z,1546454758.324 [GobyModem](INFO): modem://1: set _.pressure 102559.632812 pascal 2019-01-02T18:45:58.392Z,1546454758.392 [senddata_direct_test:B] Stopped 2019-01-02T18:45:58.392Z,1546454758.392 [senddata_direct_test:C] Running Loop=1 2019-01-02T18:45:58.724Z,1546454758.724 [GobyModem](INFO): modem://1: set _.temperature 23.292627 celsius 2019-01-02T18:45:58.796Z,1546454758.796 [senddata_direct_test:C] Stopped 2019-01-02T18:45:58.796Z,1546454758.796 [senddata_direct_test](INFO): Completed senddata_direct_test 2019-01-02T18:45:58.796Z,1546454758.796 [MissionManager](INFO): senddata_direct_test is completed. 2019-01-02T18:45:58.796Z,1546454758.796 [MissionManager](INFO): Uninitializing Mission senddata_direct_test 2019-01-02T18:45:58.796Z,1546454758.796 [senddata_direct_test] Stopped 2019-01-02T18:45:58.797Z,1546454758.797 [senddata_direct_test](DEBUG): Aggregate::uninitialize senddata_direct_test 2019-01-02T18:45:59.126Z,1546454759.126 [GobyModem](INFO): modem://1: set _.humidity 19.271151 percent 2019-01-02T18:45:59.245Z,1546454759.245 [MissionManager](IMPORTANT): Started mission Default 2019-01-02T18:45:59.246Z,1546454759.246 [Default] Running Loop=1 2019-01-02T18:45:59.246Z,1546454759.246 [Default](DEBUG): Aggregate::initialize Default 2019-01-02T18:45:59.246Z,1546454759.246 [Default:B.GoToSurface] Running Loop=1 2019-01-02T18:45:59.246Z,1546454759.246 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-01-02T18:45:59.246Z,1546454759.246 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-01-02T18:45:59.247Z,1546454759.247 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-01-02T18:45:59.247Z,1546454759.247 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-01-02T18:45:59.247Z,1546454759.247 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-01-02T18:45:59.248Z,1546454759.248 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-01-02T18:45:59.248Z,1546454759.248 [Default:A.Wait] Running Loop=1 2019-01-02T18:45:59.248Z,1546454759.248 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-01-02T18:46:12.473Z,1546454772.473 [Default:A.Wait](INFO): Done Waiting. 2019-01-02T18:46:12.474Z,1546454772.474 [Default:A.Wait] Stopped 2019-01-02T18:46:12.474Z,1546454772.474 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-01-02T18:46:12.799Z,1546454772.799 [Default:CheckIn] Running Loop=1 2019-01-02T18:46:12.799Z,1546454772.799 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-01-02T18:46:12.799Z,1546454772.799 [Default:CheckIn:Read_GPS] Running Loop=1 2019-01-02T18:47:00.748Z,1546454820.748 [CommandLine](IMPORTANT): got command quit 2019-01-02T18:47:01.755Z,1546454821.755 [Supervisor](INFO): Stop Mission called by Supervisor::terminate 2019-01-02T18:47:01.758Z,1546454821.758 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2019-01-02T18:47:01.758Z,1546454821.758 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-01-02T18:47:01.762Z,1546454821.762 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2019-01-02T18:47:01.763Z,1546454821.763 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-01-02T18:47:01.763Z,1546454821.763 [CommandLine](INFO): Join timeout helper Thread ID is 2144 2019-01-02T18:47:01.774Z,1546454821.774 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2019-01-02T18:47:01.775Z,1546454821.775 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-01-02T18:47:01.775Z,1546454821.775 [NavChartDb](INFO): Join timeout helper Thread ID is 2145 2019-01-02T18:47:01.803Z,1546454821.803 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2019-01-02T18:47:01.803Z,1546454821.803 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-01-02T18:47:01.815Z,1546454821.815 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2019-01-02T18:47:01.815Z,1546454821.815 [WetLabsBB2FL ThreadHandler](INFO):