2018-07-30T18:30:13.203Z,1532975413.203 [Supervisor](DEBUG): Initializing supervisor. 2018-07-30T18:30:13.206Z,1532975413.206 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2018-07-30T18:30:13.207Z,1532975413.207 [SyncHandler](INFO): Protected caller Thread ID is 970 2018-07-30T18:30:13.207Z,1532975413.207 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2018-07-30T18:30:13.208Z,1532975413.208 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2018-07-30T18:30:13.209Z,1532975413.209 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 971 2018-07-30T18:30:13.212Z,1532975413.212 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2018-07-30T18:30:13.224Z,1532975413.224 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2018-07-30T18:30:13.225Z,1532975413.225 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2018-07-30T18:30:13.225Z,1532975413.225 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 972 2018-07-30T18:30:13.226Z,1532975413.226 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2018-07-30T18:30:13.227Z,1532975413.227 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2018-07-30T18:30:13.227Z,1532975413.227 [logger ThreadHandler](INFO): Protected caller Thread ID is 973 2018-07-30T18:30:13.229Z,1532975413.229 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2018-07-30T18:30:13.230Z,1532975413.230 [Supervisor](INFO): Looking for Config files in directory: Config/ 2018-07-30T18:30:13.231Z,1532975413.231 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2018-07-30T18:30:13.432Z,1532975413.432 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2018-07-30T18:30:13.432Z,1532975413.432 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2018-07-30T18:30:13.576Z,1532975413.576 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2018-07-30T18:30:13.577Z,1532975413.577 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2018-07-30T18:30:13.942Z,1532975413.942 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2018-07-30T18:30:13.943Z,1532975413.943 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2018-07-30T18:30:14.083Z,1532975414.083 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2018-07-30T18:30:14.083Z,1532975414.083 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2018-07-30T18:30:14.165Z,1532975414.165 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2018-07-30T18:30:14.372Z,1532975414.372 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2018-07-30T18:30:14.373Z,1532975414.373 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2018-07-30T18:30:14.472Z,1532975414.472 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2018-07-30T18:30:14.473Z,1532975414.473 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2018-07-30T18:30:14.821Z,1532975414.821 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2018-07-30T18:30:14.822Z,1532975414.822 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2018-07-30T18:30:15.266Z,1532975415.266 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2018-07-30T18:30:15.267Z,1532975415.267 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2018-07-30T18:30:15.581Z,1532975415.581 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2018-07-30T18:30:15.582Z,1532975415.582 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2018-07-30T18:30:16.096Z,1532975416.096 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2018-07-30T18:30:16.096Z,1532975416.096 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2018-07-30T18:30:16.310Z,1532975416.310 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2018-07-30T18:30:16.311Z,1532975416.311 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2018-07-30T18:30:16.409Z,1532975416.409 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2018-07-30T18:30:16.410Z,1532975416.410 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2018-07-30T18:30:16.906Z,1532975416.906 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2018-07-30T18:30:16.906Z,1532975416.906 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2018-07-30T18:30:17.036Z,1532975417.036 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2018-07-30T18:30:17.038Z,1532975417.038 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/ 2018-07-30T18:30:17.038Z,1532975417.038 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg 2018-07-30T18:30:17.476Z,1532975417.476 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2018-07-30T18:30:17.477Z,1532975417.477 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg 2018-07-30T18:30:17.576Z,1532975417.576 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg 2018-07-30T18:30:17.671Z,1532975417.671 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg 2018-07-30T18:30:17.775Z,1532975417.775 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg 2018-07-30T18:30:17.862Z,1532975417.862 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg 2018-07-30T18:30:17.996Z,1532975417.996 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg 2018-07-30T18:30:18.203Z,1532975418.203 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg 2018-07-30T18:30:18.315Z,1532975418.315 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg 2018-07-30T18:30:18.400Z,1532975418.400 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg 2018-07-30T18:30:18.484Z,1532975418.484 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg 2018-07-30T18:30:18.676Z,1532975418.676 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2018-07-30T18:30:18.682Z,1532975418.682 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2018-07-30T18:30:18.837Z,1532975418.837 [SBIT](DEBUG): Construct Startup Built In Test. 2018-07-30T18:30:18.867Z,1532975418.867 [SBIT] Loaded 2018-07-30T18:30:18.867Z,1532975418.867 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2018-07-30T18:30:18.868Z,1532975418.868 [IBIT](DEBUG): Construct Initiated Built In Test. 2018-07-30T18:30:18.896Z,1532975418.896 [IBIT] Loaded 2018-07-30T18:30:18.896Z,1532975418.896 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2018-07-30T18:30:18.899Z,1532975418.899 [CBIT](DEBUG): Construct Continuous Built In Test. 2018-07-30T18:30:19.056Z,1532975419.056 [CBIT] Loaded 2018-07-30T18:30:19.057Z,1532975419.057 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2018-07-30T18:30:19.057Z,1532975419.057 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2018-07-30T18:30:19.058Z,1532975419.058 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2018-07-30T18:30:19.127Z,1532975419.127 [VerticalControl](DEBUG): Construct VerticalControl. 2018-07-30T18:30:19.227Z,1532975419.227 [VerticalControl] Loaded 2018-07-30T18:30:19.227Z,1532975419.227 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2018-07-30T18:30:19.228Z,1532975419.228 [HorizontalControl](DEBUG): Construct HorizontalControl. 2018-07-30T18:30:19.344Z,1532975419.344 [HorizontalControl] Loaded 2018-07-30T18:30:19.345Z,1532975419.345 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2018-07-30T18:30:19.345Z,1532975419.345 [SpeedControl](DEBUG): Construct SpeedControl. 2018-07-30T18:30:19.351Z,1532975419.351 [SpeedControl] Loaded 2018-07-30T18:30:19.351Z,1532975419.351 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2018-07-30T18:30:19.352Z,1532975419.352 [LoopControl](DEBUG): Construct LoopControl. 2018-07-30T18:30:19.372Z,1532975419.372 [LoopControl] Loaded 2018-07-30T18:30:19.373Z,1532975419.373 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2018-07-30T18:30:19.373Z,1532975419.373 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2018-07-30T18:30:19.374Z,1532975419.374 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2018-07-30T18:30:19.515Z,1532975419.515 [DepthRateCalculator] Loaded 2018-07-30T18:30:19.516Z,1532975419.516 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2018-07-30T18:30:19.522Z,1532975419.522 [PitchRateCalculator] Loaded 2018-07-30T18:30:19.523Z,1532975419.523 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2018-07-30T18:30:19.591Z,1532975419.591 [SpeedCalculator] Loaded 2018-07-30T18:30:19.592Z,1532975419.592 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2018-07-30T18:30:19.613Z,1532975419.613 [TempGradientCalculator] Loaded 2018-07-30T18:30:19.614Z,1532975419.614 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2018-07-30T18:30:19.629Z,1532975419.629 [VerticalTemperatureHomogeneityIndexCalculator] Loaded 2018-07-30T18:30:19.630Z,1532975419.630 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread. 2018-07-30T18:30:19.635Z,1532975419.635 [YawRateCalculator] Loaded 2018-07-30T18:30:19.635Z,1532975419.635 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2018-07-30T18:30:19.664Z,1532975419.664 [ElevatorOffsetCalculator] Loaded 2018-07-30T18:30:19.665Z,1532975419.665 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2018-07-30T18:30:19.665Z,1532975419.665 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2018-07-30T18:30:19.666Z,1532975419.666 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2018-07-30T18:30:19.753Z,1532975419.753 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC 2018-07-30T18:30:19.753Z,1532975419.753 [StratificationFrontDetector](DEBUG): (re)initializing 2018-07-30T18:30:19.754Z,1532975419.754 [StratificationFrontDetector] Loaded 2018-07-30T18:30:19.754Z,1532975419.754 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread. 2018-07-30T18:30:19.755Z,1532975419.755 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2018-07-30T18:30:19.755Z,1532975419.755 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2018-07-30T18:30:20.002Z,1532975420.002 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2018-07-30T18:30:20.003Z,1532975420.003 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2018-07-30T18:30:20.100Z,1532975420.100 [DeadReckonUsingMultipleVelocitySources] Loaded 2018-07-30T18:30:20.101Z,1532975420.101 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2018-07-30T18:30:20.156Z,1532975420.156 [DeadReckonUsingSpeedCalculator] Loaded 2018-07-30T18:30:20.156Z,1532975420.156 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2018-07-30T18:30:20.173Z,1532975420.173 [NavChart] Loaded 2018-07-30T18:30:20.173Z,1532975420.173 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2018-07-30T18:30:20.177Z,1532975420.177 [UniversalFixResidualReporter] Loaded 2018-07-30T18:30:20.178Z,1532975420.178 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2018-07-30T18:30:20.178Z,1532975420.178 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2018-07-30T18:30:20.179Z,1532975420.179 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2018-07-30T18:30:20.193Z,1532975420.193 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2018-07-30T18:30:20.193Z,1532975420.193 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2018-07-30T18:30:20.352Z,1532975420.352 [Aanderaa_O2] Loaded 2018-07-30T18:30:20.352Z,1532975420.352 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2018-07-30T18:30:20.403Z,1532975420.403 [WetLabsBB2FL] Loaded 2018-07-30T18:30:20.404Z,1532975420.404 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2018-07-30T18:30:20.405Z,1532975420.405 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406D34E0 2018-07-30T18:30:20.405Z,1532975420.405 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1052 2018-07-30T18:30:20.406Z,1532975420.406 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2018-07-30T18:30:20.406Z,1532975420.406 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2018-07-30T18:30:20.698Z,1532975420.698 [AHRS_M2] Loaded 2018-07-30T18:30:20.698Z,1532975420.698 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2018-07-30T18:30:20.766Z,1532975420.766 [DataOverHttps] Loaded 2018-07-30T18:30:20.766Z,1532975420.766 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2018-07-30T18:30:20.780Z,1532975420.780 [Depth_Keller] Loaded 2018-07-30T18:30:20.780Z,1532975420.780 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2018-07-30T18:30:20.785Z,1532975420.785 [DropWeight] Loaded 2018-07-30T18:30:20.785Z,1532975420.785 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2018-07-30T18:30:20.876Z,1532975420.876 [NAL9602] Loaded 2018-07-30T18:30:20.876Z,1532975420.876 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2018-07-30T18:30:20.882Z,1532975420.882 [Onboard] Loaded 2018-07-30T18:30:20.882Z,1532975420.882 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2018-07-30T18:30:20.889Z,1532975420.889 [Radio_Surface] Loaded 2018-07-30T18:30:20.889Z,1532975420.889 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2018-07-30T18:30:20.890Z,1532975420.890 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409294E0 2018-07-30T18:30:20.891Z,1532975420.891 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1053 2018-07-30T18:30:20.920Z,1532975420.920 [RDI_Pathfinder] Loaded 2018-07-30T18:30:20.920Z,1532975420.920 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread. 2018-07-30T18:30:20.926Z,1532975420.926 [SCPI] Loaded 2018-07-30T18:30:20.927Z,1532975420.927 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread. 2018-07-30T18:30:22.842Z,1532975422.842 [BPC1] Loaded 2018-07-30T18:30:22.842Z,1532975422.842 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2018-07-30T18:30:22.842Z,1532975422.842 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2018-07-30T18:30:22.843Z,1532975422.843 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2018-07-30T18:30:23.057Z,1532975423.057 [BuoyancyServo] Loaded 2018-07-30T18:30:23.057Z,1532975423.057 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2018-07-30T18:30:23.069Z,1532975423.069 [ElevatorServo] Loaded 2018-07-30T18:30:23.069Z,1532975423.069 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2018-07-30T18:30:23.080Z,1532975423.080 [MassServo] Loaded 2018-07-30T18:30:23.080Z,1532975423.080 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2018-07-30T18:30:23.092Z,1532975423.092 [RudderServo] Loaded 2018-07-30T18:30:23.092Z,1532975423.092 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2018-07-30T18:30:23.103Z,1532975423.103 [ThrusterServo] Loaded 2018-07-30T18:30:23.103Z,1532975423.103 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2018-07-30T18:30:23.104Z,1532975423.104 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2018-07-30T18:30:23.104Z,1532975423.104 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2018-07-30T18:30:23.208Z,1532975423.208 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2018-07-30T18:30:23.208Z,1532975423.208 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2018-07-30T18:30:23.233Z,1532975423.233 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2018-07-30T18:30:23.237Z,1532975423.237 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2018-07-30T18:30:23.238Z,1532975423.238 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2018-07-30T18:30:23.245Z,1532975423.245 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2018-07-30T18:30:23.246Z,1532975423.246 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 409D24E0 2018-07-30T18:30:23.246Z,1532975423.246 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1054 2018-07-30T18:30:23.251Z,1532975423.251 [Supervisor](INFO): Main Thread ID is 795 2018-07-30T18:30:23.251Z,1532975423.251 [Supervisor](DEBUG): Running supervisor. 2018-07-30T18:30:23.252Z,1532975423.252 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1055 2018-07-30T18:30:23.254Z,1532975423.254 [controlThread ThreadHandler](INFO): Handler Thread ID is 1056 2018-07-30T18:30:23.255Z,1532975423.255 [controlThread](DEBUG): Initializing ControlThread 2018-07-30T18:30:23.256Z,1532975423.256 [SBIT](INFO): Initialize SBIT Component. 2018-07-30T18:30:23.256Z,1532975423.256 [SBIT](IMPORTANT): git: 2018-07-30 2018-07-30T18:30:23.256Z,1532975423.256 [SBIT](INFO): git hash: d4f8f0da1cb083ba9f96282d65d9cbbd19acaad4 2018-07-30T18:30:23.257Z,1532975423.257 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2018-07-30T18:30:23.258Z,1532975423.258 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 Kernel Reported: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 2018-07-30T18:30:23.259Z,1532975423.259 [SBIT](INFO): Beginning SBIT in 24.000000 seconds. 2018-07-30T18:30:23.260Z,1532975423.260 [IBIT](INFO): Initialize IBIT Component. 2018-07-30T18:30:23.261Z,1532975423.261 [CBIT](DEBUG): Initialize CBIT Component. 2018-07-30T18:30:23.261Z,1532975423.261 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2018-07-30T18:30:23.262Z,1532975423.262 [logger ThreadHandler](INFO): Handler Thread ID is 1057 2018-07-30T18:30:23.281Z,1532975423.281 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1058 2018-07-30T18:30:23.293Z,1532975423.293 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1059 2018-07-30T18:30:23.299Z,1532975423.299 [Radio_Surface](INFO): Powering up 2018-07-30T18:30:23.305Z,1532975423.305 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1060 2018-07-30T18:30:23.308Z,1532975423.308 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2018-07-30T18:30:23.309Z,1532975423.309 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2018-07-30T18:30:23.309Z,1532975423.309 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2018-07-30T18:30:23.309Z,1532975423.309 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2018-07-30T18:30:23.309Z,1532975423.309 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2018-07-30T18:30:23.309Z,1532975423.309 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2018-07-30T18:30:23.310Z,1532975423.310 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2018-07-30T18:30:23.310Z,1532975423.310 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2018-07-30T18:30:23.310Z,1532975423.310 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2018-07-30T18:30:23.310Z,1532975423.310 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2018-07-30T18:30:23.310Z,1532975423.310 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2018-07-30T18:30:23.310Z,1532975423.310 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2018-07-30T18:30:23.311Z,1532975423.311 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2018-07-30T18:30:23.311Z,1532975423.311 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2018-07-30T18:30:23.311Z,1532975423.311 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2018-07-30T18:30:23.311Z,1532975423.311 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2018-07-30T18:30:23.369Z,1532975423.369 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2018-07-30T18:30:23.371Z,1532975423.371 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2018-07-30T18:30:23.371Z,1532975423.371 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2018-07-30T18:30:23.372Z,1532975423.372 [LoopControl](DEBUG): Initialize LoopControlComponent. 2018-07-30T18:30:23.372Z,1532975423.372 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2018-07-30T18:30:23.373Z,1532975423.373 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2018-07-30T18:30:23.373Z,1532975423.373 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2018-07-30T18:30:23.373Z,1532975423.373 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2018-07-30T18:30:23.374Z,1532975423.374 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing 2018-07-30T18:30:23.375Z,1532975423.375 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2018-07-30T18:30:23.375Z,1532975423.375 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2018-07-30T18:30:23.376Z,1532975423.376 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2018-07-30T18:30:23.377Z,1532975423.377 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2018-07-30T18:30:23.377Z,1532975423.377 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2018-07-30T18:30:23.378Z,1532975423.378 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-07-30T18:30:23.378Z,1532975423.378 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-07-30T18:30:23.378Z,1532975423.378 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-07-30T18:30:23.379Z,1532975423.379 [NavChart](DEBUG): Initialize NavChart Navigation. 2018-07-30T18:30:23.379Z,1532975423.379 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2018-07-30T18:30:23.405Z,1532975423.405 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2018-07-30T18:30:23.442Z,1532975423.442 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2018-07-30T18:30:23.473Z,1532975423.473 [MissionManager](DEBUG): 2018-07-30T18:30:23.474Z,1532975423.474 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2018-07-30T18:30:23.583Z,1532975423.583 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2018-07-30T18:30:23.584Z,1532975423.584 [Default:A.Wait](DEBUG): Construct Wait. 2018-07-30T18:30:23.586Z,1532975423.586 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2018-07-30T18:30:23.625Z,1532975423.625 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2018-07-30T18:30:23.628Z,1532975423.628 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2018-07-30T18:30:23.646Z,1532975423.646 [Default:E.Execute](DEBUG): Construct Execute. 2018-07-30T18:30:23.650Z,1532975423.650 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn 300 Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2018-07-30T18:30:23.665Z,1532975423.665 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,AHRS_M2,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,RDI_Pathfinder,SCPI,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2018-07-30T18:30:23.725Z,1532975423.725 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2018-07-30T18:30:23.769Z,1532975423.769 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2018-07-30T18:30:23.797Z,1532975423.797 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar 2018-07-30T18:30:24.007Z,1532975424.007 [DepthRateCalculator](ERROR): Depth measurement is not active 2018-07-30T18:30:24.105Z,1532975424.105 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:24.129Z,1532975424.129 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:24.237Z,1532975424.237 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2018-07-30T18:30:24.245Z,1532975424.245 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2018-07-30T18:30:24.255Z,1532975424.255 [ElevatorServo](DEBUG): Initializing EZServoServo. 2018-07-30T18:30:24.261Z,1532975424.261 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2018-07-30T18:30:24.283Z,1532975424.283 [MassServo](DEBUG): Initializing EZServoServo. 2018-07-30T18:30:24.289Z,1532975424.289 [MassServo](DEBUG): Initializing MassServo. 2018-07-30T18:30:24.315Z,1532975424.315 [RudderServo](DEBUG): Initializing EZServoServo. 2018-07-30T18:30:24.321Z,1532975424.321 [RudderServo](DEBUG): Initializing RudderServo. 2018-07-30T18:30:24.327Z,1532975424.327 [ThrusterServo](DEBUG): Initializing EZServoServo. 2018-07-30T18:30:24.337Z,1532975424.337 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2018-07-30T18:30:24.541Z,1532975424.541 [DepthRateCalculator](ERROR): Depth measurement is not active 2018-07-30T18:30:24.545Z,1532975424.545 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:24.546Z,1532975424.546 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:24.861Z,1532975424.861 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:24.862Z,1532975424.862 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:25.193Z,1532975425.193 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout 2018-07-30T18:30:25.193Z,1532975425.193 [BuoyancyServo](FAULT): Buoyancy failed to initialize 2018-07-30T18:30:25.193Z,1532975425.193 [BuoyancyServo] Communications Fault, FailCount= 1 2018-07-30T18:30:25.193Z,1532975425.193 [BuoyancyServo](ERROR): Communications Fault 2018-07-30T18:30:25.405Z,1532975425.405 [CBIT](ERROR): Communications Fault in component: BuoyancyServo 2018-07-30T18:30:25.454Z,1532975425.454 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:25.455Z,1532975425.455 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:25.477Z,1532975425.477 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2018-07-30T18:30:25.478Z,1532975425.478 [BuoyancyServo](INFO): Powering down 2018-07-30T18:30:25.845Z,1532975425.845 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:25.846Z,1532975425.846 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:26.245Z,1532975426.245 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:26.246Z,1532975426.246 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:26.641Z,1532975426.641 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:26.642Z,1532975426.642 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:27.133Z,1532975427.133 [Aanderaa_O2](INFO): Powering down 2018-07-30T18:30:27.281Z,1532975427.281 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:27.282Z,1532975427.282 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:27.505Z,1532975427.505 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:27.506Z,1532975427.506 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:27.558Z,1532975427.558 [CBIT](INFO): Clearing failed state for component BuoyancyServo 2018-07-30T18:30:27.558Z,1532975427.558 [BuoyancyServo] No Fault, FailCount= 1 2018-07-30T18:30:27.868Z,1532975427.868 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:27.870Z,1532975427.870 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:27.876Z,1532975427.876 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2018-07-30T18:30:27.993Z,1532975427.993 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2018-07-30T18:30:28.273Z,1532975428.273 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:28.274Z,1532975428.274 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:28.747Z,1532975428.747 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:28.748Z,1532975428.748 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:29.122Z,1532975429.122 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:29.123Z,1532975429.123 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:29.510Z,1532975429.510 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:29.511Z,1532975429.511 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:29.922Z,1532975429.922 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:29.923Z,1532975429.923 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:30.314Z,1532975430.314 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:30.315Z,1532975430.315 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:30.710Z,1532975430.710 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:30.711Z,1532975430.711 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:31.082Z,1532975431.082 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:31.083Z,1532975431.083 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:31.482Z,1532975431.482 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:31.483Z,1532975431.483 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:31.910Z,1532975431.910 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:31.911Z,1532975431.911 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-30T18:30:37.493Z,1532975437.493 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder 2018-07-30T18:30:47.936Z,1532975447.936 [SBIT](IMPORTANT): Beginning Startup BIT 2018-07-30T18:30:47.949Z,1532975447.949 [CBIT](IMPORTANT): Beginning ground fault scan 2018-07-30T18:30:51.191Z,1532975451.191 [NAL9602](INFO): Powering up NAL9602 2018-07-30T18:30:58.906Z,1532975458.906 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.019644 CHAN A1 (24V): -0.022763 CHAN A2 (12V): -0.007411 CHAN A3 (5V): -0.002228 CHAN B0 (3.3V): 0.000250 CHAN B1 (3.15aV): 0.000251 CHAN B2 (3.15bV): 0.000345 CHAN B3 (GND): 0.002147 OPEN: 0.004611 Full Scale Calc: 4.765 mA, -1.589 mA 2018-07-30T18:31:02.399Z,1532975462.399 [NAL9602](INFO): NAL9602 initialized 2018-07-30T18:31:29.780Z,1532975489.780 [NAL9602](INFO): SBD MO Status=2, MOMSN=536, MT Status=2, MTMSN=0 2018-07-30T18:31:29.780Z,1532975489.780 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2018-07-30T18:31:39.128Z,1532975499.128 [NAL9602](INFO): SBD MO Status=0, MOMSN=536, MT Status=0, MTMSN=0 2018-07-30T18:31:39.128Z,1532975499.128 [NAL9602](INFO): No messages in MT queue 2018-07-30T18:31:40.351Z,1532975500.351 [NAL9602](INFO): GPS fix at 20180730T183138: (36.802178, -121.787016) 2018-07-30T18:31:41.993Z,1532975501.993 [SBIT](IMPORTANT): SBIT PASSED 2018-07-30T18:31:42.069Z,1532975502.069 [CommandLine](IMPORTANT): got command configSet list 2018-07-30T18:31:42.070Z,1532975502.070 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2018-07-30T18:31:42.070Z,1532975502.070 [CommandLine](IMPORTANT): AHRS_M2.readAccelerations=1 bool; 2018-07-30T18:31:42.070Z,1532975502.070 [CommandLine](IMPORTANT): AHRS_M2.readMagnetics=1 bool; 2018-07-30T18:31:42.071Z,1532975502.071 [CommandLine](IMPORTANT): Express linearApproximation height_above_sea_floor 5.000000 meter; 2018-07-30T18:31:42.071Z,1532975502.071 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=160 cubic_centimeter; 2018-07-30T18:31:42.071Z,1532975502.071 [CommandLine](IMPORTANT): VerticalControl.massDefault=-1 millimeter; 2018-07-30T18:31:42.431Z,1532975502.431 [MissionManager](IMPORTANT): Started mission Startup 2018-07-30T18:31:42.431Z,1532975502.431 [Startup] Running Loop=1 2018-07-30T18:31:42.432Z,1532975502.432 [Startup](DEBUG): Aggregate::initialize Startup 2018-07-30T18:31:42.432Z,1532975502.432 [Startup:A.GoToSurface] Running Loop=1 2018-07-30T18:31:42.432Z,1532975502.432 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2018-07-30T18:31:42.433Z,1532975502.433 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2018-07-30T18:31:42.433Z,1532975502.433 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2018-07-30T18:31:42.433Z,1532975502.433 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2018-07-30T18:31:42.434Z,1532975502.434 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2018-07-30T18:31:42.434Z,1532975502.434 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2018-07-30T18:31:42.441Z,1532975502.441 [Startup:StartupSatComms] Running Loop=1 2018-07-30T18:31:42.441Z,1532975502.441 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2018-07-30T18:31:42.441Z,1532975502.441 [Startup:StartupSatComms:A] Running Loop=1 2018-07-30T18:31:42.789Z,1532975502.789 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2018-07-30T18:31:44.342Z,1532975504.342 [NAL9602](INFO): GPS fix at 20180730T183142: (36.802179, -121.787015) 2018-07-30T18:31:44.405Z,1532975504.405 [Startup:StartupSatComms:A] Stopped 2018-07-30T18:31:44.405Z,1532975504.405 [Startup:StartupSatComms:B] Running Loop=1 2018-07-30T18:31:44.821Z,1532975504.821 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2018-07-30T18:32:07.124Z,1532975527.124 [NAL9602](INFO): SBD MO Status=2, MOMSN=537, MT Status=2, MTMSN=0 2018-07-30T18:32:07.124Z,1532975527.124 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2018-07-30T18:32:17.280Z,1532975537.280 [NAL9602](INFO): SBD MO Status=1, MOMSN=537, MT Status=0, MTMSN=0 2018-07-30T18:32:17.329Z,1532975537.329 [NAL9602](INFO): Sent 25 bytes from file Logs/20180730T181223/Courier0016.lzma 2018-07-30T18:32:17.330Z,1532975537.330 [NAL9602](INFO): Packets left to send: 0 2018-07-30T18:32:17.333Z,1532975537.333 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180730T181223/Courier0016.lzma.parts/0000.sbd 2018-07-30T18:32:17.334Z,1532975537.334 [NAL9602](DEBUG): Completed sending Logs/20180730T181223/Courier0016.lzma 2018-07-30T18:32:40.244Z,1532975560.244 [NAL9602](INFO): SBD MO Status=1, MOMSN=538, MT Status=0, MTMSN=0 2018-07-30T18:32:40.298Z,1532975560.298 [NAL9602](INFO): Sent 212 bytes from file Logs/20180730T183013/Courier0000.lzma 2018-07-30T18:32:40.298Z,1532975560.298 [NAL9602](INFO): Packets left to send: 0 2018-07-30T18:32:40.301Z,1532975560.301 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180730T183013/Courier0000.lzma.parts/0000.sbd 2018-07-30T18:32:40.302Z,1532975560.302 [NAL9602](DEBUG): Completed sending Logs/20180730T183013/Courier0000.lzma 2018-07-30T18:32:44.457Z,1532975564.457 [Startup:StartupSatComms:B](INFO): Timed out from 2018-07-30T18:31:44.4Z 2018-07-30T18:32:44.457Z,1532975564.457 [Startup:StartupSatComms:B] Stopped 2018-07-30T18:32:44.458Z,1532975564.458 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2018-07-30T18:32:44.458Z,1532975564.458 [Startup:StartupSatComms] Stopped 2018-07-30T18:32:44.458Z,1532975564.458 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2018-07-30T18:32:44.459Z,1532975564.459 [Startup](INFO): Completed Startup 2018-07-30T18:32:44.459Z,1532975564.459 [MissionManager](INFO): Startup is completed. 2018-07-30T18:32:44.459Z,1532975564.459 [MissionManager](INFO): Uninitializing Mission Startup 2018-07-30T18:32:44.459Z,1532975564.459 [Startup] Stopped 2018-07-30T18:32:44.459Z,1532975564.459 [Startup](DEBUG): Aggregate::uninitialize Startup 2018-07-30T18:32:44.460Z,1532975564.460 [Startup:A.GoToSurface] Stopped 2018-07-30T18:32:44.460Z,1532975564.460 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2018-07-30T18:32:44.872Z,1532975564.872 [MissionManager](IMPORTANT): Started mission Default 2018-07-30T18:32:44.872Z,1532975564.872 [Default] Running Loop=1 2018-07-30T18:32:44.872Z,1532975564.872 [Default](DEBUG): Aggregate::initialize Default 2018-07-30T18:32:44.872Z,1532975564.872 [Default:B.GoToSurface] Running Loop=1 2018-07-30T18:32:44.872Z,1532975564.872 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2018-07-30T18:32:44.873Z,1532975564.873 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2018-07-30T18:32:44.873Z,1532975564.873 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2018-07-30T18:32:44.874Z,1532975564.874 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2018-07-30T18:32:44.874Z,1532975564.874 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2018-07-30T18:32:44.874Z,1532975564.874 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2018-07-30T18:32:44.875Z,1532975564.875 [Default:A.Wait] Running Loop=1 2018-07-30T18:32:44.875Z,1532975564.875 [Default:A.Wait](DEBUG): Initialize Wait Component. 2018-07-30T18:32:52.395Z,1532975572.395 [NAL9602](INFO): SBD MO Status=1, MOMSN=539, MT Status=0, MTMSN=0 2018-07-30T18:32:52.446Z,1532975572.446 [NAL9602](INFO): Sent 270 bytes from file Logs/20180730T181223/Express0017.lzma 2018-07-30T18:32:52.446Z,1532975572.446 [NAL9602](INFO): Packets left to send: 0 2018-07-30T18:32:52.447Z,1532975572.447 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180730T181223/Express0017.lzma.parts/0000.sbd 2018-07-30T18:32:52.448Z,1532975572.448 [NAL9602](DEBUG): Completed sending Logs/20180730T181223/Express0017.lzma 2018-07-30T18:32:58.073Z,1532975578.073 [Default:A.Wait](INFO): Done Waiting. 2018-07-30T18:32:58.073Z,1532975578.073 [Default:A.Wait] Stopped 2018-07-30T18:32:58.073Z,1532975578.073 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2018-07-30T18:32:58.498Z,1532975578.498 [Default:CheckIn] Running Loop=1 2018-07-30T18:32:58.498Z,1532975578.498 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-30T18:32:58.498Z,1532975578.498 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-30T18:32:58.857Z,1532975578.857 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2018-07-30T18:33:00.410Z,1532975580.410 [NAL9602](INFO): GPS fix at 20180730T183258: (36.802179, -121.787033) 2018-07-30T18:33:00.473Z,1532975580.473 [Default:CheckIn:Read_GPS] Stopped 2018-07-30T18:33:00.474Z,1532975580.474 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-30T18:33:00.873Z,1532975580.873 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2018-07-30T18:33:14.564Z,1532975594.564 [NAL9602](INFO): SBD MO Status=1, MOMSN=540, MT Status=0, MTMSN=0 2018-07-30T18:33:14.613Z,1532975594.613 [NAL9602](INFO): Sent 62 bytes from file Logs/20180730T183013/Courier0004.lzma 2018-07-30T18:33:14.613Z,1532975594.613 [NAL9602](INFO): Packets left to send: 0 2018-07-30T18:33:14.615Z,1532975594.615 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180730T183013/Courier0004.lzma.parts/0000.sbd 2018-07-30T18:33:14.615Z,1532975594.615 [NAL9602](DEBUG): Completed sending Logs/20180730T183013/Courier0004.lzma 2018-07-30T18:33:25.916Z,1532975605.916 [NAL9602](INFO): SBD MO Status=1, MOMSN=541, MT Status=0, MTMSN=0 2018-07-30T18:33:25.969Z,1532975605.969 [NAL9602](INFO): Sent 332 bytes from file Logs/20180730T183013/Express0001.lzma 2018-07-30T18:33:25.969Z,1532975605.969 [NAL9602](INFO): Packets left to send: 2 2018-07-30T18:33:25.971Z,1532975605.971 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180730T183013/Express0001.lzma.parts/0002.sbd 2018-07-30T18:33:34.882Z,1532975614.882 [RDI_Pathfinder](ERROR): Failed to parse: :HM,G,G,0e87,0e87,*14.577,*-0.056,*0.000 2018-07-30T18:33:37.256Z,1532975617.256 [NAL9602](INFO): SBD MO Status=1, MOMSN=542, MT Status=0, MTMSN=0 2018-07-30T18:33:37.305Z,1532975617.305 [NAL9602](INFO): Sent 332 bytes from file Logs/20180730T183013/Express0001.lzma 2018-07-30T18:33:37.305Z,1532975617.305 [NAL9602](INFO): Packets left to send: 1 2018-07-30T18:33:37.307Z,1532975617.307 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180730T183013/Express0001.lzma.parts/0001.sbd 2018-07-30T18:33:48.218Z,1532975628.218 [NAL9602](INFO): SBD MO Status=1, MOMSN=543, MT Status=0, MTMSN=0 2018-07-30T18:33:48.274Z,1532975628.274 [NAL9602](INFO): Sent 182 bytes from file Logs/20180730T183013/Express0001.lzma 2018-07-30T18:33:48.274Z,1532975628.274 [NAL9602](INFO): Packets left to send: 0 2018-07-30T18:33:48.277Z,1532975628.277 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180730T183013/Express0001.lzma.parts/0000.sbd 2018-07-30T18:33:48.278Z,1532975628.278 [NAL9602](DEBUG): Completed sending Logs/20180730T183013/Express0001.lzma 2018-07-30T18:33:51.042Z,1532975631.042 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004069 2018-07-30T18:33:55.118Z,1532975635.118 [NAL9602](INFO): SBD MO Status=1, MOMSN=544, MT Status=0, MTMSN=0 2018-07-30T18:33:55.173Z,1532975635.173 [NAL9602](INFO): Sent 96 bytes from file Logs/20180730T183013/Express0005.lzma 2018-07-30T18:33:55.173Z,1532975635.173 [NAL9602](INFO): Packets left to send: 0 2018-07-30T18:33:55.175Z,1532975635.175 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180730T183013/Express0005.lzma.parts/0000.sbd 2018-07-30T18:33:55.175Z,1532975635.175 [NAL9602](DEBUG): Completed sending Logs/20180730T183013/Express0005.lzma 2018-07-30T18:33:55.286Z,1532975635.286 [Default:CheckIn:Read_Iridium] Stopped 2018-07-30T18:33:55.286Z,1532975635.286 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-30T18:33:55.286Z,1532975635.286 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-30T18:33:55.357Z,1532975635.357 [DataOverHttps](IMPORTANT): Could not stat file Logs/20180730T183013/Express0005.lzma 2018-07-30T18:33:55.357Z,1532975635.357 [DataOverHttps](CRITICAL): Could not open file Logs/20180730T183013/Express0005.lzma 2018-07-30T18:33:55.438Z,1532975635.438 [CommandLine](FAULT): Scheduling is paused 2018-07-30T18:33:55.438Z,1532975635.438 [CBIT](INFO): Critical error at 20180730T183355 2018-07-30T18:33:55.439Z,1532975635.439 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2018-07-30T18:34:00.288Z,1532975640.288 [DataOverHttps](IMPORTANT): Could not stat file Logs/20180730T183013/Express0005.lzma 2018-07-30T18:34:00.297Z,1532975640.297 [DataOverHttps](CRITICAL): Could not open file Logs/20180730T183013/Express0005.lzma 2018-07-30T18:34:00.419Z,1532975640.419 [CBIT](INFO): Critical error at 20180730T183400 2018-07-30T18:34:25.446Z,1532975665.446 [NAL9602](INFO): Powering down 2018-07-30T18:35:00.885Z,1532975700.885 [DataOverHttps](IMPORTANT): Could not stat file Logs/20180730T183013/Express0005.lzma 2018-07-30T18:35:00.885Z,1532975700.885 [DataOverHttps](CRITICAL): Could not open file Logs/20180730T183013/Express0005.lzma 2018-07-30T18:35:00.971Z,1532975700.971 [CBIT](INFO): Critical error at 20180730T183500 2018-07-30T18:36:01.166Z,1532975761.166 [DataOverHttps](IMPORTANT): Could not stat file Logs/20180730T183013/Express0005.lzma 2018-07-30T18:36:01.166Z,1532975761.166 [DataOverHttps](CRITICAL): Could not open file Logs/20180730T183013/Express0005.lzma 2018-07-30T18:36:01.243Z,1532975761.243 [CBIT](INFO): Critical error at 20180730T183601 2018-07-30T18:37:01.278Z,1532975821.278 [DataOverHttps](IMPORTANT): Could not stat file Logs/20180730T183013/Express0005.lzma 2018-07-30T18:37:01.278Z,1532975821.278 [DataOverHttps](CRITICAL): Could not open file Logs/20180730T183013/Express0005.lzma 2018-07-30T18:37:01.393Z,1532975821.393 [CBIT](INFO): Critical error at 20180730T183701 2018-07-30T18:38:01.015Z,1532975881.015 [DataOverHttps](IMPORTANT): Could not stat file Logs/20180730T183013/Express0005.lzma 2018-07-30T18:38:01.016Z,1532975881.016 [DataOverHttps](CRITICAL): Could not open file Logs/20180730T183013/Express0005.lzma 2018-07-30T18:38:01.094Z,1532975881.094 [CBIT](INFO): Critical error at 20180730T183801 2018-07-30T18:38:55.447Z,1532975935.447 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-30T18:38:55.447Z,1532975935.447 [Default:CheckIn:C.Wait] Stopped 2018-07-30T18:38:55.448Z,1532975935.448 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-30T18:38:55.448Z,1532975935.448 [Default:CheckIn:D] Running Loop=1 2018-07-30T18:38:55.868Z,1532975935.868 [Default:CheckIn:D] Stopped 2018-07-30T18:38:55.870Z,1532975935.870 [Default:CheckIn:E] Running Loop=1 2018-07-30T18:38:56.249Z,1532975936.249 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.183239 min 2018-07-30T18:38:56.251Z,1532975936.251 [Default:CheckIn:E] Stopped 2018-07-30T18:38:56.252Z,1532975936.252 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-30T18:38:56.252Z,1532975936.252 [Default:CheckIn] Stopped 2018-07-30T18:38:56.252Z,1532975936.252 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-30T18:38:56.252Z,1532975936.252 [Default:CheckIn](INFO): Running loop #2 2018-07-30T18:38:56.252Z,1532975936.252 [Default:CheckIn] Running Loop=2 2018-07-30T18:38:56.252Z,1532975936.252 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-30T18:38:56.257Z,1532975936.257 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-30T18:38:56.996Z,1532975936.996 [NAL9602](INFO): Powering up 2018-07-30T18:39:01.326Z,1532975941.326 [DataOverHttps](IMPORTANT): Could not stat file Logs/20180730T183013/Express0005.lzma 2018-07-30T18:39:01.326Z,1532975941.326 [DataOverHttps](CRITICAL): Could not open file Logs/20180730T183013/Express0005.lzma 2018-07-30T18:39:01.424Z,1532975941.424 [CBIT](INFO): Critical error at 20180730T183901 2018-07-30T18:39:08.074Z,1532975948.074 [NAL9602](INFO): NAL9602 initialized 2018-07-30T18:39:28.508Z,1532975968.508 [RDI_Pathfinder](ERROR): Failed to parse: 0 2018-07-30T18:39:36.476Z,1532975976.476 [NAL9602](INFO): SBD MO Status=0, MOMSN=545, MT Status=0, MTMSN=0 2018-07-30T18:39:36.477Z,1532975976.477 [NAL9602](INFO): No messages in MT queue 2018-07-30T18:40:01.426Z,1532976001.426 [DataOverHttps](IMPORTANT): Could not stat file Logs/20180730T183013/Express0005.lzma 2018-07-30T18:40:01.426Z,1532976001.426 [DataOverHttps](CRITICAL): Could not open file Logs/20180730T183013/Express0005.lzma 2018-07-30T18:40:01.504Z,1532976001.504 [CBIT](INFO): Critical error at 20180730T184001 2018-07-30T18:40:06.206Z,1532976006.206 [NAL9602](INFO): GPS fix at 20180730T184004: (36.802463, -121.787027) 2018-07-30T18:40:06.283Z,1532976006.283 [Default:CheckIn:Read_GPS] Stopped 2018-07-30T18:40:06.284Z,1532976006.284 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-30T18:40:10.930Z,1532976010.930 [DataOverHttps](INFO): Sending 349 bytes from file Logs/20180730T183013/Courier0007.lzma 2018-07-30T18:40:11.694Z,1532976011.694 [DataOverHttps](INFO): Moved sent file to Logs/20180730T183013/Courier0007.lzma.bak 2018-07-30T18:40:11.695Z,1532976011.695 [DataOverHttps](INFO): SBD MOMSN=8386147 2018-07-30T18:40:20.726Z,1532976020.726 [DataOverHttps](INFO): Sending 299 bytes from file Logs/20180730T183013/Express0008.lzma 2018-07-30T18:40:21.501Z,1532976021.501 [DataOverHttps](INFO): Moved sent file to Logs/20180730T183013/Express0008.lzma.bak 2018-07-30T18:40:21.501Z,1532976021.501 [DataOverHttps](INFO): SBD MOMSN=8386158 2018-07-30T18:40:22.005Z,1532976022.005 [Default:CheckIn:Read_Iridium] Stopped 2018-07-30T18:40:22.005Z,1532976022.005 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-30T18:40:22.005Z,1532976022.005 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-30T18:40:40.990Z,1532976040.990 [NAL9602](INFO): Powering down 2018-07-30T18:45:22.648Z,1532976322.648 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-30T18:45:22.649Z,1532976322.649 [Default:CheckIn:C.Wait] Stopped 2018-07-30T18:45:22.649Z,1532976322.649 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-30T18:45:22.649Z,1532976322.649 [Default:CheckIn:D] Running Loop=1 2018-07-30T18:45:23.030Z,1532976323.030 [Default:CheckIn:D] Stopped 2018-07-30T18:45:23.030Z,1532976323.030 [Default:CheckIn:E] Running Loop=1 2018-07-30T18:45:23.471Z,1532976323.471 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.635953 min 2018-07-30T18:45:23.471Z,1532976323.471 [Default:CheckIn:E] Stopped 2018-07-30T18:45:23.471Z,1532976323.471 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-30T18:45:23.471Z,1532976323.471 [Default:CheckIn] Stopped 2018-07-30T18:45:23.471Z,1532976323.471 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-30T18:45:23.471Z,1532976323.471 [Default:CheckIn](INFO): Running loop #3 2018-07-30T18:45:23.472Z,1532976323.472 [Default:CheckIn] Running Loop=3 2018-07-30T18:45:23.472Z,1532976323.472 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-30T18:45:23.472Z,1532976323.472 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-30T18:45:26.742Z,1532976326.742 [NAL9602](INFO): Powering up 2018-07-30T18:45:37.910Z,1532976337.910 [NAL9602](INFO): NAL9602 initialized 2018-07-30T18:45:53.507Z,1532976353.507 [NAL9602](INFO): SBD MO Status=0, MOMSN=546, MT Status=0, MTMSN=0 2018-07-30T18:45:53.508Z,1532976353.508 [NAL9602](INFO): No messages in MT queue 2018-07-30T18:46:57.258Z,1532976417.258 [NAL9602](INFO): GPS fix at 20180730T184655: (36.802524, -121.787122) 2018-07-30T18:46:57.355Z,1532976417.355 [Default:CheckIn:Read_GPS] Stopped 2018-07-30T18:46:57.355Z,1532976417.355 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-30T18:47:01.821Z,1532976421.821 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20180730T183013/Courier0010.lzma 2018-07-30T18:47:02.602Z,1532976422.602 [DataOverHttps](INFO): Moved sent file to Logs/20180730T183013/Courier0010.lzma.bak 2018-07-30T18:47:02.602Z,1532976422.602 [DataOverHttps](INFO): SBD MOMSN=8386179 2018-07-30T18:47:11.651Z,1532976431.651 [DataOverHttps](INFO): Sending 122 bytes from file Logs/20180730T183013/Express0011.lzma 2018-07-30T18:47:12.437Z,1532976432.437 [DataOverHttps](INFO): Moved sent file to Logs/20180730T183013/Express0011.lzma.bak 2018-07-30T18:47:12.437Z,1532976432.437 [DataOverHttps](INFO): SBD MOMSN=8386182 2018-07-30T18:47:12.952Z,1532976432.952 [Default:CheckIn:Read_Iridium] Stopped 2018-07-30T18:47:12.952Z,1532976432.952 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-30T18:47:12.952Z,1532976432.952 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-30T18:47:31.994Z,1532976451.994 [NAL9602](INFO): Powering down 2018-07-30T18:52:13.554Z,1532976733.554 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-30T18:52:13.555Z,1532976733.555 [Default:CheckIn:C.Wait] Stopped 2018-07-30T18:52:13.555Z,1532976733.555 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-30T18:52:13.555Z,1532976733.555 [Default:CheckIn:D] Running Loop=1 2018-07-30T18:52:13.941Z,1532976733.941 [Default:CheckIn:D] Stopped 2018-07-30T18:52:13.941Z,1532976733.941 [Default:CheckIn:E] Running Loop=1 2018-07-30T18:52:14.329Z,1532976734.329 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 19.484408 min 2018-07-30T18:52:14.330Z,1532976734.330 [Default:CheckIn:E] Stopped 2018-07-30T18:52:14.330Z,1532976734.330 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-30T18:52:14.330Z,1532976734.330 [Default:CheckIn] Stopped 2018-07-30T18:52:14.330Z,1532976734.330 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-30T18:52:14.330Z,1532976734.330 [Default:CheckIn](INFO): Running loop #4 2018-07-30T18:52:14.330Z,1532976734.330 [Default:CheckIn] Running Loop=4 2018-07-30T18:52:14.331Z,1532976734.331 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-30T18:52:14.331Z,1532976734.331 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-30T18:52:17.602Z,1532976737.602 [NAL9602](INFO): Powering up 2018-07-30T18:52:18.765Z,1532976738.765 [DataOverHttps](IMPORTANT): SBD MTMSN=20180730T185217 2018-07-30T18:52:23.688Z,1532976743.688 [DataOverHttps](INFO): Received command:ibit 2018-07-30T18:52:23.729Z,1532976743.729 [CommandLine](IMPORTANT): got command ibit 2018-07-30T18:52:23.801Z,1532976743.801 [IBIT](IMPORTANT): Beginning Initiated BIT 2018-07-30T18:52:23.801Z,1532976743.801 [IBIT](IMPORTANT): Beginning control surface checks. 2018-07-30T18:52:23.804Z,1532976743.804 [CBIT](IMPORTANT): Beginning ground fault scan 2018-07-30T18:52:28.490Z,1532976748.490 [NAL9602](INFO): NAL9602 initialized 2018-07-30T18:52:34.601Z,1532976754.601 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.115196 CHAN A1 (24V): -0.022484 CHAN A2 (12V): -0.007250 CHAN A3 (5V): -0.001677 CHAN B0 (3.3V): 0.000444 CHAN B1 (3.15aV): -0.000069 CHAN B2 (3.15bV): -0.000217 CHAN B3 (GND): 0.002018 OPEN: 0.004967 Full Scale Calc: 4.765 mA, -1.589 mA 2018-07-30T18:52:50.088Z,1532976770.088 [NAL9602](INFO): SBD MO Status=0, MOMSN=547, MT Status=0, MTMSN=0 2018-07-30T18:52:50.088Z,1532976770.088 [NAL9602](INFO): No messages in MT queue 2018-07-30T18:52:57.344Z,1532976777.344 [NAL9602](INFO): GPS fix at 20180730T185255: (36.807864, -121.785288) 2018-07-30T18:53:00.094Z,1532976780.094 [NAL9602](INFO): GPS fix at 20180730T185258: (36.807938, -121.785303) 2018-07-30T18:53:03.291Z,1532976783.291 [NAL9602](INFO): GPS fix at 20180730T185301: (36.808018, -121.785326) 2018-07-30T18:53:06.094Z,1532976786.094 [NAL9602](INFO): GPS fix at 20180730T185304: (36.808096, -121.785360) 2018-07-30T18:53:09.313Z,1532976789.313 [NAL9602](INFO): GPS fix at 20180730T185307: (36.808179, -121.785400) 2018-07-30T18:53:09.770Z,1532976789.770 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 5 Latitude: 36.808178 Longitude: -121.785400 2018-07-30T18:53:10.154Z,1532976790.154 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 0.000000 Voltage: 0.000000 2018-07-30T18:53:10.154Z,1532976790.154 [IBIT](IMPORTANT): batteryCapacityThreshold: 5.000000 Ah 2018-07-30T18:53:10.155Z,1532976790.155 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.500000 V 2018-07-30T18:53:10.572Z,1532976790.572 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2018-07-30T18:53:10.572Z,1532976790.572 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2018-07-30T18:53:10.577Z,1532976790.577 [IBIT](IMPORTANT): Pressure:10.636564 PSI 2018-07-30T18:53:10.577Z,1532976790.577 [IBIT](IMPORTANT): Humidity:20.083017 % 2018-07-30T18:53:10.957Z,1532976790.957 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2018-07-30T18:53:10.957Z,1532976790.957 [IBIT](IMPORTANT): buoyancyNeutral: 160.000000 cc 2018-07-30T18:53:10.957Z,1532976790.957 [IBIT](IMPORTANT): massDefault: -0.100000 cm 2018-07-30T18:53:10.958Z,1532976790.958 [IBIT](IMPORTANT): stopDepth: 215.000000 m 2018-07-30T18:53:10.958Z,1532976790.958 [IBIT](IMPORTANT): abortDepth: 255.000000 m 2018-07-30T18:53:10.958Z,1532976790.958 [IBIT](IMPORTANT): IBIT PASSED 2018-07-30T18:53:11.384Z,1532976791.384 [Default:CheckIn:Read_GPS] Stopped 2018-07-30T18:53:11.384Z,1532976791.384 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-30T18:53:12.336Z,1532976792.336 [NAL9602](INFO): GPS fix at 20180730T185310: (36.808257, -121.785451) 2018-07-30T18:53:16.859Z,1532976796.859 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20180730T183013/Courier0013.lzma 2018-07-30T18:53:17.654Z,1532976797.654 [DataOverHttps](INFO): Moved sent file to Logs/20180730T183013/Courier0013.lzma.bak 2018-07-30T18:53:17.654Z,1532976797.654 [DataOverHttps](INFO): SBD MOMSN=8386207 2018-07-30T18:53:27.510Z,1532976807.510 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180730T183013/Courier0016.lzma 2018-07-30T18:53:28.341Z,1532976808.341 [DataOverHttps](INFO): Moved sent file to Logs/20180730T183013/Courier0016.lzma.bak 2018-07-30T18:53:28.342Z,1532976808.342 [DataOverHttps](INFO): SBD MOMSN=8386210 2018-07-30T18:53:37.922Z,1532976817.922 [DataOverHttps](INFO): Sending 761 bytes from file Logs/20180730T183013/Express0014.lzma 2018-07-30T18:53:38.674Z,1532976818.674 [DataOverHttps](INFO): Moved sent file to Logs/20180730T183013/Express0014.lzma.bak 2018-07-30T18:53:38.675Z,1532976818.675 [DataOverHttps](INFO): SBD MOMSN=8386212 2018-07-30T18:53:47.738Z,1532976827.738 [NAL9602](INFO): Powering down 2018-07-30T18:53:48.315Z,1532976828.315 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180730T183013/Express0017.lzma 2018-07-30T18:53:49.117Z,1532976829.117 [DataOverHttps](INFO): Moved sent file to Logs/20180730T183013/Express0017.lzma.bak 2018-07-30T18:53:49.117Z,1532976829.117 [DataOverHttps](INFO): SBD MOMSN=8386235 2018-07-30T18:53:49.591Z,1532976829.591 [Default:CheckIn:Read_Iridium] Stopped 2018-07-30T18:53:49.591Z,1532976829.591 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-30T18:53:49.591Z,1532976829.591 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-30T18:58:50.381Z,1532977130.381 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-30T18:58:50.381Z,1532977130.381 [Default:CheckIn:C.Wait] Stopped 2018-07-30T18:58:50.381Z,1532977130.381 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-30T18:58:50.381Z,1532977130.381 [Default:CheckIn:D] Running Loop=1 2018-07-30T18:58:50.738Z,1532977130.738 [Default:CheckIn:D] Stopped 2018-07-30T18:58:50.738Z,1532977130.738 [Default:CheckIn:E] Running Loop=1 2018-07-30T18:58:54.132Z,1532977134.132 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 26.097762 min 2018-07-30T18:58:54.132Z,1532977134.132 [Default:CheckIn:E] Stopped 2018-07-30T18:58:54.137Z,1532977134.137 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-30T18:58:54.137Z,1532977134.137 [Default:CheckIn] Stopped 2018-07-30T18:58:54.137Z,1532977134.137 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-30T18:58:54.137Z,1532977134.137 [Default:CheckIn](INFO): Running loop #5 2018-07-30T18:58:54.137Z,1532977134.137 [Default:CheckIn] Running Loop=5 2018-07-30T18:58:54.137Z,1532977134.137 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-30T18:58:54.137Z,1532977134.137 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-30T18:58:54.586Z,1532977134.586 [NAL9602](INFO): Powering up 2018-07-30T18:59:05.392Z,1532977145.392 [NAL9602](INFO): NAL9602 initialized 2018-07-30T18:59:54.283Z,1532977194.283 [NAL9602](INFO): SBD MO Status=2, MOMSN=548, MT Status=2, MTMSN=0 2018-07-30T18:59:54.284Z,1532977194.284 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2018-07-30T19:00:04.251Z,1532977204.251 [NAL9602](INFO): SBD MO Status=0, MOMSN=548, MT Status=0, MTMSN=0 2018-07-30T19:00:04.252Z,1532977204.252 [NAL9602](INFO): No messages in MT queue 2018-07-30T19:00:55.641Z,1532977255.641 [DataOverHttps](IMPORTANT): SBD MTMSN=20180730T190054