2019-07-03T05:04:29.508Z,1562130269.508 [Supervisor](DEBUG): Initializing supervisor. 2019-07-03T05:04:29.510Z,1562130269.510 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2019-07-03T05:04:29.511Z,1562130269.511 [SyncHandler](INFO): Protected caller Thread ID is 806 2019-07-03T05:04:29.511Z,1562130269.511 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2019-07-03T05:04:29.512Z,1562130269.512 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2019-07-03T05:04:29.513Z,1562130269.513 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 807 2019-07-03T05:04:29.515Z,1562130269.515 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2019-07-03T05:04:29.526Z,1562130269.526 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2019-07-03T05:04:29.527Z,1562130269.527 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2019-07-03T05:04:29.527Z,1562130269.527 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 808 2019-07-03T05:04:29.528Z,1562130269.528 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2019-07-03T05:04:29.529Z,1562130269.529 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2019-07-03T05:04:29.530Z,1562130269.530 [logger ThreadHandler](INFO): Protected caller Thread ID is 809 2019-07-03T05:04:29.532Z,1562130269.532 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2019-07-03T05:04:29.532Z,1562130269.532 [Supervisor](INFO): Looking for Config files in directory: Config/ 2019-07-03T05:04:29.536Z,1562130269.536 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2019-07-03T05:04:29.948Z,1562130269.948 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2019-07-03T05:04:29.949Z,1562130269.949 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2019-07-03T05:04:30.046Z,1562130270.046 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2019-07-03T05:04:30.048Z,1562130270.048 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2019-07-03T05:04:30.357Z,1562130270.357 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2019-07-03T05:04:30.359Z,1562130270.359 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2019-07-03T05:04:30.496Z,1562130270.496 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2019-07-03T05:04:30.497Z,1562130270.497 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2019-07-03T05:04:30.685Z,1562130270.685 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2019-07-03T05:04:30.687Z,1562130270.687 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2019-07-03T05:04:31.136Z,1562130271.136 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2019-07-03T05:04:31.138Z,1562130271.138 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2019-07-03T05:04:31.340Z,1562130271.340 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2019-07-03T05:04:31.341Z,1562130271.341 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2019-07-03T05:04:31.483Z,1562130271.483 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2019-07-03T05:04:31.485Z,1562130271.485 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2019-07-03T05:04:31.674Z,1562130271.674 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2019-07-03T05:04:31.676Z,1562130271.676 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2019-07-03T05:04:31.771Z,1562130271.771 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2019-07-03T05:04:31.772Z,1562130271.772 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2019-07-03T05:04:32.065Z,1562130272.065 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2019-07-03T05:04:32.066Z,1562130272.066 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2019-07-03T05:04:32.147Z,1562130272.147 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2019-07-03T05:04:32.248Z,1562130272.248 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2019-07-03T05:04:32.249Z,1562130272.249 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2019-07-03T05:04:32.829Z,1562130272.829 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2019-07-03T05:04:33.035Z,1562130273.035 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2019-07-03T05:04:33.870Z,1562130273.870 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2019-07-03T05:04:33.872Z,1562130273.872 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/ 2019-07-03T05:04:33.889Z,1562130273.889 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg 2019-07-03T05:04:34.094Z,1562130274.094 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg 2019-07-03T05:04:34.193Z,1562130274.193 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg 2019-07-03T05:04:34.291Z,1562130274.291 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg 2019-07-03T05:04:34.514Z,1562130274.514 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2019-07-03T05:04:34.515Z,1562130274.515 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg 2019-07-03T05:04:34.598Z,1562130274.598 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg 2019-07-03T05:04:34.692Z,1562130274.692 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg 2019-07-03T05:04:34.787Z,1562130274.787 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg 2019-07-03T05:04:34.870Z,1562130274.870 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg 2019-07-03T05:04:34.976Z,1562130274.976 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg 2019-07-03T05:04:35.151Z,1562130275.151 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg 2019-07-03T05:04:35.277Z,1562130275.277 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2019-07-03T05:04:35.281Z,1562130275.281 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2019-07-03T05:04:36.005Z,1562130276.005 [AHRS_M2] Loaded 2019-07-03T05:04:36.005Z,1562130276.005 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2019-07-03T05:04:36.146Z,1562130276.146 [DataOverHttps] Loaded 2019-07-03T05:04:36.146Z,1562130276.146 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2019-07-03T05:04:36.147Z,1562130276.147 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407654E0 2019-07-03T05:04:36.148Z,1562130276.148 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 888 2019-07-03T05:04:36.160Z,1562130276.160 [Depth_Keller] Loaded 2019-07-03T05:04:36.161Z,1562130276.161 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2019-07-03T05:04:36.165Z,1562130276.165 [DropWeight] Loaded 2019-07-03T05:04:36.165Z,1562130276.165 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2019-07-03T05:04:36.221Z,1562130276.221 [DUSBL_Hydroid] Loaded 2019-07-03T05:04:36.221Z,1562130276.221 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread. 2019-07-03T05:04:36.268Z,1562130276.268 [Micromodem] Loaded 2019-07-03T05:04:36.269Z,1562130276.269 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread. 2019-07-03T05:04:36.364Z,1562130276.364 [NAL9602] Loaded 2019-07-03T05:04:36.364Z,1562130276.364 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2019-07-03T05:04:36.379Z,1562130276.379 [Onboard] Loaded 2019-07-03T05:04:36.380Z,1562130276.380 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2019-07-03T05:04:36.386Z,1562130276.386 [PowerOnly] Loaded 2019-07-03T05:04:36.386Z,1562130276.386 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread. 2019-07-03T05:04:36.392Z,1562130276.392 [Radio_Surface] Loaded 2019-07-03T05:04:36.392Z,1562130276.392 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2019-07-03T05:04:36.393Z,1562130276.393 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407954E0 2019-07-03T05:04:36.394Z,1562130276.394 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 889 2019-07-03T05:04:36.437Z,1562130276.437 [RDI_Pathfinder] Loaded 2019-07-03T05:04:36.437Z,1562130276.437 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread. 2019-07-03T05:04:37.889Z,1562130277.889 [BPC1] Loaded 2019-07-03T05:04:37.890Z,1562130277.890 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2019-07-03T05:04:37.890Z,1562130277.890 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2019-07-03T05:04:37.891Z,1562130277.891 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2019-07-03T05:04:37.990Z,1562130277.990 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2019-07-03T05:04:37.991Z,1562130277.991 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2019-07-03T05:04:38.756Z,1562130278.756 [DeadReckonUsingMultipleVelocitySources] Loaded 2019-07-03T05:04:38.756Z,1562130278.756 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2019-07-03T05:04:38.776Z,1562130278.776 [NavChart] Loaded 2019-07-03T05:04:38.776Z,1562130278.776 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2019-07-03T05:04:38.780Z,1562130278.780 [UniversalFixResidualReporter] Loaded 2019-07-03T05:04:38.780Z,1562130278.780 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2019-07-03T05:04:38.781Z,1562130278.781 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2019-07-03T05:04:38.781Z,1562130278.781 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2019-07-03T05:04:38.909Z,1562130278.909 [BuoyancyServo] Loaded 2019-07-03T05:04:38.909Z,1562130278.909 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2019-07-03T05:04:38.924Z,1562130278.924 [ElevatorServo] Loaded 2019-07-03T05:04:38.924Z,1562130278.924 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2019-07-03T05:04:38.939Z,1562130278.939 [MassServo] Loaded 2019-07-03T05:04:38.939Z,1562130278.939 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2019-07-03T05:04:38.954Z,1562130278.954 [RudderServo] Loaded 2019-07-03T05:04:38.954Z,1562130278.954 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2019-07-03T05:04:38.968Z,1562130278.968 [ThrusterServo] Loaded 2019-07-03T05:04:38.969Z,1562130278.969 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2019-07-03T05:04:38.969Z,1562130278.969 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2019-07-03T05:04:38.970Z,1562130278.970 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2019-07-03T05:04:39.286Z,1562130279.286 [CTD_NeilBrown] Loaded 2019-07-03T05:04:39.286Z,1562130279.286 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2019-07-03T05:04:39.287Z,1562130279.287 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408E04E0 2019-07-03T05:04:39.288Z,1562130279.288 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 890 2019-07-03T05:04:39.331Z,1562130279.331 [WetLabsSeaOWL_UV_A] Loaded 2019-07-03T05:04:39.332Z,1562130279.332 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread. 2019-07-03T05:04:39.333Z,1562130279.333 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409104E0 2019-07-03T05:04:39.333Z,1562130279.333 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 891 2019-07-03T05:04:39.334Z,1562130279.334 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2019-07-03T05:04:39.334Z,1562130279.334 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2019-07-03T05:04:39.669Z,1562130279.669 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2019-07-03T05:04:39.670Z,1562130279.670 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2019-07-03T05:04:39.725Z,1562130279.725 [DepthRateCalculator] Loaded 2019-07-03T05:04:39.725Z,1562130279.725 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2019-07-03T05:04:39.731Z,1562130279.731 [PitchRateCalculator] Loaded 2019-07-03T05:04:39.731Z,1562130279.731 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2019-07-03T05:04:39.743Z,1562130279.743 [SpeedCalculator] Loaded 2019-07-03T05:04:39.743Z,1562130279.743 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2019-07-03T05:04:39.764Z,1562130279.764 [TempGradientCalculator] Loaded 2019-07-03T05:04:39.764Z,1562130279.764 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2019-07-03T05:04:39.770Z,1562130279.770 [YawRateCalculator] Loaded 2019-07-03T05:04:39.770Z,1562130279.770 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2019-07-03T05:04:39.810Z,1562130279.810 [ElevatorOffsetCalculator] Loaded 2019-07-03T05:04:39.810Z,1562130279.810 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2019-07-03T05:04:39.810Z,1562130279.810 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2019-07-03T05:04:39.811Z,1562130279.811 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2019-07-03T05:04:39.970Z,1562130279.970 [SBIT](DEBUG): Construct Startup Built In Test. 2019-07-03T05:04:39.991Z,1562130279.991 [SBIT] Loaded 2019-07-03T05:04:39.992Z,1562130279.992 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2019-07-03T05:04:39.993Z,1562130279.993 [IBIT](DEBUG): Construct Initiated Built In Test. 2019-07-03T05:04:40.004Z,1562130280.004 [IBIT] Loaded 2019-07-03T05:04:40.004Z,1562130280.004 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2019-07-03T05:04:40.007Z,1562130280.007 [CBIT](DEBUG): Construct Continuous Built In Test. 2019-07-03T05:04:40.147Z,1562130280.147 [CBIT] Loaded 2019-07-03T05:04:40.148Z,1562130280.148 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2019-07-03T05:04:40.148Z,1562130280.148 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2019-07-03T05:04:40.149Z,1562130280.149 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2019-07-03T05:04:40.270Z,1562130280.270 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2019-07-03T05:04:40.270Z,1562130280.270 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2019-07-03T05:04:40.393Z,1562130280.393 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2019-07-03T05:04:40.393Z,1562130280.393 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2019-07-03T05:04:40.479Z,1562130280.479 [VerticalControl](DEBUG): Construct VerticalControl. 2019-07-03T05:04:40.561Z,1562130280.561 [VerticalControl] Loaded 2019-07-03T05:04:40.562Z,1562130280.562 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2019-07-03T05:04:40.563Z,1562130280.563 [HorizontalControl](DEBUG): Construct HorizontalControl. 2019-07-03T05:04:40.618Z,1562130280.618 [HorizontalControl] Loaded 2019-07-03T05:04:40.619Z,1562130280.619 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2019-07-03T05:04:40.619Z,1562130280.619 [SpeedControl](DEBUG): Construct SpeedControl. 2019-07-03T05:04:40.621Z,1562130280.621 [SpeedControl] Loaded 2019-07-03T05:04:40.621Z,1562130280.621 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2019-07-03T05:04:40.622Z,1562130280.622 [LoopControl](DEBUG): Construct LoopControl. 2019-07-03T05:04:40.622Z,1562130280.622 [LoopControl] Loaded 2019-07-03T05:04:40.623Z,1562130280.623 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2019-07-03T05:04:40.623Z,1562130280.623 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2019-07-03T05:04:40.624Z,1562130280.624 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2019-07-03T05:04:40.671Z,1562130280.671 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2019-07-03T05:04:40.675Z,1562130280.675 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2019-07-03T05:04:40.676Z,1562130280.676 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2019-07-03T05:04:40.682Z,1562130280.682 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2019-07-03T05:04:40.683Z,1562130280.683 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AEC4E0 2019-07-03T05:04:40.684Z,1562130280.684 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 892 2019-07-03T05:04:40.688Z,1562130280.688 [Supervisor](INFO): Main Thread ID is 802 2019-07-03T05:04:40.688Z,1562130280.688 [Supervisor](DEBUG): Running supervisor. 2019-07-03T05:04:40.689Z,1562130280.689 [CommandLine ThreadHandler](INFO): Handler Thread ID is 893 2019-07-03T05:04:40.691Z,1562130280.691 [controlThread ThreadHandler](INFO): Handler Thread ID is 894 2019-07-03T05:04:40.692Z,1562130280.692 [controlThread](DEBUG): Initializing ControlThread 2019-07-03T05:04:40.698Z,1562130280.698 [NavChart](DEBUG): Initialize NavChart Navigation. 2019-07-03T05:04:40.699Z,1562130280.699 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2019-07-03T05:04:40.700Z,1562130280.700 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2019-07-03T05:04:40.700Z,1562130280.700 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2019-07-03T05:04:40.701Z,1562130280.701 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2019-07-03T05:04:40.701Z,1562130280.701 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2019-07-03T05:04:40.701Z,1562130280.701 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2019-07-03T05:04:40.702Z,1562130280.702 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2019-07-03T05:04:40.702Z,1562130280.702 [SBIT](INFO): Initialize SBIT Component. 2019-07-03T05:04:40.703Z,1562130280.703 [SBIT](IMPORTANT): git: 2019-07-01 2019-07-03T05:04:40.703Z,1562130280.703 [SBIT](INFO): git hash: 66ee1f914ed66d399bd38d45ccca9e12ca50b60d 2019-07-03T05:04:40.703Z,1562130280.703 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2019-07-03T05:04:40.705Z,1562130280.705 [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-03T05:04:40.706Z,1562130280.706 [SBIT](INFO): Beginning SBIT in 28.000000 seconds. 2019-07-03T05:04:40.706Z,1562130280.706 [IBIT](INFO): Initialize IBIT Component. 2019-07-03T05:04:40.707Z,1562130280.707 [CBIT](DEBUG): Initialize CBIT Component. 2019-07-03T05:04:40.708Z,1562130280.708 [logger ThreadHandler](INFO): Handler Thread ID is 895 2019-07-03T05:04:40.719Z,1562130280.719 [CBIT](DEBUG): Initialized mux pins. 2019-07-03T05:04:40.719Z,1562130280.719 [CBIT](DEBUG): Initializing the watchdog timer. 2019-07-03T05:04:40.728Z,1562130280.728 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 896 2019-07-03T05:04:40.729Z,1562130280.729 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2019-07-03T05:04:40.740Z,1562130280.740 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 897 2019-07-03T05:04:40.743Z,1562130280.743 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2019-07-03T05:04:40.743Z,1562130280.743 [CBIT](DEBUG): Initializing heartbeat. 2019-07-03T05:04:40.752Z,1562130280.752 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 898 2019-07-03T05:04:40.753Z,1562130280.753 [CTD_NeilBrown](INFO): Powering down 2019-07-03T05:04:40.788Z,1562130280.788 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 899 2019-07-03T05:04:40.788Z,1562130280.788 [WetLabsSeaOWL_UV_A](INFO): Powering down 2019-07-03T05:04:40.815Z,1562130280.815 [CBIT](DEBUG): Deactivating GF circuits. 2019-07-03T05:04:40.815Z,1562130280.815 [CBIT](DEBUG): Deactivating emergency mode. 2019-07-03T05:04:40.816Z,1562130280.816 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 900 2019-07-03T05:04:40.824Z,1562130280.824 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2019-07-03T05:04:40.824Z,1562130280.824 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2019-07-03T05:04:40.825Z,1562130280.825 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2019-07-03T05:04:40.825Z,1562130280.825 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2019-07-03T05:04:40.825Z,1562130280.825 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2019-07-03T05:04:40.825Z,1562130280.825 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2019-07-03T05:04:40.825Z,1562130280.825 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2019-07-03T05:04:40.825Z,1562130280.825 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2019-07-03T05:04:40.826Z,1562130280.826 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2019-07-03T05:04:40.826Z,1562130280.826 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2019-07-03T05:04:40.826Z,1562130280.826 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2019-07-03T05:04:40.826Z,1562130280.826 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2019-07-03T05:04:40.826Z,1562130280.826 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2019-07-03T05:04:40.826Z,1562130280.826 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2019-07-03T05:04:40.827Z,1562130280.827 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2019-07-03T05:04:40.827Z,1562130280.827 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2019-07-03T05:04:40.851Z,1562130280.851 [CBIT](DEBUG): Backplane powered. 2019-07-03T05:04:40.852Z,1562130280.852 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2019-07-03T05:04:40.853Z,1562130280.853 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2019-07-03T05:04:40.854Z,1562130280.854 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2019-07-03T05:04:40.854Z,1562130280.854 [LoopControl](DEBUG): Initialize LoopControlComponent. 2019-07-03T05:04:40.855Z,1562130280.855 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2019-07-03T05:04:40.878Z,1562130280.878 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2019-07-03T05:04:40.901Z,1562130280.901 [MissionManager](DEBUG): 2019-07-03T05:04:40.902Z,1562130280.902 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2019-07-03T05:04:40.990Z,1562130280.990 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2019-07-03T05:04:40.991Z,1562130280.991 [Default:A.Wait](DEBUG): Construct Wait. 2019-07-03T05:04:40.993Z,1562130280.993 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2019-07-03T05:04:41.027Z,1562130281.027 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2019-07-03T05:04:41.029Z,1562130281.029 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2019-07-03T05:04:41.064Z,1562130281.064 [Default:E.Execute](DEBUG): Construct Execute. 2019-07-03T05:04:41.068Z,1562130281.068 [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-03T05:04:41.079Z,1562130281.079 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,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-03T05:04:41.088Z,1562130281.088 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-07-03T05:04:41.143Z,1562130281.143 [Radio_Surface](INFO): Powering up 2019-07-03T05:04:41.168Z,1562130281.168 [Depth_Keller](ERROR): Pressure reading out of range: 957.962097 decibar 2019-07-03T05:04:41.169Z,1562130281.169 [DUSBL_Hydroid](INFO): Powering up 2019-07-03T05:04:41.169Z,1562130281.169 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid. 2019-07-03T05:04:41.244Z,1562130281.244 [DepthRateCalculator](ERROR): Depth measurement is not active 2019-07-03T05:04:41.296Z,1562130281.296 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2019-07-03T05:04:41.304Z,1562130281.304 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2019-07-03T05:04:41.305Z,1562130281.305 [ElevatorServo](DEBUG): Initializing EZServoServo. 2019-07-03T05:04:41.312Z,1562130281.312 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2019-07-03T05:04:41.312Z,1562130281.312 [MassServo](DEBUG): Initializing EZServoServo. 2019-07-03T05:04:41.320Z,1562130281.320 [MassServo](DEBUG): Initializing MassServo. 2019-07-03T05:04:41.320Z,1562130281.320 [RudderServo](DEBUG): Initializing EZServoServo. 2019-07-03T05:04:41.328Z,1562130281.328 [RudderServo](DEBUG): Initializing RudderServo. 2019-07-03T05:04:41.328Z,1562130281.328 [ThrusterServo](DEBUG): Initializing EZServoServo. 2019-07-03T05:04:41.336Z,1562130281.336 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2019-07-03T05:04:41.510Z,1562130281.510 [Micromodem](INFO): Powering up 2019-07-03T05:04:41.510Z,1562130281.510 [Micromodem](DEBUG): Initializing Micromodem. 2019-07-03T05:04:41.548Z,1562130281.548 [DepthRateCalculator](ERROR): Depth measurement is not active 2019-07-03T05:04:42.223Z,1562130282.223 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2019-07-03T05:04:42.223Z,1562130282.223 [RudderServo](FAULT): Rudder failed to initialize 2019-07-03T05:04:42.224Z,1562130282.224 [RudderServo] Communications Fault, FailCount= 1 2019-07-03T05:04:42.224Z,1562130282.224 [RudderServo](ERROR): Communications Fault 2019-07-03T05:04:42.335Z,1562130282.335 [CBIT](ERROR): Communications Fault in component: RudderServo 2019-07-03T05:04:42.492Z,1562130282.492 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-07-03T05:04:42.492Z,1562130282.492 [RudderServo](INFO): Powering down 2019-07-03T05:04:43.179Z,1562130283.179 [RudderServo](DEBUG): Initializing EZServoServo. 2019-07-03T05:04:43.300Z,1562130283.300 [RudderServo](DEBUG): Initializing RudderServo. 2019-07-03T05:04:43.304Z,1562130283.304 [CBIT](INFO): Clearing failed state for component RudderServo 2019-07-03T05:04:43.304Z,1562130283.304 [RudderServo] No Fault, FailCount= 1 2019-07-03T05:04:46.423Z,1562130286.423 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33 2019-07-03T05:04:46.826Z,1562130286.826 [Micromodem](INFO): Nmea in: $CATMG,2019-07-03T05:04:46Z,RTC,RTC*73 2019-07-03T05:04:46.826Z,1562130286.826 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2019-07-03T05:04:46Z,RTC,RTC*73 2019-07-03T05:04:47.266Z,1562130287.266 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31 2019-07-03T05:04:47.266Z,1562130287.266 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31 2019-07-03T05:04:47.657Z,1562130287.657 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33 2019-07-03T05:04:47.658Z,1562130287.658 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64 2019-07-03T05:04:48.074Z,1562130288.074 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66 2019-07-03T05:04:48.074Z,1562130288.074 [Micromodem](INFO): Nmea out: $CCCFG,nav.nst,1*4D 2019-07-03T05:04:48.477Z,1562130288.477 [Micromodem](INFO): Nmea in: $CACFG,nav.nst,1*4F 2019-07-03T05:04:48.478Z,1562130288.478 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F 2019-07-03T05:04:48.882Z,1562130288.882 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D 2019-07-03T05:04:48.882Z,1562130288.882 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E 2019-07-03T05:04:49.274Z,1562130289.274 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C 2019-07-03T05:04:49.274Z,1562130289.274 [Micromodem](INFO): Nmea out: $CCCFG,FC0,10000*46 2019-07-03T05:04:49.682Z,1562130289.682 [Micromodem](INFO): Nmea in: $CACFG,FC0,10000*44 2019-07-03T05:04:49.682Z,1562130289.682 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63 2019-07-03T05:04:50.070Z,1562130290.070 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61 2019-07-03T05:04:50.070Z,1562130290.070 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A 2019-07-03T05:04:50.482Z,1562130290.482 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38 2019-07-03T05:04:50.482Z,1562130290.482 [Micromodem](INFO): Nmea out: $CCCLK,2019,07,03,05,04,51*4F 2019-07-03T05:04:50.878Z,1562130290.878 [Micromodem](INFO): Nmea in: $CACLK,2019,7,3,5,4,51*4D 2019-07-03T05:04:51.278Z,1562130291.278 [Micromodem](INFO): Nmea in: $CATMS,0,2019-07-03T05:04:52Z*7E 2019-07-03T05:04:51.279Z,1562130291.279 [Micromodem](INFO): Nmea in: $CATMG,2019-07-03T05:04:52Z,USER_CMD,RTC*37 2019-07-03T05:04:54.527Z,1562130294.527 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder 2019-07-03T05:04:59.353Z,1562130299.353 [DUSBL_Hydroid](INFO): DUSBL Version:O 2019-07-03T05:05:06.622Z,1562130306.622 [NAL9602](INFO): Powering up NAL9602 2019-07-03T05:05:09.073Z,1562130309.073 [SBIT](IMPORTANT): Beginning Startup BIT 2019-07-03T05:05:09.081Z,1562130309.081 [CBIT](IMPORTANT): Beginning ground fault scan 2019-07-03T05:05:17.613Z,1562130317.614 [NAL9602](INFO): NAL9602 initialized 2019-07-03T05:05:18.463Z,1562130318.463 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:05:20.108Z,1562130320.108 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.019011 CHAN A1 (24V): -0.025877 CHAN A2 (12V): -0.006429 CHAN A3 (5V): -0.002189 CHAN B0 (3.3V): 0.000635 CHAN B1 (3.15aV): -0.000189 CHAN B2 (3.15bV): 0.000190 CHAN B3 (GND): 0.001662 OPEN: 0.007068 Full Scale Calc: 4.765 mA, -1.589 mA 2019-07-03T05:05:20.883Z,1562130320.883 [RDI_Pathfinder](ERROR): Failed to parse: :BI,-32768,-32768,-32768,-32768,V 2019-07-03T05:05:39.947Z,1562130339.947 [NAL9602](INFO): SBD MO Status=2, MOMSN=8011, MT Status=2, MTMSN=0 2019-07-03T05:05:39.947Z,1562130339.947 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-07-03T05:06:02.315Z,1562130362.315 [SBIT](IMPORTANT): SBIT PASSED 2019-07-03T05:06:02.351Z,1562130362.351 [CommandLine](IMPORTANT): got command configSet list 2019-07-03T05:06:02.352Z,1562130362.352 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2019-07-03T05:06:02.352Z,1562130362.352 [CommandLine](IMPORTANT): No configSet variables persisted 2019-07-03T05:06:02.695Z,1562130362.695 [MissionManager](IMPORTANT): Started mission Startup 2019-07-03T05:06:02.695Z,1562130362.695 [Startup] Running Loop=1 2019-07-03T05:06:02.695Z,1562130362.695 [Startup](DEBUG): Aggregate::initialize Startup 2019-07-03T05:06:02.696Z,1562130362.696 [Startup:A.GoToSurface] Running Loop=1 2019-07-03T05:06:02.696Z,1562130362.696 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-07-03T05:06:02.696Z,1562130362.696 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-07-03T05:06:02.697Z,1562130362.697 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-07-03T05:06:02.697Z,1562130362.697 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-07-03T05:06:02.697Z,1562130362.697 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-07-03T05:06:02.698Z,1562130362.698 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-07-03T05:06:02.699Z,1562130362.699 [Startup:StartupSatComms] Running Loop=1 2019-07-03T05:06:02.699Z,1562130362.699 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2019-07-03T05:06:02.699Z,1562130362.699 [Startup:StartupSatComms:A] Running Loop=1 2019-07-03T05:06:03.117Z,1562130363.117 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2019-07-03T05:06:05.880Z,1562130365.880 [NAL9602](INFO): SBD MO Status=2, MOMSN=8011, MT Status=2, MTMSN=0 2019-07-03T05:06:05.880Z,1562130365.880 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-07-03T05:06:18.461Z,1562130378.461 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2019-07-03T05:06:18.461Z,1562130378.461 [RDI_Pathfinder](ERROR): Failed to parse: :BD, 00 2019-07-03T05:06:34.559Z,1562130394.559 [NAL9602](INFO): SBD MO Status=0, MOMSN=8011, MT Status=0, MTMSN=0 2019-07-03T05:06:34.559Z,1562130394.559 [NAL9602](INFO): No messages in MT queue 2019-07-03T05:06:35.380Z,1562130395.380 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:06:38.619Z,1562130398.619 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:06:41.443Z,1562130401.443 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:06:44.671Z,1562130404.671 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:06:47.499Z,1562130407.499 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:06:50.327Z,1562130410.327 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:06:53.559Z,1562130413.559 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:06:56.387Z,1562130416.387 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:06:59.619Z,1562130419.619 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:07:02.450Z,1562130422.450 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:07:02.899Z,1562130422.899 [Startup:StartupSatComms:A](INFO): Timed out from 2019-07-03T05:06:02.7Z 2019-07-03T05:07:02.899Z,1562130422.899 [Startup:StartupSatComms:A] Stopped 2019-07-03T05:07:02.899Z,1562130422.899 [Startup:StartupSatComms:B] Running Loop=1 2019-07-03T05:07:03.292Z,1562130423.292 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-07-03T05:07:04.558Z,1562130424.558 [Micromodem](INFO): Outgoing frame #1, 64 bytes: 66331C5D070001005D00000400540100000000000000151D80030C5669BF3148E2FA22188B6A3173E5573572661C0BCBDFFAB423BD32D9A51E8904B0A920CE9A 2019-07-03T05:07:04.559Z,1562130424.559 [Micromodem](INFO): Outgoing frame #2, 64 bytes: EF9F66414C9B9FD6761AD008C3E3DC4FCA2E4E25B6359B14B772C256AEDD60B95108769F11B6F1CAFDFCAA023BD2A6AC8267BF03117F45C2DD2DCA8C8EEBE5F9 2019-07-03T05:07:04.559Z,1562130424.559 [Micromodem](INFO): Outgoing frame #3, 64 bytes: 7BD9043D223D555CF9F8C344436B63EF13BFE530A3AD5AB43B65A7E1E292F063AFC71143C404EE6C0C15F8C294BA7DF68FFC9140509ADDBECA5CC395C941E4F9 2019-07-03T05:07:04.559Z,1562130424.559 [Micromodem](INFO): Nmea out: $CCCYC,0,1,9,1,0,3*53 2019-07-03T05:07:04.705Z,1562130424.705 [Micromodem](INFO): Nmea in: $CACYC,0,1,9,1,0,3*51 2019-07-03T05:07:05.066Z,1562130425.066 [Micromodem](INFO): Nmea in: $CADRQ,050705,1,9,0,64,1*49 2019-07-03T05:07:05.066Z,1562130425.066 [Micromodem](INFO): Nmea out: $CCTXD,1,9,1,66331C5D070001005D00000400540100000000000000151D80030C5669BF3148E2FA22188B6A3173E5573572661C0BCBDFFAB423BD32D9A51E8904B0A920CE9A*77 2019-07-03T05:07:05.086Z,1562130425.086 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:07:05.474Z,1562130425.474 [Micromodem](INFO): Nmea in: $CATXD,1,9,1,64*71 2019-07-03T05:07:05.890Z,1562130425.890 [Micromodem](INFO): Nmea in: $CADRQ,050705,1,9,0,64,2*4A 2019-07-03T05:07:05.890Z,1562130425.890 [Micromodem](INFO): Nmea out: $CCTXD,1,9,1,EF9F66414C9B9FD6761AD008C3E3DC4FCA2E4E25B6359B14B772C256AEDD60B95108769F11B6F1CAFDFCAA023BD2A6AC8267BF03117F45C2DD2DCA8C8EEBE5F9*70 2019-07-03T05:07:06.281Z,1562130426.281 [Micromodem](INFO): Nmea in: $CATXD,1,9,1,64*71 2019-07-03T05:07:06.686Z,1562130426.686 [Micromodem](INFO): Nmea in: $CADRQ,050706,1,9,0,64,3*48 2019-07-03T05:07:06.686Z,1562130426.686 [Micromodem](INFO): Nmea out: $CCTXD,1,9,1,7BD9043D223D555CF9F8C344436B63EF13BFE530A3AD5AB43B65A7E1E292F063AFC71143C404EE6C0C15F8C294BA7DF68FFC9140509ADDBECA5CC395C941E4F9*03 2019-07-03T05:07:07.085Z,1562130427.085 [Micromodem](INFO): Nmea in: $CATXD,1,9,1,64*71 2019-07-03T05:07:07.493Z,1562130427.493 [Micromodem](INFO): Nmea in: $CATXP,192*48 2019-07-03T05:07:07.507Z,1562130427.507 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:07:10.336Z,1562130430.336 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:07:11.130Z,1562130431.130 [Micromodem](INFO): Nmea in: $CATXF,192*5E 2019-07-03T05:07:11.535Z,1562130431.535 [Micromodem](INFO): Nmea in: $CAXST,6,20190703,050707.648256,3,0,200,4000,10000,1,1,9,1,3,3,3,192*40 2019-07-03T05:07:13.563Z,1562130433.563 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:07:16.451Z,1562130436.451 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:07:19.623Z,1562130439.623 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:07:22.455Z,1562130442.455 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:07:25.687Z,1562130445.687 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:07:28.511Z,1562130448.511 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:07:31.743Z,1562130451.743 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:07:34.571Z,1562130454.571 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:07:37.808Z,1562130457.808 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:07:40.635Z,1562130460.635 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:07:41.078Z,1562130461.078 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2019-07-03T05:07:41.078Z,1562130461.078 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-03T05:07:41.117Z,1562130461.117 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-03T05:07:41.480Z,1562130461.480 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-03T05:07:41.480Z,1562130461.480 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2019-07-03T05:07:43.459Z,1562130463.459 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:07:46.287Z,1562130466.287 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:07:49.519Z,1562130469.519 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:07:52.352Z,1562130472.352 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:07:55.587Z,1562130475.587 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:07:58.427Z,1562130478.427 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:08:01.647Z,1562130481.647 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:08:02.954Z,1562130482.954 [Startup:StartupSatComms:B](INFO): Timed out from 2019-07-03T05:07:02.9Z 2019-07-03T05:08:02.954Z,1562130482.954 [Startup:StartupSatComms:B] Stopped 2019-07-03T05:08:02.954Z,1562130482.954 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2019-07-03T05:08:02.954Z,1562130482.954 [Startup:StartupSatComms] Stopped 2019-07-03T05:08:02.954Z,1562130482.954 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2019-07-03T05:08:02.955Z,1562130482.955 [Startup](INFO): Completed Startup 2019-07-03T05:08:02.955Z,1562130482.955 [MissionManager](INFO): Startup is completed. 2019-07-03T05:08:02.955Z,1562130482.955 [MissionManager](INFO): Uninitializing Mission Startup 2019-07-03T05:08:02.956Z,1562130482.956 [Startup] Stopped 2019-07-03T05:08:02.956Z,1562130482.956 [Startup](DEBUG): Aggregate::uninitialize Startup 2019-07-03T05:08:02.956Z,1562130482.956 [Startup:A.GoToSurface] Stopped 2019-07-03T05:08:02.956Z,1562130482.956 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-07-03T05:08:03.304Z,1562130483.304 [MissionManager](IMPORTANT): Started mission Default 2019-07-03T05:08:03.304Z,1562130483.304 [Default] Running Loop=1 2019-07-03T05:08:03.304Z,1562130483.304 [Default](DEBUG): Aggregate::initialize Default 2019-07-03T05:08:03.304Z,1562130483.304 [Default:B.GoToSurface] Running Loop=1 2019-07-03T05:08:03.305Z,1562130483.305 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-07-03T05:08:03.305Z,1562130483.305 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-07-03T05:08:03.305Z,1562130483.305 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-07-03T05:08:03.305Z,1562130483.305 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-07-03T05:08:03.306Z,1562130483.306 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-07-03T05:08:03.306Z,1562130483.306 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-07-03T05:08:03.306Z,1562130483.306 [Default:A.Wait] Running Loop=1 2019-07-03T05:08:03.306Z,1562130483.306 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-07-03T05:08:04.471Z,1562130484.471 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:08:07.703Z,1562130487.703 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:08:10.531Z,1562130490.531 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:08:11.190Z,1562130491.190 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005097 2019-07-03T05:08:13.768Z,1562130493.768 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:08:16.327Z,1562130496.327 [Default:A.Wait](INFO): Done Waiting. 2019-07-03T05:08:16.327Z,1562130496.327 [Default:A.Wait] Stopped 2019-07-03T05:08:16.327Z,1562130496.327 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-07-03T05:08:16.595Z,1562130496.595 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:08:16.653Z,1562130496.653 [Default:CheckIn] Running Loop=1 2019-07-03T05:08:16.653Z,1562130496.653 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-07-03T05:08:16.653Z,1562130496.653 [Default:CheckIn:Read_GPS] Running Loop=1 2019-07-03T05:08:17.053Z,1562130497.053 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2019-07-03T05:08:19.471Z,1562130499.471 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:08:22.656Z,1562130502.656 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:08:25.487Z,1562130505.487 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:08:28.315Z,1562130508.315 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:08:31.544Z,1562130511.544 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:08:33.171Z,1562130513.171 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2019-07-03T05:08:33.171Z,1562130513.171 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-3276,-32768,V 2019-07-03T05:08:34.371Z,1562130514.371 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:08:37.607Z,1562130517.607 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:08:40.435Z,1562130520.435 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:08:43.667Z,1562130523.667 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:08:46.491Z,1562130526.491 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:08:49.727Z,1562130529.727 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:08:52.555Z,1562130532.555 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:08:55.791Z,1562130535.791 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:08:58.616Z,1562130538.616 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:09:01.848Z,1562130541.848 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:09:04.679Z,1562130544.679 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:09:07.499Z,1562130547.499 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:09:10.331Z,1562130550.331 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:09:13.559Z,1562130553.559 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:09:16.392Z,1562130556.392 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:09:19.619Z,1562130559.619 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:09:22.451Z,1562130562.451 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:09:25.695Z,1562130565.695 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:09:28.511Z,1562130568.511 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:09:31.743Z,1562130571.743 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:09:34.567Z,1562130574.567 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:09:37.799Z,1562130577.799 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:09:40.627Z,1562130580.627 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:09:43.859Z,1562130583.859 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:09:46.687Z,1562130586.687 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:09:49.519Z,1562130589.519 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:09:52.755Z,1562130592.755 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:09:55.575Z,1562130595.575 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:09:58.815Z,1562130598.815 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:10:01.647Z,1562130601.647 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:10:04.475Z,1562130604.475 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:10:07.695Z,1562130607.695 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:10:10.523Z,1562130610.523 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:10:13.756Z,1562130613.756 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:10:16.591Z,1562130616.591 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:10:19.827Z,1562130619.827 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:10:22.647Z,1562130622.647 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:10:25.875Z,1562130625.875 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:10:28.708Z,1562130628.708 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:10:31.935Z,1562130631.935 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:10:34.767Z,1562130634.767 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:10:37.599Z,1562130637.599 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:10:40.828Z,1562130640.828 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:10:42.063Z,1562130642.063 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2019-07-03T05:10:42.063Z,1562130642.063 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-03T05:10:42.073Z,1562130642.073 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-03T05:10:42.473Z,1562130642.473 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-03T05:10:42.473Z,1562130642.473 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2019-07-03T05:10:43.655Z,1562130643.655 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:10:46.479Z,1562130646.479 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:10:49.711Z,1562130649.711 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:10:52.547Z,1562130652.547 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:10:55.771Z,1562130655.771 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:10:57.008Z,1562130657.008 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2019-07-03T05:10:57.012Z,1562130657.012 [BPC1](INFO): Received data from all battery sticks. 2019-07-03T05:10:58.604Z,1562130658.604 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:11:01.834Z,1562130661.834 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:11:04.663Z,1562130664.663 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:11:07.895Z,1562130667.895 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:11:10.720Z,1562130670.720 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:11:13.956Z,1562130673.956 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:11:16.783Z,1562130676.783 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:11:19.611Z,1562130679.611 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:11:22.843Z,1562130682.843 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:11:25.667Z,1562130685.667 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:11:28.495Z,1562130688.495 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:11:31.732Z,1562130691.732 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:11:34.560Z,1562130694.560 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:11:37.792Z,1562130697.792 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:11:40.615Z,1562130700.615 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:11:43.847Z,1562130703.847 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:11:46.691Z,1562130706.691 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:11:49.907Z,1562130709.907 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:11:52.735Z,1562130712.735 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:11:55.971Z,1562130715.971 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:11:58.800Z,1562130718.800 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:12:01.631Z,1562130721.631 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:12:04.860Z,1562130724.860 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:12:07.687Z,1562130727.687 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:12:10.527Z,1562130730.527 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:12:13.764Z,1562130733.764 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:12:16.575Z,1562130736.575 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:12:19.803Z,1562130739.803 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:12:22.639Z,1562130742.639 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:12:25.867Z,1562130745.867 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:12:28.691Z,1562130748.691 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:12:31.923Z,1562130751.923 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:12:34.760Z,1562130754.760 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:12:37.988Z,1562130757.988 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:12:40.819Z,1562130760.819 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:12:43.639Z,1562130763.639 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:12:46.471Z,1562130766.471 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:12:49.699Z,1562130769.699 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:12:52.532Z,1562130772.532 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:12:55.763Z,1562130775.763 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:12:58.595Z,1562130778.595 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:13:01.824Z,1562130781.824 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:13:04.651Z,1562130784.651 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:13:07.884Z,1562130787.884 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:13:10.711Z,1562130790.711 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:13:13.947Z,1562130793.947 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:13:16.772Z,1562130796.772 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:13:16.809Z,1562130796.809 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-07-03T05:08:16.7Z 2019-07-03T05:13:16.809Z,1562130796.809 [Default:CheckIn:Read_GPS] Stopped 2019-07-03T05:13:16.809Z,1562130796.809 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-07-03T05:13:17.217Z,1562130797.217 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-07-03T05:13:17.573Z,1562130797.573 [Micromodem](ERROR): Buffer fill timout failure. 2019-07-03T05:13:18.711Z,1562130798.711 [Micromodem](INFO): Outgoing frame #1, 64 bytes: 66331C5D070001005D00000400540100000000000000151D80030C5669BF3148E2FA22188B6A3173E5573572661C0BCBDFFAB423BD32D9A51E8904B0A920CE9A 2019-07-03T05:13:18.712Z,1562130798.712 [Micromodem](INFO): Outgoing frame #2, 64 bytes: EF9F66414C9B9FD6761AD008C3E3DC4FCA2E4E25B6359B14B772C256AEDD60B95108769F11B6F1CAFDFCAA023BD2A6AC8267BF03117F45C2DD2DCA8C8EEBE5F9 2019-07-03T05:13:18.719Z,1562130798.719 [Micromodem](INFO): Outgoing frame #3, 64 bytes: 7BD9043D223D555CF9F8C344436B63EF13BFE530A3AD5AB43B65A7E1E292F063AFC71143C404EE6C0C15F8C294BA7DF68FFC9140509ADDBECA5CC395C941E4F9 2019-07-03T05:13:18.719Z,1562130798.719 [Micromodem](INFO): Nmea out: $CCCYC,0,1,9,1,0,3*53 2019-07-03T05:13:18.917Z,1562130798.917 [Micromodem](INFO): Nmea in: $CACYC,0,1,9,1,0,3*51 2019-07-03T05:13:19.270Z,1562130799.270 [Micromodem](INFO): Nmea in: $CADRQ,051319,1,9,0,64,1*41 2019-07-03T05:13:19.270Z,1562130799.270 [Micromodem](INFO): Nmea out: $CCTXD,1,9,1,66331C5D070001005D00000400540100000000000000151D80030C5669BF3148E2FA22188B6A3173E5573572661C0BCBDFFAB423BD32D9A51E8904B0A920CE9A*77 2019-07-03T05:13:19.665Z,1562130799.665 [Micromodem](INFO): Nmea in: $CATXD,1,9,1,64*71 2019-07-03T05:13:19.679Z,1562130799.679 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:13:20.065Z,1562130800.065 [Micromodem](INFO): Nmea in: $CADRQ,051320,1,9,0,64,2*48 2019-07-03T05:13:20.066Z,1562130800.066 [Micromodem](INFO): Nmea out: $CCTXD,1,9,1,EF9F66414C9B9FD6761AD008C3E3DC4FCA2E4E25B6359B14B772C256AEDD60B95108769F11B6F1CAFDFCAA023BD2A6AC8267BF03117F45C2DD2DCA8C8EEBE5F9*70 2019-07-03T05:13:20.496Z,1562130800.496 [Micromodem](INFO): Nmea in: $CATXD,1,9,1,64*71 2019-07-03T05:13:20.877Z,1562130800.877 [Micromodem](INFO): Nmea in: $CADRQ,051320,1,9,0,64,3*49 2019-07-03T05:13:20.878Z,1562130800.878 [Micromodem](INFO): Nmea out: $CCTXD,1,9,1,7BD9043D223D555CF9F8C344436B63EF13BFE530A3AD5AB43B65A7E1E292F063AFC71143C404EE6C0C15F8C294BA7DF68FFC9140509ADDBECA5CC395C941E4F9*03 2019-07-03T05:13:21.277Z,1562130801.277 [Micromodem](INFO): Nmea in: $CATXD,1,9,1,64*71 2019-07-03T05:13:21.681Z,1562130801.681 [Micromodem](INFO): Nmea in: $CATXP,192*48 2019-07-03T05:13:22.506Z,1562130802.506 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:13:25.337Z,1562130805.337 [Micromodem](INFO): Nmea in: $CATXF,192*5E 2019-07-03T05:13:25.723Z,1562130805.723 [DataOverHttps](INFO): Sending 186 bytes from file Logs/20190703T044734/Courier0007.lzma 2019-07-03T05:13:25.751Z,1562130805.751 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:13:26.530Z,1562130806.530 [DataOverHttps](INFO): Moved sent file to Logs/20190703T044734/Courier0007.lzma.bak 2019-07-03T05:13:26.530Z,1562130806.530 [DataOverHttps](INFO): SBD MOMSN=11423816 2019-07-03T05:13:26.546Z,1562130806.546 [Micromodem](INFO): Nmea in: $CAXST,6,20190703,051321.847524,3,0,200,4000,10000,1,1,9,1,3,3,3,192*42 2019-07-03T05:13:28.563Z,1562130808.563 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:13:31.815Z,1562130811.815 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:13:34.623Z,1562130814.623 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:13:37.859Z,1562130817.859 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:13:40.683Z,1562130820.683 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:13:41.192Z,1562130821.192 [DataOverHttps](INFO): Sending 186 bytes from file Logs/20190703T050429/Courier0004.lzma 2019-07-03T05:13:41.997Z,1562130821.997 [DataOverHttps](INFO): Moved sent file to Logs/20190703T050429/Courier0004.lzma.bak 2019-07-03T05:13:41.997Z,1562130821.997 [DataOverHttps](INFO): SBD MOMSN=11423818 2019-07-03T05:13:43.147Z,1562130823.147 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2019-07-03T05:13:43.147Z,1562130823.147 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-03T05:13:43.169Z,1562130823.169 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-03T05:13:43.552Z,1562130823.552 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-03T05:13:43.552Z,1562130823.552 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2019-07-03T05:13:43.915Z,1562130823.915 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:13:46.747Z,1562130826.747 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:13:49.979Z,1562130829.979 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:13:52.807Z,1562130832.807 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:13:56.035Z,1562130836.035 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:13:58.866Z,1562130838.866 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:14:01.711Z,1562130841.711 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:14:04.523Z,1562130844.523 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:14:07.755Z,1562130847.755 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:14:10.579Z,1562130850.579 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:14:13.815Z,1562130853.815 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:14:16.639Z,1562130856.639 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:14:19.474Z,1562130859.474 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:14:22.707Z,1562130862.707 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:14:23.917Z,1562130863.917 [Micromodem](ERROR): Buffer fill timout failure. 2019-07-03T05:14:26.037Z,1562130866.037 [Default:CheckIn:Read_Iridium] Stopped 2019-07-03T05:14:26.037Z,1562130866.037 [Default:CheckIn:C.Wait] Running Loop=1 2019-07-03T05:14:26.037Z,1562130866.037 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-07-03T05:14:26.491Z,1562130866.491 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:14:29.723Z,1562130869.723 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:14:30.904Z,1562130870.904 [DataOverHttps](INFO): Sending 278 bytes from file Logs/20190703T044734/Express0008.lzma 2019-07-03T05:14:32.113Z,1562130872.113 [DataOverHttps](INFO): Moved sent file to Logs/20190703T044734/Express0008.lzma.bak 2019-07-03T05:14:32.113Z,1562130872.113 [DataOverHttps](INFO): SBD MOMSN=11423821 2019-07-03T05:14:32.551Z,1562130872.551 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:14:35.783Z,1562130875.783 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:14:38.607Z,1562130878.607 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:14:41.839Z,1562130881.839 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:14:44.667Z,1562130884.667 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:14:47.499Z,1562130887.499 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:14:50.727Z,1562130890.727 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:14:53.559Z,1562130893.559 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:14:56.787Z,1562130896.787 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:14:59.626Z,1562130899.626 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:15:02.043Z,1562130902.043 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:15:04.467Z,1562130904.467 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:15:07.695Z,1562130907.695 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:15:10.523Z,1562130910.523 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:15:13.759Z,1562130913.759 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:15:16.583Z,1562130916.583 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:15:19.802Z,1562130919.802 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-07-03T05:15:19.802Z,1562130919.802 [NAL9602] Data Fault, FailCount= 1 2019-07-03T05:15:19.802Z,1562130919.802 [NAL9602](ERROR): Data Fault 2019-07-03T05:15:19.856Z,1562130919.856 [CBIT](ERROR): Data Fault in component: NAL9602 2019-07-03T05:15:20.206Z,1562130920.206 [NAL9602](INFO): Powering down 2019-07-03T05:15:21.049Z,1562130921.049 [CBIT](INFO): Clearing failed state for component NAL9602 2019-07-03T05:15:21.049Z,1562130921.049 [NAL9602] No Fault, FailCount= 1 2019-07-03T05:15:50.505Z,1562130950.505 [NAL9602](INFO): Powering up NAL9602 2019-07-03T05:16:01.418Z,1562130961.418 [NAL9602](INFO): NAL9602 initialized 2019-07-03T05:16:02.235Z,1562130962.235 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:16:05.467Z,1562130965.467 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:16:08.715Z,1562130968.715 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:16:11.531Z,1562130971.531 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:16:14.355Z,1562130974.355 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:16:17.591Z,1562130977.591 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:16:20.428Z,1562130980.428 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:16:23.667Z,1562130983.667 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:16:26.483Z,1562130986.483 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:16:29.307Z,1562130989.307 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:16:31.735Z,1562130991.735 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:16:34.563Z,1562130994.563 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:16:37.798Z,1562130997.798 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:16:40.627Z,1562131000.627 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:16:43.448Z,1562131003.448 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:16:44.287Z,1562131004.287 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2019-07-03T05:16:44.287Z,1562131004.287 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-03T05:16:44.297Z,1562131004.297 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-03T05:16:44.725Z,1562131004.725 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-03T05:16:44.725Z,1562131004.725 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2019-07-03T05:16:46.679Z,1562131006.679 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:16:49.915Z,1562131009.915 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:16:52.335Z,1562131012.335 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:16:55.567Z,1562131015.567 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:16:58.396Z,1562131018.396 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:17:01.627Z,1562131021.627 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:17:04.467Z,1562131024.467 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:17:07.687Z,1562131027.687 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:17:10.523Z,1562131030.523 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:17:13.760Z,1562131033.760 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:17:16.579Z,1562131036.579 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:17:17.427Z,1562131037.427 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-07-03T05:17:17.427Z,1562131037.427 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00, I,-32768,-32768,-32768,-32768,V 2019-07-03T05:17:19.811Z,1562131039.811 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:17:22.638Z,1562131042.638 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:17:25.867Z,1562131045.867 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:17:28.695Z,1562131048.695 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:17:31.535Z,1562131051.535 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:17:34.351Z,1562131054.351 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:17:37.583Z,1562131057.583 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:17:40.411Z,1562131060.411 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:17:43.647Z,1562131063.647 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:17:46.471Z,1562131066.471 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:17:49.707Z,1562131069.707 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:17:52.535Z,1562131072.535 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:17:55.783Z,1562131075.783 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:17:58.595Z,1562131078.595 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:18:01.827Z,1562131081.827 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:18:04.651Z,1562131084.651 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:18:07.887Z,1562131087.887 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:18:10.711Z,1562131090.711 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:18:13.943Z,1562131093.943 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:18:16.771Z,1562131096.771 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:18:19.614Z,1562131099.614 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:18:22.435Z,1562131102.435 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:18:25.663Z,1562131105.663 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:18:28.496Z,1562131108.496 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:18:31.719Z,1562131111.719 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:18:34.551Z,1562131114.551 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:18:37.783Z,1562131117.783 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:18:40.607Z,1562131120.607 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:18:43.839Z,1562131123.839 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:18:46.671Z,1562131126.671 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:18:49.899Z,1562131129.899 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:18:52.727Z,1562131132.727 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:18:55.967Z,1562131135.967 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:18:58.787Z,1562131138.787 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:19:01.627Z,1562131141.627 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:19:04.467Z,1562131144.467 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:19:07.679Z,1562131147.679 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:19:10.515Z,1562131150.515 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:19:13.739Z,1562131153.739 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:19:16.566Z,1562131156.566 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:19:19.795Z,1562131159.795 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:19:22.623Z,1562131162.623 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:19:25.855Z,1562131165.855 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:19:26.289Z,1562131166.289 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-07-03T05:19:26.289Z,1562131166.289 [Default:CheckIn:C.Wait] Stopped 2019-07-03T05:19:26.289Z,1562131166.289 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-07-03T05:19:26.289Z,1562131166.289 [Default:CheckIn:D] Running Loop=1 2019-07-03T05:19:26.703Z,1562131166.703 [Default:CheckIn:D] Stopped 2019-07-03T05:19:26.703Z,1562131166.703 [Default:CheckIn:E] Running Loop=1 2019-07-03T05:19:27.089Z,1562131167.089 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.389970 min 2019-07-03T05:19:27.089Z,1562131167.089 [Default:CheckIn:E] Stopped 2019-07-03T05:19:27.089Z,1562131167.089 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-07-03T05:19:27.089Z,1562131167.089 [Default:CheckIn] Stopped 2019-07-03T05:19:27.090Z,1562131167.090 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-07-03T05:19:27.090Z,1562131167.090 [Default:CheckIn](INFO): Running loop #2 2019-07-03T05:19:27.090Z,1562131167.090 [Default:CheckIn] Running Loop=2 2019-07-03T05:19:27.090Z,1562131167.090 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-07-03T05:19:27.090Z,1562131167.090 [Default:CheckIn:Read_GPS] Running Loop=1 2019-07-03T05:19:28.683Z,1562131168.683 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:19:31.915Z,1562131171.915 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:19:34.743Z,1562131174.743 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:19:37.975Z,1562131177.975 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:19:40.819Z,1562131180.819 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:19:43.635Z,1562131183.635 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:19:45.259Z,1562131185.259 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2019-07-03T05:19:45.259Z,1562131185.259 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-07-03T05:19:45.270Z,1562131185.270 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-07-03T05:19:45.689Z,1562131185.689 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-07-03T05:19:45.689Z,1562131185.689 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2019-07-03T05:19:46.463Z,1562131186.463 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:19:49.699Z,1562131189.699 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:19:52.519Z,1562131192.519 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:19:55.759Z,1562131195.759 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:19:58.579Z,1562131198.579 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:20:01.819Z,1562131201.819 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:20:04.639Z,1562131204.639 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:20:07.467Z,1562131207.467 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:20:10.703Z,1562131210.703 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:20:13.535Z,1562131213.535 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:20:16.771Z,1562131216.771 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:20:19.587Z,1562131219.587 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:20:22.415Z,1562131222.415 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:20:25.647Z,1562131225.647 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:20:28.479Z,1562131228.479 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:20:31.707Z,1562131231.707 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:20:34.535Z,1562131234.535 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:20:37.767Z,1562131237.767 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:20:40.603Z,1562131240.603 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:20:43.827Z,1562131243.827 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:20:46.659Z,1562131246.659 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:20:49.499Z,1562131249.499 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:20:52.724Z,1562131252.724 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:20:55.543Z,1562131255.543 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:20:58.779Z,1562131258.779 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:21:01.619Z,1562131261.619 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:21:04.839Z,1562131264.839 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:21:07.666Z,1562131267.666 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:21:10.507Z,1562131270.507 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:21:13.723Z,1562131273.723 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:21:16.551Z,1562131276.551 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:21:19.787Z,1562131279.787 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:21:22.611Z,1562131282.611 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:21:25.469Z,1562131285.469 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:21:28.675Z,1562131288.675 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:21:31.499Z,1562131291.499 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:21:34.735Z,1562131294.735 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:21:37.563Z,1562131297.563 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:21:40.799Z,1562131300.799 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:21:43.619Z,1562131303.619 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:21:46.447Z,1562131306.447 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:21:49.679Z,1562131309.679 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:21:52.507Z,1562131312.507 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:21:55.739Z,1562131315.739 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:21:58.571Z,1562131318.571 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:22:01.821Z,1562131321.821 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:22:04.631Z,1562131324.631 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:22:07.459Z,1562131327.459 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:22:10.691Z,1562131330.691 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:22:13.515Z,1562131333.515 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:22:16.751Z,1562131336.751 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:22:19.583Z,1562131339.583 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:22:22.811Z,1562131342.811 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:22:25.643Z,1562131345.643 [NAL9602](DEBUG): Fix Requested 2019-07-03T05:22:26.032Z,1562131346.032 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,052212.00,A,3648.78518,N,12150.34597,W,0.467,283.55,030719,,,A*7B 2019-07-03T05:22:26.035Z,1562131346.035 [NAL9602](INFO): GPS fix at 20190703T052212: (36.813086, -121.839100) 2019-07-03T05:22:26.062Z,1562131346.062 [Default:CheckIn:Read_GPS] Stopped 2019-07-03T05:22:26.062Z,1562131346.062 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-07-03T05:22:27.893Z,1562131347.893 [Micromodem](INFO): Outgoing frame #1, 64 bytes: 5D371C5D070001005D00000400DB0100000000000000151D80030C5669BF3148E2FA22188B6A3173E6960F887FF8A99E669AC91D474B0DB47F940EC581E0D567 2019-07-03T05:22:27.894Z,1562131347.894 [Micromodem](INFO): Outgoing frame #2, 64 bytes: 266CC0E6F1A517638CB0C0B8BE3619E02B8F4A169EC22D30546A87042BC836DF836B942BC3C4A9EFC1B6C4BDD91F97B2782B4B03CB56EA92D77C6909485B9FDE 2019-07-03T05:22:27.894Z,1562131347.894 [Micromodem](INFO): Outgoing frame #3, 64 bytes: C9BA76D6E11C7243AB9F1CB76D4E14F7CBE1C6B0B40F2F0A19DC25B10B3C6279A2D80F52F03F1275F5BE973EA20943C61E76D18516091C6168D113CBFC440963 2019-07-03T05:22:27.895Z,1562131347.895 [Micromodem](INFO): Nmea out: $CCCYC,0,1,9,1,0,3*53 2019-07-03T05:22:28.037Z,1562131348.037 [Micromodem](INFO): Nmea in: $CACYC,0,1,9,1,0,3*51 2019-07-03T05:22:28.393Z,1562131348.393 [Micromodem](INFO): Nmea in: $CADRQ,052228,1,9,0,64,1*41 2019-07-03T05:22:28.395Z,1562131348.395 [Micromodem](INFO): Nmea out: $CCTXD,1,9,1,5D371C5D070001005D00000400DB0100000000000000151D80030C5669BF3148E2FA22188B6A3173E6960F887FF8A99E669AC91D474B0DB47F940EC581E0D567*7C 2019-07-03T05:22:28.785Z,1562131348.785 [Micromodem](INFO): Nmea in: $CATXD,1,9,1,64*71 2019-07-03T05:22:29.189Z,1562131349.189 [Micromodem](INFO): Nmea in: $CADRQ,052229,1,9,0,64,2*43 2019-07-03T05:22:29.190Z,1562131349.190 [Micromodem](INFO): Nmea out: $CCTXD,1,9,1,266CC0E6F1A517638CB0C0B8BE3619E02B8F4A169EC22D30546A87042BC836DF836B942BC3C4A9EFC1B6C4BDD91F97B2782B4B03CB56EA92D77C6909485B9FDE*74 2019-07-03T05:22:29.593Z,1562131349.593 [Micromodem](INFO): Nmea in: $CATXD,1,9,1,64*71 2019-07-03T05:22:29.997Z,1562131349.997 [Micromodem](INFO): Nmea in: $CADRQ,052230,1,9,0,64,3*4A 2019-07-03T05:22:29.997Z,1562131349.997 [Micromodem](INFO): Nmea out: $CCTXD,1,9,1,C9BA76D6E11C7243AB9F1CB76D4E14F7CBE1C6B0B40F2F0A19DC25B10B3C6279A2D80F52F03F1275F5BE973EA20943C61E76D18516091C6168D113CBFC440963*08 2019-07-03T05:22:30.401Z,1562131350.401 [Micromodem](INFO): Nmea in: $CATXD,1,9,1,64*71 2019-07-03T05:22:30.811Z,1562131350.811 [Micromodem](INFO): Nmea in: $CATXP,192*48 2019-07-03T05:22:34.453Z,1562131354.453 [Micromodem](INFO): Nmea in: $CATXF,192*5E 2019-07-03T05:22:34.846Z,1562131354.846 [Micromodem](INFO): Nmea in: $CAXST,6,20190703,052230.963297,3,0,200,4000,10000,1,1,9,1,3,3,3,192*48 2019-07-03T05:22:36.107Z,1562131356.107 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20190703T050429/Courier0007.lzma 2019-07-03T05:22:36.913Z,1562131356.913 [DataOverHttps](INFO): Moved sent file to Logs/20190703T050429/Courier0007.lzma.bak 2019-07-03T05:22:36.913Z,1562131356.913 [DataOverHttps](INFO): SBD MOMSN=11423828 2019-07-03T05:22:52.856Z,1562131372.856 [DataOverHttps](INFO): Sending 627 bytes from file Logs/20190703T050429/Express0001.lzma 2019-07-03T05:22:53.661Z,1562131373.661 [DataOverHttps](INFO): Moved sent file to Logs/20190703T050429/Express0001.lzma.bak 2019-07-03T05:22:53.661Z,1562131373.661 [DataOverHttps](INFO): SBD MOMSN=11423831 2019-07-03T05:22:58.277Z,1562131378.277 [NAL9602](INFO): Powering down 2019-07-03T05:23:06.871Z,1562131386.871 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20190703T050429/Express0005.lzma 2019-07-03T05:23:07.677Z,1562131387.677 [DataOverHttps](INFO): Moved sent file to Logs/20190703T050429/Express0005.lzma.bak 2019-07-03T05:23:07.677Z,1562131387.677 [DataOverHttps](INFO): SBD MOMSN=11423845 2019-07-03T05:23:22.315Z,1562131402.315 [DataOverHttps](INFO): Sending 308 bytes from file Logs/20190703T050429/Express0008.lzma 2019-07-03T05:23:23.121Z,1562131403.121 [DataOverHttps](INFO): Moved sent file to Logs/20190703T050429/Express0008.lzma.bak 2019-07-03T05:23:23.121Z,1562131403.121 [DataOverHttps](INFO): SBD MOMSN=11423848 2019-07-03T05:23:24.970Z,1562131404.970 [Default:CheckIn:Read_Iridium] Stopped 2019-07-03T05:23:24.970Z,1562131404.970 [Default:CheckIn:C.Wait] Running Loop=1 2019-07-03T05:23:24.970Z,1562131404.970 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-07-03T05:24:54.673Z,1562131494.673 [DataOverHttps](IMPORTANT): SBD MTMSN=20190703T052441 2019-07-03T05:25:00.243Z,1562131500.243 [DataOverHttps](INFO): Received command:configSet NAL9602.fastGPSFix 1 bool persist 2019-07-03T05:25:00.491Z,1562131500.491 [CommandLine](IMPORTANT): got command configSet NAL9602.fastGPSFix 1.000000 bool persist 2019-07-03T05:25:37.256Z,1562131537.256 [DataOverHttps](IMPORTANT): SBD MTMSN=20190703T052524 2019-07-03T05:25:42.523Z,1562131542.523 [DataOverHttps](INFO): Received command:Restart app 2019-07-03T05:25:42.604Z,1562131542.604 [CommandLine](IMPORTANT): got command restart application 2019-07-03T05:25:43.607Z,1562131543.607 [Supervisor](INFO): Stop Mission called by Supervisor::terminate 2019-07-03T05:25:43.608Z,1562131543.608 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-03T05:25:43.608Z,1562131543.608 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-07-03T05:25:43.767Z,1562131543.767 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2019-07-03T05:25:43.768Z,1562131543.768 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-07-03T05:25:43.770Z,1562131543.770 [CommandLine](INFO): Join timeout helper Thread ID is 974 2019-07-03T05:25:43.773Z,1562131543.773 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2019-07-03T05:25:43.773Z,1562131543.773 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-07-03T05:25:43.774Z,1562131543.774 [NavChartDb](INFO): Join timeout helper Thread ID is 975 2019-07-03T05:25:43.791Z,1562131543.791 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-03T05:25:43.792Z,1562131543.792 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-07-03T05:25:43.811Z,1562131543.811 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler 2019-07-03T05:25:43.811Z,1562131543.811 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2019-07-03T05:25:43.812Z,1562131543.812 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 976 2019-07-03T05:25:43.819Z,1562131543.819 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-03T05:25:43.820Z,1562131543.820 [WetLabsSeaOWL_UV_A](INFO): Powering down 2019-07-03T05:25:43.820Z,1562131543.820 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2019-07-03T05:25:43.831Z,1562131543.831 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler 2019-07-03T05:25:43.831Z,1562131543.831 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2019-07-03T05:25:43.832Z,1562131543.832 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 977 2019-07-03T05:25:43.904Z,1562131543.904 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-03T05:25:43.904Z,1562131543.904 [CTD_NeilBrown](INFO): Powering down 2019-07-03T05:25:43.919Z,1562131543.919 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2019-07-03T05:25:43.923Z,1562131543.923 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2019-07-03T05:25:43.923Z,1562131543.923 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-07-03T05:25:43.924Z,1562131543.924 [Radio_Surface](INFO): Join timeout helper Thread ID is 978 2019-07-03T05:25:44.171Z,1562131544.171 [Radio_Surface](INFO): Powering down 2019-07-03T05:25:44.172Z,1562131544.172 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-03T05:25:44.172Z,1562131544.172 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-07-03T05:25:44.188Z,1562131544.188 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2019-07-03T05:25:44.188Z,1562131544.188 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-07-03T05:25:44.189Z,1562131544.189 [DataOverHttps](INFO): Join timeout helper Thread ID is 979 2019-07-03T05:25:44.539Z,1562131544.539 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-03T05:25:44.540Z,1562131544.540 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-07-03T05:25:44.544Z,1562131544.544 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2019-07-03T05:25:44.544Z,1562131544.544 [logger ThreadHandler](INFO): Thread cancelled. 2019-07-03T05:25:44.544Z,1562131544.544 [logger](INFO): Join timeout helper Thread ID is 980 2019-07-03T05:25:44.595Z,1562131544.595 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-03T05:25:44.596Z,1562131544.596 [logger ThreadHandler](INFO): Thread cancelled. 2019-07-03T05:25:44.604Z,1562131544.604 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2019-07-03T05:25:44.604Z,1562131544.604 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-07-03T05:25:44.604Z,1562131544.604 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2019-07-03T05:25:44.604Z,1562131544.604 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-07-03T05:25:44.605Z,1562131544.605 [controlThread](INFO): Join timeout helper Thread ID is 981 2019-07-03T05:25:44.715Z,1562131544.715 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-03T05:25:44.716Z,1562131544.716 [controlThread](DEBUG): Uninitializing ControlThread 2019-07-03T05:25:44.716Z,1562131544.716 [AHRS_M2](INFO): Powering down 2019-07-03T05:25:44.788Z,1562131544.788 [DUSBL_Hydroid](INFO): Powering down 2019-07-03T05:25:44.892Z,1562131544.892 [Micromodem](INFO): Powering down 2019-07-03T05:25:44.988Z,1562131544.988 [NAL9602](INFO): Powering down 2019-07-03T05:25:45.059Z,1562131545.059 [RDI_Pathfinder](INFO): Powering down 2019-07-03T05:25:45.061Z,1562131545.061 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2019-07-03T05:25:45.061Z,1562131545.061 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2019-07-03T05:25:45.062Z,1562131545.062 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2019-07-03T05:25:45.062Z,1562131545.062 [MissionManager](INFO): Uninitializing Mission Default 2019-07-03T05:25:45.063Z,1562131545.063 [Default] Stopped 2019-07-03T05:25:45.063Z,1562131545.063 [Default](DEBUG): Aggregate::uninitialize Default 2019-07-03T05:25:45.063Z,1562131545.063 [Default:B.GoToSurface] Stopped 2019-07-03T05:25:45.063Z,1562131545.063 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-07-03T05:25:45.063Z,1562131545.063 [Default:CheckIn] Stopped 2019-07-03T05:25:45.063Z,1562131545.063 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-07-03T05:25:45.063Z,1562131545.063 [Default:CheckIn:C.Wait] Stopped 2019-07-03T05:25:45.063Z,1562131545.063 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-07-03T05:25:45.066Z,1562131545.066 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2019-07-03T05:25:45.066Z,1562131545.066 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2019-07-03T05:25:45.066Z,1562131545.066 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2019-07-03T05:25:45.066Z,1562131545.066 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2019-07-03T05:25:45.067Z,1562131545.067 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2019-07-03T05:25:45.067Z,1562131545.067 [BuoyancyServo](INFO): Powering down 2019-07-03T05:25:45.079Z,1562131545.079 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2019-07-03T05:25:45.079Z,1562131545.079 [ElevatorServo](INFO): Powering down 2019-07-03T05:25:45.080Z,1562131545.080 [MassServo](DEBUG): Uninitialize Mass Servo. 2019-07-03T05:25:45.080Z,1562131545.080 [MassServo](INFO): Powering down 2019-07-03T05:25:45.081Z,1562131545.081 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-07-03T05:25:45.081Z,1562131545.081 [RudderServo](INFO): Powering down 2019-07-03T05:25:45.082Z,1562131545.082 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2019-07-03T05:25:45.082Z,1562131545.082 [ThrusterServo](INFO): Powering down 2019-07-03T05:25:45.083Z,1562131545.083 [SBIT](DEBUG): Uninitialize SBIT Component. 2019-07-03T05:25:45.083Z,1562131545.083 [IBIT](DEBUG): Uninitialize IBIT Component. 2019-07-03T05:25:45.084Z,1562131545.084 [CBIT](DEBUG): Uninitialize CBIT Component. 2019-07-03T05:25:45.084Z,1562131545.084 [CBIT](DEBUG): Powering off loads. 2019-07-03T05:25:45.095Z,1562131545.095 [CBIT](DEBUG): Disabling WDT. 2019-07-03T05:25:45.107Z,1562131545.107 [CBIT](DEBUG): Opening all GF detection circuits. 2019-07-03T05:25:45.108Z,1562131545.108 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-07-03T05:25:45.160Z,1562131545.160 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-07-03T05:25:45.170Z,1562131545.170 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-07-03T05:25:45.211Z,1562131545.211 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2019-07-03T05:25:45.213Z,1562131545.213 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2019-07-03T05:25:45.269Z,1562131545.269 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-07-03T05:25:45.341Z,1562131545.341 [logger ThreadHandler](INFO): Thread cancelled.