2019-07-19T01:57:55.905Z,1563501475.905 [Supervisor](DEBUG): Initializing supervisor. 2019-07-19T01:57:55.908Z,1563501475.908 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2019-07-19T01:57:55.909Z,1563501475.909 [SyncHandler](INFO): Protected caller Thread ID is 5991 2019-07-19T01:57:55.909Z,1563501475.909 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2019-07-19T01:57:55.910Z,1563501475.910 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2019-07-19T01:57:55.911Z,1563501475.911 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 5992 2019-07-19T01:57:55.914Z,1563501475.914 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2019-07-19T01:57:55.927Z,1563501475.927 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2019-07-19T01:57:55.928Z,1563501475.928 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2019-07-19T01:57:55.928Z,1563501475.928 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 5993 2019-07-19T01:57:55.929Z,1563501475.929 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2019-07-19T01:57:55.930Z,1563501475.930 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2019-07-19T01:57:55.930Z,1563501475.930 [logger ThreadHandler](INFO): Protected caller Thread ID is 5994 2019-07-19T01:57:55.932Z,1563501475.932 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2019-07-19T01:57:55.933Z,1563501475.933 [Supervisor](INFO): Looking for Config files in directory: Config/ 2019-07-19T01:57:55.935Z,1563501475.935 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2019-07-19T01:57:56.101Z,1563501476.101 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2019-07-19T01:57:56.103Z,1563501476.103 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2019-07-19T01:57:56.326Z,1563501476.326 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2019-07-19T01:57:56.327Z,1563501476.327 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2019-07-19T01:57:56.475Z,1563501476.475 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2019-07-19T01:57:56.476Z,1563501476.476 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2019-07-19T01:57:57.113Z,1563501477.113 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2019-07-19T01:57:57.113Z,1563501477.113 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2019-07-19T01:57:57.606Z,1563501477.606 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2019-07-19T01:57:57.608Z,1563501477.608 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2019-07-19T01:57:58.130Z,1563501478.130 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2019-07-19T01:57:58.130Z,1563501478.130 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2019-07-19T01:57:58.471Z,1563501478.471 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2019-07-19T01:57:58.472Z,1563501478.472 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2019-07-19T01:57:59.291Z,1563501479.291 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2019-07-19T01:57:59.292Z,1563501479.292 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2019-07-19T01:57:59.719Z,1563501479.719 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2019-07-19T01:57:59.720Z,1563501479.720 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2019-07-19T01:57:59.881Z,1563501479.881 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2019-07-19T01:57:59.882Z,1563501479.882 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2019-07-19T01:57:59.994Z,1563501479.994 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2019-07-19T01:57:59.996Z,1563501479.996 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2019-07-19T01:58:00.083Z,1563501480.083 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2019-07-19T01:58:00.190Z,1563501480.190 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2019-07-19T01:58:00.191Z,1563501480.191 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2019-07-19T01:58:00.417Z,1563501480.417 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2019-07-19T01:58:00.418Z,1563501480.418 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2019-07-19T01:58:00.652Z,1563501480.652 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2019-07-19T01:58:00.654Z,1563501480.654 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2019-07-19T01:58:00.655Z,1563501480.655 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2019-07-19T01:58:00.745Z,1563501480.745 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2019-07-19T01:58:00.987Z,1563501480.987 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2019-07-19T01:58:00.988Z,1563501480.988 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2019-07-19T01:58:01.090Z,1563501481.090 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2019-07-19T01:58:01.274Z,1563501481.274 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2019-07-19T01:58:01.504Z,1563501481.504 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2019-07-19T01:58:01.595Z,1563501481.595 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2019-07-19T01:58:01.701Z,1563501481.701 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2019-07-19T01:58:01.801Z,1563501481.801 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2019-07-19T01:58:01.972Z,1563501481.972 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2019-07-19T01:58:02.086Z,1563501482.086 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2019-07-19T01:58:02.193Z,1563501482.193 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/ 2019-07-19T01:58:02.194Z,1563501482.194 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2019-07-19T01:58:02.208Z,1563501482.208 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2019-07-19T01:58:02.331Z,1563501482.331 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2019-07-19T01:58:02.332Z,1563501482.332 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2019-07-19T01:58:02.484Z,1563501482.484 [BuoyancyServo] Loaded 2019-07-19T01:58:02.484Z,1563501482.484 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2019-07-19T01:58:02.499Z,1563501482.499 [ElevatorServo] Loaded 2019-07-19T01:58:02.500Z,1563501482.500 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2019-07-19T01:58:02.515Z,1563501482.515 [MassServo] Loaded 2019-07-19T01:58:02.515Z,1563501482.515 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2019-07-19T01:58:02.530Z,1563501482.530 [RudderServo] Loaded 2019-07-19T01:58:02.531Z,1563501482.531 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2019-07-19T01:58:02.546Z,1563501482.546 [ThrusterServo] Loaded 2019-07-19T01:58:02.546Z,1563501482.546 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2019-07-19T01:58:02.546Z,1563501482.546 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2019-07-19T01:58:02.547Z,1563501482.547 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2019-07-19T01:58:02.703Z,1563501482.703 [SBIT](DEBUG): Construct Startup Built In Test. 2019-07-19T01:58:02.733Z,1563501482.733 [SBIT] Loaded 2019-07-19T01:58:02.733Z,1563501482.733 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2019-07-19T01:58:02.734Z,1563501482.734 [IBIT](DEBUG): Construct Initiated Built In Test. 2019-07-19T01:58:02.762Z,1563501482.762 [IBIT] Loaded 2019-07-19T01:58:02.763Z,1563501482.763 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2019-07-19T01:58:02.766Z,1563501482.766 [CBIT](DEBUG): Construct Continuous Built In Test. 2019-07-19T01:58:03.164Z,1563501483.164 [CBIT] Loaded 2019-07-19T01:58:03.164Z,1563501483.164 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2019-07-19T01:58:03.164Z,1563501483.164 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2019-07-19T01:58:03.165Z,1563501483.165 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2019-07-19T01:58:03.419Z,1563501483.419 [ESPComponent] Loaded 2019-07-19T01:58:03.419Z,1563501483.419 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2019-07-19T01:58:03.434Z,1563501483.434 [PAR_Licor] Loaded 2019-07-19T01:58:03.434Z,1563501483.434 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2019-07-19T01:58:03.435Z,1563501483.435 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2019-07-19T01:58:03.436Z,1563501483.436 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2019-07-19T01:58:03.486Z,1563501483.486 [DepthRateCalculator] Loaded 2019-07-19T01:58:03.486Z,1563501483.486 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2019-07-19T01:58:03.492Z,1563501483.492 [PitchRateCalculator] Loaded 2019-07-19T01:58:03.492Z,1563501483.492 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2019-07-19T01:58:03.508Z,1563501483.508 [SpeedCalculator] Loaded 2019-07-19T01:58:03.508Z,1563501483.508 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2019-07-19T01:58:03.530Z,1563501483.530 [TempGradientCalculator] Loaded 2019-07-19T01:58:03.530Z,1563501483.530 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2019-07-19T01:58:03.536Z,1563501483.536 [YawRateCalculator] Loaded 2019-07-19T01:58:03.537Z,1563501483.537 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2019-07-19T01:58:03.571Z,1563501483.571 [ElevatorOffsetCalculator] Loaded 2019-07-19T01:58:03.571Z,1563501483.571 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2019-07-19T01:58:03.571Z,1563501483.571 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2019-07-19T01:58:03.572Z,1563501483.572 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2019-07-19T01:58:03.615Z,1563501483.615 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2019-07-19T01:58:03.615Z,1563501483.615 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2019-07-19T01:58:03.732Z,1563501483.732 [DeadReckonUsingMultipleVelocitySources] Loaded 2019-07-19T01:58:03.732Z,1563501483.732 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2019-07-19T01:58:03.754Z,1563501483.754 [NavChart] Loaded 2019-07-19T01:58:03.754Z,1563501483.754 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2019-07-19T01:58:03.758Z,1563501483.758 [UniversalFixResidualReporter] Loaded 2019-07-19T01:58:03.758Z,1563501483.758 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2019-07-19T01:58:03.759Z,1563501483.759 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2019-07-19T01:58:03.759Z,1563501483.759 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2019-07-19T01:58:04.193Z,1563501484.193 [DataOverHttps] Loaded 2019-07-19T01:58:04.193Z,1563501484.193 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2019-07-19T01:58:04.194Z,1563501484.194 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409134E0 2019-07-19T01:58:04.195Z,1563501484.195 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 6073 2019-07-19T01:58:04.208Z,1563501484.208 [Depth_Keller] Loaded 2019-07-19T01:58:04.209Z,1563501484.209 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2019-07-19T01:58:04.302Z,1563501484.302 [NAL9602] Loaded 2019-07-19T01:58:04.302Z,1563501484.302 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2019-07-19T01:58:04.308Z,1563501484.308 [Onboard] Loaded 2019-07-19T01:58:04.308Z,1563501484.308 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2019-07-19T01:58:04.311Z,1563501484.311 [Radio_Surface] Loaded 2019-07-19T01:58:04.312Z,1563501484.312 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2019-07-19T01:58:04.313Z,1563501484.313 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409434E0 2019-07-19T01:58:04.313Z,1563501484.313 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 6074 2019-07-19T01:58:04.443Z,1563501484.443 [DAT] Loaded 2019-07-19T01:58:04.443Z,1563501484.443 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2019-07-19T01:58:06.263Z,1563501486.263 [BPC1] Loaded 2019-07-19T01:58:06.263Z,1563501486.263 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2019-07-19T01:58:06.263Z,1563501486.263 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2019-07-19T01:58:06.264Z,1563501486.264 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2019-07-19T01:58:06.369Z,1563501486.369 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2019-07-19T01:58:06.369Z,1563501486.369 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2019-07-19T01:58:06.452Z,1563501486.452 [VerticalControl](DEBUG): Construct VerticalControl. 2019-07-19T01:58:06.539Z,1563501486.539 [VerticalControl] Loaded 2019-07-19T01:58:06.539Z,1563501486.539 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2019-07-19T01:58:06.540Z,1563501486.540 [HorizontalControl](DEBUG): Construct HorizontalControl. 2019-07-19T01:58:06.599Z,1563501486.599 [HorizontalControl] Loaded 2019-07-19T01:58:06.599Z,1563501486.599 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2019-07-19T01:58:06.600Z,1563501486.600 [SpeedControl](DEBUG): Construct SpeedControl. 2019-07-19T01:58:06.602Z,1563501486.602 [SpeedControl] Loaded 2019-07-19T01:58:06.602Z,1563501486.602 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2019-07-19T01:58:06.603Z,1563501486.603 [LoopControl](DEBUG): Construct LoopControl. 2019-07-19T01:58:06.604Z,1563501486.604 [LoopControl] Loaded 2019-07-19T01:58:06.604Z,1563501486.604 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2019-07-19T01:58:06.604Z,1563501486.604 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2019-07-19T01:58:06.605Z,1563501486.605 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2019-07-19T01:58:06.626Z,1563501486.626 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2019-07-19T01:58:06.627Z,1563501486.627 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2019-07-19T01:58:06.957Z,1563501486.957 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2019-07-19T01:58:06.961Z,1563501486.961 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2019-07-19T01:58:06.962Z,1563501486.962 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2019-07-19T01:58:06.969Z,1563501486.969 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2019-07-19T01:58:06.970Z,1563501486.970 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A7E4E0 2019-07-19T01:58:06.970Z,1563501486.970 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 6075 2019-07-19T01:58:06.975Z,1563501486.975 [Supervisor](INFO): Main Thread ID is 803 2019-07-19T01:58:06.975Z,1563501486.975 [Supervisor](DEBUG): Running supervisor. 2019-07-19T01:58:06.976Z,1563501486.976 [CommandLine ThreadHandler](INFO): Handler Thread ID is 6076 2019-07-19T01:58:06.978Z,1563501486.978 [controlThread ThreadHandler](INFO): Handler Thread ID is 6077 2019-07-19T01:58:06.979Z,1563501486.979 [controlThread](DEBUG): Initializing ControlThread 2019-07-19T01:58:06.980Z,1563501486.980 [SBIT](INFO): Initialize SBIT Component. 2019-07-19T01:58:06.981Z,1563501486.981 [SBIT](IMPORTANT): git: 2019-07-16 2019-07-19T01:58:06.981Z,1563501486.981 [SBIT](INFO): git hash: 5dde538a58d6fd4f55501de4ce986b4d4d3b120b 2019-07-19T01:58:06.982Z,1563501486.982 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2019-07-19T01:58:06.983Z,1563501486.983 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019 2019-07-19T01:58:06.984Z,1563501486.984 [SBIT](INFO): Beginning SBIT in 48.000000 seconds. 2019-07-19T01:58:06.985Z,1563501486.985 [IBIT](INFO): Initialize IBIT Component. 2019-07-19T01:58:06.985Z,1563501486.985 [CBIT](DEBUG): Initialize CBIT Component. 2019-07-19T01:58:06.986Z,1563501486.986 [logger ThreadHandler](INFO): Handler Thread ID is 6078 2019-07-19T01:58:06.997Z,1563501486.997 [CBIT](DEBUG): Initialized mux pins. 2019-07-19T01:58:06.997Z,1563501486.997 [CBIT](DEBUG): Initializing the watchdog timer. 2019-07-19T01:58:07.005Z,1563501487.005 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 6079 2019-07-19T01:58:07.006Z,1563501487.006 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2019-07-19T01:58:07.021Z,1563501487.021 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2019-07-19T01:58:07.021Z,1563501487.021 [CBIT](DEBUG): Initializing heartbeat. 2019-07-19T01:58:07.022Z,1563501487.022 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 6080 2019-07-19T01:58:07.033Z,1563501487.033 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 6081 2019-07-19T01:58:07.039Z,1563501487.039 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2019-07-19T01:58:07.039Z,1563501487.039 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2019-07-19T01:58:07.039Z,1563501487.039 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2019-07-19T01:58:07.040Z,1563501487.040 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2019-07-19T01:58:07.040Z,1563501487.040 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2019-07-19T01:58:07.040Z,1563501487.040 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2019-07-19T01:58:07.040Z,1563501487.040 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2019-07-19T01:58:07.040Z,1563501487.040 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2019-07-19T01:58:07.040Z,1563501487.040 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2019-07-19T01:58:07.041Z,1563501487.041 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2019-07-19T01:58:07.041Z,1563501487.041 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2019-07-19T01:58:07.041Z,1563501487.041 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2019-07-19T01:58:07.041Z,1563501487.041 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2019-07-19T01:58:07.041Z,1563501487.041 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2019-07-19T01:58:07.042Z,1563501487.042 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2019-07-19T01:58:07.042Z,1563501487.042 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2019-07-19T01:58:07.093Z,1563501487.093 [CBIT](DEBUG): Deactivating GF circuits. 2019-07-19T01:58:07.093Z,1563501487.093 [CBIT](DEBUG): Deactivating emergency mode. 2019-07-19T01:58:07.129Z,1563501487.129 [CBIT](DEBUG): Backplane powered. 2019-07-19T01:58:07.133Z,1563501487.133 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2019-07-19T01:58:07.134Z,1563501487.134 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2019-07-19T01:58:07.134Z,1563501487.134 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2019-07-19T01:58:07.134Z,1563501487.134 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2019-07-19T01:58:07.135Z,1563501487.135 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2019-07-19T01:58:07.135Z,1563501487.135 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2019-07-19T01:58:07.136Z,1563501487.136 [NavChart](DEBUG): Initialize NavChart Navigation. 2019-07-19T01:58:07.136Z,1563501487.136 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2019-07-19T01:58:07.146Z,1563501487.146 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2019-07-19T01:58:07.148Z,1563501487.148 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2019-07-19T01:58:07.148Z,1563501487.148 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2019-07-19T01:58:07.157Z,1563501487.157 [LoopControl](DEBUG): Initialize LoopControlComponent. 2019-07-19T01:58:07.158Z,1563501487.158 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2019-07-19T01:58:07.194Z,1563501487.194 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2019-07-19T01:58:07.234Z,1563501487.234 [MissionManager](DEBUG): 2019-07-19T01:58:07.235Z,1563501487.235 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2019-07-19T01:58:07.321Z,1563501487.321 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2019-07-19T01:58:07.322Z,1563501487.322 [Default:A.Wait](DEBUG): Construct Wait. 2019-07-19T01:58:07.324Z,1563501487.324 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2019-07-19T01:58:07.363Z,1563501487.363 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2019-07-19T01:58:07.365Z,1563501487.365 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2019-07-19T01:58:07.397Z,1563501487.397 [Default:E.Execute](DEBUG): Construct Execute. 2019-07-19T01:58:07.400Z,1563501487.400 [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-07-19T01:58:07.421Z,1563501487.421 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,Depth_Keller,NAL9602,Onboard,DAT,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2019-07-19T01:58:07.425Z,1563501487.425 [Radio_Surface](INFO): Powering up 2019-07-19T01:58:07.474Z,1563501487.474 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-07-19T01:58:07.474Z,1563501487.474 [DAT](INFO): Powering up 2019-07-19T01:58:07.474Z,1563501487.474 [DAT](DEBUG): Initializing DAT. 2019-07-19T01:58:07.477Z,1563501487.477 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-07-19T01:58:07.599Z,1563501487.599 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2019-07-19T01:58:07.605Z,1563501487.605 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2019-07-19T01:58:07.606Z,1563501487.606 [ElevatorServo](DEBUG): Initializing EZServoServo. 2019-07-19T01:58:07.613Z,1563501487.613 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2019-07-19T01:58:07.614Z,1563501487.614 [MassServo](DEBUG): Initializing EZServoServo. 2019-07-19T01:58:07.621Z,1563501487.621 [MassServo](DEBUG): Initializing MassServo. 2019-07-19T01:58:07.622Z,1563501487.622 [RudderServo](DEBUG): Initializing EZServoServo. 2019-07-19T01:58:07.637Z,1563501487.637 [RudderServo](DEBUG): Initializing RudderServo. 2019-07-19T01:58:07.638Z,1563501487.638 [ThrusterServo](DEBUG): Initializing EZServoServo. 2019-07-19T01:58:07.645Z,1563501487.645 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2019-07-19T01:58:08.589Z,1563501488.589 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2019-07-19T01:58:08.589Z,1563501488.589 [RudderServo](FAULT): Rudder failed to initialize 2019-07-19T01:58:08.589Z,1563501488.589 [RudderServo] Communications Fault, FailCount= 1 2019-07-19T01:58:08.589Z,1563501488.589 [RudderServo](ERROR): Communications Fault 2019-07-19T01:58:08.700Z,1563501488.700 [CBIT](ERROR): Communications Fault in component: RudderServo 2019-07-19T01:58:08.886Z,1563501488.886 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-07-19T01:58:08.886Z,1563501488.886 [RudderServo](INFO): Powering down 2019-07-19T01:58:09.567Z,1563501489.567 [RudderServo](DEBUG): Initializing EZServoServo. 2019-07-19T01:58:09.686Z,1563501489.686 [RudderServo](DEBUG): Initializing RudderServo. 2019-07-19T01:58:09.690Z,1563501489.690 [CBIT](INFO): Clearing failed state for component RudderServo 2019-07-19T01:58:09.690Z,1563501489.690 [RudderServo] No Fault, FailCount= 1 2019-07-19T01:58:22.868Z,1563501502.868 [DAT](INFO): setting local address to 3 2019-07-19T01:58:23.274Z,1563501503.274 [DAT](INFO): set local address to 3 2019-07-19T01:58:34.570Z,1563501514.570 [NAL9602](INFO): Powering up NAL9602 2019-07-19T01:58:45.478Z,1563501525.478 [NAL9602](INFO): NAL9602 initialized 2019-07-19T01:58:46.297Z,1563501526.297 [NAL9602](DEBUG): Fix Requested 2019-07-19T01:58:55.610Z,1563501535.610 [SBIT](IMPORTANT): Beginning Startup BIT 2019-07-19T01:58:55.642Z,1563501535.642 [CBIT](IMPORTANT): Beginning ground fault scan 2019-07-19T01:59:06.637Z,1563501546.637 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.012238 CHAN A1 (24V): -0.023955 CHAN A2 (12V): -0.005469 CHAN A3 (5V): -0.002687 CHAN B0 (3.3V): -0.000814 CHAN B1 (3.15aV): -0.000960 CHAN B2 (3.15bV): -0.000943 CHAN B3 (GND): 0.000115 OPEN: 0.007322 Full Scale Calc: 4.765 mA, -1.589 mA 2019-07-19T01:59:14.627Z,1563501554.627 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.latitude_fix 36.797001 degree 2019-07-19T01:59:14.628Z,1563501554.628 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.latitude_fix" handled in the control thread. 2019-07-19T01:59:14.938Z,1563501554.938 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,Depth_Keller,NAL9602,Onboard,DAT,BPC1,PAR_Licor,Depth_Keller,Maintain_NAL9602.latitude_fix,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2019-07-19T01:59:35.763Z,1563501575.763 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.longitude_fix -121.847000 degree 2019-07-19T01:59:35.764Z,1563501575.764 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.longitude_fix" handled in the control thread. 2019-07-19T01:59:35.873Z,1563501575.873 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,Depth_Keller,NAL9602,Onboard,DAT,BPC1,PAR_Licor,Depth_Keller,Maintain_NAL9602.latitude_fix,Maintain_NAL9602.longitude_fix,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2019-07-19T01:59:36.245Z,1563501576.245 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-07-19T01:59:36.245Z,1563501576.245 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2019-07-19T01:59:36.245Z,1563501576.245 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T01:59:36.257Z,1563501576.257 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:36.647Z,1563501576.647 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:36.647Z,1563501576.647 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2019-07-19T01:59:37.442Z,1563501577.442 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-07-19T01:59:37.442Z,1563501577.442 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2019-07-19T01:59:37.442Z,1563501577.442 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T01:59:37.929Z,1563501577.929 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:38.073Z,1563501578.073 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:38.073Z,1563501578.073 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2019-07-19T01:59:38.777Z,1563501578.777 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-07-19T01:59:38.777Z,1563501578.777 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2019-07-19T01:59:38.777Z,1563501578.777 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T01:59:38.878Z,1563501578.878 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:39.281Z,1563501579.281 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:39.281Z,1563501579.281 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2019-07-19T01:59:39.997Z,1563501579.997 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-07-19T01:59:39.997Z,1563501579.997 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2019-07-19T01:59:39.997Z,1563501579.997 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T01:59:40.197Z,1563501580.197 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:40.697Z,1563501580.697 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:40.697Z,1563501580.697 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2019-07-19T01:59:41.227Z,1563501581.227 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-07-19T01:59:41.227Z,1563501581.227 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2019-07-19T01:59:41.228Z,1563501581.228 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T01:59:41.277Z,1563501581.277 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:41.721Z,1563501581.721 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:41.721Z,1563501581.721 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2019-07-19T01:59:42.408Z,1563501582.408 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-07-19T01:59:42.408Z,1563501582.408 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2019-07-19T01:59:42.408Z,1563501582.408 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T01:59:42.418Z,1563501582.418 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:42.842Z,1563501582.842 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:42.842Z,1563501582.842 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2019-07-19T01:59:43.631Z,1563501583.631 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-07-19T01:59:43.631Z,1563501583.631 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2019-07-19T01:59:43.631Z,1563501583.631 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T01:59:43.640Z,1563501583.640 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:44.146Z,1563501584.146 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:44.146Z,1563501584.146 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2019-07-19T01:59:44.848Z,1563501584.848 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-07-19T01:59:44.848Z,1563501584.848 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2019-07-19T01:59:44.848Z,1563501584.848 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T01:59:44.858Z,1563501584.858 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:45.297Z,1563501585.297 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:45.297Z,1563501585.297 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2019-07-19T01:59:46.061Z,1563501586.061 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-07-19T01:59:46.061Z,1563501586.061 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9 2019-07-19T01:59:46.061Z,1563501586.061 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T01:59:46.071Z,1563501586.071 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:46.474Z,1563501586.474 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:46.474Z,1563501586.474 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9 2019-07-19T01:59:47.269Z,1563501587.269 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-07-19T01:59:47.269Z,1563501587.269 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10 2019-07-19T01:59:47.269Z,1563501587.269 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T01:59:47.278Z,1563501587.278 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:47.686Z,1563501587.686 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:47.686Z,1563501587.686 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10 2019-07-19T01:59:48.468Z,1563501588.468 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-07-19T01:59:48.468Z,1563501588.468 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11 2019-07-19T01:59:48.468Z,1563501588.468 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T01:59:48.477Z,1563501588.477 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:48.876Z,1563501588.876 [SBIT](IMPORTANT): SBIT PASSED 2019-07-19T01:59:48.894Z,1563501588.894 [CommandLine](IMPORTANT): got command configSet list 2019-07-19T01:59:48.894Z,1563501588.894 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2019-07-19T01:59:48.895Z,1563501588.895 [CommandLine](IMPORTANT): AHRS_M2.loadAtStartup=0 bool; 2019-07-19T01:59:48.895Z,1563501588.895 [CommandLine](IMPORTANT): Aanderaa_O2.loadAtStartup=0 bool; 2019-07-19T01:59:48.896Z,1563501588.896 [CommandLine](IMPORTANT): BuoyancyServo.fastPumpCoefficient=6 none; 2019-07-19T01:59:48.896Z,1563501588.896 [CommandLine](IMPORTANT): BuoyancyServo.fastPumpDepth=5 meter; 2019-07-19T01:59:48.896Z,1563501588.896 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup=0 bool; 2019-07-19T01:59:48.896Z,1563501588.896 [CommandLine](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool; 2019-07-19T01:59:48.896Z,1563501588.896 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup=0 bool; 2019-07-19T01:59:48.896Z,1563501588.896 [CommandLine](IMPORTANT): DropWeight.loadAtStartup=0 bool; 2019-07-19T01:59:48.896Z,1563501588.896 [CommandLine](IMPORTANT): Radio_Surface.loadAtStartup=1 bool; 2019-07-19T01:59:48.896Z,1563501588.896 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=378 cubic_centimeter; 2019-07-19T01:59:48.896Z,1563501588.896 [CommandLine](IMPORTANT): VerticalControl.kiDepthBuoy=0.3 reciprocal_second; 2019-07-19T01:59:48.896Z,1563501588.896 [CommandLine](IMPORTANT): VerticalControl.massDefault=-7 millimeter; 2019-07-19T01:59:48.897Z,1563501588.897 [CommandLine](IMPORTANT): WetLabsBB2FL.loadAtStartup=0 bool; 2019-07-19T01:59:48.906Z,1563501588.906 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:48.907Z,1563501588.907 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11 2019-07-19T01:59:49.286Z,1563501589.286 [MissionManager](IMPORTANT): Started mission Startup 2019-07-19T01:59:49.286Z,1563501589.286 [Startup] Running Loop=1 2019-07-19T01:59:49.286Z,1563501589.286 [Startup](DEBUG): Aggregate::initialize Startup 2019-07-19T01:59:49.286Z,1563501589.286 [Startup:A.GoToSurface] Running Loop=1 2019-07-19T01:59:49.286Z,1563501589.286 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-07-19T01:59:49.287Z,1563501589.287 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-07-19T01:59:49.287Z,1563501589.287 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-07-19T01:59:49.288Z,1563501589.288 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-07-19T01:59:49.288Z,1563501589.288 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-07-19T01:59:49.288Z,1563501589.288 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-07-19T01:59:49.290Z,1563501589.290 [Startup:StartupSatComms] Running Loop=1 2019-07-19T01:59:49.290Z,1563501589.290 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2019-07-19T01:59:49.290Z,1563501589.290 [Startup:StartupSatComms:A] Running Loop=1 2019-07-19T01:59:49.684Z,1563501589.684 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-07-19T01:59:49.684Z,1563501589.684 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12 2019-07-19T01:59:49.684Z,1563501589.684 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T01:59:49.686Z,1563501589.686 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2019-07-19T01:59:49.686Z,1563501589.686 [Startup:StartupSatComms:A] Stopped 2019-07-19T01:59:49.686Z,1563501589.686 [Startup:StartupSatComms:B] Running Loop=1 2019-07-19T01:59:49.695Z,1563501589.695 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:50.090Z,1563501590.090 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-07-19T01:59:50.099Z,1563501590.099 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:50.099Z,1563501590.099 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12 2019-07-19T01:59:50.905Z,1563501590.905 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-07-19T01:59:50.905Z,1563501590.905 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13 2019-07-19T01:59:50.905Z,1563501590.905 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T01:59:50.946Z,1563501590.946 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:51.322Z,1563501591.322 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:51.322Z,1563501591.322 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13 2019-07-19T01:59:52.109Z,1563501592.109 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-07-19T01:59:52.109Z,1563501592.109 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 14 2019-07-19T01:59:52.109Z,1563501592.109 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T01:59:52.119Z,1563501592.119 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:52.522Z,1563501592.522 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:52.522Z,1563501592.522 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 14 2019-07-19T01:59:53.329Z,1563501593.329 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-07-19T01:59:53.329Z,1563501593.329 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 15 2019-07-19T01:59:53.330Z,1563501593.330 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T01:59:53.339Z,1563501593.339 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:53.765Z,1563501593.765 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:53.765Z,1563501593.765 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 15 2019-07-19T01:59:54.537Z,1563501594.537 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-07-19T01:59:54.537Z,1563501594.537 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 16 2019-07-19T01:59:54.537Z,1563501594.537 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T01:59:54.547Z,1563501594.547 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:54.983Z,1563501594.983 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:54.983Z,1563501594.983 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 16 2019-07-19T01:59:55.761Z,1563501595.761 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-07-19T01:59:55.761Z,1563501595.761 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 17 2019-07-19T01:59:55.761Z,1563501595.761 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T01:59:55.771Z,1563501595.771 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:56.198Z,1563501596.198 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:56.198Z,1563501596.198 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 17 2019-07-19T01:59:56.981Z,1563501596.981 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-07-19T01:59:56.981Z,1563501596.981 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 18 2019-07-19T01:59:56.981Z,1563501596.981 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T01:59:56.991Z,1563501596.991 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:57.442Z,1563501597.442 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:57.442Z,1563501597.442 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 18 2019-07-19T01:59:58.174Z,1563501598.174 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-07-19T01:59:58.174Z,1563501598.174 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 19 2019-07-19T01:59:58.174Z,1563501598.174 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T01:59:58.184Z,1563501598.184 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:58.594Z,1563501598.594 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:58.594Z,1563501598.594 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 19 2019-07-19T01:59:59.375Z,1563501599.375 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-07-19T01:59:59.375Z,1563501599.375 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 20 2019-07-19T01:59:59.375Z,1563501599.375 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T01:59:59.385Z,1563501599.385 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:59.807Z,1563501599.807 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T01:59:59.807Z,1563501599.807 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 20 2019-07-19T02:00:00.587Z,1563501600.587 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-07-19T02:00:00.587Z,1563501600.587 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 21 2019-07-19T02:00:00.587Z,1563501600.587 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:00:00.636Z,1563501600.636 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:00:01.025Z,1563501601.025 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:00:01.025Z,1563501601.025 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 21 2019-07-19T02:00:01.812Z,1563501601.812 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-07-19T02:00:01.812Z,1563501601.812 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 22 2019-07-19T02:00:01.812Z,1563501601.812 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:00:01.822Z,1563501601.822 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:00:02.230Z,1563501602.230 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:00:02.230Z,1563501602.230 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 22 2019-07-19T02:00:03.014Z,1563501603.014 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-07-19T02:00:03.014Z,1563501603.014 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 23 2019-07-19T02:00:03.014Z,1563501603.014 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:00:03.024Z,1563501603.024 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:00:03.426Z,1563501603.426 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:00:03.426Z,1563501603.426 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 23 2019-07-19T02:00:04.234Z,1563501604.234 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-07-19T02:00:04.235Z,1563501604.235 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 24 2019-07-19T02:00:04.235Z,1563501604.235 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:00:04.277Z,1563501604.277 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:00:04.645Z,1563501604.645 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:00:04.645Z,1563501604.645 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 24 2019-07-19T02:00:05.436Z,1563501605.436 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2019-07-19T02:00:05.436Z,1563501605.436 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 25 2019-07-19T02:00:05.436Z,1563501605.436 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:00:05.446Z,1563501605.446 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:00:05.794Z,1563501605.794 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1563501568.000000 second 2019-07-19T02:00:05.865Z,1563501605.865 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:00:05.865Z,1563501605.865 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 25 2019-07-19T02:00:13.135Z,1563501613.135 [CommandLine](IMPORTANT): got command show stack 2019-07-19T02:00:13.135Z,1563501613.135 [CommandLine](IMPORTANT): Behavior Stack: 2019-07-19T02:00:13.135Z,1563501613.135 [Startup](IMPORTANT): Priority 0: Startup:A.GoToSurface 2019-07-19T02:00:13.136Z,1563501613.136 [Startup:StartupSatComms](IMPORTANT): Priority 1: Startup:StartupSatComms:B 2019-07-19T02:00:30.262Z,1563501630.262 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1563501568.000000 second 2019-07-19T02:00:46.579Z,1563501646.579 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004987 2019-07-19T02:00:49.882Z,1563501649.882 [Startup:StartupSatComms:B](INFO): Timed out from 2019-07-19T01:59:49.7Z 2019-07-19T02:00:49.882Z,1563501649.882 [Startup:StartupSatComms:B] Stopped 2019-07-19T02:00:49.883Z,1563501649.883 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2019-07-19T02:00:49.883Z,1563501649.883 [Startup:StartupSatComms] Stopped 2019-07-19T02:00:49.883Z,1563501649.883 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2019-07-19T02:00:49.883Z,1563501649.883 [Startup](INFO): Completed Startup 2019-07-19T02:00:49.884Z,1563501649.884 [MissionManager](INFO): Startup is completed. 2019-07-19T02:00:49.884Z,1563501649.884 [MissionManager](INFO): Uninitializing Mission Startup 2019-07-19T02:00:49.884Z,1563501649.884 [Startup] Stopped 2019-07-19T02:00:49.884Z,1563501649.884 [Startup](DEBUG): Aggregate::uninitialize Startup 2019-07-19T02:00:49.884Z,1563501649.884 [Startup:A.GoToSurface] Stopped 2019-07-19T02:00:49.884Z,1563501649.884 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-07-19T02:00:50.296Z,1563501650.296 [MissionManager](IMPORTANT): Started mission Default 2019-07-19T02:00:50.296Z,1563501650.296 [Default] Running Loop=1 2019-07-19T02:00:50.297Z,1563501650.297 [Default](DEBUG): Aggregate::initialize Default 2019-07-19T02:00:50.297Z,1563501650.297 [Default:B.GoToSurface] Running Loop=1 2019-07-19T02:00:50.297Z,1563501650.297 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-07-19T02:00:50.297Z,1563501650.297 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-07-19T02:00:50.297Z,1563501650.297 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-07-19T02:00:50.298Z,1563501650.298 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-07-19T02:00:50.298Z,1563501650.298 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-07-19T02:00:50.298Z,1563501650.298 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-07-19T02:00:50.299Z,1563501650.299 [Default:A.Wait] Running Loop=1 2019-07-19T02:00:50.299Z,1563501650.299 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-07-19T02:00:54.800Z,1563501654.800 [DataOverHttps](INFO): Sending 79 bytes from file Logs/20190718T183539/Courier0124.lzma 2019-07-19T02:00:55.607Z,1563501655.607 [DataOverHttps](INFO): Moved sent file to Logs/20190718T183539/Courier0124.lzma.bak 2019-07-19T02:00:55.607Z,1563501655.607 [DataOverHttps](INFO): SBD MOMSN=11455716 2019-07-19T02:01:03.614Z,1563501663.614 [Default:A.Wait](INFO): Done Waiting. 2019-07-19T02:01:03.614Z,1563501663.614 [Default:A.Wait] Stopped 2019-07-19T02:01:03.614Z,1563501663.614 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-07-19T02:01:04.035Z,1563501664.035 [Default:CheckIn] Running Loop=1 2019-07-19T02:01:04.035Z,1563501664.035 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-07-19T02:01:04.035Z,1563501664.035 [Default:CheckIn:Read_GPS] Running Loop=1 2019-07-19T02:01:04.494Z,1563501664.494 [CommandLine](IMPORTANT): got command run ./Missions/Science/esp_kiss.xml 2019-07-19T02:01:04.494Z,1563501664.494 [MissionManager](INFO): Loading Mission: ./Missions/Science/esp_kiss.xml 2019-07-19T02:01:04.633Z,1563501664.633 [MissionManager](INFO): DefineArg esp_kiss.MissionTimeout = 4.000000 h 2019-07-19T02:01:04.636Z,1563501664.636 [MissionManager](INFO): DefineArg esp_kiss.NeedCommsTime = 240.000000 min 2019-07-19T02:01:04.639Z,1563501664.639 [MissionManager](INFO): DefineArg esp_kiss.Depth = 2.500000 m 2019-07-19T02:01:04.642Z,1563501664.642 [MissionManager](INFO): DefineArg esp_kiss.ESPCartridgeType_1 = -4.000000 count 2019-07-19T02:01:04.645Z,1563501664.645 [MissionManager](INFO): DefineArg esp_kiss.ESPCartridgeType_2 = -9.000000 count 2019-07-19T02:01:04.648Z,1563501664.648 [MissionManager](INFO): DefineArg esp_kiss.ESPCartridgeType_3 = nan count 2019-07-19T02:01:04.651Z,1563501664.651 [MissionManager](INFO): DefineArg esp_kiss.ESPCartridgeType_4 = nan count 2019-07-19T02:01:04.654Z,1563501664.654 [MissionManager](INFO): DefineArg esp_kiss.WaitBeforeSample = 3.000000 min 2019-07-19T02:01:04.657Z,1563501664.657 [MissionManager](INFO): DefineArg esp_kiss.ApproachDepthTimeout = 20.000000 min 2019-07-19T02:01:04.660Z,1563501664.660 [MissionManager](INFO): DefineArg esp_kiss.DepthDeadband = 0.010000 m 2019-07-19T02:01:04.663Z,1563501664.663 [MissionManager](INFO): DefineArg esp_kiss.Speed = 0.000000 m/s 2019-07-19T02:01:04.666Z,1563501664.666 [MissionManager](INFO): DefineArg esp_kiss.MaxDepth = 5.000000 m 2019-07-19T02:01:04.715Z,1563501664.715 [MissionManager](INFO): DefineArg esp_kiss.PitchLimit = 20.000000 arcdeg 2019-07-19T02:01:04.718Z,1563501664.718 [MissionManager](INFO): DefineArg esp_kiss.MinOffshore = 1.000000 km 2019-07-19T02:01:04.721Z,1563501664.721 [MissionManager](INFO): DefineOutput esp_kiss.StartFromSurface = 1 bool 2019-07-19T02:01:04.722Z,1563501664.722 [esp_kiss:A.AbortSample](DEBUG): Construct. 2019-07-19T02:01:04.723Z,1563501664.723 [MissionManager](INFO): Inserting Stack: Missions/Insert/StandardEnvelopes.xml 2019-07-19T02:01:04.754Z,1563501664.754 [MissionManager](INFO): DefineArg esp_kiss:StandardEnvelopes.MinAltitude = 5.000000 m 2019-07-19T02:01:04.757Z,1563501664.757 [MissionManager](INFO): DefineArg esp_kiss:StandardEnvelopes.MaxDepth = 200.000000 m 2019-07-19T02:01:04.760Z,1563501664.760 [MissionManager](INFO): DefineArg esp_kiss:StandardEnvelopes.MinOffshore = 2000.000000 m 2019-07-19T02:01:04.781Z,1563501664.781 [esp_kiss:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2019-07-19T02:01:04.788Z,1563501664.788 [esp_kiss:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2019-07-19T02:01:04.861Z,1563501664.861 [esp_kiss:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope. 2019-07-19T02:01:04.888Z,1563501664.888 [MissionManager](INFO): Inserting Stack: Missions/Insert/NeedComms.xml 2019-07-19T02:01:04.974Z,1563501664.974 [MissionManager](INFO): DefineArg esp_kiss:NeedComms.DiveInterval = 3.000000 h 2019-07-19T02:01:04.977Z,1563501664.977 [MissionManager](INFO): DefineArg esp_kiss:NeedComms.WaitForPitchUp = 10.000000 min 2019-07-19T02:01:04.980Z,1563501664.980 [MissionManager](INFO): DefineArg esp_kiss:NeedComms.SurfacePitch = 20.000000 arcdeg 2019-07-19T02:01:04.983Z,1563501664.983 [MissionManager](INFO): DefineArg esp_kiss:NeedComms.SurfaceDepthRate = nan m/s 2019-07-19T02:01:04.986Z,1563501664.986 [MissionManager](INFO): DefineArg esp_kiss:NeedComms.SurfaceSpeed = 1.000000 m/s 2019-07-19T02:01:04.989Z,1563501664.989 [MissionManager](INFO): DefineArg esp_kiss:NeedComms.GPSTimeout = 7.000000 min 2019-07-19T02:01:04.992Z,1563501664.992 [MissionManager](INFO): DefineArg esp_kiss:NeedComms.CommsTimeout = 30.000000 min 2019-07-19T02:01:05.034Z,1563501665.034 [esp_kiss:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface. 2019-07-19T02:01:05.089Z,1563501665.089 [esp_kiss:I.Mass](DEBUG): Construct. 2019-07-19T02:01:05.094Z,1563501665.094 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml 2019-07-19T02:01:05.487Z,1563501665.487 [MissionManager](INFO): DefineArg esp_kiss:Science.SampleISUS = 0 bool 2019-07-19T02:01:05.492Z,1563501665.492 [MissionManager](INFO): DefineArg esp_kiss:Science.SampleISUSmaxPitch = 60.000000 arcdeg 2019-07-19T02:01:05.503Z,1563501665.503 [MissionManager](INFO): DefineArg esp_kiss:Science.SampleISUSminPitch = -60.000000 arcdeg 2019-07-19T02:01:05.507Z,1563501665.507 [MissionManager](INFO): DefineArg esp_kiss:Science.PeakDetectChlActive = 0 bool 2019-07-19T02:01:05.518Z,1563501665.518 [MissionManager](INFO): DefineArg esp_kiss:Science.TimeWindowPeakReport = nan min 2019-07-19T02:01:05.521Z,1563501665.521 [MissionManager](INFO): DefineArg esp_kiss:Science.HighestChlPeakReportActive = 0 bool 2019-07-19T02:01:05.524Z,1563501665.524 [MissionManager](INFO): DefineArg esp_kiss:Science.PatchTracking = 0 bool 2019-07-19T02:01:05.528Z,1563501665.528 [MissionManager](INFO): DefineArg esp_kiss:Science.FilterWidthHorizontal = 3.000000 count 2019-07-19T02:01:05.542Z,1563501665.542 [MissionManager](INFO): DefineArg esp_kiss:Science.NumProfilesSlidingwindow = 100.000000 count 2019-07-19T02:01:05.546Z,1563501665.546 [MissionManager](INFO): DefineArg esp_kiss:Science.OffPeakFractionHorizontal = 80.000000 % 2019-07-19T02:01:05.548Z,1563501665.548 [MissionManager](INFO): DefineArg esp_kiss:Science.PeakDetectNO3Active = 0 bool 2019-07-19T02:01:05.555Z,1563501665.555 [MissionManager](INFO): DefineArg esp_kiss:Science.PeakDetectOilActive = 0 bool 2019-07-19T02:01:05.561Z,1563501665.561 [MissionManager](INFO): DefineArg esp_kiss:Science.PeakDetectFDOMActive = 0 bool 2019-07-19T02:01:05.571Z,1563501665.571 [MissionManager](INFO): DefineArg esp_kiss:Science.UpwardDerivativeOfTemperatureActive = 0 bool 2019-07-19T02:01:05.579Z,1563501665.579 [MissionManager](INFO): DefineArg esp_kiss:Science.EnabledAanderaaO2 = 0.000000 bool 2019-07-19T02:01:05.583Z,1563501665.583 [MissionManager](INFO): DefineArg esp_kiss:Science.EnabledNeilBrown = 0.000000 bool 2019-07-19T02:01:05.586Z,1563501665.586 [MissionManager](INFO): DefineArg esp_kiss:Science.EnabledSeabird = 0.000000 bool 2019-07-19T02:01:05.641Z,1563501665.641 [MissionManager](INFO): DefineArg esp_kiss:Science.EnabledTurbulence_NPS = 0.000000 bool 2019-07-19T02:01:05.644Z,1563501665.644 [MissionManager](INFO): DefineArg esp_kiss:Science.EnabledWetLabsBB2FL = 0.000000 bool 2019-07-19T02:01:05.660Z,1563501665.660 [MissionManager](INFO): DefineArg esp_kiss:Science.EnabledWetLabsSeaOWL_UV_A = 0.000000 bool 2019-07-19T02:01:05.681Z,1563501665.681 [MissionManager](INFO): DefineArg esp_kiss:Science.EnabledWetLabsUBAT = 0.000000 bool 2019-07-19T02:01:05.684Z,1563501665.684 [MissionManager](INFO): DefineArg esp_kiss:Science.EnabledISUS = 0.000000 bool 2019-07-19T02:01:05.696Z,1563501665.696 [MissionManager](INFO): DefineArg esp_kiss:Science.LowPassWindowLength = 20.000000 count 2019-07-19T02:01:05.703Z,1563501665.703 [MissionManager](INFO): DefineArg esp_kiss:Science.MedianFilterLen = 5.000000 count 2019-07-19T02:01:05.717Z,1563501665.717 [MissionManager](INFO): DefineArg esp_kiss:Science.PeakChlShallowBound = nan m 2019-07-19T02:01:05.721Z,1563501665.721 [MissionManager](INFO): DefineArg esp_kiss:Science.PeakChlDeepBound = nan m 2019-07-19T02:01:05.729Z,1563501665.729 [MissionManager](INFO): DefineArg esp_kiss:Science.PeakShallowBound = nan m 2019-07-19T02:01:05.733Z,1563501665.733 [MissionManager](INFO): DefineArg esp_kiss:Science.PeakDeepBound = nan m 2019-07-19T02:01:05.753Z,1563501665.753 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakChl = 0.000000 ug/l 2019-07-19T02:01:05.756Z,1563501665.756 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakChlDepth = 0.000000 m 2019-07-19T02:01:05.768Z,1563501665.768 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakChlTemperature = 0.000000 degC 2019-07-19T02:01:05.775Z,1563501665.775 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakChlLatitude = nan arcdeg 2019-07-19T02:01:05.779Z,1563501665.779 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakChlLongitude = nan arcdeg 2019-07-19T02:01:05.790Z,1563501665.790 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakNO3 = 0.000000 umol/l 2019-07-19T02:01:05.797Z,1563501665.797 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakNO3Depth = 0.000000 m 2019-07-19T02:01:05.800Z,1563501665.800 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakNO3Latitude = nan arcdeg 2019-07-19T02:01:05.803Z,1563501665.803 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakNO3Longitude = nan arcdeg 2019-07-19T02:01:05.807Z,1563501665.807 [MissionManager](INFO): DefineOutput esp_kiss:Science.PatchChl = 0.000000 m 2019-07-19T02:01:05.830Z,1563501665.830 [MissionManager](INFO): DefineOutput esp_kiss:Science.PatchChlDepth = 0.000000 m 2019-07-19T02:01:05.845Z,1563501665.845 [MissionManager](INFO): DefineOutput esp_kiss:Science.PatchChlLatitude = nan arcdeg 2019-07-19T02:01:05.848Z,1563501665.848 [MissionManager](INFO): DefineOutput esp_kiss:Science.PatchChlLongitude = nan arcdeg 2019-07-19T02:01:05.864Z,1563501665.864 [MissionManager](INFO): DefineOutput esp_kiss:Science.PatchChlDistance = nan m 2019-07-19T02:01:05.867Z,1563501665.867 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakOil = 0.000000 kg/m3 2019-07-19T02:01:05.870Z,1563501665.870 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakOilDepth = 0.000000 m 2019-07-19T02:01:05.873Z,1563501665.873 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakOilLatitude = nan arcdeg 2019-07-19T02:01:05.876Z,1563501665.876 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakOilLongitude = nan arcdeg 2019-07-19T02:01:05.936Z,1563501665.936 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakFDOM = 0.000000 ppb 2019-07-19T02:01:05.939Z,1563501665.939 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakFDOMDepth = 0.000000 m 2019-07-19T02:01:05.942Z,1563501665.942 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakFDOMLatitude = nan arcdeg 2019-07-19T02:01:05.957Z,1563501665.957 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakFDOMLongitude = nan arcdeg 2019-07-19T02:01:05.960Z,1563501665.960 [MissionManager](INFO): DefineOutput esp_kiss:Science.PatchFDOMDistance = nan m 2019-07-19T02:01:05.989Z,1563501665.989 [esp_kiss:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2019-07-19T02:01:06.093Z,1563501666.093 [esp_kiss:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal. 2019-07-19T02:01:06.156Z,1563501666.156 [esp_kiss:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2019-07-19T02:01:06.176Z,1563501666.176 [esp_kiss:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2019-07-19T02:01:06.212Z,1563501666.212 [esp_kiss:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2019-07-19T02:01:06.267Z,1563501666.267 [esp_kiss:InitialDive:B.Buoyancy](DEBUG): Construct Buoyancy. 2019-07-19T02:01:06.272Z,1563501666.272 [esp_kiss:InitialDive:C.SetSpeed](DEBUG): Construct. 2019-07-19T02:01:06.276Z,1563501666.276 [esp_kiss:InitialDive:D.Point](DEBUG): Construct. 2019-07-19T02:01:06.307Z,1563501666.307 [esp_kiss:InitialDive:E.Pitch](DEBUG): Construct. 2019-07-19T02:01:06.350Z,1563501666.350 [esp_kiss:InitialDive:E.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute. 2019-07-19T02:01:06.378Z,1563501666.378 [esp_kiss:TargetDepth:B.SetSpeed](DEBUG): Construct. 2019-07-19T02:01:06.401Z,1563501666.401 [esp_kiss:TargetDepth:C.Pitch](DEBUG): Construct. 2019-07-19T02:01:06.452Z,1563501666.452 [esp_kiss:TargetDepth:Spinout:A.Buoyancy](DEBUG): Construct Buoyancy. 2019-07-19T02:01:06.462Z,1563501666.462 [esp_kiss:TargetDepth:Spinout:B.Point](DEBUG): Construct. 2019-07-19T02:01:06.531Z,1563501666.531 [MissionManager](INFO): Inserting Stack: Missions/Insert/SampleAtDepth.xml 2019-07-19T02:01:07.012Z,1563501667.012 [MissionManager](INFO): DefineArg esp_kiss:TargetDepth:GrabSamples:SampleAtDepth.TargetDepth = 5.000000 m 2019-07-19T02:01:07.074Z,1563501667.074 [MissionManager](INFO): DefineArg esp_kiss:TargetDepth:GrabSamples:SampleAtDepth.SettleTime = 10.000000 s 2019-07-19T02:01:07.078Z,1563501667.078 [MissionManager](INFO): DefineArg esp_kiss:TargetDepth:GrabSamples:SampleAtDepth.MaxWaitNotReachingDepth = 3.000000 h 2019-07-19T02:01:07.085Z,1563501667.085 [MissionManager](INFO): DefineArg esp_kiss:TargetDepth:GrabSamples:SampleAtDepth.RotateOnly = 0.000000 bool 2019-07-19T02:01:07.094Z,1563501667.094 [MissionManager](INFO): DefineArg esp_kiss:TargetDepth:GrabSamples:SampleAtDepth.UseCANONSampler = 0.000000 bool 2019-07-19T02:01:07.114Z,1563501667.114 [MissionManager](INFO): DefineArg esp_kiss:TargetDepth:GrabSamples:SampleAtDepth.UseESP = 1.000000 bool 2019-07-19T02:01:07.127Z,1563501667.127 [MissionManager](INFO): DefineArg esp_kiss:TargetDepth:GrabSamples:SampleAtDepth.ESPCartridgeType = nan count 2019-07-19T02:01:07.144Z,1563501667.144 [MissionManager](INFO): DefineArg esp_kiss:TargetDepth:GrabSamples:SampleAtDepth.CANONSamplerTriggerTimeout = 1.000000 min 2019-07-19T02:01:07.152Z,1563501667.152 [MissionManager](INFO): DefineArg esp_kiss:TargetDepth:GrabSamples:SampleAtDepth.CANONSamplerTimeout = 6.000000 min 2019-07-19T02:01:07.171Z,1563501667.171 [MissionManager](INFO): DefineArg esp_kiss:TargetDepth:GrabSamples:SampleAtDepth.BuoyancyNeutral = 377.999997 cc 2019-07-19T02:01:07.258Z,1563501667.258 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:ApproachDepth:B.Pitch](DEBUG): Construct. 2019-07-19T02:01:07.293Z,1563501667.293 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:ApproachDepth:B.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute. 2019-07-19T02:01:07.325Z,1563501667.325 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:A.Pitch](DEBUG): Construct. 2019-07-19T02:01:07.332Z,1563501667.332 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:C.Wait](DEBUG): Construct Wait. 2019-07-19T02:01:07.379Z,1563501667.379 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler:A_Timeout:B.Execute](DEBUG): Construct Execute. 2019-07-19T02:01:07.413Z,1563501667.413 [MissionManager](ERROR): Slate does not contain CTD_NeilBrown.bin_mean_sea_water_temperature 2019-07-19T02:01:07.413Z,1563501667.413 [MissionManager](ERROR): Slate does not contain celsius 2019-07-19T02:01:07.414Z,1563501667.414 [MissionManager](ERROR): Slate does not contain WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2019-07-19T02:01:07.414Z,1563501667.414 [MissionManager](ERROR): Slate does not contain microgram_per_liter 2019-07-19T02:01:07.418Z,1563501667.418 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleCANONSampler:E:A_Timeout:B.Execute](DEBUG): Construct Execute. 2019-07-19T02:01:07.457Z,1563501667.457 [MissionManager](ERROR): Slate does not contain CTD_NeilBrown.bin_mean_sea_water_temperature 2019-07-19T02:01:07.458Z,1563501667.458 [MissionManager](ERROR): Slate does not contain celsius 2019-07-19T02:01:07.458Z,1563501667.458 [MissionManager](ERROR): Slate does not contain WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2019-07-19T02:01:07.458Z,1563501667.458 [MissionManager](ERROR): Slate does not contain microgram_per_liter 2019-07-19T02:01:08.401Z,1563501668.401 [MissionManager](DEBUG): This mission takes ESP samples at the designated depth. Maximum duration of mission 4 How often to surface for communications 240 Depth held during drift mode 2.5 Specifies ESP cartridge type code for sample# 1. Set to NaN to skip this sample. -4 Specifies ESP cartridge type code for sample# 2. Set to NaN to skip this sample. -9 Specifies ESP cartridge type code for sample# 3. Set to NaN to skip this sample. NaN Specifies ESP cartridge type code for sample# 4. Set to NaN to skip this sample. NaN How long to wait between samples. This starts *before* the first sample to exercise the SettleTime setting in the insert aggregate. 3 Maximum time duration for the vehicle to reach the approach depth 20 How much vertical drift from the specified depth is allowed while sampling. 0.01 Vehicle transit speed 0 Maximum allowable depth during the mission 5 Max vehicle pitch (+/-) when decending from the surface 20 Minimum distance from the shoreline to maintain 1 Mission variable (don't change). The mission sets this to true after surface comms are done. 0 Descend from the surface to approach depth using the thruster, limit pitch and hold the rudder. 1.0 13 Timed out while trying to reach approach depth at current depth of . stop Maintain target depth and acquire ESP samples. 0.0 13 2019-07-19T02:01:08.404Z,1563501668.404 [CommandLine](IMPORTANT): Running ./Missions/Science/esp_kiss.xml 2019-07-19T02:01:08.501Z,1563501668.501 [Default] Stopped 2019-07-19T02:01:08.501Z,1563501668.501 [Default](DEBUG): Aggregate::uninitialize Default 2019-07-19T02:01:08.501Z,1563501668.501 [Default:B.GoToSurface] Stopped 2019-07-19T02:01:08.501Z,1563501668.501 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-07-19T02:01:08.502Z,1563501668.502 [Default:CheckIn] Stopped 2019-07-19T02:01:08.502Z,1563501668.502 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-07-19T02:01:08.502Z,1563501668.502 [Default:CheckIn:Read_GPS] Stopped 2019-07-19T02:01:08.502Z,1563501668.502 [MissionManager](IMPORTANT): Started mission esp_kiss 2019-07-19T02:01:08.502Z,1563501668.502 [esp_kiss] Running Loop=1 2019-07-19T02:01:08.502Z,1563501668.502 [esp_kiss](DEBUG): Aggregate::initialize esp_kiss 2019-07-19T02:01:08.502Z,1563501668.502 [esp_kiss:A.AbortSample] Running Loop=1 2019-07-19T02:01:08.502Z,1563501668.502 [esp_kiss:A.AbortSample](INFO): Initializing AbortSample. 2019-07-19T02:01:08.503Z,1563501668.503 [esp_kiss:StandardEnvelopes] Running Loop=1 2019-07-19T02:01:08.503Z,1563501668.503 [esp_kiss:StandardEnvelopes](DEBUG): Aggregate::initialize esp_kiss:StandardEnvelopes 2019-07-19T02:01:08.503Z,1563501668.503 [esp_kiss:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2019-07-19T02:01:08.503Z,1563501668.503 [esp_kiss:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2019-07-19T02:01:08.503Z,1563501668.503 [esp_kiss:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2019-07-19T02:01:08.503Z,1563501668.503 [esp_kiss:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2019-07-19T02:01:08.503Z,1563501668.503 [esp_kiss:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2019-07-19T02:01:08.503Z,1563501668.503 [esp_kiss:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent. 2019-07-19T02:01:08.504Z,1563501668.504 [esp_kiss:I.Mass] Running Loop=1 2019-07-19T02:01:08.504Z,1563501668.504 [esp_kiss:I.Mass](DEBUG): Initialize. 2019-07-19T02:01:08.504Z,1563501668.504 [esp_kiss:Science] Running Loop=1 2019-07-19T02:01:08.504Z,1563501668.504 [esp_kiss:Science](DEBUG): Aggregate::initialize esp_kiss:Science 2019-07-19T02:01:08.504Z,1563501668.504 [esp_kiss:Science:A] Running Loop=1 2019-07-19T02:01:08.505Z,1563501668.505 [esp_kiss:Science:B] Running Loop=1 2019-07-19T02:01:08.505Z,1563501668.505 [esp_kiss:Science:C] Running Loop=1 2019-07-19T02:01:08.505Z,1563501668.505 [esp_kiss:Science:D] Running Loop=1 2019-07-19T02:01:08.505Z,1563501668.505 [esp_kiss:Science:E] Running Loop=1 2019-07-19T02:01:08.505Z,1563501668.505 [esp_kiss:Science:F] Running Loop=1 2019-07-19T02:01:08.505Z,1563501668.505 [esp_kiss:Science:G] Running Loop=1 2019-07-19T02:01:08.505Z,1563501668.505 [esp_kiss:Science:H] Running Loop=1 2019-07-19T02:01:08.505Z,1563501668.505 [esp_kiss:Science:Read_Oil] Running Loop=1 2019-07-19T02:01:08.506Z,1563501668.506 [esp_kiss:Science:PeakDetectChl] Running Loop=1 2019-07-19T02:01:08.506Z,1563501668.506 [esp_kiss:Science:PeakDetectChl](DEBUG): Aggregate::initialize esp_kiss:Science:PeakDetectChl 2019-07-19T02:01:08.506Z,1563501668.506 [esp_kiss:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1 2019-07-19T02:01:08.506Z,1563501668.506 [esp_kiss:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize. 2019-07-19T02:01:08.508Z,1563501668.508 [esp_kiss:Science:HighestChlPeakReport] Running Loop=1 2019-07-19T02:01:08.508Z,1563501668.508 [esp_kiss:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize esp_kiss:Science:HighestChlPeakReport 2019-07-19T02:01:08.508Z,1563501668.508 [esp_kiss:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1 2019-07-19T02:01:08.509Z,1563501668.509 [esp_kiss:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize. 2019-07-19T02:01:08.513Z,1563501668.513 [esp_kiss:Science:PeakDetectNO3] Running Loop=1 2019-07-19T02:01:08.513Z,1563501668.513 [esp_kiss:Science:PeakDetectNO3](DEBUG): Aggregate::initialize esp_kiss:Science:PeakDetectNO3 2019-07-19T02:01:08.513Z,1563501668.513 [esp_kiss:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1 2019-07-19T02:01:08.514Z,1563501668.514 [esp_kiss:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize. 2019-07-19T02:01:08.515Z,1563501668.515 [esp_kiss:Science:PeakDetectOil] Running Loop=1 2019-07-19T02:01:08.515Z,1563501668.515 [esp_kiss:Science:PeakDetectOil](DEBUG): Aggregate::initialize esp_kiss:Science:PeakDetectOil 2019-07-19T02:01:08.516Z,1563501668.516 [esp_kiss:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1 2019-07-19T02:01:08.516Z,1563501668.516 [esp_kiss:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize. 2019-07-19T02:01:08.523Z,1563501668.523 [esp_kiss:Science:PeakDetectFDOM] Running Loop=1 2019-07-19T02:01:08.523Z,1563501668.523 [esp_kiss:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize esp_kiss:Science:PeakDetectFDOM 2019-07-19T02:01:08.523Z,1563501668.523 [esp_kiss:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1 2019-07-19T02:01:08.524Z,1563501668.524 [esp_kiss:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize. 2019-07-19T02:01:08.531Z,1563501668.531 [esp_kiss:C] Running Loop=1 2019-07-19T02:01:08.532Z,1563501668.532 [esp_kiss:InitialDive] Running Loop=1 2019-07-19T02:01:08.534Z,1563501668.534 [esp_kiss:InitialDive](DEBUG): Aggregate::initialize esp_kiss:InitialDive 2019-07-19T02:01:08.534Z,1563501668.534 [esp_kiss:InitialDive:A] Running Loop=1 2019-07-19T02:01:08.534Z,1563501668.534 [esp_kiss:InitialDive:B.Buoyancy] Running Loop=1 2019-07-19T02:01:08.534Z,1563501668.534 [esp_kiss:InitialDive:B.Buoyancy](DEBUG): Initialize Buoyancy Component. 2019-07-19T02:01:08.534Z,1563501668.534 [esp_kiss:InitialDive:C.SetSpeed] Running Loop=1 2019-07-19T02:01:08.534Z,1563501668.534 [esp_kiss:InitialDive:C.SetSpeed](DEBUG): Initialize. 2019-07-19T02:01:08.545Z,1563501668.545 [esp_kiss:InitialDive:D.Point] Running Loop=1 2019-07-19T02:01:08.545Z,1563501668.545 [esp_kiss:InitialDive:D.Point](DEBUG): Initialize. 2019-07-19T02:01:08.545Z,1563501668.545 [esp_kiss:InitialDive:E.Pitch] Running Loop=1 2019-07-19T02:01:08.545Z,1563501668.545 [esp_kiss:InitialDive:E.Pitch](DEBUG): Initialize. 2019-07-19T02:01:08.547Z,1563501668.547 [esp_kiss:InitialDive:D.Point] Running Loop=1 2019-07-19T02:01:08.547Z,1563501668.547 [esp_kiss:InitialDive:C.SetSpeed] Running Loop=1 2019-07-19T02:01:08.547Z,1563501668.547 [esp_kiss:InitialDive:B.Buoyancy] Running Loop=1 2019-07-19T02:01:08.548Z,1563501668.548 [esp_kiss:InitialDive:A] Running Loop=1 2019-07-19T02:01:08.548Z,1563501668.548 [esp_kiss:Science] Running Loop=1 2019-07-19T02:01:08.549Z,1563501668.549 [esp_kiss:Science:PeakDetectFDOM] Stopped 2019-07-19T02:01:08.549Z,1563501668.549 [esp_kiss:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize esp_kiss:Science:PeakDetectFDOM 2019-07-19T02:01:08.549Z,1563501668.549 [esp_kiss:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped 2019-07-19T02:01:08.550Z,1563501668.550 [esp_kiss:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2019-07-19T02:01:08.550Z,1563501668.550 [esp_kiss:Science:PeakDetectOil] Stopped 2019-07-19T02:01:08.550Z,1563501668.550 [esp_kiss:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize esp_kiss:Science:PeakDetectOil 2019-07-19T02:01:08.550Z,1563501668.550 [esp_kiss:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped 2019-07-19T02:01:08.550Z,1563501668.550 [esp_kiss:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2019-07-19T02:01:08.550Z,1563501668.550 [esp_kiss:Science:PeakDetectNO3] Stopped 2019-07-19T02:01:08.550Z,1563501668.550 [esp_kiss:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize esp_kiss:Science:PeakDetectNO3 2019-07-19T02:01:08.550Z,1563501668.550 [esp_kiss:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped 2019-07-19T02:01:08.550Z,1563501668.550 [esp_kiss:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2019-07-19T02:01:08.550Z,1563501668.550 [esp_kiss:Science:HighestChlPeakReport] Stopped 2019-07-19T02:01:08.550Z,1563501668.550 [esp_kiss:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize esp_kiss:Science:HighestChlPeakReport 2019-07-19T02:01:08.550Z,1563501668.550 [esp_kiss:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped 2019-07-19T02:01:08.550Z,1563501668.550 [esp_kiss:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize. 2019-07-19T02:01:08.551Z,1563501668.551 [esp_kiss:Science:PeakDetectChl] Stopped 2019-07-19T02:01:08.551Z,1563501668.551 [esp_kiss:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize esp_kiss:Science:PeakDetectChl 2019-07-19T02:01:08.551Z,1563501668.551 [esp_kiss:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped 2019-07-19T02:01:08.551Z,1563501668.551 [esp_kiss:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2019-07-19T02:01:08.551Z,1563501668.551 [esp_kiss:Science:Read_Oil] Stopped 2019-07-19T02:01:08.551Z,1563501668.551 [esp_kiss:Science:H] Stopped 2019-07-19T02:01:08.551Z,1563501668.551 [esp_kiss:Science:G] Stopped 2019-07-19T02:01:08.551Z,1563501668.551 [esp_kiss:Science:F] Stopped 2019-07-19T02:01:08.551Z,1563501668.551 [esp_kiss:Science:E] Stopped 2019-07-19T02:01:08.551Z,1563501668.551 [esp_kiss:Science:D] Stopped 2019-07-19T02:01:08.551Z,1563501668.551 [esp_kiss:Science:C] Stopped 2019-07-19T02:01:08.552Z,1563501668.552 [esp_kiss:Science:B] Stopped 2019-07-19T02:01:08.552Z,1563501668.552 [esp_kiss:Science:A] Stopped 2019-07-19T02:01:08.552Z,1563501668.552 [esp_kiss:I.Mass] Running Loop=1 2019-07-19T02:01:08.552Z,1563501668.552 [esp_kiss:C] Stopped 2019-07-19T02:01:08.561Z,1563501668.561 [esp_kiss:D] Running Loop=1 2019-07-19T02:01:08.561Z,1563501668.561 [esp_kiss:StandardEnvelopes] Running Loop=1 2019-07-19T02:01:08.561Z,1563501668.561 [esp_kiss:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2019-07-19T02:01:08.561Z,1563501668.561 [esp_kiss:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2019-07-19T02:01:08.562Z,1563501668.562 [esp_kiss:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2019-07-19T02:01:08.562Z,1563501668.562 [esp_kiss:A.AbortSample] Running Loop=1 2019-07-19T02:01:08.878Z,1563501668.878 [esp_kiss:D] Stopped 2019-07-19T02:01:08.878Z,1563501668.878 [esp_kiss:F] Running Loop=1 2019-07-19T02:01:09.308Z,1563501669.308 [esp_kiss:F] Stopped 2019-07-19T02:01:09.309Z,1563501669.309 [esp_kiss:G] Running Loop=1 2019-07-19T02:01:09.361Z,1563501669.361 [BuoyancyServo](FAULT): Reading outside of valid range:0.000000 2019-07-19T02:01:09.361Z,1563501669.361 [BuoyancyServo](FAULT): Buoyancy engine reporting null position 2019-07-19T02:01:09.362Z,1563501669.362 [BuoyancyServo] Hardware Fault, FailCount= 1 2019-07-19T02:01:09.362Z,1563501669.362 [BuoyancyServo](ERROR): Hardware Fault 2019-07-19T02:01:09.517Z,1563501669.517 [CBIT](ERROR): Hardware Fault in component: BuoyancyServo 2019-07-19T02:01:09.688Z,1563501669.688 [esp_kiss:G] Stopped 2019-07-19T02:01:09.689Z,1563501669.689 [esp_kiss:StartingMission] Running Loop=1 2019-07-19T02:01:09.689Z,1563501669.689 [esp_kiss:StartingMission](DEBUG): Aggregate::initialize esp_kiss:StartingMission 2019-07-19T02:01:10.107Z,1563501670.107 [esp_kiss:SurfaceComms] Running Loop=1 2019-07-19T02:01:10.107Z,1563501670.107 [esp_kiss:SurfaceComms](DEBUG): Aggregate::initialize esp_kiss:SurfaceComms 2019-07-19T02:01:10.107Z,1563501670.107 [esp_kiss:SurfaceComms:A] Running Loop=1 2019-07-19T02:01:10.107Z,1563501670.107 [esp_kiss:SurfaceComms:A](DEBUG): Aggregate::initialize esp_kiss:SurfaceComms:A 2019-07-19T02:01:10.108Z,1563501670.108 [esp_kiss:StandardEnvelopes:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active. 2019-07-19T02:01:10.517Z,1563501670.517 [esp_kiss:NeedComms] Running Loop=1 2019-07-19T02:01:10.517Z,1563501670.517 [esp_kiss:NeedComms](DEBUG): Aggregate::initialize esp_kiss:NeedComms 2019-07-19T02:01:10.517Z,1563501670.517 [esp_kiss:NeedComms:B.GoToSurface] Running Loop=1 2019-07-19T02:01:10.517Z,1563501670.517 [esp_kiss:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-07-19T02:01:10.518Z,1563501670.518 [esp_kiss:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2019-07-19T02:01:10.518Z,1563501670.518 [esp_kiss:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2019-07-19T02:01:10.519Z,1563501670.519 [esp_kiss:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2019-07-19T02:01:10.519Z,1563501670.519 [esp_kiss:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-07-19T02:01:10.519Z,1563501670.519 [esp_kiss:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-07-19T02:01:10.519Z,1563501670.519 [esp_kiss:NeedComms:A] Running Loop=1 2019-07-19T02:01:10.525Z,1563501670.525 [esp_kiss:NeedComms:A](INFO): last time_fix was: 1563501568.000000 second since 1970/01/01T00:00:00Z 2019-07-19T02:01:10.525Z,1563501670.525 [esp_kiss:NeedComms:A] Stopped 2019-07-19T02:01:10.898Z,1563501670.898 [esp_kiss:NeedComms:C] Running Loop=1 2019-07-19T02:01:11.290Z,1563501671.290 [esp_kiss:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix 2019-07-19T02:01:11.295Z,1563501671.295 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2019-07-19T02:01:11.295Z,1563501671.295 [BuoyancyServo](INFO): Powering down 2019-07-19T02:01:12.176Z,1563501672.176 [CBIT](INFO): Clearing failed state for component BuoyancyServo 2019-07-19T02:01:12.177Z,1563501672.177 [BuoyancyServo] No Fault, FailCount= 1 2019-07-19T02:01:12.508Z,1563501672.508 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2019-07-19T02:01:12.509Z,1563501672.509 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2019-07-19T02:01:26.435Z,1563501686.435 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1563501696.000000 second 2019-07-19T02:01:26.653Z,1563501686.653 [esp_kiss:NeedComms:C] Stopped 2019-07-19T02:01:26.653Z,1563501686.653 [esp_kiss:NeedComms:D] Running Loop=1 2019-07-19T02:01:27.070Z,1563501687.070 [esp_kiss:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-07-19T02:01:34.164Z,1563501694.164 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20190719T015755/Courier0004.lzma 2019-07-19T02:01:34.974Z,1563501694.974 [DataOverHttps](INFO): Moved sent file to Logs/20190719T015755/Courier0004.lzma.bak 2019-07-19T02:01:34.974Z,1563501694.974 [DataOverHttps](INFO): SBD MOMSN=11455719 2019-07-19T02:01:42.390Z,1563501702.390 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1563501696.000000 second 2019-07-19T02:01:52.865Z,1563501712.865 [DataOverHttps](INFO): Sending 508 bytes from file Logs/20190718T183539/Express0125.lzma 2019-07-19T02:01:53.671Z,1563501713.671 [DataOverHttps](INFO): Moved sent file to Logs/20190718T183539/Express0125.lzma.bak 2019-07-19T02:01:53.671Z,1563501713.671 [DataOverHttps](INFO): SBD MOMSN=11455722 2019-07-19T02:01:59.622Z,1563501719.622 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1563501696.000000 second 2019-07-19T02:02:06.353Z,1563501726.353 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T02:02:06.353Z,1563501726.353 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2019-07-19T02:02:06.353Z,1563501726.353 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:02:06.367Z,1563501726.367 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:02:06.776Z,1563501726.776 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:02:06.776Z,1563501726.776 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2019-07-19T02:02:10.746Z,1563501730.746 [DataOverHttps](INFO): Sending 944 bytes from file Logs/20190719T015755/Express0001.lzma 2019-07-19T02:02:11.550Z,1563501731.550 [DataOverHttps](INFO): Moved sent file to Logs/20190719T015755/Express0001.lzma.bak 2019-07-19T02:02:11.550Z,1563501731.550 [DataOverHttps](INFO): SBD MOMSN=11455741 2019-07-19T02:02:27.501Z,1563501747.501 [DataOverHttps](INFO): Sending 531 bytes from file Logs/20190719T015755/Express0005.lzma 2019-07-19T02:02:28.306Z,1563501748.306 [DataOverHttps](INFO): Moved sent file to Logs/20190719T015755/Express0005.lzma.bak 2019-07-19T02:02:28.307Z,1563501748.307 [DataOverHttps](INFO): SBD MOMSN=11455770 2019-07-19T02:02:33.033Z,1563501753.033 [esp_kiss:NeedComms:D] Stopped 2019-07-19T02:02:33.034Z,1563501753.034 [esp_kiss:NeedComms:E] Running Loop=1 2019-07-19T02:02:33.438Z,1563501753.438 [esp_kiss:NeedComms:E](DEBUG): Initialize ReadDataComponent to sense time_fix 2019-07-19T02:02:55.342Z,1563501775.342 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1563501696.000000 second 2019-07-19T02:02:55.638Z,1563501775.638 [esp_kiss:NeedComms:E] Stopped 2019-07-19T02:02:55.639Z,1563501775.639 [esp_kiss:NeedComms](INFO): Completed esp_kiss:NeedComms 2019-07-19T02:02:55.639Z,1563501775.639 [esp_kiss:NeedComms] Stopped 2019-07-19T02:02:55.639Z,1563501775.639 [esp_kiss:NeedComms](DEBUG): Aggregate::uninitialize esp_kiss:NeedComms 2019-07-19T02:02:55.639Z,1563501775.639 [esp_kiss:NeedComms:B.GoToSurface] Stopped 2019-07-19T02:02:55.639Z,1563501775.639 [esp_kiss:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-07-19T02:02:56.042Z,1563501776.042 [esp_kiss:SurfaceComms:A](INFO): Completed esp_kiss:SurfaceComms:A 2019-07-19T02:02:56.042Z,1563501776.042 [esp_kiss:SurfaceComms:A] Stopped 2019-07-19T02:02:56.042Z,1563501776.042 [esp_kiss:SurfaceComms:A](DEBUG): Aggregate::uninitialize esp_kiss:SurfaceComms:A 2019-07-19T02:02:56.042Z,1563501776.042 [esp_kiss:SurfaceComms:B] Running Loop=1 2019-07-19T02:02:56.450Z,1563501776.450 [esp_kiss:SurfaceComms:B] Stopped 2019-07-19T02:02:56.451Z,1563501776.451 [esp_kiss:SurfaceComms](INFO): Completed esp_kiss:SurfaceComms 2019-07-19T02:02:56.451Z,1563501776.451 [esp_kiss:SurfaceComms] Stopped 2019-07-19T02:02:56.451Z,1563501776.451 [esp_kiss:SurfaceComms](DEBUG): Aggregate::uninitialize esp_kiss:SurfaceComms 2019-07-19T02:02:56.856Z,1563501776.856 [esp_kiss:StartingMission](INFO): Completed esp_kiss:StartingMission 2019-07-19T02:02:56.856Z,1563501776.856 [esp_kiss:StartingMission] Stopped 2019-07-19T02:02:56.857Z,1563501776.857 [esp_kiss:StartingMission](DEBUG): Aggregate::uninitialize esp_kiss:StartingMission 2019-07-19T02:02:56.857Z,1563501776.857 [esp_kiss:TargetDepth] Running Loop=1 2019-07-19T02:02:56.857Z,1563501776.857 [esp_kiss:TargetDepth](DEBUG): Aggregate::initialize esp_kiss:TargetDepth 2019-07-19T02:02:56.857Z,1563501776.857 [esp_kiss:TargetDepth:A] Running Loop=1 2019-07-19T02:02:56.857Z,1563501776.857 [esp_kiss:TargetDepth:B.SetSpeed] Running Loop=1 2019-07-19T02:02:56.857Z,1563501776.857 [esp_kiss:TargetDepth:B.SetSpeed](DEBUG): Initialize. 2019-07-19T02:02:56.857Z,1563501776.857 [esp_kiss:TargetDepth:C.Pitch] Running Loop=1 2019-07-19T02:02:56.858Z,1563501776.858 [esp_kiss:TargetDepth:C.Pitch](DEBUG): Initialize. 2019-07-19T02:02:56.858Z,1563501776.858 [esp_kiss:TargetDepth:Spinout] Running Loop=1 2019-07-19T02:02:56.858Z,1563501776.858 [esp_kiss:TargetDepth:Spinout](DEBUG): Aggregate::initialize esp_kiss:TargetDepth:Spinout 2019-07-19T02:02:56.858Z,1563501776.858 [esp_kiss:TargetDepth:Spinout:A.Buoyancy] Running Loop=1 2019-07-19T02:02:56.858Z,1563501776.858 [esp_kiss:TargetDepth:Spinout:A.Buoyancy](DEBUG): Initialize Buoyancy Component. 2019-07-19T02:02:56.858Z,1563501776.858 [esp_kiss:TargetDepth:Spinout:B.Point] Running Loop=1 2019-07-19T02:02:56.858Z,1563501776.858 [esp_kiss:TargetDepth:Spinout:B.Point](DEBUG): Initialize. 2019-07-19T02:02:56.858Z,1563501776.858 [esp_kiss:TargetDepth:GrabSamples] Running Loop=1 2019-07-19T02:02:56.858Z,1563501776.858 [esp_kiss:TargetDepth:GrabSamples](DEBUG): Aggregate::initialize esp_kiss:TargetDepth:GrabSamples 2019-07-19T02:02:56.859Z,1563501776.859 [esp_kiss:TargetDepth:GrabSamples:B] Running Loop=1 2019-07-19T02:02:57.252Z,1563501777.252 [esp_kiss:TargetDepth:GrabSamples:B] Stopped 2019-07-19T02:02:57.253Z,1563501777.253 [esp_kiss:TargetDepth:GrabSamples:C] Running Loop=1 2019-07-19T02:02:57.253Z,1563501777.253 [esp_kiss:TargetDepth:Spinout] Stopped 2019-07-19T02:02:57.253Z,1563501777.253 [esp_kiss:TargetDepth:Spinout](DEBUG): Aggregate::uninitialize esp_kiss:TargetDepth:Spinout 2019-07-19T02:02:57.253Z,1563501777.253 [esp_kiss:TargetDepth:Spinout:A.Buoyancy] Stopped 2019-07-19T02:02:57.253Z,1563501777.253 [esp_kiss:TargetDepth:Spinout:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2019-07-19T02:02:57.253Z,1563501777.253 [esp_kiss:TargetDepth:Spinout:B.Point] Stopped 2019-07-19T02:02:57.253Z,1563501777.253 [esp_kiss:TargetDepth:C.Pitch] Running Loop=1 2019-07-19T02:02:57.254Z,1563501777.254 [esp_kiss:TargetDepth:B.SetSpeed] Running Loop=1 2019-07-19T02:02:57.254Z,1563501777.254 [esp_kiss:TargetDepth:A] Running Loop=1 2019-07-19T02:02:57.649Z,1563501777.649 [esp_kiss:TargetDepth:GrabSamples:C] Stopped 2019-07-19T02:02:57.649Z,1563501777.649 [esp_kiss:TargetDepth:GrabSamples:Sample1] Running Loop=1 2019-07-19T02:02:57.649Z,1563501777.649 [esp_kiss:TargetDepth:GrabSamples:Sample1](DEBUG): Aggregate::initialize esp_kiss:TargetDepth:GrabSamples:Sample1 2019-07-19T02:02:57.650Z,1563501777.650 [esp_kiss:TargetDepth:GrabSamples:Sample1:A] Running Loop=1 2019-07-19T02:02:58.053Z,1563501778.053 [esp_kiss:TargetDepth:GrabSamples:Sample1:A] Stopped 2019-07-19T02:02:58.054Z,1563501778.054 [esp_kiss:TargetDepth:GrabSamples:Sample1:sampling] Running Loop=1 2019-07-19T02:02:58.054Z,1563501778.054 [esp_kiss:TargetDepth:GrabSamples:Sample1:sampling](DEBUG): Aggregate::initialize esp_kiss:TargetDepth:GrabSamples:Sample1:sampling 2019-07-19T02:02:58.459Z,1563501778.459 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth] Running Loop=1 2019-07-19T02:02:58.459Z,1563501778.459 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth](DEBUG): Aggregate::initialize esp_kiss:TargetDepth:GrabSamples:SampleAtDepth 2019-07-19T02:02:58.459Z,1563501778.459 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:ApproachDepth] Running Loop=1 2019-07-19T02:02:58.459Z,1563501778.459 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:ApproachDepth](DEBUG): Aggregate::initialize esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:ApproachDepth 2019-07-19T02:02:58.460Z,1563501778.460 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:ApproachDepth:A] Running Loop=1 2019-07-19T02:02:58.460Z,1563501778.460 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:ApproachDepth:A](INFO): Moving to 2.500000 m 2019-07-19T02:02:58.460Z,1563501778.460 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:ApproachDepth:A] Stopped 2019-07-19T02:02:58.460Z,1563501778.460 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:ApproachDepth:B.Pitch] Running Loop=1 2019-07-19T02:02:58.460Z,1563501778.460 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:ApproachDepth:B.Pitch](DEBUG): Initialize. 2019-07-19T02:03:22.794Z,1563501802.794 [CommandLine](IMPORTANT): got command maintain sensor Depth_Keller.depth 2.500000 meter 2019-07-19T02:03:22.795Z,1563501802.795 [ComponentRegistry](DEBUG): SyncComponent "Maintain_Depth_Keller.depth" handled in the control thread. 2019-07-19T02:03:22.830Z,1563501802.830 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,Depth_Keller,NAL9602,Onboard,DAT,BPC1,PAR_Licor,Depth_Keller,Maintain_NAL9602.latitude_fix,Maintain_NAL9602.longitude_fix,Maintain_Depth_Keller.depth,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2019-07-19T02:03:23.132Z,1563501803.132 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:ApproachDepth:B.Pitch] Stopped 2019-07-19T02:03:23.132Z,1563501803.132 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:ApproachDepth](INFO): Completed esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:ApproachDepth 2019-07-19T02:03:23.132Z,1563501803.132 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:ApproachDepth] Stopped 2019-07-19T02:03:23.133Z,1563501803.133 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:ApproachDepth](DEBUG): Aggregate::uninitialize esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:ApproachDepth 2019-07-19T02:03:23.141Z,1563501803.141 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper] Running Loop=1 2019-07-19T02:03:23.141Z,1563501803.141 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper](DEBUG): Aggregate::initialize esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper 2019-07-19T02:03:23.141Z,1563501803.141 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:A.Pitch] Running Loop=1 2019-07-19T02:03:23.141Z,1563501803.141 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:A.Pitch](DEBUG): Initialize. 2019-07-19T02:03:23.142Z,1563501803.142 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:B] Running Loop=1 2019-07-19T02:03:23.143Z,1563501803.143 [esp_kiss:InitialDive:E.Pitch] Stopped 2019-07-19T02:03:23.143Z,1563501803.143 [esp_kiss:InitialDive:F] Running Loop=1 2019-07-19T02:03:23.544Z,1563501803.544 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:B](IMPORTANT): At 2.500000 m , settling for 3.000000 min 2019-07-19T02:03:23.544Z,1563501803.544 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:B] Stopped 2019-07-19T02:03:23.544Z,1563501803.544 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:C.Wait] Running Loop=1 2019-07-19T02:03:23.544Z,1563501803.544 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:C.Wait](DEBUG): Initialize Wait Component. 2019-07-19T02:03:23.545Z,1563501803.545 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:A.Pitch] Running Loop=1 2019-07-19T02:03:23.554Z,1563501803.554 [esp_kiss:InitialDive:F] Stopped 2019-07-19T02:03:23.555Z,1563501803.555 [esp_kiss:InitialDive](INFO): Completed esp_kiss:InitialDive 2019-07-19T02:03:23.555Z,1563501803.555 [esp_kiss:InitialDive] Stopped 2019-07-19T02:03:23.555Z,1563501803.555 [esp_kiss:InitialDive](DEBUG): Aggregate::uninitialize esp_kiss:InitialDive 2019-07-19T02:03:23.556Z,1563501803.556 [esp_kiss:InitialDive:A] Stopped 2019-07-19T02:03:23.556Z,1563501803.556 [esp_kiss:InitialDive:B.Buoyancy] Stopped 2019-07-19T02:03:23.556Z,1563501803.556 [esp_kiss:InitialDive:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2019-07-19T02:03:23.556Z,1563501803.556 [esp_kiss:InitialDive:C.SetSpeed] Stopped 2019-07-19T02:03:23.556Z,1563501803.556 [esp_kiss:InitialDive:C.SetSpeed](DEBUG): Uninitialize. 2019-07-19T02:03:23.556Z,1563501803.556 [esp_kiss:InitialDive:D.Point] Stopped 2019-07-19T02:03:48.530Z,1563501828.530 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-07-19T02:04:07.545Z,1563501847.545 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T02:04:07.545Z,1563501847.545 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2019-07-19T02:04:07.545Z,1563501847.545 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:04:07.621Z,1563501847.621 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:04:08.093Z,1563501848.093 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:04:08.093Z,1563501848.093 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2019-07-19T02:04:19.234Z,1563501859.234 [NAL9602](INFO): Not Powering down - fast GPS 2019-07-19T02:04:23.549Z,1563501863.549 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2019-07-19T02:04:23.589Z,1563501863.589 [Radio_Surface](INFO): Powering down 2019-07-19T02:05:29.149Z,1563501929.149 [BPC1](ERROR): Battery stick #38 (s/n: 0139) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2019-07-19T02:05:29.150Z,1563501929.150 [BPC1](ERROR): Battery stick #39 (s/n: 00F0) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2019-07-19T02:05:29.151Z,1563501929.151 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5. 2019-07-19T02:05:29.154Z,1563501929.154 [BPC1](INFO): Received data from all battery sticks. 2019-07-19T02:06:08.734Z,1563501968.734 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T02:06:08.734Z,1563501968.734 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2019-07-19T02:06:08.734Z,1563501968.734 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:06:08.748Z,1563501968.748 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:06:09.156Z,1563501969.156 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:06:09.156Z,1563501969.156 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2019-07-19T02:06:24.094Z,1563501984.094 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:C.Wait](INFO): Done Waiting. 2019-07-19T02:06:24.095Z,1563501984.095 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:C.Wait] Stopped 2019-07-19T02:06:24.095Z,1563501984.095 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:C.Wait](DEBUG): Uninitialize Wait Component. 2019-07-19T02:06:24.095Z,1563501984.095 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleCANONSampler] Running Loop=1 2019-07-19T02:06:24.095Z,1563501984.095 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::initialize esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleCANONSampler 2019-07-19T02:06:24.095Z,1563501984.095 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleCANONSampler:A] Running Loop=1 2019-07-19T02:06:24.095Z,1563501984.095 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleCANONSampler:B] Running Loop=1 2019-07-19T02:06:24.095Z,1563501984.095 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Running Loop=1 2019-07-19T02:06:24.489Z,1563501984.489 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleCANONSampler] Stopped 2019-07-19T02:06:24.489Z,1563501984.489 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::uninitialize esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleCANONSampler 2019-07-19T02:06:24.489Z,1563501984.489 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleCANONSampler:A] Stopped 2019-07-19T02:06:24.489Z,1563501984.489 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleCANONSampler:B] Stopped 2019-07-19T02:06:24.489Z,1563501984.489 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Stopped 2019-07-19T02:06:24.489Z,1563501984.489 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleESP] Running Loop=1 2019-07-19T02:06:24.489Z,1563501984.490 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleESP](DEBUG): Aggregate::initialize esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleESP 2019-07-19T02:06:24.490Z,1563501984.490 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge] Running Loop=1 2019-07-19T02:06:24.490Z,1563501984.490 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge](DEBUG): Aggregate::initialize esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge 2019-07-19T02:06:24.490Z,1563501984.490 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge:A] Running Loop=1 2019-07-19T02:06:24.903Z,1563501984.903 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge:A] Stopped 2019-07-19T02:06:24.903Z,1563501984.903 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge](INFO): Completed esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge 2019-07-19T02:06:24.903Z,1563501984.903 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge] Stopped 2019-07-19T02:06:24.904Z,1563501984.904 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge](DEBUG): Aggregate::uninitialize esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge 2019-07-19T02:06:24.904Z,1563501984.904 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP] Running Loop=1 2019-07-19T02:06:25.308Z,1563501985.308 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP](DEBUG): Initialize ReadDataComponent to sense ESPComponent.sampling 2019-07-19T02:06:26.082Z,1563501986.082 [ESPComponent](IMPORTANT): Setting regex for ESP Log summary: 'Selecting Cartridge|Sampled|Error|Fail|Retry|Cmd::|Sampler::' 2019-07-19T02:06:26.084Z,1563501986.084 [ESPComponent](INFO): compiled regex: "Selecting Cartridge|Sampled|Error|Fail|Retry|Cmd::|Sampler::" 2019-07-19T02:06:26.487Z,1563501986.487 [ESPComponent](INFO): powering up ESP 2019-07-19T02:06:26.505Z,1563501986.505 [ESPComponent](INFO): powering up ESP secondary power supply 2019-07-19T02:06:26.522Z,1563501986.522 [ESPComponent](IMPORTANT): Starting PPPD with command:/sbin/pppd xonxoff asyncmap A0000 /dev/ttyTX1 linkname esp noauth local lock 115200 10.89.5.2:10.89.5.3 persist maxfail 0 holdoff 10 lcp-echo-interval 60 lcp-echo-failure 3 proxyarp ktune deflate 12 ms-dns 8.8.8.8 2019-07-19T02:06:26.626Z,1563501986.626 [ESPComponent](IMPORTANT): Waiting for ESP to connect (timeout=150.0000) 2019-07-19T02:06:26.961Z,1563501986.961 [ESPComponent](INFO): console: 2019-07-19T02:06:27.645Z,1563501987.645 [BuoyancyServo](ERROR): getPosition uart error serial timeout 2019-07-19T02:06:27.645Z,1563501987.645 [BuoyancyServo](FAULT): Buoyancy getPosition uart error.serial timeout 2019-07-19T02:06:27.645Z,1563501987.645 [BuoyancyServo] Communications Fault, FailCount= 1 2019-07-19T02:06:27.645Z,1563501987.645 [BuoyancyServo](ERROR): Communications Fault 2019-07-19T02:06:27.655Z,1563501987.655 [CBIT](ERROR): Communications Fault in component: BuoyancyServo 2019-07-19T02:06:27.698Z,1563501987.698 [ESPComponent](INFO): console: 2019-07-19T02:06:28.103Z,1563501988.103 [ESPComponent](INFO): console:NAND: 256 MiB 2019-07-19T02:06:28.517Z,1563501988.517 [ESPComponent](INFO): console: BOOTMODE: SDMMC 2019-07-19T02:06:28.910Z,1563501988.910 [ESPComponent](INFO): console: 2019-07-19T02:06:29.313Z,1563501989.313 [ESPComponent](INFO): console: 2019-07-19T02:06:29.367Z,1563501989.367 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2019-07-19T02:06:29.368Z,1563501989.368 [BuoyancyServo](INFO): Powering down 2019-07-19T02:06:29.729Z,1563501989.729 [ESPComponent](INFO): console: U-Boot 2009.11-mbariC (Apr 02 2019 - 18:00:17) 2019-07-19T02:06:30.122Z,1563501990.122 [ESPComponent](INFO): console: 2019-07-19T02:06:30.164Z,1563501990.164 [CBIT](INFO): Clearing failed state for component BuoyancyServo 2019-07-19T02:06:30.164Z,1563501990.164 [BuoyancyServo] No Fault, FailCount= 1 2019-07-19T02:06:30.526Z,1563501990.526 [ESPComponent](INFO): console: MBARI LPC31xx ESP 3G 2019-07-19T02:06:30.567Z,1563501990.567 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2019-07-19T02:06:30.568Z,1563501990.568 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2019-07-19T02:06:30.930Z,1563501990.930 [ESPComponent](INFO): console: flash params are already written into flash 2019-07-19T02:06:31.334Z,1563501991.334 [ESPComponent](INFO): console: DRAM: 64 MB 2019-07-19T02:06:31.737Z,1563501991.737 [ESPComponent](INFO): console: In: serial 2019-07-19T02:06:32.142Z,1563501992.142 [ESPComponent](INFO): console: Out: serial 2019-07-19T02:06:32.546Z,1563501992.546 [ESPComponent](INFO): console: Err: serial 2019-07-19T02:06:32.950Z,1563501992.950 [ESPComponent](INFO): console: Net: ks8851_mll 2019-07-19T02:06:33.354Z,1563501993.354 [ESPComponent](INFO): console: Hit to stop autoboot: 1  0 2019-07-19T02:06:33.758Z,1563501993.758 [ESPComponent](INFO): console: mmc1 is available 2019-07-19T02:06:34.162Z,1563501994.162 [ESPComponent](INFO): console: reading uImage 2019-07-19T02:06:34.566Z,1563501994.566 [ESPComponent](INFO): console: 2019-07-19T02:06:34.970Z,1563501994.970 [ESPComponent](INFO): console: 1681452 bytes read 2019-07-19T02:06:35.374Z,1563501995.374 [ESPComponent](INFO): console: ## Booting kernel from Legacy Image at 31000000 ... 2019-07-19T02:06:35.778Z,1563501995.778 [ESPComponent](INFO): console: Image Name: Linux-2.6.33-ea3131-mbari6 2019-07-19T02:06:36.182Z,1563501996.182 [ESPComponent](INFO): console: Image Type: ARM Linux Kernel Image (uncompressed) 2019-07-19T02:06:36.586Z,1563501996.586 [ESPComponent](INFO): console: Data Size: 1681388 Bytes = 1.6 MB 2019-07-19T02:06:36.990Z,1563501996.990 [ESPComponent](INFO): console: Load Address: 30008000 2019-07-19T02:06:37.394Z,1563501997.394 [ESPComponent](INFO): console: Entry Point: 30008000 2019-07-19T02:06:37.798Z,1563501997.798 [ESPComponent](INFO): console: Verifying Checksum ... OK 2019-07-19T02:06:38.202Z,1563501998.202 [ESPComponent](INFO): console: Loading Kernel Image ... OK 2019-07-19T02:06:38.605Z,1563501998.605 [ESPComponent](INFO): console: OK 2019-07-19T02:06:39.009Z,1563501999.009 [ESPComponent](INFO): console: 2019-07-19T02:06:39.414Z,1563501999.414 [ESPComponent](INFO): console: Starting kernel ... 2019-07-19T02:06:39.817Z,1563501999.817 [ESPComponent](INFO): console: 2019-07-19T02:06:40.222Z,1563502000.222 [ESPComponent](INFO): console: Uncompressing Linux... done, booting the kernel. 2019-07-19T02:06:40.627Z,1563502000.627 [ESPComponent](INFO): console: [ 0.00] CPU: ARM926EJ-S [41069265] revision 5 (ARMv5TEJ), cr=00053177 2019-07-19T02:06:41.030Z,1563502001.030 [ESPComponent](INFO): console: [ 0.00] CPU: VIVT data cache, VIVT instruction cache 2019-07-19T02:06:41.434Z,1563502001.434 [ESPComponent](INFO): console: [ 0.00] Machine: NXP EA313X 2019-07-19T02:06:41.839Z,1563502001.839 [ESPComponent](INFO): console: [ 0.00] Memory policy: ECC disabled, Data cache writeback 2019-07-19T02:06:42.243Z,1563502002.243 [ESPComponent](INFO): console: [ 0.00] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 16256 2019-07-19T02:06:42.646Z,1563502002.646 [ESPComponent](INFO): console: [ Mount-cactable entries: 512 2019-07-19T02:06:43.050Z,1563502003.050 [ESPComponent](INFO): console: [ 0.29] MBARI ESP 3G 2019-07-19T02:06:43.454Z,1563502003.454 [ESPComponent](INFO): console: [ 0.39] bio: create slab at 0 2019-07-19T02:06:43.859Z,1563502003.859 [ESPComponent](INFO): console: [ 0.46] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master... 2019-07-19T02:06:44.263Z,1563502004.263 [ESPComponent](INFO): console: [ 0.48] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master... 2019-07-19T02:06:44.667Z,1563502004.667 [ESPComponent](INFO): console: [ 0.50] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master... 2019-07-19T02:06:45.071Z,1563502005.071 [ESPComponent](INFO): console: [ 0.52] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master... 2019-07-19T02:06:45.475Z,1563502005.475 [ESPComponent](INFO): console: [ 0.54] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master... 2019-07-19T02:06:45.879Z,1563502005.879 [ESPComponent](INFO): console: [ 0.56] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master... 2019-07-19T02:06:46.282Z,1563502006.282 [ESPComponent](INFO): console: [ 0.56] NetWinder Floating Point Emulator V0.97 (double precision) 2019-07-19T02:06:46.687Z,1563502006.687 [ESPComponent](INFO): console: [ 0.58] yaffs Dec 14 2018 09:19:05 Installing. 2019-07-19T02:06:47.090Z,1563502007.090 [ESPComponent](INFO): console: [ 0.72] m25p80 spi0.3: m25p80 found s25sl032a flash 2019-07-19T02:06:47.494Z,1563502007.494 [ESPComponent](INFO): console: [ 2.28] VFS: Mounted root (ext2 filesystem) readonly on device 179:2. 2019-07-19T02:06:47.898Z,1563502007.898 [ESPComponent](INFO): console: 2019-07-19T02:06:48.302Z,1563502008.302 [ESPComponent](INFO): console:INIT: version 2.85 booting 2019-07-19T02:06:48.706Z,1563502008.706 [ESPComponent](INFO): console: 2019-07-19T02:06:49.111Z,1563502009.111 [ESPComponent](INFO): console:MBARI ESP Embedded Linux http://www.mbari.org mailto:brent@mbari.org 2019-07-19T02:06:49.514Z,1563502009.514 [ESPComponent](INFO): console: ESPhonu 2019-07-19T02:06:49.917Z,1563502009.917 [ESPComponent](INFO): console: 2019-07-19T02:06:50.322Z,1563502010.322 [ESPComponent](INFO): console:INIT: Entering runlevel: 3 2019-07-19T02:06:50.725Z,1563502010.725 [ESPComponent](INFO): console: 2019-07-19T02:06:51.130Z,1563502011.130 [ESPComponent](INFO): console:Loading kernel modules 2019-07-19T02:06:51.535Z,1563502011.535 [ESPComponent](INFO): console: Mounting filesystems and adding swapfiles listed in /etc/fstab 2019-07-19T02:06:51.938Z,1563502011.938 [ESPComponent](INFO): console: mount: /dev/mmcblk0p2 already mounted or /card busy 2019-07-19T02:06:52.342Z,1563502012.342 [ESPComponent](INFO): console: Starting hotplug events dispatcher udevd 2019-07-19T02:06:52.747Z,1563502012.747 [ESPComponent](INFO): console: Set system clock to: Thu Jul 18 19:03:54 PDT 2019 2019-07-19T02:06:53.151Z,1563502013.151 [ESPComponent](INFO): console: Starting syslogd klogd... 2019-07-19T02:06:53.554Z,1563502013.554 [ESPComponent](INFO): console: Bringing up interface lo ... 2019-07-19T02:06:53.958Z,1563502013.958 [ESPComponent](INFO): console: lo IP=127.0.0.1 2019-07-19T02:06:54.362Z,1563502014.362 [ESPComponent](INFO): console: Packet forwarding enabled 2019-07-19T02:06:54.766Z,1563502014.766 [ESPComponent](INFO): console: Bringing up interface ppp2 ... 2019-07-19T02:06:55.170Z,1563502015.170 [ESPComponent](INFO): console: Bringing up interface eth0 ... 2019-07-19T02:06:55.575Z,1563502015.575 [ESPComponent](INFO): console: Determining IP configuration for eth0....udhcpc (v1.11.2) started 2019-07-19T02:06:55.978Z,1563502015.978 [ESPComponent](INFO): console: Sending discover... 2019-07-19T02:06:56.382Z,1563502016.382 [ESPComponent](INFO): console: Sending discover... 2019-07-19T02:06:56.786Z,1563502016.786 [ESPComponent](INFO): console: Sending discover... 2019-07-19T02:06:57.261Z,1563502017.261 [ESPComponent](INFO): console: 2019-07-19T02:06:59.614Z,1563502019.614 [ESPComponent](INFO): console:No lease, forking to background 2019-07-19T02:07:00.018Z,1563502020.018 [ESPComponent](INFO): console: Bringing up interface eth0:10 ... 2019-07-19T02:07:00.422Z,1563502020.422 [ESPComponent](INFO): console: eth0:10 IP=10.10.10.10 2019-07-19T02:07:00.826Z,1563502020.826 [ESPComponent](INFO): console: Bringing up interface wlan0 ... 2019-07-19T02:07:01.230Z,1563502021.230 [ESPComponent](INFO): console: Successfully initialized wpa_supplicant 2019-07-19T02:07:01.705Z,1563502021.705 [ESPComponent](INFO): console: 2019-07-19T02:07:04.462Z,1563502024.462 [ESPComponent](INFO): console:rfkill: Cannot open RFKILL control device 2019-07-19T02:07:04.937Z,1563502024.937 [ESPComponent](INFO): console: 2019-07-19T02:07:08.098Z,1563502028.098 [ESPComponent](INFO): console:Determining IP configuration for wlan0....udhcpc (v1.11.2) started 2019-07-19T02:07:08.573Z,1563502028.573 [ESPComponent](INFO): console: 2019-07-19T02:07:10.118Z,1563502030.118 [ESPComponent](INFO): console:Sending discover... 2019-07-19T02:07:10.593Z,1563502030.593 [ESPComponent](INFO): console: 2019-07-19T02:07:12.541Z,1563502032.541 [ESPComponent](IMPORTANT): ESP has connected as client 2019-07-19T02:07:13.355Z,1563502033.355 [ESPComponent](IMPORTANT): [sample #1] Setting cartridge argument to -4 2019-07-19T02:07:13.356Z,1563502033.356 [ESPComponent](IMPORTANT): [sample #1] ESP sampling sequence starting. Sampling state: S_WAITING_INITIAL_PROMPT 2019-07-19T02:07:13.356Z,1563502033.356 [ESPComponent](DEBUG): Writing samplingActive=1, sampleNumber=1 2019-07-19T02:07:13.416Z,1563502033.416 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP] Stopped 2019-07-19T02:07:13.416Z,1563502033.416 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleESP:C] Running Loop=1 2019-07-19T02:07:13.784Z,1563502033.784 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleESP:C](IMPORTANT): ESP sampling at 2.500000 m inwater withchlorophyll fluorescence. 2019-07-19T02:07:13.784Z,1563502033.784 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleESP:C] Stopped 2019-07-19T02:07:13.784Z,1563502033.784 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleESP:WaitForESP] Running Loop=1 2019-07-19T02:07:14.192Z,1563502034.192 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleESP:WaitForESP](DEBUG): Initialize ReadDataComponent to sense ESPComponent.sample_number 2019-07-19T02:07:14.562Z,1563502034.562 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PREPARING_SHOW_LOG 2019-07-19T02:07:14.966Z,1563502034.966 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PREPARING_SHOW_STATUS 2019-07-19T02:07:16.581Z,1563502036.581 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_LOADING_CARTRIDGE 2019-07-19T02:07:22.522Z,1563502042.522 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.183868 2019-07-19T02:07:55.366Z,1563502075.366 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_WAITING_FOR_PRIMING (@46,archiveHiBiomass_bac) 2019-07-19T02:07:56.982Z,1563502076.982 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PRIMING (@100.0) 2019-07-19T02:07:57.790Z,1563502077.790 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_WAITING_FOR_FILTERING (@100.0) 2019-07-19T02:08:09.940Z,1563502089.940 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T02:08:09.940Z,1563502089.940 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2019-07-19T02:08:09.940Z,1563502089.940 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:08:09.956Z,1563502089.956 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:08:10.366Z,1563502090.366 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:08:10.366Z,1563502090.366 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2019-07-19T02:10:11.143Z,1563502211.143 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T02:10:11.143Z,1563502211.143 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2019-07-19T02:10:11.143Z,1563502211.143 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:10:11.158Z,1563502211.158 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:10:11.566Z,1563502211.566 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:10:11.566Z,1563502211.566 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2019-07-19T02:10:26.058Z,1563502226.058 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_FILTERING (@0.0) 2019-07-19T02:10:26.462Z,1563502226.462 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_WAITING_FOR_PAUSED (@0.0) 2019-07-19T02:12:12.338Z,1563502332.338 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T02:12:12.338Z,1563502332.338 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2019-07-19T02:12:12.338Z,1563502332.338 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:12:12.381Z,1563502332.381 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:12:12.758Z,1563502332.758 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:12:12.758Z,1563502332.758 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2019-07-19T02:14:13.540Z,1563502453.540 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T02:14:13.541Z,1563502453.541 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2019-07-19T02:14:13.541Z,1563502453.541 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:14:13.556Z,1563502453.556 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:14:13.958Z,1563502453.958 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:14:13.958Z,1563502453.958 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2019-07-19T02:16:14.738Z,1563502574.738 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T02:16:14.738Z,1563502574.738 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2019-07-19T02:16:14.738Z,1563502574.738 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:16:14.753Z,1563502574.753 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:16:15.162Z,1563502575.162 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:16:15.162Z,1563502575.162 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2019-07-19T02:17:23.427Z,1563502643.427 [VerticalControl](CRITICAL): Failure to ascend, stopping mission after 840.260803 seconds, depthRate=0.081359 m/s, pitch=nan deg. 2019-07-19T02:17:23.432Z,1563502643.432 [CommandLine](FAULT): Scheduling is paused 2019-07-19T02:17:23.432Z,1563502643.432 [CBIT](INFO): Critical error at 20190719T021723 2019-07-19T02:17:23.432Z,1563502643.432 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2019-07-19T02:17:23.829Z,1563502643.829 [MissionManager](INFO): MissionManager is completed. 2019-07-19T02:17:23.830Z,1563502643.830 [MissionManager](INFO): Uninitializing Mission esp_kiss 2019-07-19T02:17:23.830Z,1563502643.830 [esp_kiss] Stopped 2019-07-19T02:17:23.830Z,1563502643.830 [esp_kiss](DEBUG): Aggregate::uninitialize esp_kiss 2019-07-19T02:17:23.830Z,1563502643.830 [esp_kiss:A.AbortSample] Stopped 2019-07-19T02:17:23.830Z,1563502643.830 [esp_kiss:A.AbortSample](INFO): Uninitializing AbortSample. 2019-07-19T02:17:23.830Z,1563502643.830 [esp_kiss:StandardEnvelopes] Stopped 2019-07-19T02:17:23.830Z,1563502643.830 [esp_kiss:StandardEnvelopes](DEBUG): Aggregate::uninitialize esp_kiss:StandardEnvelopes 2019-07-19T02:17:23.830Z,1563502643.830 [esp_kiss:StandardEnvelopes:A.AltitudeEnvelope] Stopped 2019-07-19T02:17:23.830Z,1563502643.830 [esp_kiss:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2019-07-19T02:17:23.830Z,1563502643.830 [esp_kiss:StandardEnvelopes:B.DepthEnvelope] Stopped 2019-07-19T02:17:23.830Z,1563502643.830 [esp_kiss:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize. 2019-07-19T02:17:23.831Z,1563502643.831 [esp_kiss:StandardEnvelopes:C.OffshoreEnvelope] Stopped 2019-07-19T02:17:23.831Z,1563502643.831 [esp_kiss:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2019-07-19T02:17:23.831Z,1563502643.831 [esp_kiss:I.Mass] Stopped 2019-07-19T02:17:23.831Z,1563502643.831 [esp_kiss:I.Mass](DEBUG): Uninitialize. 2019-07-19T02:17:23.831Z,1563502643.831 [esp_kiss:Science] Stopped 2019-07-19T02:17:23.831Z,1563502643.831 [esp_kiss:Science](DEBUG): Aggregate::uninitialize esp_kiss:Science 2019-07-19T02:17:23.831Z,1563502643.831 [esp_kiss:TargetDepth] Stopped 2019-07-19T02:17:23.831Z,1563502643.831 [esp_kiss:TargetDepth](DEBUG): Aggregate::uninitialize esp_kiss:TargetDepth 2019-07-19T02:17:23.831Z,1563502643.831 [esp_kiss:TargetDepth:A] Stopped 2019-07-19T02:17:23.832Z,1563502643.832 [esp_kiss:TargetDepth:B.SetSpeed] Stopped 2019-07-19T02:17:23.832Z,1563502643.832 [esp_kiss:TargetDepth:B.SetSpeed](DEBUG): Uninitialize. 2019-07-19T02:17:23.832Z,1563502643.832 [esp_kiss:TargetDepth:C.Pitch] Stopped 2019-07-19T02:17:23.832Z,1563502643.832 [esp_kiss:TargetDepth:GrabSamples] Stopped 2019-07-19T02:17:23.832Z,1563502643.832 [esp_kiss:TargetDepth:GrabSamples](DEBUG): Aggregate::uninitialize esp_kiss:TargetDepth:GrabSamples 2019-07-19T02:17:23.832Z,1563502643.832 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth] Stopped 2019-07-19T02:17:23.832Z,1563502643.832 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth](DEBUG): Aggregate::uninitialize esp_kiss:TargetDepth:GrabSamples:SampleAtDepth 2019-07-19T02:17:23.832Z,1563502643.832 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper] Stopped 2019-07-19T02:17:23.832Z,1563502643.832 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper](DEBUG): Aggregate::uninitialize esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper 2019-07-19T02:17:23.832Z,1563502643.832 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:A.Pitch] Stopped 2019-07-19T02:17:23.832Z,1563502643.832 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleESP] Stopped 2019-07-19T02:17:23.832Z,1563502643.832 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleESP](DEBUG): Aggregate::uninitialize esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleESP 2019-07-19T02:17:23.833Z,1563502643.833 [esp_kiss:TargetDepth:GrabSamples:SampleAtDepth:SampleWrapper:SampleESP:WaitForESP] Stopped 2019-07-19T02:17:23.833Z,1563502643.833 [esp_kiss:TargetDepth:GrabSamples:Sample1] Stopped 2019-07-19T02:17:23.833Z,1563502643.833 [esp_kiss:TargetDepth:GrabSamples:Sample1](DEBUG): Aggregate::uninitialize esp_kiss:TargetDepth:GrabSamples:Sample1 2019-07-19T02:17:23.833Z,1563502643.833 [esp_kiss:TargetDepth:GrabSamples:Sample1:sampling] Stopped 2019-07-19T02:17:23.833Z,1563502643.833 [esp_kiss:TargetDepth:GrabSamples:Sample1:sampling](DEBUG): Aggregate::uninitialize esp_kiss:TargetDepth:GrabSamples:Sample1:sampling 2019-07-19T02:17:24.198Z,1563502644.198 [ESPComponent](DEBUG): Resetting stopSampling to false 2019-07-19T02:17:24.198Z,1563502644.198 [ESPComponent](IMPORTANT): [sample #1] Stop sampling requested. 2019-07-19T02:17:24.239Z,1563502644.239 [MissionManager](IMPORTANT): Started mission Default 2019-07-19T02:17:24.239Z,1563502644.239 [Default] Running Loop=1 2019-07-19T02:17:24.239Z,1563502644.239 [Default](DEBUG): Aggregate::initialize Default 2019-07-19T02:17:24.239Z,1563502644.239 [Default:B.GoToSurface] Running Loop=1 2019-07-19T02:17:24.239Z,1563502644.239 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-07-19T02:17:24.240Z,1563502644.240 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-07-19T02:17:24.240Z,1563502644.240 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-07-19T02:17:24.240Z,1563502644.240 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-07-19T02:17:24.241Z,1563502644.241 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-07-19T02:17:24.241Z,1563502644.241 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-07-19T02:17:24.242Z,1563502644.242 [Default:A.Wait] Running Loop=1 2019-07-19T02:17:24.242Z,1563502644.242 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-07-19T02:17:24.601Z,1563502644.601 [ESPComponent](IMPORTANT): Stop sampling requested. Issuing Cmd.pauseFiltering 2019-07-19T02:17:24.925Z,1563502644.925 [Radio_Surface](INFO): Powering up 2019-07-19T02:17:30.541Z,1563502650.541 [DataOverHttps](INFO): Radio surface powered ON. 2019-07-19T02:17:30.686Z,1563502650.686 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PAUSED (@152.769) 2019-07-19T02:17:30.686Z,1563502650.686 [ESPComponent](DEBUG): Writing sampleVolume=152.768997 2019-07-19T02:17:31.091Z,1563502651.091 [ESPComponent](IMPORTANT): In S_PAUSED received result: 152.769 2019-07-19T02:17:31.495Z,1563502651.495 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PROCESSING (@152.769) 2019-07-19T02:17:33.918Z,1563502653.918 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_WAITING_FOR_PROCESSED (@46,archiveHiBiomass_bac) 2019-07-19T02:17:37.587Z,1563502657.587 [Default:A.Wait](INFO): Done Waiting. 2019-07-19T02:17:37.588Z,1563502657.588 [Default:A.Wait] Stopped 2019-07-19T02:17:37.588Z,1563502657.588 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-07-19T02:18:00.841Z,1563502680.841 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-07-19T02:18:15.565Z,1563502695.565 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T02:18:15.565Z,1563502695.565 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2019-07-19T02:18:15.565Z,1563502695.565 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:18:15.577Z,1563502695.577 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:18:15.987Z,1563502695.987 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:18:15.987Z,1563502695.987 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2019-07-19T02:18:31.545Z,1563502711.545 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-07-19T02:19:02.249Z,1563502742.249 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-07-19T02:19:32.953Z,1563502772.953 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-07-19T02:19:59.222Z,1563502799.222 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003871 2019-07-19T02:20:16.765Z,1563502816.765 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T02:20:16.765Z,1563502816.765 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9 2019-07-19T02:20:16.765Z,1563502816.765 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:20:16.777Z,1563502816.777 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:20:17.179Z,1563502817.179 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:20:17.179Z,1563502817.179 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9 2019-07-19T02:22:17.963Z,1563502937.963 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T02:22:17.963Z,1563502937.963 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10 2019-07-19T02:22:17.963Z,1563502937.963 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:22:17.975Z,1563502937.975 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:22:18.386Z,1563502938.386 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:22:18.386Z,1563502938.386 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10 2019-07-19T02:22:23.622Z,1563502943.622 [VerticalControl](CRITICAL): Failure to ascend, dropping drop weight after 300.193909 seconds, depthRate=0.081359 m/s, pitch=nan deg. 2019-07-19T02:22:23.637Z,1563502943.637 [CBIT](INFO): Critical error at 20190719T022223 2019-07-19T02:24:19.155Z,1563503059.155 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T02:24:19.155Z,1563503059.155 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11 2019-07-19T02:24:19.155Z,1563503059.155 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:24:19.167Z,1563503059.167 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:24:19.587Z,1563503059.587 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:24:19.587Z,1563503059.587 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11 2019-07-19T02:26:20.357Z,1563503180.357 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T02:26:20.357Z,1563503180.357 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12 2019-07-19T02:26:20.358Z,1563503180.358 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:26:20.401Z,1563503180.401 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:26:20.775Z,1563503180.775 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:26:20.775Z,1563503180.775 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12 2019-07-19T02:28:21.565Z,1563503301.565 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T02:28:21.565Z,1563503301.565 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13 2019-07-19T02:28:21.565Z,1563503301.565 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:28:21.577Z,1563503301.577 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:28:21.990Z,1563503301.990 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:28:21.990Z,1563503301.990 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13 2019-07-19T02:30:22.730Z,1563503422.730 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_STOPPING (@46,archiveHiBiomass_bac) 2019-07-19T02:30:22.762Z,1563503422.762 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T02:30:22.762Z,1563503422.762 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 14 2019-07-19T02:30:22.762Z,1563503422.762 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:30:22.774Z,1563503422.774 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:30:23.183Z,1563503423.183 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:30:23.183Z,1563503423.183 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 14 2019-07-19T02:30:49.395Z,1563503449.395 [ESPComponent](IMPORTANT): [sample #1] ESP sampling sequence completed normally. 2019-07-19T02:30:49.395Z,1563503449.395 [ESPComponent](DEBUG): Writing samplingActive=0, sampleNumber=1 2019-07-19T02:30:49.797Z,1563503449.797 [ESPComponent](DEBUG): Resetting stopSampling to false 2019-07-19T02:30:49.798Z,1563503449.798 [ESPComponent](IMPORTANT): [sample #1] ESP log summary report (2 messages): @19:07:30.80 Selecting Cartridge 46 @19:14:31.75 Cmd::Paused in FILTERING -- during Sample Pump (SP) move after sampling 152.769ml 2019-07-19T02:30:49.799Z,1563503449.799 [ESPComponent](INFO): powering down ESP 2019-07-19T02:30:49.800Z,1563503449.800 [ESPComponent](INFO): powering down ESP secondary power supply 2019-07-19T02:32:23.951Z,1563503543.951 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T02:32:23.951Z,1563503543.951 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 15 2019-07-19T02:32:23.951Z,1563503543.951 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:32:23.988Z,1563503543.988 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:32:24.375Z,1563503544.375 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:32:24.375Z,1563503544.375 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 15 2019-07-19T02:34:04.571Z,1563503644.571 [Default:B.GoToSurface](CRITICAL): Surfacing timeout. Returning calc satisfied. 2019-07-19T02:34:04.572Z,1563503644.572 [Default:CheckIn] Running Loop=1 2019-07-19T02:34:04.575Z,1563503644.575 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-07-19T02:34:04.575Z,1563503644.575 [Default:CheckIn:Read_GPS] Running Loop=1 2019-07-19T02:34:04.584Z,1563503644.584 [CBIT](INFO): Critical error at 20190719T023404 2019-07-19T02:34:04.980Z,1563503644.980 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2019-07-19T02:34:06.167Z,1563503646.167 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-07-19T02:34:06.167Z,1563503646.167 [NAL9602] Data Fault, FailCount= 1 2019-07-19T02:34:06.167Z,1563503646.167 [NAL9602](ERROR): Data Fault 2019-07-19T02:34:06.593Z,1563503646.593 [CBIT](ERROR): Data Fault in component: NAL9602 2019-07-19T02:34:06.607Z,1563503646.607 [NAL9602](INFO): Powering down 2019-07-19T02:34:07.485Z,1563503647.485 [CBIT](INFO): Clearing failed state for component NAL9602 2019-07-19T02:34:07.485Z,1563503647.485 [NAL9602] No Fault, FailCount= 1 2019-07-19T02:34:24.807Z,1563503664.807 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T02:34:24.808Z,1563503664.808 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 16 2019-07-19T02:34:24.808Z,1563503664.808 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:34:24.819Z,1563503664.819 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:34:25.228Z,1563503665.228 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:34:25.228Z,1563503665.228 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 16 2019-07-19T02:34:36.906Z,1563503676.906 [NAL9602](INFO): Powering up NAL9602 2019-07-19T02:34:47.815Z,1563503687.815 [NAL9602](INFO): NAL9602 initialized 2019-07-19T02:34:48.641Z,1563503688.641 [NAL9602](DEBUG): Fix Requested 2019-07-19T02:36:26.025Z,1563503786.025 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T02:36:26.025Z,1563503786.025 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 17 2019-07-19T02:36:26.025Z,1563503786.025 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:36:26.037Z,1563503786.037 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:36:26.426Z,1563503786.426 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:36:26.426Z,1563503786.426 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 17 2019-07-19T02:38:27.213Z,1563503907.213 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T02:38:27.213Z,1563503907.213 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 18 2019-07-19T02:38:27.213Z,1563503907.213 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:38:27.249Z,1563503907.249 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:38:27.623Z,1563503907.623 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:38:27.623Z,1563503907.623 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 18 2019-07-19T02:38:50.216Z,1563503930.216 [NAL9602](INFO): SBD MO Status=2, MOMSN=29927, MT Status=2, MTMSN=0 2019-07-19T02:38:50.216Z,1563503930.216 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-07-19T02:39:04.783Z,1563503944.783 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-07-19T02:34:04.6Z 2019-07-19T02:39:04.784Z,1563503944.784 [Default:CheckIn:Read_GPS] Stopped 2019-07-19T02:39:04.784Z,1563503944.784 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-07-19T02:39:05.187Z,1563503945.187 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-07-19T02:39:13.237Z,1563503953.237 [DataOverHttps](INFO): Sending 408 bytes from file Logs/20190719T015755/Courier0007.lzma 2019-07-19T02:39:14.042Z,1563503954.042 [DataOverHttps](INFO): Moved sent file to Logs/20190719T015755/Courier0007.lzma.bak 2019-07-19T02:39:14.043Z,1563503954.043 [DataOverHttps](INFO): SBD MOMSN=11455785 2019-07-19T02:39:29.167Z,1563503969.167 [DataOverHttps](INFO): Sending 1646 bytes from file Logs/20190719T015755/Express0008.lzma 2019-07-19T02:39:29.970Z,1563503969.970 [DataOverHttps](INFO): Moved sent file to Logs/20190719T015755/Express0008.lzma.bak 2019-07-19T02:39:29.971Z,1563503969.971 [DataOverHttps](INFO): SBD MOMSN=11455790 2019-07-19T02:39:34.358Z,1563503974.358 [Default:CheckIn:Read_Iridium] Stopped 2019-07-19T02:39:34.358Z,1563503974.358 [Default:CheckIn:C.Wait] Running Loop=1 2019-07-19T02:39:34.358Z,1563503974.358 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-07-19T02:39:50.887Z,1563503990.887 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-07-19T02:40:21.589Z,1563504021.589 [NAL9602](INFO): Not Powering down - fast GPS 2019-07-19T02:40:28.074Z,1563504028.074 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T02:40:28.074Z,1563504028.074 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 19 2019-07-19T02:40:28.074Z,1563504028.074 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:40:28.085Z,1563504028.085 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:40:28.490Z,1563504028.490 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:40:28.490Z,1563504028.490 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 19 2019-07-19T02:42:29.275Z,1563504149.275 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T02:42:29.275Z,1563504149.275 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 20 2019-07-19T02:42:29.275Z,1563504149.275 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:42:29.287Z,1563504149.287 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:42:29.694Z,1563504149.694 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:42:29.694Z,1563504149.694 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 20 2019-07-19T02:42:41.451Z,1563504161.451 [CommandLine](IMPORTANT): got command maintain clear 2019-07-19T02:42:41.815Z,1563504161.815 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,Depth_Keller,NAL9602,Onboard,DAT,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2019-07-19T02:42:49.278Z,1563504169.278 [CommandLine](IMPORTANT): got command get depth 2019-07-19T02:42:49.278Z,1563504169.278 [CommandLine](IMPORTANT): depth 0.026179 m 2019-07-19T02:42:59.895Z,1563504179.895 [CommandLine](IMPORTANT): got command show stack 2019-07-19T02:42:59.895Z,1563504179.895 [CommandLine](IMPORTANT): Behavior Stack: 2019-07-19T02:42:59.895Z,1563504179.895 [Default](IMPORTANT): Priority 0: Default:B.GoToSurface 2019-07-19T02:42:59.895Z,1563504179.895 [Default:CheckIn](IMPORTANT): Priority 1: Default:CheckIn:C.Wait 2019-07-19T02:44:30.477Z,1563504270.477 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T02:44:30.477Z,1563504270.477 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 21 2019-07-19T02:44:30.477Z,1563504270.477 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:44:30.488Z,1563504270.488 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:44:30.904Z,1563504270.904 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:44:30.904Z,1563504270.904 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 21 2019-07-19T02:44:34.949Z,1563504274.949 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-07-19T02:44:34.949Z,1563504274.949 [Default:CheckIn:C.Wait] Stopped 2019-07-19T02:44:34.949Z,1563504274.949 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-07-19T02:44:34.949Z,1563504274.949 [Default:CheckIn:D] Running Loop=1 2019-07-19T02:44:35.331Z,1563504275.331 [Default:CheckIn:D] Stopped 2019-07-19T02:44:35.331Z,1563504275.331 [Default:CheckIn:E] Running Loop=1 2019-07-19T02:44:35.733Z,1563504275.733 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 27.184857 min 2019-07-19T02:44:35.734Z,1563504275.734 [Default:CheckIn:E] Stopped 2019-07-19T02:44:35.734Z,1563504275.734 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-07-19T02:44:35.734Z,1563504275.734 [Default:CheckIn] Stopped 2019-07-19T02:44:35.734Z,1563504275.734 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-07-19T02:44:35.734Z,1563504275.734 [Default:CheckIn](INFO): Running loop #2 2019-07-19T02:44:35.734Z,1563504275.734 [Default:CheckIn] Running Loop=2 2019-07-19T02:44:35.734Z,1563504275.734 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-07-19T02:44:35.734Z,1563504275.734 [Default:CheckIn:Read_GPS] Running Loop=1 2019-07-19T02:44:37.337Z,1563504277.337 [NAL9602](DEBUG): Fix Requested 2019-07-19T02:46:31.678Z,1563504391.678 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T02:46:31.678Z,1563504391.678 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 22 2019-07-19T02:46:31.678Z,1563504391.678 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:46:31.689Z,1563504391.689 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:46:32.098Z,1563504392.098 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:46:32.098Z,1563504392.098 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 22 2019-07-19T02:48:32.878Z,1563504512.878 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T02:48:32.878Z,1563504512.878 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 23 2019-07-19T02:48:32.878Z,1563504512.878 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:48:32.889Z,1563504512.889 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:48:33.297Z,1563504513.297 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:48:33.297Z,1563504513.297 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 23 2019-07-19T02:49:35.925Z,1563504575.925 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-07-19T02:44:35.7Z 2019-07-19T02:49:35.925Z,1563504575.925 [Default:CheckIn:Read_GPS] Stopped 2019-07-19T02:49:35.925Z,1563504575.925 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-07-19T02:49:39.923Z,1563504579.923 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-07-19T02:49:43.948Z,1563504583.948 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190719T015755/Courier0010.lzma 2019-07-19T02:49:44.755Z,1563504584.755 [DataOverHttps](INFO): Moved sent file to Logs/20190719T015755/Courier0010.lzma.bak 2019-07-19T02:49:44.755Z,1563504584.755 [DataOverHttps](INFO): SBD MOMSN=11455845 2019-07-19T02:50:00.157Z,1563504600.157 [DataOverHttps](INFO): Sending 441 bytes from file Logs/20190719T015755/Express0011.lzma 2019-07-19T02:50:00.962Z,1563504600.962 [DataOverHttps](INFO): Moved sent file to Logs/20190719T015755/Express0011.lzma.bak 2019-07-19T02:50:00.963Z,1563504600.963 [DataOverHttps](INFO): SBD MOMSN=11455847 2019-07-19T02:50:05.421Z,1563504605.421 [Default:CheckIn:Read_Iridium] Stopped 2019-07-19T02:50:05.421Z,1563504605.421 [Default:CheckIn:C.Wait] Running Loop=1 2019-07-19T02:50:05.422Z,1563504605.422 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-07-19T02:50:10.626Z,1563504610.626 [NAL9602](INFO): Not Powering down - fast GPS 2019-07-19T02:50:34.077Z,1563504634.077 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T02:50:34.077Z,1563504634.077 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 24 2019-07-19T02:50:34.077Z,1563504634.077 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:50:34.088Z,1563504634.088 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:50:34.497Z,1563504634.497 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:50:34.497Z,1563504634.497 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 24 2019-07-19T02:52:35.277Z,1563504755.277 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T02:52:35.277Z,1563504755.277 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 25 2019-07-19T02:52:35.277Z,1563504755.277 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:52:35.288Z,1563504755.288 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:52:35.697Z,1563504755.697 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:52:35.697Z,1563504755.697 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 25 2019-07-19T02:54:36.480Z,1563504876.480 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T02:54:36.480Z,1563504876.480 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 26 2019-07-19T02:54:36.480Z,1563504876.480 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:54:36.491Z,1563504876.491 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:54:36.889Z,1563504876.889 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:54:36.889Z,1563504876.889 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 26 2019-07-19T02:55:05.978Z,1563504905.978 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-07-19T02:55:05.978Z,1563504905.978 [Default:CheckIn:C.Wait] Stopped 2019-07-19T02:55:05.978Z,1563504905.978 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-07-19T02:55:05.980Z,1563504905.980 [Default:CheckIn:D] Running Loop=1 2019-07-19T02:55:06.368Z,1563504906.368 [Default:CheckIn:D] Stopped 2019-07-19T02:55:06.368Z,1563504906.368 [Default:CheckIn:E] Running Loop=1 2019-07-19T02:55:06.783Z,1563504906.783 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 37.702148 min 2019-07-19T02:55:06.783Z,1563504906.783 [Default:CheckIn:E] Stopped 2019-07-19T02:55:06.783Z,1563504906.783 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-07-19T02:55:06.783Z,1563504906.783 [Default:CheckIn] Stopped 2019-07-19T02:55:06.783Z,1563504906.783 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-07-19T02:55:06.784Z,1563504906.784 [Default:CheckIn](INFO): Running loop #3 2019-07-19T02:55:06.784Z,1563504906.784 [Default:CheckIn] Running Loop=3 2019-07-19T02:55:06.784Z,1563504906.784 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-07-19T02:55:06.784Z,1563504906.784 [Default:CheckIn:Read_GPS] Running Loop=1 2019-07-19T02:55:08.374Z,1563504908.374 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-07-19T02:55:08.374Z,1563504908.374 [NAL9602] Data Fault, FailCount= 2 2019-07-19T02:55:08.374Z,1563504908.374 [NAL9602](ERROR): Data Fault 2019-07-19T02:55:08.411Z,1563504908.411 [CBIT](ERROR): Data Fault in component: NAL9602 2019-07-19T02:55:08.779Z,1563504908.779 [NAL9602](INFO): Powering down 2019-07-19T02:55:09.612Z,1563504909.612 [CBIT](INFO): Clearing failed state for component NAL9602 2019-07-19T02:55:09.612Z,1563504909.612 [NAL9602] No Fault, FailCount= 2 2019-07-19T02:55:39.098Z,1563504939.098 [NAL9602](INFO): Powering up NAL9602 2019-07-19T02:55:50.006Z,1563504950.006 [NAL9602](INFO): NAL9602 initialized 2019-07-19T02:55:50.825Z,1563504950.825 [NAL9602](DEBUG): Fix Requested 2019-07-19T02:56:37.286Z,1563504997.286 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T02:56:37.286Z,1563504997.286 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 27 2019-07-19T02:56:37.287Z,1563504997.287 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:56:37.309Z,1563504997.309 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:56:37.706Z,1563504997.706 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:56:37.706Z,1563504997.706 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 27 2019-07-19T02:56:38.488Z,1563504998.488 [NAL9602](INFO): SBD MO Status=2, MOMSN=29927, MT Status=2, MTMSN=0 2019-07-19T02:56:38.488Z,1563504998.488 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-07-19T02:58:38.486Z,1563505118.486 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T02:58:38.486Z,1563505118.486 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 28 2019-07-19T02:58:38.486Z,1563505118.486 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T02:58:38.497Z,1563505118.497 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T02:58:38.913Z,1563505118.913 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T02:58:38.913Z,1563505118.913 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 28 2019-07-19T03:00:06.973Z,1563505206.973 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-07-19T02:55:06.8Z 2019-07-19T03:00:06.973Z,1563505206.973 [Default:CheckIn:Read_GPS] Stopped 2019-07-19T03:00:06.974Z,1563505206.974 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-07-19T03:00:15.368Z,1563505215.368 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190719T015755/Courier0013.lzma 2019-07-19T03:00:16.174Z,1563505216.174 [DataOverHttps](INFO): Moved sent file to Logs/20190719T015755/Courier0013.lzma.bak 2019-07-19T03:00:16.174Z,1563505216.174 [DataOverHttps](INFO): SBD MOMSN=11455863 2019-07-19T03:00:32.073Z,1563505232.073 [DataOverHttps](INFO): Sending 284 bytes from file Logs/20190719T015755/Express0014.lzma 2019-07-19T03:00:32.878Z,1563505232.878 [DataOverHttps](INFO): Moved sent file to Logs/20190719T015755/Express0014.lzma.bak 2019-07-19T03:00:32.879Z,1563505232.879 [DataOverHttps](INFO): SBD MOMSN=11455865 2019-07-19T03:00:37.702Z,1563505237.702 [Default:CheckIn:Read_Iridium] Stopped 2019-07-19T03:00:37.702Z,1563505237.702 [Default:CheckIn:C.Wait] Running Loop=1 2019-07-19T03:00:37.702Z,1563505237.702 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-07-19T03:00:39.310Z,1563505239.310 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T03:00:39.310Z,1563505239.310 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 29 2019-07-19T03:00:39.310Z,1563505239.310 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T03:00:39.321Z,1563505239.321 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T03:00:39.734Z,1563505239.734 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T03:00:39.734Z,1563505239.734 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 29 2019-07-19T03:00:53.006Z,1563505253.006 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-07-19T03:01:23.709Z,1563505283.709 [NAL9602](INFO): Not Powering down - fast GPS 2019-07-19T03:02:40.496Z,1563505360.496 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T03:02:40.496Z,1563505360.496 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 30 2019-07-19T03:02:40.497Z,1563505360.497 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T03:02:40.518Z,1563505360.518 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T03:02:40.910Z,1563505360.910 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T03:02:40.910Z,1563505360.910 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 30 2019-07-19T03:04:41.689Z,1563505481.689 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T03:04:41.689Z,1563505481.689 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 31 2019-07-19T03:04:41.689Z,1563505481.689 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T03:04:41.700Z,1563505481.700 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T03:04:42.105Z,1563505482.105 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T03:04:42.105Z,1563505482.105 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 31 2019-07-19T03:05:38.253Z,1563505538.253 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-07-19T03:05:38.253Z,1563505538.253 [Default:CheckIn:C.Wait] Stopped 2019-07-19T03:05:38.253Z,1563505538.253 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-07-19T03:05:38.253Z,1563505538.253 [Default:CheckIn:D] Running Loop=1 2019-07-19T03:05:38.661Z,1563505538.661 [Default:CheckIn:D] Stopped 2019-07-19T03:05:38.661Z,1563505538.661 [Default:CheckIn:E] Running Loop=1 2019-07-19T03:05:39.053Z,1563505539.053 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.240369 min 2019-07-19T03:05:39.053Z,1563505539.053 [Default:CheckIn:E] Stopped 2019-07-19T03:05:39.053Z,1563505539.053 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-07-19T03:05:39.053Z,1563505539.053 [Default:CheckIn] Stopped 2019-07-19T03:05:39.053Z,1563505539.053 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-07-19T03:05:39.053Z,1563505539.053 [Default:CheckIn](INFO): Running loop #4 2019-07-19T03:05:39.054Z,1563505539.054 [Default:CheckIn] Running Loop=4 2019-07-19T03:05:39.054Z,1563505539.054 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-07-19T03:05:39.054Z,1563505539.054 [Default:CheckIn:Read_GPS] Running Loop=1 2019-07-19T03:05:40.669Z,1563505540.669 [NAL9602](DEBUG): Fix Requested 2019-07-19T03:06:11.762Z,1563505571.762 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-07-19T03:06:11.845Z,1563505571.845 [NAL9602](FAULT): received: +CSQ:0 OK927, 2, 0, 0, 0 OK 2019-07-19T03:06:11.845Z,1563505571.845 [NAL9602] Data Fault, FailCount= 3 2019-07-19T03:06:11.845Z,1563505571.845 [NAL9602](ERROR): Data Fault 2019-07-19T03:06:11.915Z,1563505571.915 [CBIT](ERROR): Data Fault in component: NAL9602 2019-07-19T03:06:12.166Z,1563505572.166 [NAL9602](INFO): Powering down 2019-07-19T03:06:13.021Z,1563505573.021 [CBIT](INFO): Clearing failed state for component NAL9602 2019-07-19T03:06:13.021Z,1563505573.021 [NAL9602] No Fault, FailCount= 3 2019-07-19T03:06:42.466Z,1563505602.466 [NAL9602](INFO): Powering up NAL9602 2019-07-19T03:06:42.892Z,1563505602.892 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T03:06:42.893Z,1563505602.893 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 32 2019-07-19T03:06:42.893Z,1563505602.893 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T03:06:42.903Z,1563505602.903 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T03:06:43.299Z,1563505603.299 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T03:06:43.299Z,1563505603.299 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 32 2019-07-19T03:06:53.375Z,1563505613.375 [NAL9602](INFO): NAL9602 initialized 2019-07-19T03:06:54.182Z,1563505614.182 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-07-19T03:06:54.182Z,1563505614.182 [NAL9602] Data Fault, FailCount= 4 2019-07-19T03:06:54.182Z,1563505614.182 [NAL9602](ERROR): Data Fault 2019-07-19T03:06:54.274Z,1563505614.274 [CBIT](ERROR): Data Fault in component: NAL9602 2019-07-19T03:06:54.586Z,1563505614.586 [NAL9602](INFO): Powering down 2019-07-19T03:06:55.454Z,1563505615.454 [CBIT](INFO): Clearing failed state for component NAL9602 2019-07-19T03:06:55.454Z,1563505615.454 [NAL9602] No Fault, FailCount= 4 2019-07-19T03:07:24.886Z,1563505644.886 [NAL9602](INFO): Powering up NAL9602 2019-07-19T03:07:35.794Z,1563505655.794 [NAL9602](INFO): NAL9602 initialized 2019-07-19T03:07:36.609Z,1563505656.609 [NAL9602](DEBUG): Fix Requested 2019-07-19T03:08:23.965Z,1563505703.965 [PAR_Licor](INFO): A/D timeout, 1 tries over 154 ms 2019-07-19T03:08:23.966Z,1563505703.966 [PAR_Licor] Data Fault, FailCount= 1 2019-07-19T03:08:23.966Z,1563505703.966 [PAR_Licor](ERROR): Data Fault 2019-07-19T03:08:24.023Z,1563505704.023 [CBIT](ERROR): Data Fault in component: PAR_Licor 2019-07-19T03:08:24.023Z,1563505704.023 [CBIT](INFO): Clearing failed state for component PAR_Licor 2019-07-19T03:08:24.023Z,1563505704.023 [PAR_Licor] No Fault, FailCount= 1 2019-07-19T03:08:43.716Z,1563505723.716 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T03:08:43.717Z,1563505723.717 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 33 2019-07-19T03:08:43.717Z,1563505723.717 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T03:08:43.728Z,1563505723.728 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T03:08:44.148Z,1563505724.148 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T03:08:44.148Z,1563505724.148 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 33 2019-07-19T03:10:39.283Z,1563505839.283 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-07-19T03:05:39.1Z 2019-07-19T03:10:39.283Z,1563505839.283 [Default:CheckIn:Read_GPS] Stopped 2019-07-19T03:10:39.283Z,1563505839.283 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-07-19T03:10:42.878Z,1563505842.878 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-07-19T03:10:44.540Z,1563505844.540 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T03:10:44.540Z,1563505844.540 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 34 2019-07-19T03:10:44.540Z,1563505844.540 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T03:10:44.550Z,1563505844.550 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T03:10:44.937Z,1563505844.937 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T03:10:44.937Z,1563505844.937 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 34 2019-07-19T03:10:47.256Z,1563505847.256 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190719T015755/Courier0016.lzma 2019-07-19T03:10:48.062Z,1563505848.062 [DataOverHttps](INFO): Moved sent file to Logs/20190719T015755/Courier0016.lzma.bak 2019-07-19T03:10:48.062Z,1563505848.062 [DataOverHttps](INFO): SBD MOMSN=11455875 2019-07-19T03:11:04.881Z,1563505864.881 [DataOverHttps](INFO): Sending 332 bytes from file Logs/20190719T015755/Express0017.lzma 2019-07-19T03:11:05.686Z,1563505865.686 [DataOverHttps](INFO): Moved sent file to Logs/20190719T015755/Express0017.lzma.bak 2019-07-19T03:11:05.687Z,1563505865.687 [DataOverHttps](INFO): SBD MOMSN=11455877 2019-07-19T03:11:12.799Z,1563505872.799 [Default:CheckIn:Read_Iridium] Stopped 2019-07-19T03:11:12.799Z,1563505872.799 [Default:CheckIn:C.Wait] Running Loop=1 2019-07-19T03:11:12.799Z,1563505872.799 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-07-19T03:11:13.577Z,1563505873.577 [NAL9602](INFO): Not Powering down - fast GPS 2019-07-19T03:12:45.711Z,1563505965.711 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-07-19T03:12:45.711Z,1563505965.711 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 35 2019-07-19T03:12:45.711Z,1563505965.711 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-19T03:12:45.721Z,1563505965.721 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-19T03:12:46.138Z,1563505966.138 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-19T03:12:46.138Z,1563505966.138 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 35