2018-08-01T00:23:59.620Z,1533083039.620 [Supervisor](DEBUG): Initializing supervisor.
2018-08-01T00:23:59.623Z,1533083039.623 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-08-01T00:23:59.624Z,1533083039.624 [SyncHandler](INFO): Protected caller Thread ID is 2309
2018-08-01T00:23:59.624Z,1533083039.624 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-08-01T00:23:59.625Z,1533083039.625 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-08-01T00:23:59.626Z,1533083039.626 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2310
2018-08-01T00:23:59.628Z,1533083039.628 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-08-01T00:23:59.640Z,1533083039.640 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-08-01T00:23:59.641Z,1533083039.641 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-08-01T00:23:59.642Z,1533083039.642 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2311
2018-08-01T00:23:59.642Z,1533083039.642 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-08-01T00:23:59.643Z,1533083039.643 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-08-01T00:23:59.644Z,1533083039.644 [logger ThreadHandler](INFO): Protected caller Thread ID is 2312
2018-08-01T00:23:59.646Z,1533083039.646 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-08-01T00:23:59.646Z,1533083039.646 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-08-01T00:23:59.648Z,1533083039.648 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-08-01T00:23:59.843Z,1533083039.843 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-08-01T00:23:59.844Z,1533083039.844 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-08-01T00:23:59.986Z,1533083039.986 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-08-01T00:23:59.987Z,1533083039.987 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-08-01T00:24:00.334Z,1533083040.334 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-08-01T00:24:00.335Z,1533083040.335 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-08-01T00:24:00.473Z,1533083040.473 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-08-01T00:24:00.474Z,1533083040.474 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-08-01T00:24:00.554Z,1533083040.554 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-08-01T00:24:00.756Z,1533083040.756 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-08-01T00:24:00.757Z,1533083040.757 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-08-01T00:24:00.856Z,1533083040.856 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-08-01T00:24:00.856Z,1533083040.856 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-08-01T00:24:01.197Z,1533083041.197 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-08-01T00:24:01.198Z,1533083041.198 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-08-01T00:24:01.635Z,1533083041.635 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-08-01T00:24:01.635Z,1533083041.635 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-08-01T00:24:01.960Z,1533083041.960 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-08-01T00:24:01.960Z,1533083041.960 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-08-01T00:24:02.484Z,1533083042.484 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-08-01T00:24:02.484Z,1533083042.484 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-08-01T00:24:02.712Z,1533083042.712 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-08-01T00:24:02.712Z,1533083042.712 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-08-01T00:24:02.810Z,1533083042.810 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-08-01T00:24:02.811Z,1533083042.811 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-08-01T00:24:03.295Z,1533083043.295 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-08-01T00:24:03.295Z,1533083043.295 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-08-01T00:24:03.469Z,1533083043.469 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-08-01T00:24:03.471Z,1533083043.471 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2018-08-01T00:24:03.472Z,1533083043.472 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2018-08-01T00:24:03.703Z,1533083043.703 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-08-01T00:24:03.704Z,1533083043.704 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2018-08-01T00:24:03.802Z,1533083043.802 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2018-08-01T00:24:03.896Z,1533083043.896 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2018-08-01T00:24:03.999Z,1533083043.999 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2018-08-01T00:24:04.084Z,1533083044.084 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2018-08-01T00:24:04.217Z,1533083044.217 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2018-08-01T00:24:04.383Z,1533083044.383 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2018-08-01T00:24:04.494Z,1533083044.494 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2018-08-01T00:24:04.578Z,1533083044.578 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2018-08-01T00:24:04.662Z,1533083044.662 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2018-08-01T00:24:04.849Z,1533083044.849 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-08-01T00:24:04.852Z,1533083044.852 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-08-01T00:24:04.983Z,1533083044.983 [SBIT](DEBUG): Construct Startup Built In Test.
2018-08-01T00:24:05.013Z,1533083045.013 [SBIT] Loaded
2018-08-01T00:24:05.013Z,1533083045.013 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-08-01T00:24:05.014Z,1533083045.014 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-08-01T00:24:05.042Z,1533083045.042 [IBIT] Loaded
2018-08-01T00:24:05.042Z,1533083045.042 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-08-01T00:24:05.046Z,1533083045.046 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-08-01T00:24:05.203Z,1533083045.203 [CBIT] Loaded
2018-08-01T00:24:05.203Z,1533083045.203 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-08-01T00:24:05.203Z,1533083045.203 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-08-01T00:24:05.204Z,1533083045.204 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-08-01T00:24:05.273Z,1533083045.273 [VerticalControl](DEBUG): Construct VerticalControl.
2018-08-01T00:24:05.374Z,1533083045.374 [VerticalControl] Loaded
2018-08-01T00:24:05.374Z,1533083045.374 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-08-01T00:24:05.375Z,1533083045.375 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-08-01T00:24:05.436Z,1533083045.436 [HorizontalControl] Loaded
2018-08-01T00:24:05.437Z,1533083045.437 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-08-01T00:24:05.437Z,1533083045.437 [SpeedControl](DEBUG): Construct SpeedControl.
2018-08-01T00:24:05.443Z,1533083045.443 [SpeedControl] Loaded
2018-08-01T00:24:05.443Z,1533083045.443 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-08-01T00:24:05.444Z,1533083045.444 [LoopControl](DEBUG): Construct LoopControl.
2018-08-01T00:24:05.445Z,1533083045.445 [LoopControl] Loaded
2018-08-01T00:24:05.445Z,1533083045.445 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-08-01T00:24:05.445Z,1533083045.445 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-08-01T00:24:05.446Z,1533083045.446 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-08-01T00:24:05.488Z,1533083045.488 [DepthRateCalculator] Loaded
2018-08-01T00:24:05.488Z,1533083045.488 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-08-01T00:24:05.493Z,1533083045.493 [PitchRateCalculator] Loaded
2018-08-01T00:24:05.494Z,1533083045.494 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-08-01T00:24:05.510Z,1533083045.510 [SpeedCalculator] Loaded
2018-08-01T00:24:05.510Z,1533083045.510 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-08-01T00:24:05.532Z,1533083045.532 [TempGradientCalculator] Loaded
2018-08-01T00:24:05.532Z,1533083045.532 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-08-01T00:24:05.548Z,1533083045.548 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2018-08-01T00:24:05.548Z,1533083045.548 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2018-08-01T00:24:05.554Z,1533083045.554 [YawRateCalculator] Loaded
2018-08-01T00:24:05.554Z,1533083045.554 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-08-01T00:24:05.584Z,1533083045.584 [ElevatorOffsetCalculator] Loaded
2018-08-01T00:24:05.584Z,1533083045.584 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-08-01T00:24:05.584Z,1533083045.584 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-08-01T00:24:05.585Z,1533083045.585 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-08-01T00:24:05.669Z,1533083045.669 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2018-08-01T00:24:05.669Z,1533083045.669 [StratificationFrontDetector](DEBUG): (re)initializing
2018-08-01T00:24:05.669Z,1533083045.669 [StratificationFrontDetector] Loaded
2018-08-01T00:24:05.670Z,1533083045.670 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2018-08-01T00:24:05.670Z,1533083045.670 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-08-01T00:24:05.671Z,1533083045.671 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-08-01T00:24:05.919Z,1533083045.919 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-08-01T00:24:05.919Z,1533083045.919 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-08-01T00:24:06.017Z,1533083046.017 [DeadReckonUsingMultipleVelocitySources] Loaded
2018-08-01T00:24:06.017Z,1533083046.017 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2018-08-01T00:24:06.072Z,1533083046.072 [DeadReckonUsingSpeedCalculator] Loaded
2018-08-01T00:24:06.073Z,1533083046.073 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-08-01T00:24:06.090Z,1533083046.090 [NavChart] Loaded
2018-08-01T00:24:06.090Z,1533083046.090 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-08-01T00:24:06.094Z,1533083046.094 [UniversalFixResidualReporter] Loaded
2018-08-01T00:24:06.094Z,1533083046.094 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-08-01T00:24:06.095Z,1533083046.095 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-08-01T00:24:06.095Z,1533083046.095 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-08-01T00:24:06.109Z,1533083046.109 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-08-01T00:24:06.109Z,1533083046.109 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-08-01T00:24:06.268Z,1533083046.268 [Aanderaa_O2] Loaded
2018-08-01T00:24:06.268Z,1533083046.268 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-08-01T00:24:06.319Z,1533083046.319 [WetLabsBB2FL] Loaded
2018-08-01T00:24:06.319Z,1533083046.319 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-08-01T00:24:06.321Z,1533083046.321 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406D44E0
2018-08-01T00:24:06.321Z,1533083046.321 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 2391
2018-08-01T00:24:06.322Z,1533083046.322 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-08-01T00:24:06.322Z,1533083046.322 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-08-01T00:24:06.611Z,1533083046.611 [AHRS_M2] Loaded
2018-08-01T00:24:06.611Z,1533083046.611 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2018-08-01T00:24:06.679Z,1533083046.679 [DataOverHttps] Loaded
2018-08-01T00:24:06.679Z,1533083046.679 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-08-01T00:24:06.693Z,1533083046.693 [Depth_Keller] Loaded
2018-08-01T00:24:06.693Z,1533083046.693 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-08-01T00:24:06.698Z,1533083046.698 [DropWeight] Loaded
2018-08-01T00:24:06.698Z,1533083046.698 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-08-01T00:24:06.790Z,1533083046.790 [NAL9602] Loaded
2018-08-01T00:24:06.790Z,1533083046.790 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-08-01T00:24:06.795Z,1533083046.795 [Onboard] Loaded
2018-08-01T00:24:06.796Z,1533083046.796 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-08-01T00:24:06.803Z,1533083046.803 [Radio_Surface] Loaded
2018-08-01T00:24:06.803Z,1533083046.803 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-08-01T00:24:06.804Z,1533083046.804 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4092A4E0
2018-08-01T00:24:06.804Z,1533083046.804 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2392
2018-08-01T00:24:06.834Z,1533083046.834 [RDI_Pathfinder] Loaded
2018-08-01T00:24:06.834Z,1533083046.834 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2018-08-01T00:24:06.840Z,1533083046.840 [SCPI] Loaded
2018-08-01T00:24:06.841Z,1533083046.841 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread.
2018-08-01T00:24:08.934Z,1533083048.934 [BPC1] Loaded
2018-08-01T00:24:08.934Z,1533083048.934 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-08-01T00:24:08.934Z,1533083048.934 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-08-01T00:24:08.935Z,1533083048.935 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-08-01T00:24:09.035Z,1533083049.035 [BuoyancyServo] Loaded
2018-08-01T00:24:09.035Z,1533083049.035 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-08-01T00:24:09.047Z,1533083049.047 [ElevatorServo] Loaded
2018-08-01T00:24:09.047Z,1533083049.047 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-08-01T00:24:09.059Z,1533083049.059 [MassServo] Loaded
2018-08-01T00:24:09.059Z,1533083049.059 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-08-01T00:24:09.070Z,1533083049.070 [RudderServo] Loaded
2018-08-01T00:24:09.071Z,1533083049.071 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-08-01T00:24:09.082Z,1533083049.082 [ThrusterServo] Loaded
2018-08-01T00:24:09.082Z,1533083049.082 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-08-01T00:24:09.082Z,1533083049.082 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-08-01T00:24:09.083Z,1533083049.083 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-08-01T00:24:09.186Z,1533083049.186 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-08-01T00:24:09.186Z,1533083049.186 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-08-01T00:24:09.211Z,1533083049.211 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-08-01T00:24:09.214Z,1533083049.214 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-08-01T00:24:09.215Z,1533083049.215 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-08-01T00:24:09.222Z,1533083049.222 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-08-01T00:24:09.223Z,1533083049.223 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 409D34E0
2018-08-01T00:24:09.224Z,1533083049.224 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2393
2018-08-01T00:24:09.228Z,1533083049.228 [Supervisor](INFO): Main Thread ID is 797
2018-08-01T00:24:09.228Z,1533083049.228 [Supervisor](DEBUG): Running supervisor.
2018-08-01T00:24:09.229Z,1533083049.229 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2394
2018-08-01T00:24:09.231Z,1533083049.231 [controlThread ThreadHandler](INFO): Handler Thread ID is 2395
2018-08-01T00:24:09.232Z,1533083049.232 [controlThread](DEBUG): Initializing ControlThread
2018-08-01T00:24:09.233Z,1533083049.233 [SBIT](INFO): Initialize SBIT Component.
2018-08-01T00:24:09.233Z,1533083049.233 [SBIT](IMPORTANT): git: 2018-07-31
2018-08-01T00:24:09.233Z,1533083049.233 [SBIT](INFO): git hash: f162f5471e539e4e3a23169adacc16f438d84f2d
2018-08-01T00:24:09.234Z,1533083049.234 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-08-01T00:24:09.235Z,1533083049.235 [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-08-01T00:24:09.236Z,1533083049.236 [SBIT](INFO): Beginning SBIT in 28.000000 seconds.
2018-08-01T00:24:09.237Z,1533083049.237 [IBIT](INFO): Initialize IBIT Component.
2018-08-01T00:24:09.238Z,1533083049.238 [CBIT](DEBUG): Initialize CBIT Component.
2018-08-01T00:24:09.238Z,1533083049.238 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-08-01T00:24:09.239Z,1533083049.239 [logger ThreadHandler](INFO): Handler Thread ID is 2396
2018-08-01T00:24:09.265Z,1533083049.265 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 2397
2018-08-01T00:24:09.285Z,1533083049.285 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2398
2018-08-01T00:24:09.291Z,1533083049.291 [Radio_Surface](INFO): Powering up
2018-08-01T00:24:09.309Z,1533083049.309 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2399
2018-08-01T00:24:09.312Z,1533083049.312 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-08-01T00:24:09.313Z,1533083049.313 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-08-01T00:24:09.313Z,1533083049.313 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-08-01T00:24:09.313Z,1533083049.313 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-08-01T00:24:09.313Z,1533083049.313 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-08-01T00:24:09.313Z,1533083049.313 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-08-01T00:24:09.314Z,1533083049.314 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-08-01T00:24:09.314Z,1533083049.314 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-08-01T00:24:09.314Z,1533083049.314 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-08-01T00:24:09.314Z,1533083049.314 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-08-01T00:24:09.314Z,1533083049.314 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-08-01T00:24:09.314Z,1533083049.314 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-08-01T00:24:09.315Z,1533083049.315 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-08-01T00:24:09.315Z,1533083049.315 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-08-01T00:24:09.315Z,1533083049.315 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-08-01T00:24:09.315Z,1533083049.315 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-08-01T00:24:09.345Z,1533083049.345 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-08-01T00:24:09.347Z,1533083049.347 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-08-01T00:24:09.348Z,1533083049.348 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-08-01T00:24:09.348Z,1533083049.348 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-08-01T00:24:09.348Z,1533083049.348 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-08-01T00:24:09.349Z,1533083049.349 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-08-01T00:24:09.349Z,1533083049.349 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-08-01T00:24:09.349Z,1533083049.349 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-08-01T00:24:09.350Z,1533083049.350 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2018-08-01T00:24:09.351Z,1533083049.351 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-08-01T00:24:09.351Z,1533083049.351 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-08-01T00:24:09.352Z,1533083049.352 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2018-08-01T00:24:09.353Z,1533083049.353 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2018-08-01T00:24:09.353Z,1533083049.353 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2018-08-01T00:24:09.354Z,1533083049.354 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-01T00:24:09.354Z,1533083049.354 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-01T00:24:09.354Z,1533083049.354 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-01T00:24:09.355Z,1533083049.355 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-08-01T00:24:09.355Z,1533083049.355 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-08-01T00:24:09.362Z,1533083049.362 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-08-01T00:24:09.390Z,1533083049.390 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-08-01T00:24:09.425Z,1533083049.425 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2018-08-01T00:24:09.426Z,1533083049.426 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-08-01T00:24:09.522Z,1533083049.522 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-08-01T00:24:09.523Z,1533083049.523 [Default:A.Wait](DEBUG): Construct Wait.
2018-08-01T00:24:09.525Z,1533083049.525 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-08-01T00:24:09.573Z,1533083049.573 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-08-01T00:24:09.576Z,1533083049.576 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-08-01T00:24:09.590Z,1533083049.590 [Default:E.Execute](DEBUG): Construct Execute.
2018-08-01T00:24:09.613Z,1533083049.613 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn 300</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2018-08-01T00:24:09.619Z,1533083049.619 [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-08-01T00:24:09.665Z,1533083049.665 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2018-08-01T00:24:09.729Z,1533083049.729 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-08-01T00:24:09.737Z,1533083049.737 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2018-08-01T00:24:09.947Z,1533083049.947 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-08-01T00:24:10.049Z,1533083050.049 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:10.077Z,1533083050.077 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:10.187Z,1533083050.187 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-08-01T00:24:10.193Z,1533083050.193 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-08-01T00:24:10.209Z,1533083050.209 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-08-01T00:24:10.217Z,1533083050.217 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-08-01T00:24:10.223Z,1533083050.223 [MassServo](DEBUG): Initializing EZServoServo.
2018-08-01T00:24:10.229Z,1533083050.229 [MassServo](DEBUG): Initializing MassServo.
2018-08-01T00:24:10.243Z,1533083050.243 [RudderServo](DEBUG): Initializing EZServoServo.
2018-08-01T00:24:10.249Z,1533083050.249 [RudderServo](DEBUG): Initializing RudderServo.
2018-08-01T00:24:10.263Z,1533083050.263 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-08-01T00:24:10.273Z,1533083050.273 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-08-01T00:24:10.481Z,1533083050.481 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:10.482Z,1533083050.482 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:10.818Z,1533083050.818 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:10.819Z,1533083050.819 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:11.161Z,1533083051.161 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2018-08-01T00:24:11.161Z,1533083051.161 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2018-08-01T00:24:11.161Z,1533083051.161 [BuoyancyServo] Communications Fault, FailCount= 1
2018-08-01T00:24:11.161Z,1533083051.161 [BuoyancyServo](ERROR): Communications Fault
2018-08-01T00:24:11.373Z,1533083051.373 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2018-08-01T00:24:11.425Z,1533083051.425 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:11.426Z,1533083051.426 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:11.440Z,1533083051.440 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-08-01T00:24:11.449Z,1533083051.449 [BuoyancyServo](INFO): Powering down
2018-08-01T00:24:11.809Z,1533083051.809 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:11.810Z,1533083051.810 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:12.213Z,1533083052.213 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:12.214Z,1533083052.214 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:12.609Z,1533083052.609 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:12.610Z,1533083052.610 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:13.101Z,1533083053.101 [Aanderaa_O2](INFO): Powering down
2018-08-01T00:24:13.265Z,1533083053.265 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:13.266Z,1533083053.266 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:13.477Z,1533083053.477 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:13.478Z,1533083053.478 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:13.542Z,1533083053.542 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2018-08-01T00:24:13.542Z,1533083053.542 [BuoyancyServo] No Fault, FailCount= 1
2018-08-01T00:24:13.837Z,1533083053.837 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:13.838Z,1533083053.838 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:13.845Z,1533083053.845 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-08-01T00:24:13.966Z,1533083053.966 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-08-01T00:24:14.242Z,1533083054.242 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:14.243Z,1533083054.243 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:14.687Z,1533083054.687 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:14.688Z,1533083054.688 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:15.042Z,1533083055.042 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:15.043Z,1533083055.043 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:15.438Z,1533083055.438 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:15.439Z,1533083055.439 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:15.842Z,1533083055.842 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:15.843Z,1533083055.843 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:16.230Z,1533083056.230 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:16.231Z,1533083056.231 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:16.622Z,1533083056.622 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:16.623Z,1533083056.623 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:17.034Z,1533083057.034 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:17.035Z,1533083057.035 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-01T00:24:23.421Z,1533083063.421 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2018-08-01T00:24:36.991Z,1533083076.991 [NAL9602](INFO): Powering up NAL9602
2018-08-01T00:24:37.841Z,1533083077.841 [SBIT](IMPORTANT): Beginning Startup BIT
2018-08-01T00:24:37.853Z,1533083077.853 [CBIT](IMPORTANT): Beginning ground fault scan
2018-08-01T00:24:47.903Z,1533083087.903 [NAL9602](INFO): NAL9602 initialized
2018-08-01T00:24:48.811Z,1533083088.811 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.005234
CHAN A1 (24V): -0.002650
CHAN A2 (12V): 0.003137
CHAN A3 (5V): -0.005906
CHAN B0 (3.3V): -0.005069
CHAN B1 (3.15aV): -0.004654
CHAN B2 (3.15bV): -0.003783
CHAN B3 (GND): -0.006804
OPEN: 0.005149
Full Scale Calc: 4.765 mA, -1.589 mA
2018-08-01T00:25:02.893Z,1533083102.893 [NAL9602](INFO): SBD MO Status=0, MOMSN=678, MT Status=0, MTMSN=0
2018-08-01T00:25:02.893Z,1533083102.893 [NAL9602](INFO): No messages in MT queue
2018-08-01T00:25:31.867Z,1533083131.867 [SBIT](IMPORTANT): SBIT PASSED
2018-08-01T00:25:31.937Z,1533083131.937 [CommandLine](IMPORTANT): got command configSet list
2018-08-01T00:25:31.937Z,1533083131.937 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-08-01T00:25:31.938Z,1533083131.938 [CommandLine](IMPORTANT): Radio_Surface.loadAtStartup=1 bool;

2018-08-01T00:25:32.250Z,1533083132.250 [MissionManager](IMPORTANT): Started mission Startup
2018-08-01T00:25:32.250Z,1533083132.250 [Startup] Running Loop=1
2018-08-01T00:25:32.250Z,1533083132.250 [Startup](DEBUG): Aggregate::initialize Startup
2018-08-01T00:25:32.250Z,1533083132.250 [Startup:A.GoToSurface] Running Loop=1
2018-08-01T00:25:32.251Z,1533083132.251 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-08-01T00:25:32.251Z,1533083132.251 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-08-01T00:25:32.252Z,1533083132.252 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-08-01T00:25:32.252Z,1533083132.252 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-08-01T00:25:32.252Z,1533083132.252 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-08-01T00:25:32.253Z,1533083132.253 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-08-01T00:25:32.259Z,1533083132.259 [Startup:StartupSatComms] Running Loop=1
2018-08-01T00:25:32.259Z,1533083132.259 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-08-01T00:25:32.259Z,1533083132.259 [Startup:StartupSatComms:A] Running Loop=1
2018-08-01T00:25:32.668Z,1533083132.668 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-08-01T00:26:27.800Z,1533083187.800 [NAL9602](INFO): GPS fix at 20180801T002626: (36.803310, -121.801244)
2018-08-01T00:26:27.874Z,1533083187.874 [Startup:StartupSatComms:A] Stopped
2018-08-01T00:26:27.874Z,1533083187.874 [Startup:StartupSatComms:B] Running Loop=1
2018-08-01T00:26:28.296Z,1533083188.296 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-08-01T00:26:59.536Z,1533083219.536 [NAL9602](INFO): SBD MO Status=1, MOMSN=679, MT Status=0, MTMSN=0
2018-08-01T00:26:59.589Z,1533083219.589 [NAL9602](INFO): Sent 25 bytes from file Logs/20180801T001420/Courier0006.lzma
2018-08-01T00:26:59.589Z,1533083219.589 [NAL9602](INFO): Packets left to send: 0
2018-08-01T00:26:59.591Z,1533083219.591 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180801T001420/Courier0006.lzma.parts/0000.sbd
2018-08-01T00:26:59.591Z,1533083219.591 [NAL9602](DEBUG): Completed sending Logs/20180801T001420/Courier0006.lzma
2018-08-01T00:27:23.248Z,1533083243.248 [NAL9602](INFO): SBD MO Status=2, MOMSN=680, MT Status=2, MTMSN=0
2018-08-01T00:27:23.249Z,1533083243.249 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-08-01T00:27:28.215Z,1533083248.215 [Startup:StartupSatComms:B](INFO): Timed out from 2018-08-01T00:26:27.9Z
2018-08-01T00:27:28.215Z,1533083248.215 [Startup:StartupSatComms:B] Stopped
2018-08-01T00:27:28.216Z,1533083248.216 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-08-01T00:27:28.216Z,1533083248.216 [Startup:StartupSatComms] Stopped
2018-08-01T00:27:28.216Z,1533083248.216 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-08-01T00:27:28.233Z,1533083248.233 [Startup](INFO): Completed Startup
2018-08-01T00:27:28.233Z,1533083248.233 [MissionManager](INFO): Startup is completed.
2018-08-01T00:27:28.234Z,1533083248.234 [MissionManager](INFO): Uninitializing Mission Startup
2018-08-01T00:27:28.234Z,1533083248.234 [Startup] Stopped
2018-08-01T00:27:28.234Z,1533083248.234 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-08-01T00:27:28.234Z,1533083248.234 [Startup:A.GoToSurface] Stopped
2018-08-01T00:27:28.234Z,1533083248.234 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-08-01T00:27:30.546Z,1533083250.546 [MissionManager](IMPORTANT): Started mission Default
2018-08-01T00:27:30.546Z,1533083250.546 [Default] Running Loop=1
2018-08-01T00:27:30.546Z,1533083250.546 [Default](DEBUG): Aggregate::initialize Default
2018-08-01T00:27:30.546Z,1533083250.546 [Default:B.GoToSurface] Running Loop=1
2018-08-01T00:27:30.546Z,1533083250.546 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-08-01T00:27:30.547Z,1533083250.547 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-08-01T00:27:30.547Z,1533083250.547 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-08-01T00:27:30.547Z,1533083250.547 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-08-01T00:27:30.548Z,1533083250.548 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-08-01T00:27:30.548Z,1533083250.548 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-08-01T00:27:30.548Z,1533083250.548 [Default:A.Wait] Running Loop=1
2018-08-01T00:27:30.553Z,1533083250.553 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-08-01T00:27:43.872Z,1533083263.872 [Default:A.Wait](INFO): Done Waiting.
2018-08-01T00:27:43.872Z,1533083263.872 [Default:A.Wait] Stopped
2018-08-01T00:27:43.873Z,1533083263.873 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T00:27:44.305Z,1533083264.305 [Default:CheckIn] Running Loop=1
2018-08-01T00:27:44.305Z,1533083264.305 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T00:27:44.305Z,1533083264.305 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T00:27:44.682Z,1533083264.682 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-08-01T00:27:49.007Z,1533083269.007 [NAL9602](INFO): SBD MO Status=2, MOMSN=680, MT Status=2, MTMSN=0
2018-08-01T00:27:49.008Z,1533083269.008 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-08-01T00:27:49.983Z,1533083269.983 [NAL9602](INFO): GPS fix at 20180801T002748: (36.805169, -121.792997)
2018-08-01T00:27:50.027Z,1533083270.027 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T00:27:50.027Z,1533083270.027 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T00:27:50.371Z,1533083270.371 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003887
2018-08-01T00:27:50.458Z,1533083270.458 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-08-01T00:27:56.202Z,1533083276.202 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20180801T002359/Courier0000.lzma
2018-08-01T00:27:56.958Z,1533083276.958 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0000.lzma.bak
2018-08-01T00:27:56.958Z,1533083276.958 [DataOverHttps](INFO): SBD MOMSN=8389645
2018-08-01T00:28:07.532Z,1533083287.532 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20180801T002359/Courier0004.lzma
2018-08-01T00:28:08.716Z,1533083288.716 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0004.lzma.bak
2018-08-01T00:28:08.716Z,1533083288.716 [DataOverHttps](INFO): SBD MOMSN=8389649
2018-08-01T00:28:21.884Z,1533083301.884 [DataOverHttps](INFO): Sending 237 bytes from file Logs/20180801T001420/Express0007.lzma
2018-08-01T00:28:22.676Z,1533083302.676 [DataOverHttps](INFO): Moved sent file to Logs/20180801T001420/Express0007.lzma.bak
2018-08-01T00:28:22.676Z,1533083302.676 [DataOverHttps](INFO): SBD MOMSN=8389656
2018-08-01T00:28:26.844Z,1533083306.844 [NAL9602](INFO): Powering down
2018-08-01T00:28:32.315Z,1533083312.315 [DataOverHttps](INFO): Sending 720 bytes from file Logs/20180801T002359/Express0001.lzma
2018-08-01T00:28:33.108Z,1533083313.108 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0001.lzma.bak
2018-08-01T00:28:33.108Z,1533083313.108 [DataOverHttps](INFO): SBD MOMSN=8389663
2018-08-01T00:28:43.197Z,1533083323.197 [DataOverHttps](INFO): Sending 108 bytes from file Logs/20180801T002359/Express0005.lzma
2018-08-01T00:28:43.984Z,1533083323.984 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0005.lzma.bak
2018-08-01T00:28:43.984Z,1533083323.984 [DataOverHttps](INFO): SBD MOMSN=8389678
2018-08-01T00:28:44.555Z,1533083324.555 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T00:28:44.555Z,1533083324.555 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T00:28:44.555Z,1533083324.555 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T00:33:44.931Z,1533083624.931 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T00:33:44.931Z,1533083624.931 [Default:CheckIn:C.Wait] Stopped
2018-08-01T00:33:44.931Z,1533083624.931 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T00:33:44.932Z,1533083624.932 [Default:CheckIn:D] Running Loop=1
2018-08-01T00:33:45.355Z,1533083625.355 [Default:CheckIn:D] Stopped
2018-08-01T00:33:45.355Z,1533083625.355 [Default:CheckIn:E] Running Loop=1
2018-08-01T00:33:45.739Z,1533083625.739 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.246789 min 
2018-08-01T00:33:45.745Z,1533083625.745 [Default:CheckIn:E] Stopped
2018-08-01T00:33:45.745Z,1533083625.745 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T00:33:45.745Z,1533083625.745 [Default:CheckIn] Stopped
2018-08-01T00:33:45.745Z,1533083625.745 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T00:33:45.746Z,1533083625.746 [Default:CheckIn](INFO): Running loop #2
2018-08-01T00:33:45.746Z,1533083625.746 [Default:CheckIn] Running Loop=2
2018-08-01T00:33:45.746Z,1533083625.746 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T00:33:45.746Z,1533083625.746 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T00:33:49.009Z,1533083629.009 [NAL9602](INFO): Powering up
2018-08-01T00:34:00.191Z,1533083640.191 [NAL9602](INFO): NAL9602 initialized
2018-08-01T00:35:03.472Z,1533083703.472 [NAL9602](INFO): SBD MO Status=2, MOMSN=680, MT Status=2, MTMSN=0
2018-08-01T00:35:03.472Z,1533083703.472 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-08-01T00:35:20.676Z,1533083720.676 [NAL9602](INFO): SBD MO Status=2, MOMSN=680, MT Status=2, MTMSN=0
2018-08-01T00:35:20.676Z,1533083720.676 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-08-01T00:35:30.684Z,1533083730.684 [NAL9602](INFO): SBD MO Status=0, MOMSN=680, MT Status=0, MTMSN=0
2018-08-01T00:35:30.684Z,1533083730.684 [NAL9602](INFO): No messages in MT queue
2018-08-01T00:35:31.878Z,1533083731.878 [NAL9602](INFO): GPS fix at 20180801T003529: (36.802774, -121.786931)
2018-08-01T00:35:31.971Z,1533083731.971 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T00:35:31.971Z,1533083731.971 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T00:35:36.438Z,1533083736.438 [DataOverHttps](INFO): Sending 230 bytes from file Logs/20180801T002359/Courier0007.lzma
2018-08-01T00:35:37.221Z,1533083737.221 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0007.lzma.bak
2018-08-01T00:35:37.222Z,1533083737.222 [DataOverHttps](INFO): SBD MOMSN=8389681
2018-08-01T00:35:46.664Z,1533083746.664 [DataOverHttps](INFO): Sending 167 bytes from file Logs/20180801T002359/Express0008.lzma
2018-08-01T00:35:47.424Z,1533083747.424 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0008.lzma.bak
2018-08-01T00:35:47.424Z,1533083747.424 [DataOverHttps](INFO): SBD MOMSN=8389684
2018-08-01T00:35:47.958Z,1533083747.958 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T00:35:47.958Z,1533083747.958 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T00:35:47.958Z,1533083747.958 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T00:36:06.846Z,1533083766.846 [NAL9602](INFO): Powering down
2018-08-01T00:40:48.355Z,1533084048.355 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T00:40:48.355Z,1533084048.355 [Default:CheckIn:C.Wait] Stopped
2018-08-01T00:40:48.355Z,1533084048.355 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T00:40:48.355Z,1533084048.355 [Default:CheckIn:D] Running Loop=1
2018-08-01T00:40:48.755Z,1533084048.755 [Default:CheckIn:D] Stopped
2018-08-01T00:40:48.755Z,1533084048.755 [Default:CheckIn:E] Running Loop=1
2018-08-01T00:40:49.137Z,1533084049.137 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 13.303474 min 
2018-08-01T00:40:49.138Z,1533084049.138 [Default:CheckIn:E] Stopped
2018-08-01T00:40:49.138Z,1533084049.138 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T00:40:49.138Z,1533084049.138 [Default:CheckIn] Stopped
2018-08-01T00:40:49.138Z,1533084049.138 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T00:40:49.138Z,1533084049.138 [Default:CheckIn](INFO): Running loop #3
2018-08-01T00:40:49.139Z,1533084049.139 [Default:CheckIn] Running Loop=3
2018-08-01T00:40:49.139Z,1533084049.139 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T00:40:49.139Z,1533084049.139 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T00:40:52.409Z,1533084052.409 [NAL9602](INFO): Powering up
2018-08-01T00:41:03.550Z,1533084063.550 [NAL9602](INFO): NAL9602 initialized
2018-08-01T00:41:21.985Z,1533084081.985 [RDI_Pathfinder](ERROR): only read 3 of 5 data items
2018-08-01T00:41:21.985Z,1533084081.985 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-32768,-32768,-3278,V
2018-08-01T00:41:29.552Z,1533084089.552 [NAL9602](INFO): SBD MO Status=2, MOMSN=681, MT Status=2, MTMSN=0
2018-08-01T00:41:29.552Z,1533084089.552 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-08-01T00:42:29.348Z,1533084149.348 [NAL9602](INFO): SBD MO Status=0, MOMSN=681, MT Status=0, MTMSN=0
2018-08-01T00:42:29.348Z,1533084149.348 [NAL9602](INFO): No messages in MT queue
2018-08-01T00:42:30.551Z,1533084150.551 [NAL9602](INFO): GPS fix at 20180801T004228: (36.802759, -121.786951)
2018-08-01T00:42:30.618Z,1533084150.618 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T00:42:30.618Z,1533084150.618 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T00:42:35.475Z,1533084155.475 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20180801T002359/Courier0010.lzma
2018-08-01T00:42:36.272Z,1533084156.272 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0010.lzma.bak
2018-08-01T00:42:36.273Z,1533084156.273 [DataOverHttps](INFO): SBD MOMSN=8389693
2018-08-01T00:42:46.051Z,1533084166.051 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20180801T002359/Express0011.lzma
2018-08-01T00:42:46.845Z,1533084166.845 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0011.lzma.bak
2018-08-01T00:42:46.846Z,1533084166.846 [DataOverHttps](INFO): SBD MOMSN=8389696
2018-08-01T00:42:47.401Z,1533084167.401 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T00:42:47.401Z,1533084167.401 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T00:42:47.401Z,1533084167.401 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T00:43:05.410Z,1533084185.410 [NAL9602](INFO): Powering down
2018-08-01T00:45:52.569Z,1533084352.569 [RDI_Pathfinder](ERROR): Failed to parse:
:HM,G,G,0e88,0e88,*14.577,*-0.070,*0.000
2018-08-01T00:45:53.354Z,1533084353.354 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-32768,-32768,-32768,-32768,V
2018-08-01T00:47:30.797Z,1533084450.797 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2018-08-01T00:47:30.798Z,1533084450.798 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,18080100483847,35.0, -0.,1448.9,  0
2018-08-01T00:47:48.010Z,1533084468.010 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T00:47:48.010Z,1533084468.010 [Default:CheckIn:C.Wait] Stopped
2018-08-01T00:47:48.010Z,1533084468.010 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T00:47:48.010Z,1533084468.010 [Default:CheckIn:D] Running Loop=1
2018-08-01T00:47:48.439Z,1533084468.439 [Default:CheckIn:D] Stopped
2018-08-01T00:47:48.439Z,1533084468.439 [Default:CheckIn:E] Running Loop=1
2018-08-01T00:47:52.856Z,1533084472.856 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.298212 min 
2018-08-01T00:47:52.856Z,1533084472.856 [Default:CheckIn:E] Stopped
2018-08-01T00:47:52.856Z,1533084472.856 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T00:47:52.856Z,1533084472.856 [Default:CheckIn] Stopped
2018-08-01T00:47:52.856Z,1533084472.856 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T00:47:52.857Z,1533084472.857 [Default:CheckIn](INFO): Running loop #4
2018-08-01T00:47:52.857Z,1533084472.857 [Default:CheckIn] Running Loop=4
2018-08-01T00:47:52.857Z,1533084472.857 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T00:47:52.857Z,1533084472.857 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T00:47:53.306Z,1533084473.306 [NAL9602](INFO): Powering up
2018-08-01T00:48:04.498Z,1533084484.498 [NAL9602](INFO): NAL9602 initialized
2018-08-01T00:48:26.496Z,1533084506.496 [NAL9602](INFO): SBD MO Status=0, MOMSN=682, MT Status=0, MTMSN=0
2018-08-01T00:48:26.496Z,1533084506.496 [NAL9602](INFO): No messages in MT queue
2018-08-01T00:51:25.328Z,1533084685.328 [NAL9602](INFO): GPS fix at 20180801T005124: (36.802604, -121.788001)
2018-08-01T00:51:25.388Z,1533084685.388 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T00:51:25.388Z,1533084685.388 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T00:51:30.240Z,1533084690.240 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20180801T002359/Courier0013.lzma
2018-08-01T00:51:31.036Z,1533084691.036 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0013.lzma.bak
2018-08-01T00:51:31.036Z,1533084691.036 [DataOverHttps](INFO): SBD MOMSN=8389707
2018-08-01T00:51:40.792Z,1533084700.792 [DataOverHttps](INFO): Sending 133 bytes from file Logs/20180801T002359/Express0014.lzma
2018-08-01T00:51:41.599Z,1533084701.599 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0014.lzma.bak
2018-08-01T00:51:41.600Z,1533084701.600 [DataOverHttps](INFO): SBD MOMSN=8389710
2018-08-01T00:51:42.127Z,1533084702.127 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T00:51:42.127Z,1533084702.127 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T00:51:42.127Z,1533084702.127 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T00:52:00.106Z,1533084720.106 [NAL9602](INFO): Powering down
2018-08-01T00:56:42.597Z,1533085002.597 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T00:56:42.597Z,1533085002.597 [Default:CheckIn:C.Wait] Stopped
2018-08-01T00:56:42.598Z,1533085002.598 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T00:56:42.598Z,1533085002.598 [Default:CheckIn:D] Running Loop=1
2018-08-01T00:56:43.042Z,1533085003.042 [Default:CheckIn:D] Stopped
2018-08-01T00:56:43.042Z,1533085003.042 [Default:CheckIn:E] Running Loop=1
2018-08-01T00:56:46.149Z,1533085006.149 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.208262 min 
2018-08-01T00:56:46.149Z,1533085006.149 [Default:CheckIn:E] Stopped
2018-08-01T00:56:46.149Z,1533085006.149 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T00:56:46.150Z,1533085006.150 [Default:CheckIn] Stopped
2018-08-01T00:56:46.150Z,1533085006.150 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T00:56:46.150Z,1533085006.150 [Default:CheckIn](INFO): Running loop #5
2018-08-01T00:56:46.150Z,1533085006.150 [Default:CheckIn] Running Loop=5
2018-08-01T00:56:46.150Z,1533085006.150 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T00:56:46.150Z,1533085006.150 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T00:56:46.629Z,1533085006.629 [NAL9602](INFO): Powering up
2018-08-01T00:56:57.836Z,1533085017.836 [NAL9602](INFO): NAL9602 initialized
2018-08-01T00:57:30.232Z,1533085050.232 [NAL9602](INFO): SBD MO Status=0, MOMSN=683, MT Status=0, MTMSN=0
2018-08-01T00:57:30.232Z,1533085050.232 [NAL9602](INFO): No messages in MT queue
2018-08-01T00:59:23.452Z,1533085163.452 [NAL9602](INFO): GPS fix at 20180801T005921: (36.802750, -121.788140)
2018-08-01T00:59:23.535Z,1533085163.535 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T00:59:23.536Z,1533085163.536 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T00:59:28.367Z,1533085168.367 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20180801T002359/Courier0016.lzma
2018-08-01T00:59:29.564Z,1533085169.564 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0016.lzma.bak
2018-08-01T00:59:29.564Z,1533085169.564 [DataOverHttps](INFO): SBD MOMSN=8389717
2018-08-01T00:59:40.158Z,1533085180.158 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20180801T002359/Express0017.lzma
2018-08-01T00:59:41.356Z,1533085181.356 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0017.lzma.bak
2018-08-01T00:59:41.356Z,1533085181.356 [DataOverHttps](INFO): SBD MOMSN=8389722
2018-08-01T00:59:41.911Z,1533085181.911 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T00:59:41.911Z,1533085181.911 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T00:59:41.911Z,1533085181.911 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T00:59:58.350Z,1533085198.350 [NAL9602](INFO): Powering down
2018-08-01T01:04:42.571Z,1533085482.571 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T01:04:42.571Z,1533085482.571 [Default:CheckIn:C.Wait] Stopped
2018-08-01T01:04:42.571Z,1533085482.571 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T01:04:42.572Z,1533085482.572 [Default:CheckIn:D] Running Loop=1
2018-08-01T01:04:42.994Z,1533085482.994 [Default:CheckIn:D] Stopped
2018-08-01T01:04:42.994Z,1533085482.994 [Default:CheckIn:E] Running Loop=1
2018-08-01T01:04:46.129Z,1533085486.129 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 37.207454 min 
2018-08-01T01:04:46.130Z,1533085486.130 [Default:CheckIn:E] Stopped
2018-08-01T01:04:46.130Z,1533085486.130 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T01:04:46.130Z,1533085486.130 [Default:CheckIn] Stopped
2018-08-01T01:04:46.130Z,1533085486.130 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T01:04:46.130Z,1533085486.130 [Default:CheckIn](INFO): Running loop #6
2018-08-01T01:04:46.130Z,1533085486.130 [Default:CheckIn] Running Loop=6
2018-08-01T01:04:46.131Z,1533085486.131 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T01:04:46.131Z,1533085486.131 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T01:04:46.566Z,1533085486.566 [NAL9602](INFO): Powering up
2018-08-01T01:04:57.762Z,1533085497.762 [NAL9602](INFO): NAL9602 initialized
2018-08-01T01:09:47.093Z,1533085787.093 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-01T01:04:46.1Z
2018-08-01T01:09:47.093Z,1533085787.093 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T01:09:47.093Z,1533085787.093 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T01:09:52.109Z,1533085792.109 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180801T002359/Courier0019.lzma
2018-08-01T01:09:52.878Z,1533085792.878 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0019.lzma.bak
2018-08-01T01:09:52.879Z,1533085792.879 [DataOverHttps](INFO): SBD MOMSN=8389729
2018-08-01T01:10:01.751Z,1533085801.751 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-01T01:10:01.897Z,1533085801.897 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20180801T002359/Express0020.lzma
2018-08-01T01:10:02.671Z,1533085802.671 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0020.lzma.bak
2018-08-01T01:10:02.671Z,1533085802.671 [DataOverHttps](INFO): SBD MOMSN=8389731
2018-08-01T01:10:03.234Z,1533085803.234 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T01:10:03.234Z,1533085803.234 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T01:10:03.234Z,1533085803.234 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T01:10:31.943Z,1533085831.943 [NAL9602](INFO): Powering down
2018-08-01T01:11:48.635Z,1533085908.635 [RDI_Pathfinder](ERROR): only read 4 of 5 data items
2018-08-01T01:11:48.636Z,1533085908.636 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-32768,-32768,-32768,-32BS,-32768,-32768,-32768,V
2018-08-01T01:15:03.784Z,1533086103.784 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T01:15:03.784Z,1533086103.784 [Default:CheckIn:C.Wait] Stopped
2018-08-01T01:15:03.784Z,1533086103.784 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T01:15:03.784Z,1533086103.784 [Default:CheckIn:D] Running Loop=1
2018-08-01T01:15:04.187Z,1533086104.187 [Default:CheckIn:D] Stopped
2018-08-01T01:15:04.187Z,1533086104.187 [Default:CheckIn:E] Running Loop=1
2018-08-01T01:15:04.605Z,1533086104.605 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 47.560681 min 
2018-08-01T01:15:04.606Z,1533086104.606 [Default:CheckIn:E] Stopped
2018-08-01T01:15:04.606Z,1533086104.606 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T01:15:04.606Z,1533086104.606 [Default:CheckIn] Stopped
2018-08-01T01:15:04.606Z,1533086104.606 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T01:15:04.606Z,1533086104.606 [Default:CheckIn](INFO): Running loop #7
2018-08-01T01:15:04.606Z,1533086104.606 [Default:CheckIn] Running Loop=7
2018-08-01T01:15:04.607Z,1533086104.607 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T01:15:04.607Z,1533086104.607 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T01:15:08.012Z,1533086108.012 [NAL9602](INFO): Powering up
2018-08-01T01:15:19.190Z,1533086119.190 [NAL9602](INFO): NAL9602 initialized
2018-08-01T01:15:19.995Z,1533086119.995 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-08-01T01:15:19.995Z,1533086119.995 [NAL9602] Data Fault, FailCount= 1
2018-08-01T01:15:19.995Z,1533086119.995 [NAL9602](ERROR): Data Fault
2018-08-01T01:15:20.085Z,1533086120.085 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T01:15:20.404Z,1533086120.404 [NAL9602](INFO): Powering down
2018-08-01T01:15:21.250Z,1533086121.250 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T01:15:21.250Z,1533086121.250 [NAL9602] No Fault, FailCount= 1
2018-08-01T01:15:41.641Z,1533086141.641 [RDI_Pathfinder](ERROR): Failed to parse:
:H88,0e87,*16.122,*0.020,*65.535
2018-08-01T01:15:50.799Z,1533086150.799 [NAL9602](INFO): Powering up NAL9602
2018-08-01T01:16:01.994Z,1533086161.994 [NAL9602](INFO): NAL9602 initialized
2018-08-01T01:20:04.906Z,1533086404.906 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-01T01:15:04.6Z
2018-08-01T01:20:04.906Z,1533086404.906 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T01:20:04.906Z,1533086404.906 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T01:20:08.619Z,1533086408.619 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180801T002359/Courier0022.lzma
2018-08-01T01:20:09.384Z,1533086409.384 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0022.lzma.bak
2018-08-01T01:20:09.384Z,1533086409.384 [DataOverHttps](INFO): SBD MOMSN=8389737
2018-08-01T01:20:18.499Z,1533086418.499 [DataOverHttps](INFO): Sending 239 bytes from file Logs/20180801T002359/Express0023.lzma
2018-08-01T01:20:19.299Z,1533086419.299 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0023.lzma.bak
2018-08-01T01:20:19.300Z,1533086419.300 [DataOverHttps](INFO): SBD MOMSN=8389740
2018-08-01T01:20:19.808Z,1533086419.808 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T01:20:19.808Z,1533086419.808 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T01:20:19.809Z,1533086419.809 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T01:21:08.196Z,1533086468.196 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-01T01:21:38.742Z,1533086498.742 [NAL9602](INFO): Powering down
2018-08-01T01:25:20.355Z,1533086720.355 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T01:25:20.356Z,1533086720.356 [Default:CheckIn:C.Wait] Stopped
2018-08-01T01:25:20.356Z,1533086720.356 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T01:25:20.356Z,1533086720.356 [Default:CheckIn:D] Running Loop=1
2018-08-01T01:25:20.754Z,1533086720.754 [Default:CheckIn:D] Stopped
2018-08-01T01:25:20.754Z,1533086720.754 [Default:CheckIn:E] Running Loop=1
2018-08-01T01:25:24.115Z,1533086724.115 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 57.836800 min 
2018-08-01T01:25:24.115Z,1533086724.115 [Default:CheckIn:E] Stopped
2018-08-01T01:25:24.115Z,1533086724.115 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T01:25:24.116Z,1533086724.116 [Default:CheckIn] Stopped
2018-08-01T01:25:24.116Z,1533086724.116 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T01:25:24.116Z,1533086724.116 [Default:CheckIn](INFO): Running loop #8
2018-08-01T01:25:24.116Z,1533086724.116 [Default:CheckIn] Running Loop=8
2018-08-01T01:25:24.116Z,1533086724.116 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T01:25:24.116Z,1533086724.116 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T01:25:24.566Z,1533086724.566 [NAL9602](INFO): Powering up
2018-08-01T01:25:35.758Z,1533086735.758 [NAL9602](INFO): NAL9602 initialized
2018-08-01T01:26:07.770Z,1533086767.770 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2018-08-01T01:26:07.853Z,1533086767.853 [NAL9602](FAULT): received: 
+CSQ:0

OK3, 0, 0, 0, 0

OK
2018-08-01T01:26:07.853Z,1533086767.853 [NAL9602] Data Fault, FailCount= 2
2018-08-01T01:26:07.853Z,1533086767.853 [NAL9602](ERROR): Data Fault
2018-08-01T01:26:07.941Z,1533086767.941 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T01:26:08.158Z,1533086768.158 [NAL9602](INFO): Powering down
2018-08-01T01:26:09.037Z,1533086769.037 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T01:26:09.037Z,1533086769.037 [NAL9602] No Fault, FailCount= 2
2018-08-01T01:26:25.542Z,1533086785.542 [RDI_Pathfinder](ERROR): Failed to parse:
:HM,G,G,0e88,0e88, 16.115, 0.024, 65.535
2018-08-01T01:26:38.310Z,1533086798.310 [NAL9602](INFO): Powering up NAL9602
2018-08-01T01:26:49.126Z,1533086809.126 [NAL9602](INFO): NAL9602 initialized
2018-08-01T01:26:49.921Z,1533086809.921 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-08-01T01:26:49.922Z,1533086809.922 [NAL9602] Data Fault, FailCount= 3
2018-08-01T01:26:49.922Z,1533086809.922 [NAL9602](ERROR): Data Fault
2018-08-01T01:26:50.005Z,1533086810.005 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T01:26:50.316Z,1533086810.316 [NAL9602](INFO): Powering down
2018-08-01T01:26:51.189Z,1533086811.189 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T01:26:51.193Z,1533086811.193 [NAL9602] No Fault, FailCount= 3
2018-08-01T01:27:20.726Z,1533086840.726 [NAL9602](INFO): Powering up NAL9602
2018-08-01T01:27:31.765Z,1533086851.765 [NAL9602](INFO): NAL9602 initialized
2018-08-01T01:30:27.453Z,1533087027.453 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-01T01:25:24.1Z
2018-08-01T01:30:27.454Z,1533087027.454 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T01:30:27.454Z,1533087027.454 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T01:30:33.745Z,1533087033.745 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180801T002359/Courier0025.lzma
2018-08-01T01:30:34.520Z,1533087034.520 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0025.lzma.bak
2018-08-01T01:30:34.520Z,1533087034.520 [DataOverHttps](INFO): SBD MOMSN=8389749
2018-08-01T01:30:39.038Z,1533087039.038 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-01T01:30:43.540Z,1533087043.540 [DataOverHttps](INFO): Sending 249 bytes from file Logs/20180801T002359/Express0026.lzma
2018-08-01T01:30:44.304Z,1533087044.304 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0026.lzma.bak
2018-08-01T01:30:44.304Z,1533087044.304 [DataOverHttps](INFO): SBD MOMSN=8389751
2018-08-01T01:30:44.835Z,1533087044.835 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T01:30:44.835Z,1533087044.835 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T01:30:44.835Z,1533087044.835 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T01:31:09.774Z,1533087069.774 [NAL9602](INFO): Powering down
2018-08-01T01:35:45.472Z,1533087345.472 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T01:35:45.473Z,1533087345.473 [Default:CheckIn:C.Wait] Stopped
2018-08-01T01:35:45.473Z,1533087345.473 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T01:35:45.473Z,1533087345.473 [Default:CheckIn:D] Running Loop=1
2018-08-01T01:35:45.862Z,1533087345.862 [Default:CheckIn:D] Stopped
2018-08-01T01:35:45.862Z,1533087345.862 [Default:CheckIn:E] Running Loop=1
2018-08-01T01:35:49.045Z,1533087349.045 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 68.255253 min 
2018-08-01T01:35:49.045Z,1533087349.045 [Default:CheckIn:E] Stopped
2018-08-01T01:35:49.045Z,1533087349.045 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T01:35:49.045Z,1533087349.045 [Default:CheckIn] Stopped
2018-08-01T01:35:49.045Z,1533087349.045 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T01:35:49.046Z,1533087349.046 [Default:CheckIn](INFO): Running loop #9
2018-08-01T01:35:49.046Z,1533087349.046 [Default:CheckIn] Running Loop=9
2018-08-01T01:35:49.046Z,1533087349.046 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T01:35:49.046Z,1533087349.046 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T01:35:49.503Z,1533087349.503 [NAL9602](INFO): Powering up
2018-08-01T01:36:00.698Z,1533087360.698 [NAL9602](INFO): NAL9602 initialized
2018-08-01T01:36:32.699Z,1533087392.699 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2018-08-01T01:36:32.773Z,1533087392.773 [NAL9602](FAULT): received: 
+CSQ:0

OK3, 0, 0, 0, 0

OK
2018-08-01T01:36:32.773Z,1533087392.773 [NAL9602] Data Fault, FailCount= 4
2018-08-01T01:36:32.773Z,1533087392.773 [NAL9602](ERROR): Data Fault
2018-08-01T01:36:32.869Z,1533087392.869 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T01:36:33.098Z,1533087393.098 [NAL9602](INFO): Powering down
2018-08-01T01:36:33.955Z,1533087393.955 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T01:36:33.955Z,1533087393.955 [NAL9602] No Fault, FailCount= 4
2018-08-01T01:37:03.254Z,1533087423.254 [NAL9602](INFO): Powering up NAL9602
2018-08-01T01:37:14.454Z,1533087434.454 [NAL9602](INFO): NAL9602 initialized
2018-08-01T01:40:49.994Z,1533087649.994 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-01T01:35:49.0Z
2018-08-01T01:40:49.994Z,1533087649.994 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T01:40:49.994Z,1533087649.994 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T01:40:55.022Z,1533087655.022 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180801T002359/Courier0028.lzma
2018-08-01T01:40:55.792Z,1533087655.792 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0028.lzma.bak
2018-08-01T01:40:55.792Z,1533087655.792 [DataOverHttps](INFO): SBD MOMSN=8389761
2018-08-01T01:41:04.831Z,1533087664.831 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-01T01:41:04.981Z,1533087664.981 [DataOverHttps](INFO): Sending 233 bytes from file Logs/20180801T002359/Express0029.lzma
2018-08-01T01:41:05.740Z,1533087665.740 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0029.lzma.bak
2018-08-01T01:41:05.740Z,1533087665.740 [DataOverHttps](INFO): SBD MOMSN=8389763
2018-08-01T01:41:06.323Z,1533087666.323 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T01:41:06.324Z,1533087666.324 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T01:41:06.324Z,1533087666.324 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T01:41:35.142Z,1533087695.142 [NAL9602](INFO): Powering down
2018-08-01T01:46:06.816Z,1533087966.816 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T01:46:06.816Z,1533087966.816 [Default:CheckIn:C.Wait] Stopped
2018-08-01T01:46:06.816Z,1533087966.816 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T01:46:06.816Z,1533087966.816 [Default:CheckIn:D] Running Loop=1
2018-08-01T01:46:07.228Z,1533087967.228 [Default:CheckIn:D] Stopped
2018-08-01T01:46:07.228Z,1533087967.228 [Default:CheckIn:E] Running Loop=1
2018-08-01T01:46:10.400Z,1533087970.400 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 78.611353 min 
2018-08-01T01:46:10.405Z,1533087970.405 [Default:CheckIn:E] Stopped
2018-08-01T01:46:10.405Z,1533087970.405 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T01:46:10.405Z,1533087970.405 [Default:CheckIn] Stopped
2018-08-01T01:46:10.405Z,1533087970.405 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T01:46:10.406Z,1533087970.406 [Default:CheckIn](INFO): Running loop #10
2018-08-01T01:46:10.406Z,1533087970.406 [Default:CheckIn] Running Loop=10
2018-08-01T01:46:10.406Z,1533087970.406 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T01:46:10.406Z,1533087970.406 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T01:46:10.854Z,1533087970.854 [NAL9602](INFO): Powering up
2018-08-01T01:46:11.687Z,1533087971.687 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-32768,-32768,-32768,-32768,V
2018-08-01T01:46:21.659Z,1533087981.659 [NAL9602](INFO): NAL9602 initialized
2018-08-01T01:46:22.454Z,1533087982.454 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-08-01T01:46:22.455Z,1533087982.455 [NAL9602] Data Fault, FailCount= 5
2018-08-01T01:46:22.455Z,1533087982.455 [NAL9602](ERROR): Data Fault
2018-08-01T01:46:22.550Z,1533087982.550 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T01:46:22.551Z,1533087982.551 [CBIT](CRITICAL): Data Fault in component: NAL9602
2018-08-01T01:46:22.850Z,1533087982.850 [NAL9602](INFO): Powering down
2018-08-01T01:46:22.943Z,1533087982.943 [CommandLine](FAULT): Scheduling is paused
2018-08-01T01:46:22.943Z,1533087982.943 [CBIT](INFO): Critical error at 20180801T014622
2018-08-01T01:46:22.943Z,1533087982.943 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2018-08-01T01:48:22.776Z,1533088102.776 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T01:48:22.777Z,1533088102.777 [NAL9602] No Fault, FailCount= 5
2018-08-01T01:48:23.110Z,1533088103.110 [NAL9602](INFO): Powering up NAL9602
2018-08-01T01:48:34.310Z,1533088114.310 [NAL9602](INFO): NAL9602 initialized
2018-08-01T01:51:11.122Z,1533088271.122 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-01T01:46:10.4Z
2018-08-01T01:51:11.123Z,1533088271.123 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T01:51:11.123Z,1533088271.123 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T01:51:16.097Z,1533088276.097 [DataOverHttps](INFO): Sending 93 bytes from file Logs/20180801T002359/Courier0031.lzma
2018-08-01T01:51:16.881Z,1533088276.881 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0031.lzma.bak
2018-08-01T01:51:16.881Z,1533088276.881 [DataOverHttps](INFO): SBD MOMSN=8389772
2018-08-01T01:51:26.264Z,1533088286.264 [DataOverHttps](INFO): Sending 237 bytes from file Logs/20180801T002359/Express0032.lzma
2018-08-01T01:51:27.040Z,1533088287.040 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0032.lzma.bak
2018-08-01T01:51:27.040Z,1533088287.040 [DataOverHttps](INFO): SBD MOMSN=8389775
2018-08-01T01:51:27.602Z,1533088287.602 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T01:51:27.602Z,1533088287.602 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T01:51:27.602Z,1533088287.602 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T01:52:32.868Z,1533088352.868 [RDI_Pathfinder](ERROR): Failed to parse:
:HM,G,G,0e88,0e87,*16.068,*0.018,*65.535
2018-08-01T01:53:37.525Z,1533088417.525 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-01T01:54:08.323Z,1533088448.323 [NAL9602](INFO): Powering down
2018-08-01T01:54:10.758Z,1533088450.758 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2018-08-01T01:54:10.758Z,1533088450.758 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,18080101551, -0.1,   0.0,1448.9,  0
2018-08-01T01:54:11.971Z,1533088451.971 [RDI_Pathfinder](ERROR): Failed to parse:
:HM,G,G,0e88,0e88,*16.109,*0.036,*65.535
2018-08-01T01:56:28.028Z,1533088588.028 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T01:56:28.028Z,1533088588.028 [Default:CheckIn:C.Wait] Stopped
2018-08-01T01:56:28.028Z,1533088588.028 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T01:56:28.028Z,1533088588.028 [Default:CheckIn:D] Running Loop=1
2018-08-01T01:56:28.478Z,1533088588.478 [Default:CheckIn:D] Stopped
2018-08-01T01:56:28.478Z,1533088588.478 [Default:CheckIn:E] Running Loop=1
2018-08-01T01:56:28.850Z,1533088588.850 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 88.965535 min 
2018-08-01T01:56:28.850Z,1533088588.850 [Default:CheckIn:E] Stopped
2018-08-01T01:56:28.850Z,1533088588.850 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T01:56:28.850Z,1533088588.850 [Default:CheckIn] Stopped
2018-08-01T01:56:28.851Z,1533088588.851 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T01:56:28.851Z,1533088588.851 [Default:CheckIn](INFO): Running loop #11
2018-08-01T01:56:28.851Z,1533088588.851 [Default:CheckIn] Running Loop=11
2018-08-01T01:56:28.851Z,1533088588.851 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T01:56:28.851Z,1533088588.851 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T01:56:32.405Z,1533088592.405 [NAL9602](INFO): Powering up
2018-08-01T01:56:43.378Z,1533088603.378 [NAL9602](INFO): NAL9602 initialized
2018-08-01T02:01:29.162Z,1533088889.162 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-01T01:56:28.9Z
2018-08-01T02:01:29.162Z,1533088889.162 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T02:01:29.162Z,1533088889.162 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T02:01:33.629Z,1533088893.629 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180801T002359/Courier0034.lzma
2018-08-01T02:01:34.416Z,1533088894.416 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0034.lzma.bak
2018-08-01T02:01:34.416Z,1533088894.416 [DataOverHttps](INFO): SBD MOMSN=8389785
2018-08-01T02:01:43.512Z,1533088903.512 [DataOverHttps](INFO): Sending 200 bytes from file Logs/20180801T002359/Express0035.lzma
2018-08-01T02:01:44.275Z,1533088904.275 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0035.lzma.bak
2018-08-01T02:01:44.276Z,1533088904.276 [DataOverHttps](INFO): SBD MOMSN=8389787
2018-08-01T02:01:44.809Z,1533088904.809 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T02:01:44.809Z,1533088904.809 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T02:01:44.810Z,1533088904.810 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T02:01:48.246Z,1533088908.246 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-01T02:02:18.790Z,1533088938.790 [NAL9602](INFO): Powering down
2018-08-01T02:06:45.495Z,1533089205.495 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T02:06:45.495Z,1533089205.495 [Default:CheckIn:C.Wait] Stopped
2018-08-01T02:06:45.495Z,1533089205.495 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T02:06:45.495Z,1533089205.495 [Default:CheckIn:D] Running Loop=1
2018-08-01T02:06:45.882Z,1533089205.882 [Default:CheckIn:D] Stopped
2018-08-01T02:06:45.882Z,1533089205.882 [Default:CheckIn:E] Running Loop=1
2018-08-01T02:06:49.130Z,1533089209.130 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 99.255591 min 
2018-08-01T02:06:49.131Z,1533089209.131 [Default:CheckIn:E] Stopped
2018-08-01T02:06:49.131Z,1533089209.131 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T02:06:49.131Z,1533089209.131 [Default:CheckIn] Stopped
2018-08-01T02:06:49.131Z,1533089209.131 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T02:06:49.131Z,1533089209.131 [Default:CheckIn](INFO): Running loop #12
2018-08-01T02:06:49.131Z,1533089209.131 [Default:CheckIn] Running Loop=12
2018-08-01T02:06:49.131Z,1533089209.131 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T02:06:49.132Z,1533089209.132 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T02:06:49.638Z,1533089209.638 [NAL9602](INFO): Powering up
2018-08-01T02:07:00.830Z,1533089220.830 [NAL9602](INFO): NAL9602 initialized
2018-08-01T02:07:01.635Z,1533089221.635 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-08-01T02:07:01.635Z,1533089221.635 [NAL9602] Data Fault, FailCount= 1
2018-08-01T02:07:01.635Z,1533089221.635 [NAL9602](ERROR): Data Fault
2018-08-01T02:07:01.745Z,1533089221.745 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T02:07:02.030Z,1533089222.030 [NAL9602](INFO): Powering down
2018-08-01T02:07:02.917Z,1533089222.917 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T02:07:02.917Z,1533089222.917 [NAL9602] No Fault, FailCount= 1
2018-08-01T02:07:32.042Z,1533089252.042 [NAL9602](INFO): Powering up NAL9602
2018-08-01T02:07:42.830Z,1533089262.830 [NAL9602](INFO): NAL9602 initialized
2018-08-01T02:11:49.883Z,1533089509.883 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-01T02:06:49.1Z
2018-08-01T02:11:49.883Z,1533089509.883 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T02:11:49.883Z,1533089509.883 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T02:11:54.886Z,1533089514.886 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180801T002359/Courier0037.lzma
2018-08-01T02:11:55.655Z,1533089515.655 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0037.lzma.bak
2018-08-01T02:11:55.655Z,1533089515.655 [DataOverHttps](INFO): SBD MOMSN=8389795
2018-08-01T02:12:04.749Z,1533089524.749 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20180801T002359/Express0038.lzma
2018-08-01T02:12:05.535Z,1533089525.535 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0038.lzma.bak
2018-08-01T02:12:05.535Z,1533089525.535 [DataOverHttps](INFO): SBD MOMSN=8389797
2018-08-01T02:12:06.089Z,1533089526.089 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T02:12:06.089Z,1533089526.089 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T02:12:06.089Z,1533089526.089 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T02:12:49.406Z,1533089569.406 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-01T02:13:19.902Z,1533089599.902 [NAL9602](INFO): Powering down
2018-08-01T02:17:06.591Z,1533089826.591 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T02:17:06.592Z,1533089826.592 [Default:CheckIn:C.Wait] Stopped
2018-08-01T02:17:06.592Z,1533089826.592 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T02:17:06.592Z,1533089826.592 [Default:CheckIn:D] Running Loop=1
2018-08-01T02:17:06.979Z,1533089826.979 [Default:CheckIn:D] Stopped
2018-08-01T02:17:06.979Z,1533089826.979 [Default:CheckIn:E] Running Loop=1
2018-08-01T02:17:10.163Z,1533089830.163 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 109.607218 min 
2018-08-01T02:17:10.163Z,1533089830.163 [Default:CheckIn:E] Stopped
2018-08-01T02:17:10.164Z,1533089830.164 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T02:17:10.164Z,1533089830.164 [Default:CheckIn] Stopped
2018-08-01T02:17:10.164Z,1533089830.164 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T02:17:10.164Z,1533089830.164 [Default:CheckIn](INFO): Running loop #13
2018-08-01T02:17:10.164Z,1533089830.164 [Default:CheckIn] Running Loop=13
2018-08-01T02:17:10.164Z,1533089830.164 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T02:17:10.164Z,1533089830.164 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T02:17:10.614Z,1533089830.614 [NAL9602](INFO): Powering up
2018-08-01T02:17:21.818Z,1533089841.818 [NAL9602](INFO): NAL9602 initialized
2018-08-01T02:17:53.814Z,1533089873.814 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2018-08-01T02:17:53.889Z,1533089873.889 [NAL9602](FAULT): received: 
+CSQ:0

OK3, 0, 0, 0, 0

OK
2018-08-01T02:17:53.889Z,1533089873.889 [NAL9602] Data Fault, FailCount= 2
2018-08-01T02:17:53.889Z,1533089873.889 [NAL9602](ERROR): Data Fault
2018-08-01T02:17:53.936Z,1533089873.936 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T02:17:54.224Z,1533089874.224 [NAL9602](INFO): Powering down
2018-08-01T02:17:55.081Z,1533089875.081 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T02:17:55.081Z,1533089875.081 [NAL9602] No Fault, FailCount= 2
2018-08-01T02:18:24.334Z,1533089904.334 [NAL9602](INFO): Powering up NAL9602
2018-08-01T02:18:35.139Z,1533089915.139 [NAL9602](INFO): NAL9602 initialized
2018-08-01T02:18:35.943Z,1533089915.943 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-08-01T02:18:35.943Z,1533089915.943 [NAL9602] Data Fault, FailCount= 3
2018-08-01T02:18:35.943Z,1533089915.943 [NAL9602](ERROR): Data Fault
2018-08-01T02:18:36.019Z,1533089916.019 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T02:18:36.334Z,1533089916.334 [NAL9602](INFO): Powering down
2018-08-01T02:18:37.226Z,1533089917.226 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T02:18:37.226Z,1533089917.226 [NAL9602] No Fault, FailCount= 3
2018-08-01T02:19:06.734Z,1533089946.734 [NAL9602](INFO): Powering up NAL9602
2018-08-01T02:19:11.653Z,1533089951.653 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-32768,-32768,-32768,V
2018-08-01T02:19:17.626Z,1533089957.626 [NAL9602](INFO): NAL9602 initialized
2018-08-01T02:22:11.064Z,1533090131.064 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-01T02:17:10.2Z
2018-08-01T02:22:11.064Z,1533090131.064 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T02:22:11.064Z,1533090131.064 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T02:22:16.251Z,1533090136.251 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180801T002359/Courier0040.lzma
2018-08-01T02:22:16.980Z,1533090136.980 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0040.lzma.bak
2018-08-01T02:22:16.980Z,1533090136.980 [DataOverHttps](INFO): SBD MOMSN=8389812
2018-08-01T02:22:25.827Z,1533090145.827 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-01T02:22:25.960Z,1533090145.960 [DataOverHttps](INFO): Sending 252 bytes from file Logs/20180801T002359/Express0041.lzma
2018-08-01T02:22:26.753Z,1533090146.753 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0041.lzma.bak
2018-08-01T02:22:26.753Z,1533090146.753 [DataOverHttps](INFO): SBD MOMSN=8389814
2018-08-01T02:22:27.319Z,1533090147.319 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T02:22:27.319Z,1533090147.319 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T02:22:27.319Z,1533090147.319 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T02:22:56.055Z,1533090176.055 [NAL9602](INFO): Powering down
2018-08-01T02:27:27.653Z,1533090447.653 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T02:27:27.653Z,1533090447.653 [Default:CheckIn:C.Wait] Stopped
2018-08-01T02:27:27.654Z,1533090447.654 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T02:27:27.654Z,1533090447.654 [Default:CheckIn:D] Running Loop=1
2018-08-01T02:27:28.027Z,1533090448.027 [Default:CheckIn:D] Stopped
2018-08-01T02:27:28.027Z,1533090448.027 [Default:CheckIn:E] Running Loop=1
2018-08-01T02:27:28.461Z,1533090448.461 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 119.958008 min 
2018-08-01T02:27:28.461Z,1533090448.461 [Default:CheckIn:E] Stopped
2018-08-01T02:27:28.461Z,1533090448.461 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T02:27:28.461Z,1533090448.461 [Default:CheckIn] Stopped
2018-08-01T02:27:28.461Z,1533090448.461 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T02:27:28.462Z,1533090448.462 [Default:CheckIn](INFO): Running loop #14
2018-08-01T02:27:28.462Z,1533090448.462 [Default:CheckIn] Running Loop=14
2018-08-01T02:27:28.462Z,1533090448.462 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T02:27:28.462Z,1533090448.462 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T02:27:31.990Z,1533090451.990 [NAL9602](INFO): Powering up
2018-08-01T02:27:42.922Z,1533090462.922 [NAL9602](INFO): NAL9602 initialized
2018-08-01T02:28:14.926Z,1533090494.926 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2018-08-01T02:28:15.009Z,1533090495.009 [NAL9602](FAULT): received: 
+CSQ:0

OK3, 0, 0, 0, 0

OK
2018-08-01T02:28:15.009Z,1533090495.009 [NAL9602] Data Fault, FailCount= 4
2018-08-01T02:28:15.009Z,1533090495.009 [NAL9602](ERROR): Data Fault
2018-08-01T02:28:15.094Z,1533090495.094 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T02:28:15.318Z,1533090495.318 [NAL9602](INFO): Powering down
2018-08-01T02:28:16.206Z,1533090496.206 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T02:28:16.206Z,1533090496.206 [NAL9602] No Fault, FailCount= 4
2018-08-01T02:28:45.506Z,1533090525.506 [NAL9602](INFO): Powering up NAL9602
2018-08-01T02:28:56.310Z,1533090536.310 [NAL9602](INFO): NAL9602 initialized
2018-08-01T02:32:28.610Z,1533090748.610 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-01T02:27:28.5Z
2018-08-01T02:32:28.611Z,1533090748.611 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T02:32:28.611Z,1533090748.611 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T02:32:33.126Z,1533090753.126 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180801T002359/Courier0043.lzma
2018-08-01T02:32:33.892Z,1533090753.892 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0043.lzma.bak
2018-08-01T02:32:33.892Z,1533090753.892 [DataOverHttps](INFO): SBD MOMSN=8389839
2018-08-01T02:32:42.986Z,1533090762.986 [DataOverHttps](INFO): Sending 234 bytes from file Logs/20180801T002359/Express0044.lzma
2018-08-01T02:32:43.764Z,1533090763.764 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0044.lzma.bak
2018-08-01T02:32:43.764Z,1533090763.764 [DataOverHttps](INFO): SBD MOMSN=8389841
2018-08-01T02:32:44.331Z,1533090764.331 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T02:32:44.331Z,1533090764.331 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T02:32:44.331Z,1533090764.331 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T02:32:47.786Z,1533090767.786 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-01T02:33:18.314Z,1533090798.314 [NAL9602](INFO): Powering down
2018-08-01T02:37:44.777Z,1533091064.777 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T02:37:44.778Z,1533091064.778 [Default:CheckIn:C.Wait] Stopped
2018-08-01T02:37:44.778Z,1533091064.778 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T02:37:44.778Z,1533091064.778 [Default:CheckIn:D] Running Loop=1
2018-08-01T02:37:45.190Z,1533091065.190 [Default:CheckIn:D] Stopped
2018-08-01T02:37:45.190Z,1533091065.190 [Default:CheckIn:E] Running Loop=1
2018-08-01T02:37:48.378Z,1533091068.378 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 130.244067 min 
2018-08-01T02:37:48.378Z,1533091068.378 [Default:CheckIn:E] Stopped
2018-08-01T02:37:48.379Z,1533091068.379 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T02:37:48.379Z,1533091068.379 [Default:CheckIn] Stopped
2018-08-01T02:37:48.379Z,1533091068.379 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T02:37:48.379Z,1533091068.379 [Default:CheckIn](INFO): Running loop #15
2018-08-01T02:37:48.379Z,1533091068.379 [Default:CheckIn] Running Loop=15
2018-08-01T02:37:48.379Z,1533091068.379 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T02:37:48.379Z,1533091068.379 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T02:37:48.834Z,1533091068.834 [NAL9602](INFO): Powering up
2018-08-01T02:37:59.646Z,1533091079.646 [NAL9602](INFO): NAL9602 initialized
2018-08-01T02:38:00.442Z,1533091080.442 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-08-01T02:38:00.442Z,1533091080.442 [NAL9602] Data Fault, FailCount= 5
2018-08-01T02:38:00.442Z,1533091080.442 [NAL9602](ERROR): Data Fault
2018-08-01T02:38:00.530Z,1533091080.530 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T02:38:00.530Z,1533091080.530 [CBIT](CRITICAL): Data Fault in component: NAL9602
2018-08-01T02:38:00.830Z,1533091080.830 [NAL9602](INFO): Powering down
2018-08-01T02:38:00.907Z,1533091080.907 [CBIT](INFO): Critical error at 20180801T023800
2018-08-01T02:40:00.553Z,1533091200.553 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T02:40:00.553Z,1533091200.553 [NAL9602] No Fault, FailCount= 5
2018-08-01T02:40:00.878Z,1533091200.878 [NAL9602](INFO): Powering up NAL9602
2018-08-01T02:40:12.078Z,1533091212.078 [NAL9602](INFO): NAL9602 initialized
2018-08-01T02:41:38.221Z,1533091298.221 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2018-08-01T02:41:38.222Z,1533091298.222 [RDI_Pathfinder](ERROR): Failed to parse:
:HM7,.021, 0.028, 65.535
2018-08-01T02:42:49.212Z,1533091369.212 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-01T02:37:48.4Z
2018-08-01T02:42:49.212Z,1533091369.212 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T02:42:49.212Z,1533091369.212 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T02:42:54.217Z,1533091374.217 [DataOverHttps](INFO): Sending 69 bytes from file Logs/20180801T002359/Courier0046.lzma
2018-08-01T02:42:54.994Z,1533091374.994 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0046.lzma.bak
2018-08-01T02:42:54.994Z,1533091374.994 [DataOverHttps](INFO): SBD MOMSN=8389851
2018-08-01T02:43:04.263Z,1533091384.263 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20180801T002359/Express0047.lzma
2018-08-01T02:43:05.044Z,1533091385.044 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0047.lzma.bak
2018-08-01T02:43:05.044Z,1533091385.044 [DataOverHttps](INFO): SBD MOMSN=8389854
2018-08-01T02:43:05.578Z,1533091385.578 [RDI_Pathfinder](ERROR): Failed to parse:
:BD,        +0.00,        +0.00,        +0.00,   0.00,8318.21
2018-08-01T02:43:05.614Z,1533091385.614 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T02:43:05.614Z,1533091385.614 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T02:43:05.614Z,1533091385.614 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T02:45:15.586Z,1533091515.586 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-01T02:45:45.990Z,1533091545.990 [NAL9602](INFO): Powering down
2018-08-01T02:48:06.262Z,1533091686.262 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T02:48:06.263Z,1533091686.263 [Default:CheckIn:C.Wait] Stopped
2018-08-01T02:48:06.263Z,1533091686.263 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T02:48:06.263Z,1533091686.263 [Default:CheckIn:D] Running Loop=1
2018-08-01T02:48:06.652Z,1533091686.652 [Default:CheckIn:D] Stopped
2018-08-01T02:48:06.652Z,1533091686.652 [Default:CheckIn:E] Running Loop=1
2018-08-01T02:48:07.061Z,1533091687.061 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 140.601774 min 
2018-08-01T02:48:07.062Z,1533091687.062 [Default:CheckIn:E] Stopped
2018-08-01T02:48:07.062Z,1533091687.062 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T02:48:07.062Z,1533091687.062 [Default:CheckIn] Stopped
2018-08-01T02:48:07.062Z,1533091687.062 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T02:48:07.062Z,1533091687.062 [Default:CheckIn](INFO): Running loop #16
2018-08-01T02:48:07.062Z,1533091687.062 [Default:CheckIn] Running Loop=16
2018-08-01T02:48:07.063Z,1533091687.063 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T02:48:07.063Z,1533091687.063 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T02:48:10.352Z,1533091690.352 [NAL9602](INFO): Powering up
2018-08-01T02:48:21.516Z,1533091701.516 [NAL9602](INFO): NAL9602 initialized
2018-08-01T02:48:53.498Z,1533091733.498 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2018-08-01T02:48:53.581Z,1533091733.581 [NAL9602](FAULT): received: 
+CSQ:0

OK3, 0, 0, 0, 0

OK
2018-08-01T02:48:53.581Z,1533091733.581 [NAL9602] Data Fault, FailCount= 1
2018-08-01T02:48:53.581Z,1533091733.581 [NAL9602](ERROR): Data Fault
2018-08-01T02:48:53.665Z,1533091733.665 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T02:48:53.894Z,1533091733.894 [NAL9602](INFO): Powering down
2018-08-01T02:48:54.770Z,1533091734.770 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T02:48:54.770Z,1533091734.770 [NAL9602] No Fault, FailCount= 1
2018-08-01T02:49:23.974Z,1533091763.974 [NAL9602](INFO): Powering up NAL9602
2018-08-01T02:49:35.179Z,1533091775.179 [NAL9602](INFO): NAL9602 initialized
2018-08-01T02:52:28.572Z,1533091948.572 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2018-08-01T02:52:28.573Z,1533091948.573 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,18080102533647,35.0, -0.1,  8.9,  0
2018-08-01T02:53:07.376Z,1533091987.376 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-01T02:48:07.1Z
2018-08-01T02:53:07.376Z,1533091987.376 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T02:53:07.376Z,1533091987.376 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T02:53:11.074Z,1533091991.074 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180801T002359/Courier0049.lzma
2018-08-01T02:53:11.848Z,1533091991.848 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0049.lzma.bak
2018-08-01T02:53:11.848Z,1533091991.848 [DataOverHttps](INFO): SBD MOMSN=8389863
2018-08-01T02:53:21.115Z,1533092001.115 [DataOverHttps](INFO): Sending 233 bytes from file Logs/20180801T002359/Express0050.lzma
2018-08-01T02:53:21.892Z,1533092001.892 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0050.lzma.bak
2018-08-01T02:53:21.892Z,1533092001.892 [DataOverHttps](INFO): SBD MOMSN=8389865
2018-08-01T02:53:22.425Z,1533092002.425 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T02:53:22.425Z,1533092002.425 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T02:53:22.425Z,1533092002.425 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T02:53:25.861Z,1533092005.861 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-01T02:53:56.394Z,1533092036.394 [NAL9602](INFO): Powering down
2018-08-01T02:58:23.147Z,1533092303.147 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T02:58:23.148Z,1533092303.148 [Default:CheckIn:C.Wait] Stopped
2018-08-01T02:58:23.148Z,1533092303.148 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T02:58:23.148Z,1533092303.148 [Default:CheckIn:D] Running Loop=1
2018-08-01T02:58:23.542Z,1533092303.542 [Default:CheckIn:D] Stopped
2018-08-01T02:58:23.542Z,1533092303.542 [Default:CheckIn:E] Running Loop=1
2018-08-01T02:58:23.945Z,1533092303.945 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 150.883268 min 
2018-08-01T02:58:23.946Z,1533092303.946 [Default:CheckIn:E] Stopped
2018-08-01T02:58:23.946Z,1533092303.946 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T02:58:23.946Z,1533092303.946 [Default:CheckIn] Stopped
2018-08-01T02:58:23.946Z,1533092303.946 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T02:58:23.946Z,1533092303.946 [Default:CheckIn](INFO): Running loop #17
2018-08-01T02:58:23.947Z,1533092303.947 [Default:CheckIn] Running Loop=17
2018-08-01T02:58:23.947Z,1533092303.947 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T02:58:23.947Z,1533092303.947 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T02:58:27.273Z,1533092307.273 [NAL9602](INFO): Powering up
2018-08-01T02:58:38.448Z,1533092318.448 [NAL9602](INFO): NAL9602 initialized
2018-08-01T02:58:39.246Z,1533092319.246 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-08-01T02:58:39.247Z,1533092319.247 [NAL9602] Data Fault, FailCount= 2
2018-08-01T02:58:39.247Z,1533092319.247 [NAL9602](ERROR): Data Fault
2018-08-01T02:58:39.349Z,1533092319.349 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T02:58:39.648Z,1533092319.648 [NAL9602](INFO): Powering down
2018-08-01T02:58:40.563Z,1533092320.563 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T02:58:40.563Z,1533092320.563 [NAL9602] No Fault, FailCount= 2
2018-08-01T02:59:09.654Z,1533092349.654 [NAL9602](INFO): Powering up NAL9602
2018-08-01T02:59:20.840Z,1533092360.840 [NAL9602](INFO): NAL9602 initialized
2018-08-01T03:03:24.002Z,1533092604.002 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-01T02:58:23.9Z
2018-08-01T03:03:24.002Z,1533092604.002 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T03:03:24.002Z,1533092604.002 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T03:03:28.096Z,1533092608.096 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180801T002359/Courier0052.lzma
2018-08-01T03:03:28.872Z,1533092608.872 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0052.lzma.bak
2018-08-01T03:03:28.872Z,1533092608.872 [DataOverHttps](INFO): SBD MOMSN=8389874
2018-08-01T03:03:38.051Z,1533092618.051 [DataOverHttps](INFO): Sending 217 bytes from file Logs/20180801T002359/Express0053.lzma
2018-08-01T03:03:38.835Z,1533092618.835 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0053.lzma.bak
2018-08-01T03:03:38.836Z,1533092618.836 [DataOverHttps](INFO): SBD MOMSN=8389876
2018-08-01T03:03:39.415Z,1533092619.415 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T03:03:39.415Z,1533092619.415 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T03:03:39.416Z,1533092619.416 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T03:04:24.171Z,1533092664.171 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-01T03:04:54.654Z,1533092694.654 [NAL9602](INFO): Powering down
2018-08-01T03:08:40.089Z,1533092920.089 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T03:08:40.090Z,1533092920.090 [Default:CheckIn:C.Wait] Stopped
2018-08-01T03:08:40.090Z,1533092920.090 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T03:08:40.090Z,1533092920.090 [Default:CheckIn:D] Running Loop=1
2018-08-01T03:08:40.499Z,1533092920.499 [Default:CheckIn:D] Stopped
2018-08-01T03:08:40.499Z,1533092920.499 [Default:CheckIn:E] Running Loop=1
2018-08-01T03:08:43.791Z,1533092923.791 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 161.165885 min 
2018-08-01T03:08:43.791Z,1533092923.791 [Default:CheckIn:E] Stopped
2018-08-01T03:08:43.791Z,1533092923.791 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T03:08:43.791Z,1533092923.791 [Default:CheckIn] Stopped
2018-08-01T03:08:43.792Z,1533092923.792 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T03:08:43.792Z,1533092923.792 [Default:CheckIn](INFO): Running loop #18
2018-08-01T03:08:43.792Z,1533092923.792 [Default:CheckIn] Running Loop=18
2018-08-01T03:08:43.792Z,1533092923.792 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T03:08:43.792Z,1533092923.792 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T03:08:44.237Z,1533092924.237 [NAL9602](INFO): Powering up
2018-08-01T03:08:55.426Z,1533092935.426 [NAL9602](INFO): NAL9602 initialized
2018-08-01T03:09:27.427Z,1533092967.427 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2018-08-01T03:09:27.509Z,1533092967.509 [NAL9602](FAULT): received: 
+CSQ:0

OK3, 0, 0, 0, 0

OK
2018-08-01T03:09:27.509Z,1533092967.509 [NAL9602] Data Fault, FailCount= 3
2018-08-01T03:09:27.509Z,1533092967.509 [NAL9602](ERROR): Data Fault
2018-08-01T03:09:27.595Z,1533092967.595 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T03:09:27.826Z,1533092967.826 [NAL9602](INFO): Powering down
2018-08-01T03:09:28.715Z,1533092968.715 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T03:09:28.715Z,1533092968.715 [NAL9602] No Fault, FailCount= 3
2018-08-01T03:09:58.086Z,1533092998.086 [NAL9602](INFO): Powering up NAL9602
2018-08-01T03:10:08.887Z,1533093008.887 [NAL9602](INFO): NAL9602 initialized
2018-08-01T03:10:09.691Z,1533093009.691 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-08-01T03:10:09.691Z,1533093009.691 [NAL9602] Data Fault, FailCount= 4
2018-08-01T03:10:09.691Z,1533093009.691 [NAL9602](ERROR): Data Fault
2018-08-01T03:10:09.781Z,1533093009.781 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T03:10:10.095Z,1533093010.095 [NAL9602](INFO): Powering down
2018-08-01T03:10:10.967Z,1533093010.967 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T03:10:10.967Z,1533093010.967 [NAL9602] No Fault, FailCount= 4
2018-08-01T03:10:40.489Z,1533093040.489 [NAL9602](INFO): Powering up NAL9602
2018-08-01T03:10:45.444Z,1533093045.444 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-32768,-32768,-32768,-32768,V
2018-08-01T03:10:51.426Z,1533093051.426 [NAL9602](INFO): NAL9602 initialized
2018-08-01T03:13:44.776Z,1533093224.776 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-01T03:08:43.8Z
2018-08-01T03:13:44.776Z,1533093224.776 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T03:13:44.776Z,1533093224.776 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T03:13:49.858Z,1533093229.858 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180801T002359/Courier0055.lzma
2018-08-01T03:13:50.650Z,1533093230.650 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0055.lzma.bak
2018-08-01T03:13:50.651Z,1533093230.651 [DataOverHttps](INFO): SBD MOMSN=8389885
2018-08-01T03:13:59.527Z,1533093239.527 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-01T03:13:59.710Z,1533093239.710 [DataOverHttps](INFO): Sending 250 bytes from file Logs/20180801T002359/Express0056.lzma
2018-08-01T03:14:00.436Z,1533093240.436 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0056.lzma.bak
2018-08-01T03:14:00.436Z,1533093240.436 [DataOverHttps](INFO): SBD MOMSN=8389887
2018-08-01T03:14:00.982Z,1533093240.982 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T03:14:00.982Z,1533093240.982 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T03:14:00.983Z,1533093240.983 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T03:14:29.777Z,1533093269.777 [NAL9602](INFO): Powering down
2018-08-01T03:19:01.477Z,1533093541.477 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T03:19:01.478Z,1533093541.478 [Default:CheckIn:C.Wait] Stopped
2018-08-01T03:19:01.478Z,1533093541.478 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T03:19:01.478Z,1533093541.478 [Default:CheckIn:D] Running Loop=1
2018-08-01T03:19:01.892Z,1533093541.892 [Default:CheckIn:D] Stopped
2018-08-01T03:19:01.892Z,1533093541.892 [Default:CheckIn:E] Running Loop=1
2018-08-01T03:19:02.272Z,1533093542.272 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 171.522428 min 
2018-08-01T03:19:02.272Z,1533093542.272 [Default:CheckIn:E] Stopped
2018-08-01T03:19:02.272Z,1533093542.272 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T03:19:02.273Z,1533093542.273 [Default:CheckIn] Stopped
2018-08-01T03:19:02.273Z,1533093542.273 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T03:19:02.273Z,1533093542.273 [Default:CheckIn](INFO): Running loop #19
2018-08-01T03:19:02.273Z,1533093542.273 [Default:CheckIn] Running Loop=19
2018-08-01T03:19:02.273Z,1533093542.273 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T03:19:02.273Z,1533093542.273 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T03:19:05.544Z,1533093545.544 [NAL9602](INFO): Powering up
2018-08-01T03:19:16.730Z,1533093556.730 [NAL9602](INFO): NAL9602 initialized
2018-08-01T03:19:48.729Z,1533093588.729 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2018-08-01T03:19:48.813Z,1533093588.813 [NAL9602](FAULT): received: 
+CSQ:0

OK3, 0, 0, 0, 0

OK
2018-08-01T03:19:48.813Z,1533093588.813 [NAL9602] Data Fault, FailCount= 5
2018-08-01T03:19:48.813Z,1533093588.813 [NAL9602](ERROR): Data Fault
2018-08-01T03:19:48.889Z,1533093588.889 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T03:19:48.889Z,1533093588.889 [CBIT](CRITICAL): Data Fault in component: NAL9602
2018-08-01T03:19:49.130Z,1533093589.130 [NAL9602](INFO): Powering down
2018-08-01T03:19:49.226Z,1533093589.226 [CBIT](INFO): Critical error at 20180801T031948
2018-08-01T03:21:49.073Z,1533093709.073 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T03:21:49.074Z,1533093709.074 [NAL9602] No Fault, FailCount= 5
2018-08-01T03:21:49.402Z,1533093709.402 [NAL9602](INFO): Powering up NAL9602
2018-08-01T03:22:00.598Z,1533093720.598 [NAL9602](INFO): NAL9602 initialized
2018-08-01T03:22:01.406Z,1533093721.406 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-08-01T03:22:01.406Z,1533093721.406 [NAL9602] Data Fault, FailCount= 1
2018-08-01T03:22:01.406Z,1533093721.406 [NAL9602](ERROR): Data Fault
2018-08-01T03:22:01.520Z,1533093721.520 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T03:22:01.807Z,1533093721.807 [NAL9602](INFO): Powering down
2018-08-01T03:22:02.701Z,1533093722.701 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T03:22:02.701Z,1533093722.701 [NAL9602] No Fault, FailCount= 1
2018-08-01T03:22:31.870Z,1533093751.870 [NAL9602](INFO): Powering up NAL9602
2018-08-01T03:22:42.670Z,1533093762.670 [NAL9602](INFO): NAL9602 initialized
2018-08-01T03:24:02.419Z,1533093842.419 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-01T03:19:02.3Z
2018-08-01T03:24:02.419Z,1533093842.419 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T03:24:02.419Z,1533093842.419 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T03:24:06.251Z,1533093846.251 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20180801T002359/Courier0058.lzma
2018-08-01T03:24:07.017Z,1533093847.017 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0058.lzma.bak
2018-08-01T03:24:07.017Z,1533093847.017 [DataOverHttps](INFO): SBD MOMSN=8389897
2018-08-01T03:24:16.004Z,1533093856.004 [DataOverHttps](INFO): Sending 252 bytes from file Logs/20180801T002359/Express0059.lzma
2018-08-01T03:24:16.780Z,1533093856.780 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0059.lzma.bak
2018-08-01T03:24:16.780Z,1533093856.780 [DataOverHttps](INFO): SBD MOMSN=8389900
2018-08-01T03:24:17.360Z,1533093857.360 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T03:24:17.360Z,1533093857.360 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T03:24:17.360Z,1533093857.360 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T03:24:20.813Z,1533093860.813 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-01T03:24:51.350Z,1533093891.350 [NAL9602](INFO): Powering down
2018-08-01T03:27:05.523Z,1533094025.523 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2018-08-01T03:27:05.523Z,1533094025.523 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,180801032813470.1,   0.0,1448.9,  0
2018-08-01T03:29:17.677Z,1533094157.677 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T03:29:17.678Z,1533094157.678 [Default:CheckIn:C.Wait] Stopped
2018-08-01T03:29:17.678Z,1533094157.678 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T03:29:17.678Z,1533094157.678 [Default:CheckIn:D] Running Loop=1
2018-08-01T03:29:18.081Z,1533094158.081 [Default:CheckIn:D] Stopped
2018-08-01T03:29:18.082Z,1533094158.082 [Default:CheckIn:E] Running Loop=1
2018-08-01T03:29:21.234Z,1533094161.234 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 181.792253 min 
2018-08-01T03:29:21.234Z,1533094161.234 [Default:CheckIn:E] Stopped
2018-08-01T03:29:21.234Z,1533094161.234 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T03:29:21.234Z,1533094161.234 [Default:CheckIn] Stopped
2018-08-01T03:29:21.235Z,1533094161.235 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T03:29:21.235Z,1533094161.235 [Default:CheckIn](INFO): Running loop #20
2018-08-01T03:29:21.235Z,1533094161.235 [Default:CheckIn] Running Loop=20
2018-08-01T03:29:21.235Z,1533094161.235 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T03:29:21.235Z,1533094161.235 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T03:29:21.686Z,1533094161.686 [NAL9602](INFO): Powering up
2018-08-01T03:29:32.502Z,1533094172.502 [NAL9602](INFO): NAL9602 initialized
2018-08-01T03:29:36.515Z,1533094176.515 [RDI_Pathfinder](ERROR): Failed to parse:
:HM,G,G,0e87,0e88, 16.061, 0.031, 65.535
2018-08-01T03:30:04.094Z,1533094204.094 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2018-08-01T03:30:04.177Z,1533094204.177 [NAL9602](FAULT): received: 
+CSQ:0

OK3, 0, 0, 0, 0

OK
2018-08-01T03:30:04.177Z,1533094204.177 [NAL9602] Data Fault, FailCount= 2
2018-08-01T03:30:04.177Z,1533094204.177 [NAL9602](ERROR): Data Fault
2018-08-01T03:30:04.268Z,1533094204.268 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T03:30:04.482Z,1533094204.482 [NAL9602](INFO): Powering down
2018-08-01T03:30:05.373Z,1533094205.373 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T03:30:05.373Z,1533094205.373 [NAL9602] No Fault, FailCount= 2
2018-08-01T03:30:34.590Z,1533094234.590 [NAL9602](INFO): Powering up NAL9602
2018-08-01T03:30:45.391Z,1533094245.391 [NAL9602](INFO): NAL9602 initialized
2018-08-01T03:34:22.103Z,1533094462.103 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-01T03:29:21.2Z
2018-08-01T03:34:22.103Z,1533094462.103 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T03:34:22.103Z,1533094462.103 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T03:34:27.210Z,1533094467.210 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180801T002359/Courier0061.lzma
2018-08-01T03:34:27.993Z,1533094467.993 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0061.lzma.bak
2018-08-01T03:34:27.993Z,1533094467.993 [DataOverHttps](INFO): SBD MOMSN=8389910
2018-08-01T03:34:28.518Z,1533094468.518 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-32768,-32768,-32768,-32768,V
2018-08-01T03:34:37.066Z,1533094477.066 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-01T03:34:37.237Z,1533094477.237 [DataOverHttps](INFO): Sending 234 bytes from file Logs/20180801T002359/Express0062.lzma
2018-08-01T03:34:38.012Z,1533094478.012 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0062.lzma.bak
2018-08-01T03:34:38.012Z,1533094478.012 [DataOverHttps](INFO): SBD MOMSN=8389912
2018-08-01T03:34:38.577Z,1533094478.577 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T03:34:38.577Z,1533094478.577 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T03:34:38.577Z,1533094478.577 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T03:35:07.468Z,1533094507.468 [NAL9602](INFO): Powering down
2018-08-01T03:39:39.012Z,1533094779.012 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T03:39:39.012Z,1533094779.012 [Default:CheckIn:C.Wait] Stopped
2018-08-01T03:39:39.012Z,1533094779.012 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T03:39:39.013Z,1533094779.013 [Default:CheckIn:D] Running Loop=1
2018-08-01T03:39:39.429Z,1533094779.429 [Default:CheckIn:D] Stopped
2018-08-01T03:39:39.430Z,1533094779.430 [Default:CheckIn:E] Running Loop=1
2018-08-01T03:39:39.818Z,1533094779.818 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 192.148047 min 
2018-08-01T03:39:39.818Z,1533094779.818 [Default:CheckIn:E] Stopped
2018-08-01T03:39:39.818Z,1533094779.818 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T03:39:39.818Z,1533094779.818 [Default:CheckIn] Stopped
2018-08-01T03:39:39.818Z,1533094779.818 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T03:39:39.818Z,1533094779.818 [Default:CheckIn](INFO): Running loop #21
2018-08-01T03:39:39.819Z,1533094779.819 [Default:CheckIn] Running Loop=21
2018-08-01T03:39:39.819Z,1533094779.819 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T03:39:39.819Z,1533094779.819 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T03:39:43.092Z,1533094783.092 [NAL9602](INFO): Powering up
2018-08-01T03:39:54.258Z,1533094794.258 [NAL9602](INFO): NAL9602 initialized
2018-08-01T03:39:55.048Z,1533094795.048 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-08-01T03:39:55.048Z,1533094795.048 [NAL9602] Data Fault, FailCount= 3
2018-08-01T03:39:55.048Z,1533094795.048 [NAL9602](ERROR): Data Fault
2018-08-01T03:39:55.151Z,1533094795.151 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T03:39:55.459Z,1533094795.459 [NAL9602](INFO): Powering down
2018-08-01T03:39:56.332Z,1533094796.332 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T03:39:56.337Z,1533094796.337 [NAL9602] No Fault, FailCount= 3
2018-08-01T03:40:25.854Z,1533094825.854 [NAL9602](INFO): Powering up NAL9602
2018-08-01T03:40:37.054Z,1533094837.054 [NAL9602](INFO): NAL9602 initialized
2018-08-01T03:44:40.172Z,1533095080.172 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-01T03:39:39.8Z
2018-08-01T03:44:40.172Z,1533095080.172 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T03:44:40.172Z,1533095080.172 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T03:44:44.014Z,1533095084.014 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20180801T002359/Courier0064.lzma
2018-08-01T03:44:44.796Z,1533095084.796 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0064.lzma.bak
2018-08-01T03:44:44.796Z,1533095084.796 [DataOverHttps](INFO): SBD MOMSN=8389921
2018-08-01T03:44:53.802Z,1533095093.802 [DataOverHttps](INFO): Sending 217 bytes from file Logs/20180801T002359/Express0065.lzma
2018-08-01T03:44:54.565Z,1533095094.565 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0065.lzma.bak
2018-08-01T03:44:54.565Z,1533095094.565 [DataOverHttps](INFO): SBD MOMSN=8389923
2018-08-01T03:44:55.150Z,1533095095.150 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T03:44:55.150Z,1533095095.150 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T03:44:55.150Z,1533095095.150 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T03:45:43.158Z,1533095143.158 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-01T03:46:13.630Z,1533095173.630 [NAL9602](INFO): Powering down
2018-08-01T03:49:55.741Z,1533095395.741 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T03:49:55.741Z,1533095395.741 [Default:CheckIn:C.Wait] Stopped
2018-08-01T03:49:55.741Z,1533095395.741 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T03:49:55.741Z,1533095395.741 [Default:CheckIn:D] Running Loop=1
2018-08-01T03:49:56.165Z,1533095396.165 [Default:CheckIn:D] Stopped
2018-08-01T03:49:56.165Z,1533095396.165 [Default:CheckIn:E] Running Loop=1
2018-08-01T03:49:59.330Z,1533095399.330 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 202.426986 min 
2018-08-01T03:49:59.330Z,1533095399.330 [Default:CheckIn:E] Stopped
2018-08-01T03:49:59.331Z,1533095399.331 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T03:49:59.331Z,1533095399.331 [Default:CheckIn] Stopped
2018-08-01T03:49:59.331Z,1533095399.331 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T03:49:59.331Z,1533095399.331 [Default:CheckIn](INFO): Running loop #22
2018-08-01T03:49:59.331Z,1533095399.331 [Default:CheckIn] Running Loop=22
2018-08-01T03:49:59.331Z,1533095399.331 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T03:49:59.331Z,1533095399.331 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T03:49:59.774Z,1533095399.774 [NAL9602](INFO): Powering up
2018-08-01T03:50:10.570Z,1533095410.570 [NAL9602](INFO): NAL9602 initialized
2018-08-01T03:50:42.567Z,1533095442.567 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2018-08-01T03:50:42.645Z,1533095442.645 [NAL9602](FAULT): received: 
+CSQ:0

OK3, 0, 0, 0, 0

OK
2018-08-01T03:50:42.645Z,1533095442.645 [NAL9602] Data Fault, FailCount= 4
2018-08-01T03:50:42.645Z,1533095442.645 [NAL9602](ERROR): Data Fault
2018-08-01T03:50:42.731Z,1533095442.731 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T03:50:42.966Z,1533095442.966 [NAL9602](INFO): Powering down
2018-08-01T03:50:43.836Z,1533095443.836 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T03:50:43.836Z,1533095443.836 [NAL9602] No Fault, FailCount= 4
2018-08-01T03:51:13.030Z,1533095473.030 [NAL9602](INFO): Powering up NAL9602
2018-08-01T03:51:23.828Z,1533095483.828 [NAL9602](INFO): NAL9602 initialized
2018-08-01T03:51:24.634Z,1533095484.634 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-08-01T03:51:24.634Z,1533095484.634 [NAL9602] Data Fault, FailCount= 5
2018-08-01T03:51:24.635Z,1533095484.635 [NAL9602](ERROR): Data Fault
2018-08-01T03:51:24.729Z,1533095484.729 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T03:51:24.730Z,1533095484.730 [CBIT](CRITICAL): Data Fault in component: NAL9602
2018-08-01T03:51:25.038Z,1533095485.038 [NAL9602](INFO): Powering down
2018-08-01T03:51:25.138Z,1533095485.138 [CBIT](INFO): Critical error at 20180801T035124
2018-08-01T03:53:24.695Z,1533095604.695 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T03:53:24.695Z,1533095604.695 [NAL9602] No Fault, FailCount= 5
2018-08-01T03:53:25.016Z,1533095605.016 [NAL9602](INFO): Powering up NAL9602
2018-08-01T03:53:36.215Z,1533095616.215 [NAL9602](INFO): NAL9602 initialized
2018-08-01T03:55:00.040Z,1533095700.040 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-01T03:49:59.3Z
2018-08-01T03:55:00.040Z,1533095700.040 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T03:55:00.040Z,1533095700.040 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T03:55:05.007Z,1533095705.007 [DataOverHttps](INFO): Sending 69 bytes from file Logs/20180801T002359/Courier0067.lzma
2018-08-01T03:55:05.794Z,1533095705.794 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0067.lzma.bak
2018-08-01T03:55:05.794Z,1533095705.794 [DataOverHttps](INFO): SBD MOMSN=8389932
2018-08-01T03:55:14.670Z,1533095714.670 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-01T03:55:14.831Z,1533095714.831 [DataOverHttps](INFO): Sending 253 bytes from file Logs/20180801T002359/Express0068.lzma
2018-08-01T03:55:15.608Z,1533095715.608 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0068.lzma.bak
2018-08-01T03:55:15.608Z,1533095715.608 [DataOverHttps](INFO): SBD MOMSN=8389935
2018-08-01T03:55:16.203Z,1533095716.203 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T03:55:16.203Z,1533095716.203 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T03:55:16.203Z,1533095716.203 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T03:55:44.889Z,1533095744.889 [NAL9602](INFO): Powering down
2018-08-01T04:00:16.632Z,1533096016.632 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T04:00:16.632Z,1533096016.632 [Default:CheckIn:C.Wait] Stopped
2018-08-01T04:00:16.632Z,1533096016.632 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T04:00:16.633Z,1533096016.633 [Default:CheckIn:D] Running Loop=1
2018-08-01T04:00:17.032Z,1533096017.032 [Default:CheckIn:D] Stopped
2018-08-01T04:00:17.033Z,1533096017.033 [Default:CheckIn:E] Running Loop=1
2018-08-01T04:00:17.446Z,1533096017.446 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 212.774772 min 
2018-08-01T04:00:17.446Z,1533096017.446 [Default:CheckIn:E] Stopped
2018-08-01T04:00:17.446Z,1533096017.446 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T04:00:17.446Z,1533096017.446 [Default:CheckIn] Stopped
2018-08-01T04:00:17.446Z,1533096017.446 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T04:00:17.446Z,1533096017.446 [Default:CheckIn](INFO): Running loop #23
2018-08-01T04:00:17.447Z,1533096017.447 [Default:CheckIn] Running Loop=23
2018-08-01T04:00:17.447Z,1533096017.447 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T04:00:17.447Z,1533096017.447 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T04:00:20.856Z,1533096020.856 [NAL9602](INFO): Powering up
2018-08-01T04:00:32.023Z,1533096032.023 [NAL9602](INFO): NAL9602 initialized
2018-08-01T04:01:04.027Z,1533096064.027 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2018-08-01T04:01:04.103Z,1533096064.103 [NAL9602](FAULT): received: 
+CSQ:0

OK3, 0, 0, 0, 0

OK
2018-08-01T04:01:04.103Z,1533096064.103 [NAL9602] Data Fault, FailCount= 1
2018-08-01T04:01:04.104Z,1533096064.104 [NAL9602](ERROR): Data Fault
2018-08-01T04:01:04.209Z,1533096064.209 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T04:01:04.426Z,1533096064.426 [NAL9602](INFO): Powering down
2018-08-01T04:01:05.310Z,1533096065.310 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T04:01:05.310Z,1533096065.310 [NAL9602] No Fault, FailCount= 1
2018-08-01T04:01:34.506Z,1533096094.506 [NAL9602](INFO): Powering up NAL9602
2018-08-01T04:01:45.706Z,1533096105.706 [NAL9602](INFO): NAL9602 initialized
2018-08-01T04:05:17.706Z,1533096317.706 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-01T04:00:17.4Z
2018-08-01T04:05:17.706Z,1533096317.706 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T04:05:17.706Z,1533096317.706 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T04:05:21.502Z,1533096321.502 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180801T002359/Courier0070.lzma
2018-08-01T04:05:22.272Z,1533096322.272 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0070.lzma.bak
2018-08-01T04:05:22.272Z,1533096322.272 [DataOverHttps](INFO): SBD MOMSN=8389941
2018-08-01T04:05:31.335Z,1533096331.335 [DataOverHttps](INFO): Sending 234 bytes from file Logs/20180801T002359/Express0071.lzma
2018-08-01T04:05:32.113Z,1533096332.113 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0071.lzma.bak
2018-08-01T04:05:32.113Z,1533096332.113 [DataOverHttps](INFO): SBD MOMSN=8389943
2018-08-01T04:05:32.658Z,1533096332.658 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T04:05:32.658Z,1533096332.658 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T04:05:32.658Z,1533096332.658 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T04:05:36.555Z,1533096336.555 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-01T04:06:07.122Z,1533096367.122 [NAL9602](INFO): Powering down
2018-08-01T04:10:33.135Z,1533096633.135 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T04:10:33.136Z,1533096633.136 [Default:CheckIn:C.Wait] Stopped
2018-08-01T04:10:33.136Z,1533096633.136 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T04:10:33.136Z,1533096633.136 [Default:CheckIn:D] Running Loop=1
2018-08-01T04:10:33.573Z,1533096633.573 [Default:CheckIn:D] Stopped
2018-08-01T04:10:33.573Z,1533096633.573 [Default:CheckIn:E] Running Loop=1
2018-08-01T04:10:33.946Z,1533096633.946 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 223.050456 min 
2018-08-01T04:10:33.946Z,1533096633.946 [Default:CheckIn:E] Stopped
2018-08-01T04:10:33.946Z,1533096633.946 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T04:10:33.947Z,1533096633.947 [Default:CheckIn] Stopped
2018-08-01T04:10:33.947Z,1533096633.947 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T04:10:33.947Z,1533096633.947 [Default:CheckIn](INFO): Running loop #24
2018-08-01T04:10:33.947Z,1533096633.947 [Default:CheckIn] Running Loop=24
2018-08-01T04:10:33.947Z,1533096633.947 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T04:10:33.947Z,1533096633.947 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T04:10:39.438Z,1533096639.438 [NAL9602](INFO): Powering up
2018-08-01T04:10:50.614Z,1533096650.614 [NAL9602](INFO): NAL9602 initialized
2018-08-01T04:10:51.418Z,1533096651.418 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-08-01T04:10:51.419Z,1533096651.419 [NAL9602] Data Fault, FailCount= 2
2018-08-01T04:10:51.419Z,1533096651.419 [NAL9602](ERROR): Data Fault
2018-08-01T04:10:51.539Z,1533096651.539 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T04:10:51.814Z,1533096651.814 [NAL9602](INFO): Powering down
2018-08-01T04:10:52.761Z,1533096652.761 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T04:10:52.761Z,1533096652.761 [NAL9602] No Fault, FailCount= 2
2018-08-01T04:11:21.823Z,1533096681.823 [NAL9602](INFO): Powering up NAL9602
2018-08-01T04:11:33.018Z,1533096693.018 [NAL9602](INFO): NAL9602 initialized
2018-08-01T04:15:34.169Z,1533096934.169 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-01T04:10:33.9Z
2018-08-01T04:15:34.169Z,1533096934.169 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T04:15:34.169Z,1533096934.169 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T04:15:39.064Z,1533096939.064 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180801T002359/Courier0073.lzma
2018-08-01T04:15:39.826Z,1533096939.826 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0073.lzma.bak
2018-08-01T04:15:39.826Z,1533096939.826 [DataOverHttps](INFO): SBD MOMSN=8389962
2018-08-01T04:15:52.792Z,1533096952.792 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20180801T002359/Express0074.lzma
2018-08-01T04:15:53.568Z,1533096953.568 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0074.lzma.bak
2018-08-01T04:15:53.568Z,1533096953.568 [DataOverHttps](INFO): SBD MOMSN=8389965
2018-08-01T04:15:54.159Z,1533096954.159 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T04:15:54.159Z,1533096954.159 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T04:15:54.159Z,1533096954.159 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T04:16:39.247Z,1533096999.247 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-01T04:17:09.771Z,1533097029.771 [NAL9602](INFO): Powering down
2018-08-01T04:20:54.548Z,1533097254.548 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T04:20:54.548Z,1533097254.548 [Default:CheckIn:C.Wait] Stopped
2018-08-01T04:20:54.548Z,1533097254.548 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T04:20:54.548Z,1533097254.548 [Default:CheckIn:D] Running Loop=1
2018-08-01T04:20:54.949Z,1533097254.949 [Default:CheckIn:D] Stopped
2018-08-01T04:20:54.949Z,1533097254.949 [Default:CheckIn:E] Running Loop=1
2018-08-01T04:20:55.354Z,1533097255.354 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 233.406722 min 
2018-08-01T04:20:55.354Z,1533097255.354 [Default:CheckIn:E] Stopped
2018-08-01T04:20:55.354Z,1533097255.354 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T04:20:55.354Z,1533097255.354 [Default:CheckIn] Stopped
2018-08-01T04:20:55.355Z,1533097255.355 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T04:20:55.355Z,1533097255.355 [Default:CheckIn](INFO): Running loop #25
2018-08-01T04:20:55.355Z,1533097255.355 [Default:CheckIn] Running Loop=25
2018-08-01T04:20:55.355Z,1533097255.355 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T04:20:55.355Z,1533097255.355 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T04:20:58.716Z,1533097258.716 [NAL9602](INFO): Powering up
2018-08-01T04:21:09.899Z,1533097269.899 [NAL9602](INFO): NAL9602 initialized
2018-08-01T04:25:55.435Z,1533097555.435 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-01T04:20:55.4Z
2018-08-01T04:25:55.435Z,1533097555.435 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T04:25:55.435Z,1533097555.435 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T04:25:59.491Z,1533097559.491 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180801T002359/Courier0076.lzma
2018-08-01T04:26:00.285Z,1533097560.285 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0076.lzma.bak
2018-08-01T04:26:00.285Z,1533097560.285 [DataOverHttps](INFO): SBD MOMSN=8389971
2018-08-01T04:26:09.323Z,1533097569.323 [DataOverHttps](INFO): Sending 198 bytes from file Logs/20180801T002359/Express0077.lzma
2018-08-01T04:26:10.100Z,1533097570.100 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0077.lzma.bak
2018-08-01T04:26:10.100Z,1533097570.100 [DataOverHttps](INFO): SBD MOMSN=8389973
2018-08-01T04:26:10.649Z,1533097570.649 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T04:26:10.649Z,1533097570.649 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T04:26:10.649Z,1533097570.649 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T04:26:14.094Z,1533097574.094 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-01T04:26:44.639Z,1533097604.639 [NAL9602](INFO): Powering down
2018-08-01T04:31:10.977Z,1533097870.977 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T04:31:10.978Z,1533097870.978 [Default:CheckIn:C.Wait] Stopped
2018-08-01T04:31:10.978Z,1533097870.978 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T04:31:10.978Z,1533097870.978 [Default:CheckIn:D] Running Loop=1
2018-08-01T04:31:11.386Z,1533097871.386 [Default:CheckIn:D] Stopped
2018-08-01T04:31:11.386Z,1533097871.386 [Default:CheckIn:E] Running Loop=1
2018-08-01T04:31:11.798Z,1533097871.798 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 243.680648 min 
2018-08-01T04:31:11.799Z,1533097871.799 [Default:CheckIn:E] Stopped
2018-08-01T04:31:11.799Z,1533097871.799 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T04:31:11.799Z,1533097871.799 [Default:CheckIn] Stopped
2018-08-01T04:31:11.799Z,1533097871.799 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T04:31:11.799Z,1533097871.799 [Default:CheckIn](INFO): Running loop #26
2018-08-01T04:31:11.799Z,1533097871.799 [Default:CheckIn] Running Loop=26
2018-08-01T04:31:11.800Z,1533097871.800 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T04:31:11.800Z,1533097871.800 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T04:31:15.140Z,1533097875.140 [NAL9602](INFO): Powering up
2018-08-01T04:31:26.326Z,1533097886.326 [NAL9602](INFO): NAL9602 initialized
2018-08-01T04:31:27.131Z,1533097887.131 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-08-01T04:31:27.131Z,1533097887.131 [NAL9602] Data Fault, FailCount= 3
2018-08-01T04:31:27.132Z,1533097887.132 [NAL9602](ERROR): Data Fault
2018-08-01T04:31:27.219Z,1533097887.219 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T04:31:27.517Z,1533097887.517 [NAL9602](INFO): Powering down
2018-08-01T04:31:28.420Z,1533097888.420 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T04:31:28.420Z,1533097888.420 [NAL9602] No Fault, FailCount= 3
2018-08-01T04:31:57.518Z,1533097917.518 [NAL9602](INFO): Powering up NAL9602
2018-08-01T04:32:08.718Z,1533097928.718 [NAL9602](INFO): NAL9602 initialized
2018-08-01T04:36:11.859Z,1533098171.859 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-01T04:31:11.8Z
2018-08-01T04:36:11.859Z,1533098171.859 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T04:36:11.859Z,1533098171.859 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T04:36:16.137Z,1533098176.137 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180801T002359/Courier0079.lzma
2018-08-01T04:36:16.904Z,1533098176.904 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0079.lzma.bak
2018-08-01T04:36:16.904Z,1533098176.904 [DataOverHttps](INFO): SBD MOMSN=8389977
2018-08-01T04:36:26.011Z,1533098186.011 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20180801T002359/Express0080.lzma
2018-08-01T04:36:26.788Z,1533098186.788 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0080.lzma.bak
2018-08-01T04:36:26.788Z,1533098186.788 [DataOverHttps](INFO): SBD MOMSN=8389979
2018-08-01T04:36:27.358Z,1533098187.358 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T04:36:27.358Z,1533098187.358 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T04:36:27.358Z,1533098187.358 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T04:36:45.476Z,1533098205.476 [RDI_Pathfinder](ERROR): Failed to parse:
:HM,G,G,0e87,0e88, 16.021, 0.033, 65.535
2018-08-01T04:36:55.471Z,1533098215.471 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2018-08-01T04:36:55.472Z,1533098215.472 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,18080104380347,35.0, -0.1,   0.0,10
2018-08-01T04:37:05.476Z,1533098225.476 [RDI_Pathfinder](ERROR): Failed to parse:
:B  +0.00,        +0.00,        +0.00,   0.00,15152.53
2018-08-01T04:37:12.250Z,1533098232.250 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-01T04:37:42.714Z,1533098262.714 [NAL9602](INFO): Powering down
2018-08-01T04:41:27.796Z,1533098487.796 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T04:41:27.796Z,1533098487.796 [Default:CheckIn:C.Wait] Stopped
2018-08-01T04:41:27.796Z,1533098487.796 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T04:41:27.796Z,1533098487.796 [Default:CheckIn:D] Running Loop=1
2018-08-01T04:41:28.255Z,1533098488.255 [Default:CheckIn:D] Stopped
2018-08-01T04:41:28.255Z,1533098488.255 [Default:CheckIn:E] Running Loop=1
2018-08-01T04:41:31.360Z,1533098491.360 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 253.961816 min 
2018-08-01T04:41:31.361Z,1533098491.361 [Default:CheckIn:E] Stopped
2018-08-01T04:41:31.361Z,1533098491.361 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T04:41:31.361Z,1533098491.361 [Default:CheckIn] Stopped
2018-08-01T04:41:31.361Z,1533098491.361 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T04:41:31.361Z,1533098491.361 [Default:CheckIn](INFO): Running loop #27
2018-08-01T04:41:31.362Z,1533098491.362 [Default:CheckIn] Running Loop=27
2018-08-01T04:41:31.362Z,1533098491.362 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T04:41:31.362Z,1533098491.362 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T04:41:31.826Z,1533098491.826 [NAL9602](INFO): Powering up
2018-08-01T04:41:43.014Z,1533098503.014 [NAL9602](INFO): NAL9602 initialized
2018-08-01T04:42:15.019Z,1533098535.019 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2018-08-01T04:42:15.098Z,1533098535.098 [NAL9602](FAULT): received: 
+CSQ:0

OK3, 0, 0, 0, 0

OK
2018-08-01T04:42:15.098Z,1533098535.098 [NAL9602] Data Fault, FailCount= 4
2018-08-01T04:42:15.098Z,1533098535.098 [NAL9602](ERROR): Data Fault
2018-08-01T04:42:15.173Z,1533098535.173 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T04:42:15.418Z,1533098535.418 [NAL9602](INFO): Powering down
2018-08-01T04:42:16.296Z,1533098536.296 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T04:42:16.296Z,1533098536.296 [NAL9602] No Fault, FailCount= 4
2018-08-01T04:42:45.566Z,1533098565.566 [NAL9602](INFO): Powering up NAL9602
2018-08-01T04:42:56.362Z,1533098576.362 [NAL9602](INFO): NAL9602 initialized
2018-08-01T04:42:57.174Z,1533098577.174 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-08-01T04:42:57.174Z,1533098577.174 [NAL9602] Data Fault, FailCount= 5
2018-08-01T04:42:57.174Z,1533098577.174 [NAL9602](ERROR): Data Fault
2018-08-01T04:42:57.256Z,1533098577.256 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T04:42:57.261Z,1533098577.261 [CBIT](CRITICAL): Data Fault in component: NAL9602
2018-08-01T04:42:57.562Z,1533098577.562 [NAL9602](INFO): Powering down
2018-08-01T04:42:57.641Z,1533098577.641 [CBIT](INFO): Critical error at 20180801T044257
2018-08-01T04:44:57.401Z,1533098697.401 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T04:44:57.401Z,1533098697.401 [NAL9602] No Fault, FailCount= 5
2018-08-01T04:44:57.718Z,1533098697.718 [NAL9602](INFO): Powering up NAL9602
2018-08-01T04:45:08.519Z,1533098708.519 [NAL9602](INFO): NAL9602 initialized
2018-08-01T04:46:31.857Z,1533098791.857 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-01T04:41:31.4Z
2018-08-01T04:46:31.857Z,1533098791.857 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T04:46:31.857Z,1533098791.857 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T04:46:36.874Z,1533098796.874 [DataOverHttps](INFO): Sending 69 bytes from file Logs/20180801T002359/Courier0082.lzma
2018-08-01T04:46:37.656Z,1533098797.656 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0082.lzma.bak
2018-08-01T04:46:37.657Z,1533098797.657 [DataOverHttps](INFO): SBD MOMSN=8389984
2018-08-01T04:46:46.550Z,1533098806.550 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-01T04:46:46.702Z,1533098806.702 [DataOverHttps](INFO): Sending 251 bytes from file Logs/20180801T002359/Express0083.lzma
2018-08-01T04:46:47.444Z,1533098807.444 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0083.lzma.bak
2018-08-01T04:46:47.449Z,1533098807.449 [DataOverHttps](INFO): SBD MOMSN=8389987
2018-08-01T04:46:47.987Z,1533098807.987 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T04:46:47.987Z,1533098807.987 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T04:46:47.987Z,1533098807.987 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T04:47:16.882Z,1533098836.882 [NAL9602](INFO): Powering down
2018-08-01T04:50:16.091Z,1533099016.091 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2018-08-01T04:50:16.091Z,1533099016.091 [RDI_Pathfinder](ERROR): Failed to parse:
:BD,        +0.00,        +0.   +0.00,   0.00,15942.76
2018-08-01T04:50:44.476Z,1533099044.476 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2018-08-01T04:50:44.477Z,1533099044.477 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,18080104515247,35.0, -0.1,   0.0,10
2018-08-01T04:51:48.545Z,1533099108.545 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T04:51:48.545Z,1533099108.545 [Default:CheckIn:C.Wait] Stopped
2018-08-01T04:51:48.545Z,1533099108.545 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T04:51:48.546Z,1533099108.546 [Default:CheckIn:D] Running Loop=1
2018-08-01T04:51:48.963Z,1533099108.963 [Default:CheckIn:D] Stopped
2018-08-01T04:51:48.963Z,1533099108.963 [Default:CheckIn:E] Running Loop=1
2018-08-01T04:51:52.115Z,1533099112.115 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 264.306950 min 
2018-08-01T04:51:52.115Z,1533099112.115 [Default:CheckIn:E] Stopped
2018-08-01T04:51:52.115Z,1533099112.115 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T04:51:52.115Z,1533099112.115 [Default:CheckIn] Stopped
2018-08-01T04:51:52.116Z,1533099112.116 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T04:51:52.116Z,1533099112.116 [Default:CheckIn](INFO): Running loop #28
2018-08-01T04:51:52.116Z,1533099112.116 [Default:CheckIn] Running Loop=28
2018-08-01T04:51:52.116Z,1533099112.116 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T04:51:52.116Z,1533099112.116 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T04:51:52.561Z,1533099112.561 [NAL9602](INFO): Powering up
2018-08-01T04:52:03.755Z,1533099123.755 [NAL9602](INFO): NAL9602 initialized
2018-08-01T04:52:35.755Z,1533099155.755 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2018-08-01T04:52:35.833Z,1533099155.833 [NAL9602](FAULT): received: 
+CSQ:0

OK3, 0, 0, 0, 0

OK
2018-08-01T04:52:35.833Z,1533099155.833 [NAL9602] Data Fault, FailCount= 1
2018-08-01T04:52:35.833Z,1533099155.833 [NAL9602](ERROR): Data Fault
2018-08-01T04:52:35.880Z,1533099155.880 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T04:52:36.154Z,1533099156.154 [NAL9602](INFO): Powering down
2018-08-01T04:52:37.034Z,1533099157.034 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T04:52:37.034Z,1533099157.034 [NAL9602] No Fault, FailCount= 1
2018-08-01T04:53:06.315Z,1533099186.315 [NAL9602](INFO): Powering up NAL9602
2018-08-01T04:53:17.507Z,1533099197.507 [NAL9602](INFO): NAL9602 initialized
2018-08-01T04:56:52.954Z,1533099412.954 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-01T04:51:52.1Z
2018-08-01T04:56:52.954Z,1533099412.954 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T04:56:52.954Z,1533099412.954 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T04:56:57.921Z,1533099417.921 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180801T002359/Courier0085.lzma
2018-08-01T04:56:58.680Z,1533099418.680 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0085.lzma.bak
2018-08-01T04:56:58.681Z,1533099418.681 [DataOverHttps](INFO): SBD MOMSN=8390004
2018-08-01T04:57:08.064Z,1533099428.064 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-01T04:57:08.231Z,1533099428.231 [DataOverHttps](INFO): Sending 235 bytes from file Logs/20180801T002359/Express0086.lzma
2018-08-01T04:57:09.009Z,1533099429.009 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0086.lzma.bak
2018-08-01T04:57:09.009Z,1533099429.009 [DataOverHttps](INFO): SBD MOMSN=8390006
2018-08-01T04:57:09.563Z,1533099429.563 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T04:57:09.563Z,1533099429.563 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T04:57:09.563Z,1533099429.563 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T04:57:38.402Z,1533099458.402 [NAL9602](INFO): Powering down
2018-08-01T05:02:10.205Z,1533099730.205 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T05:02:10.206Z,1533099730.206 [Default:CheckIn:C.Wait] Stopped
2018-08-01T05:02:10.206Z,1533099730.206 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T05:02:10.206Z,1533099730.206 [Default:CheckIn:D] Running Loop=1
2018-08-01T05:02:10.600Z,1533099730.600 [Default:CheckIn:D] Stopped
2018-08-01T05:02:10.600Z,1533099730.600 [Default:CheckIn:E] Running Loop=1
2018-08-01T05:02:13.965Z,1533099733.965 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 274.667546 min 
2018-08-01T05:02:13.965Z,1533099733.965 [Default:CheckIn:E] Stopped
2018-08-01T05:02:13.965Z,1533099733.965 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T05:02:13.965Z,1533099733.965 [Default:CheckIn] Stopped
2018-08-01T05:02:13.965Z,1533099733.965 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T05:02:13.966Z,1533099733.966 [Default:CheckIn](INFO): Running loop #29
2018-08-01T05:02:13.966Z,1533099733.966 [Default:CheckIn] Running Loop=29
2018-08-01T05:02:13.966Z,1533099733.966 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T05:02:13.966Z,1533099733.966 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T05:02:14.415Z,1533099734.415 [NAL9602](INFO): Powering up
2018-08-01T05:02:25.608Z,1533099745.608 [NAL9602](INFO): NAL9602 initialized
2018-08-01T05:02:26.408Z,1533099746.408 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-08-01T05:02:26.408Z,1533099746.408 [NAL9602] Data Fault, FailCount= 2
2018-08-01T05:02:26.408Z,1533099746.408 [NAL9602](ERROR): Data Fault
2018-08-01T05:02:26.508Z,1533099746.508 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T05:02:26.807Z,1533099746.807 [NAL9602](INFO): Powering down
2018-08-01T05:02:27.672Z,1533099747.672 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T05:02:27.672Z,1533099747.672 [NAL9602] No Fault, FailCount= 2
2018-08-01T05:02:57.202Z,1533099777.202 [NAL9602](INFO): Powering up NAL9602
2018-08-01T05:03:08.402Z,1533099788.402 [NAL9602](INFO): NAL9602 initialized
2018-08-01T05:03:15.361Z,1533099795.361 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-32768,-32768,-32768,-32768,V
2018-08-01T05:07:14.730Z,1533100034.730 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-01T05:02:13.0Z
2018-08-01T05:07:14.731Z,1533100034.731 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T05:07:14.731Z,1533100034.731 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T05:07:19.709Z,1533100039.709 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180801T002359/Courier0088.lzma
2018-08-01T05:07:20.489Z,1533100040.489 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0088.lzma.bak
2018-08-01T05:07:20.489Z,1533100040.489 [DataOverHttps](INFO): SBD MOMSN=8390011
2018-08-01T05:07:29.570Z,1533100049.570 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20180801T002359/Express0089.lzma
2018-08-01T05:07:30.340Z,1533100050.340 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0089.lzma.bak
2018-08-01T05:07:30.340Z,1533100050.340 [DataOverHttps](INFO): SBD MOMSN=8390013
2018-08-01T05:07:30.893Z,1533100050.893 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T05:07:30.893Z,1533100050.893 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T05:07:30.894Z,1533100050.894 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T05:08:14.478Z,1533100094.478 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-01T05:08:44.982Z,1533100124.982 [NAL9602](INFO): Powering down
2018-08-01T05:12:31.253Z,1533100351.253 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T05:12:31.253Z,1533100351.253 [Default:CheckIn:C.Wait] Stopped
2018-08-01T05:12:31.253Z,1533100351.253 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T05:12:31.253Z,1533100351.253 [Default:CheckIn:D] Running Loop=1
2018-08-01T05:12:31.650Z,1533100351.650 [Default:CheckIn:D] Stopped
2018-08-01T05:12:31.650Z,1533100351.650 [Default:CheckIn:E] Running Loop=1
2018-08-01T05:12:32.034Z,1533100352.034 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 285.018392 min 
2018-08-01T05:12:32.034Z,1533100352.034 [Default:CheckIn:E] Stopped
2018-08-01T05:12:32.034Z,1533100352.034 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T05:12:32.034Z,1533100352.034 [Default:CheckIn] Stopped
2018-08-01T05:12:32.034Z,1533100352.034 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T05:12:32.035Z,1533100352.035 [Default:CheckIn](INFO): Running loop #30
2018-08-01T05:12:32.035Z,1533100352.035 [Default:CheckIn] Running Loop=30
2018-08-01T05:12:32.035Z,1533100352.035 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T05:12:32.035Z,1533100352.035 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T05:12:35.352Z,1533100355.352 [NAL9602](INFO): Powering up
2018-08-01T05:12:46.514Z,1533100366.514 [NAL9602](INFO): NAL9602 initialized
2018-08-01T05:13:18.507Z,1533100398.507 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2018-08-01T05:13:18.589Z,1533100398.589 [NAL9602](FAULT): received: 
+CSQ:0

OK3, 0, 0, 0, 0

OK
2018-08-01T05:13:18.589Z,1533100398.589 [NAL9602] Data Fault, FailCount= 3
2018-08-01T05:13:18.589Z,1533100398.589 [NAL9602](ERROR): Data Fault
2018-08-01T05:13:18.669Z,1533100398.669 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T05:13:18.910Z,1533100398.910 [NAL9602](INFO): Powering down
2018-08-01T05:13:19.820Z,1533100399.820 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T05:13:19.820Z,1533100399.820 [NAL9602] No Fault, FailCount= 3
2018-08-01T05:13:49.054Z,1533100429.054 [NAL9602](INFO): Powering up NAL9602
2018-08-01T05:14:00.254Z,1533100440.254 [NAL9602](INFO): NAL9602 initialized
2018-08-01T05:14:01.058Z,1533100441.058 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-08-01T05:14:01.058Z,1533100441.058 [NAL9602] Data Fault, FailCount= 4
2018-08-01T05:14:01.059Z,1533100441.059 [NAL9602](ERROR): Data Fault
2018-08-01T05:14:01.145Z,1533100441.145 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T05:14:01.454Z,1533100441.454 [NAL9602](INFO): Powering down
2018-08-01T05:14:02.320Z,1533100442.320 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T05:14:02.320Z,1533100442.320 [NAL9602] No Fault, FailCount= 4
2018-08-01T05:14:31.854Z,1533100471.854 [NAL9602](INFO): Powering up NAL9602
2018-08-01T05:14:42.754Z,1533100482.754 [NAL9602](INFO): NAL9602 initialized
2018-08-01T05:17:32.345Z,1533100652.345 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-01T05:12:32.0Z
2018-08-01T05:17:32.345Z,1533100652.345 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T05:17:32.345Z,1533100652.345 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T05:17:36.239Z,1533100656.239 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180801T002359/Courier0091.lzma
2018-08-01T05:17:37.030Z,1533100657.030 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0091.lzma.bak
2018-08-01T05:17:37.030Z,1533100657.030 [DataOverHttps](INFO): SBD MOMSN=8390018
2018-08-01T05:17:46.069Z,1533100666.069 [DataOverHttps](INFO): Sending 250 bytes from file Logs/20180801T002359/Express0092.lzma
2018-08-01T05:17:46.825Z,1533100666.825 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0092.lzma.bak
2018-08-01T05:17:46.825Z,1533100666.825 [DataOverHttps](INFO): SBD MOMSN=8390020
2018-08-01T05:17:47.377Z,1533100667.377 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T05:17:47.397Z,1533100667.397 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T05:17:47.397Z,1533100667.397 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T05:17:50.944Z,1533100670.944 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-01T05:18:21.502Z,1533100701.502 [NAL9602](INFO): Powering down
2018-08-01T05:22:47.901Z,1533100967.901 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T05:22:47.901Z,1533100967.901 [Default:CheckIn:C.Wait] Stopped
2018-08-01T05:22:47.902Z,1533100967.902 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T05:22:47.902Z,1533100967.902 [Default:CheckIn:D] Running Loop=1
2018-08-01T05:22:48.307Z,1533100968.307 [Default:CheckIn:D] Stopped
2018-08-01T05:22:48.307Z,1533100968.307 [Default:CheckIn:E] Running Loop=1
2018-08-01T05:22:51.488Z,1533100971.488 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 295.296029 min 
2018-08-01T05:22:51.488Z,1533100971.488 [Default:CheckIn:E] Stopped
2018-08-01T05:22:51.488Z,1533100971.488 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T05:22:51.488Z,1533100971.488 [Default:CheckIn] Stopped
2018-08-01T05:22:51.488Z,1533100971.488 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T05:22:51.489Z,1533100971.489 [Default:CheckIn](INFO): Running loop #31
2018-08-01T05:22:51.489Z,1533100971.489 [Default:CheckIn] Running Loop=31
2018-08-01T05:22:51.489Z,1533100971.489 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T05:22:51.489Z,1533100971.489 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T05:22:51.926Z,1533100971.926 [NAL9602](INFO): Powering up
2018-08-01T05:23:03.122Z,1533100983.122 [NAL9602](INFO): NAL9602 initialized
2018-08-01T05:23:35.127Z,1533101015.127 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2018-08-01T05:23:35.201Z,1533101015.201 [NAL9602](FAULT): received: 
+CSQ:0

OK3, 0, 0, 0, 0

OK
2018-08-01T05:23:35.201Z,1533101015.201 [NAL9602] Data Fault, FailCount= 5
2018-08-01T05:23:35.201Z,1533101015.201 [NAL9602](ERROR): Data Fault
2018-08-01T05:23:35.300Z,1533101015.300 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T05:23:35.300Z,1533101015.300 [CBIT](CRITICAL): Data Fault in component: NAL9602
2018-08-01T05:23:35.543Z,1533101015.543 [NAL9602](INFO): Powering down
2018-08-01T05:23:35.584Z,1533101015.584 [CBIT](INFO): Critical error at 20180801T052335
2018-08-01T05:25:35.429Z,1533101135.429 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T05:25:35.430Z,1533101135.430 [NAL9602] No Fault, FailCount= 5
2018-08-01T05:25:35.766Z,1533101135.766 [NAL9602](INFO): Powering up NAL9602
2018-08-01T05:25:46.566Z,1533101146.566 [NAL9602](INFO): NAL9602 initialized
2018-08-01T05:25:47.366Z,1533101147.366 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-08-01T05:25:47.367Z,1533101147.367 [NAL9602] Data Fault, FailCount= 1
2018-08-01T05:25:47.367Z,1533101147.367 [NAL9602](ERROR): Data Fault
2018-08-01T05:25:47.470Z,1533101147.470 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T05:25:47.770Z,1533101147.770 [NAL9602](INFO): Powering down
2018-08-01T05:25:48.642Z,1533101148.642 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T05:25:48.642Z,1533101148.642 [NAL9602] No Fault, FailCount= 1
2018-08-01T05:26:17.918Z,1533101177.918 [NAL9602](INFO): Powering up NAL9602
2018-08-01T05:26:29.124Z,1533101189.124 [NAL9602](INFO): NAL9602 initialized
2018-08-01T05:27:52.308Z,1533101272.308 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-01T05:22:51.5Z
2018-08-01T05:27:52.308Z,1533101272.308 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T05:27:52.308Z,1533101272.308 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T05:27:57.374Z,1533101277.374 [DataOverHttps](INFO): Sending 69 bytes from file Logs/20180801T002359/Courier0094.lzma
2018-08-01T05:27:58.152Z,1533101278.152 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0094.lzma.bak
2018-08-01T05:27:58.152Z,1533101278.152 [DataOverHttps](INFO): SBD MOMSN=8390027
2018-08-01T05:28:07.162Z,1533101287.162 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-01T05:28:07.307Z,1533101287.307 [DataOverHttps](INFO): Sending 250 bytes from file Logs/20180801T002359/Express0095.lzma
2018-08-01T05:28:08.085Z,1533101288.085 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0095.lzma.bak
2018-08-01T05:28:08.085Z,1533101288.085 [DataOverHttps](INFO): SBD MOMSN=8390030
2018-08-01T05:28:08.626Z,1533101288.626 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T05:28:08.626Z,1533101288.626 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T05:28:08.626Z,1533101288.626 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T05:28:37.510Z,1533101317.510 [NAL9602](INFO): Powering down
2018-08-01T05:33:09.194Z,1533101589.194 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T05:33:09.194Z,1533101589.194 [Default:CheckIn:C.Wait] Stopped
2018-08-01T05:33:09.194Z,1533101589.194 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T05:33:09.194Z,1533101589.194 [Default:CheckIn:D] Running Loop=1
2018-08-01T05:33:09.597Z,1533101589.597 [Default:CheckIn:D] Stopped
2018-08-01T05:33:09.597Z,1533101589.597 [Default:CheckIn:E] Running Loop=1
2018-08-01T05:33:09.990Z,1533101589.990 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 305.650781 min 
2018-08-01T05:33:09.990Z,1533101589.990 [Default:CheckIn:E] Stopped
2018-08-01T05:33:09.990Z,1533101589.990 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T05:33:09.990Z,1533101589.990 [Default:CheckIn] Stopped
2018-08-01T05:33:09.991Z,1533101589.991 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T05:33:09.991Z,1533101589.991 [Default:CheckIn](INFO): Running loop #32
2018-08-01T05:33:09.991Z,1533101589.991 [Default:CheckIn] Running Loop=32
2018-08-01T05:33:09.991Z,1533101589.991 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T05:33:09.991Z,1533101589.991 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T05:33:13.266Z,1533101593.266 [NAL9602](INFO): Powering up
2018-08-01T05:33:24.414Z,1533101604.414 [NAL9602](INFO): NAL9602 initialized
2018-08-01T05:33:56.435Z,1533101636.435 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2018-08-01T05:33:56.509Z,1533101636.509 [NAL9602](FAULT): received: 
+CSQ:0

OK3, 0, 0, 0, 0

OK
2018-08-01T05:33:56.509Z,1533101636.509 [NAL9602] Data Fault, FailCount= 2
2018-08-01T05:33:56.509Z,1533101636.509 [NAL9602](ERROR): Data Fault
2018-08-01T05:33:56.584Z,1533101636.584 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T05:33:56.822Z,1533101636.822 [NAL9602](INFO): Powering down
2018-08-01T05:33:57.697Z,1533101637.697 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T05:33:57.697Z,1533101637.697 [NAL9602] No Fault, FailCount= 2
2018-08-01T05:34:26.926Z,1533101666.926 [NAL9602](INFO): Powering up NAL9602
2018-08-01T05:34:38.122Z,1533101678.122 [NAL9602](INFO): NAL9602 initialized
2018-08-01T05:38:10.404Z,1533101890.404 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-01T05:33:09.0Z
2018-08-01T05:38:10.404Z,1533101890.404 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T05:38:10.404Z,1533101890.404 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-01T05:38:14.220Z,1533101894.220 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180801T002359/Courier0097.lzma
2018-08-01T05:38:15.014Z,1533101895.014 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Courier0097.lzma.bak
2018-08-01T05:38:15.014Z,1533101895.014 [DataOverHttps](INFO): SBD MOMSN=8390039
2018-08-01T05:38:20.394Z,1533101900.394 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-32768,-32768,-32768,-32768,V
2018-08-01T05:38:24.128Z,1533101904.128 [DataOverHttps](INFO): Sending 234 bytes from file Logs/20180801T002359/Express0098.lzma
2018-08-01T05:38:24.905Z,1533101904.905 [DataOverHttps](INFO): Moved sent file to Logs/20180801T002359/Express0098.lzma.bak
2018-08-01T05:38:24.905Z,1533101904.905 [DataOverHttps](INFO): SBD MOMSN=8390041
2018-08-01T05:38:25.431Z,1533101905.431 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-32768,-32768,-32768,-32768,V
2018-08-01T05:38:25.465Z,1533101905.465 [Default:CheckIn:Read_Iridium] Stopped
2018-08-01T05:38:25.465Z,1533101905.465 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-01T05:38:25.465Z,1533101905.465 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-01T05:38:28.928Z,1533101908.928 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-01T05:38:59.458Z,1533101939.458 [NAL9602](INFO): Powering down
2018-08-01T05:39:30.390Z,1533101970.390 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-32768,-32768,-32768,-32768,V
2018-08-01T05:43:26.091Z,1533102206.091 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-01T05:43:26.091Z,1533102206.091 [Default:CheckIn:C.Wait] Stopped
2018-08-01T05:43:26.091Z,1533102206.091 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-01T05:43:26.091Z,1533102206.091 [Default:CheckIn:D] Running Loop=1
2018-08-01T05:43:26.481Z,1533102206.481 [Default:CheckIn:D] Stopped
2018-08-01T05:43:26.481Z,1533102206.481 [Default:CheckIn:E] Running Loop=1
2018-08-01T05:43:29.672Z,1533102209.672 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 315.932259 min 
2018-08-01T05:43:29.672Z,1533102209.672 [Default:CheckIn:E] Stopped
2018-08-01T05:43:29.673Z,1533102209.673 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-01T05:43:29.673Z,1533102209.673 [Default:CheckIn] Stopped
2018-08-01T05:43:29.673Z,1533102209.673 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T05:43:29.673Z,1533102209.673 [Default:CheckIn](INFO): Running loop #33
2018-08-01T05:43:29.673Z,1533102209.673 [Default:CheckIn] Running Loop=33
2018-08-01T05:43:29.673Z,1533102209.673 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-01T05:43:29.673Z,1533102209.673 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-01T05:43:30.114Z,1533102210.114 [NAL9602](INFO): Powering up
2018-08-01T05:43:40.915Z,1533102220.915 [NAL9602](INFO): NAL9602 initialized
2018-08-01T05:43:41.708Z,1533102221.708 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-08-01T05:43:41.708Z,1533102221.708 [NAL9602] Data Fault, FailCount= 3
2018-08-01T05:43:41.709Z,1533102221.709 [NAL9602](ERROR): Data Fault
2018-08-01T05:43:41.804Z,1533102221.804 [CBIT](ERROR): Data Fault in component: NAL9602
2018-08-01T05:43:42.114Z,1533102222.114 [NAL9602](INFO): Powering down
2018-08-01T05:43:42.972Z,1533102222.972 [CBIT](INFO): Clearing failed state for component NAL9602
2018-08-01T05:43:42.972Z,1533102222.972 [NAL9602] No Fault, FailCount= 3
2018-08-01T05:44:12.118Z,1533102252.118 [NAL9602](INFO): Powering up NAL9602
2018-08-01T05:44:23.310Z,1533102263.310 [NAL9602](INFO): NAL9602 initialized
2018-08-01T05:44:29.041Z,1533102269.041 [CommandLine](IMPORTANT): got command quit
2018-08-01T05:44:30.048Z,1533102270.048 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-08-01T05:44:30.048Z,1533102270.048 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-08-01T05:44:30.117Z,1533102270.117 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2018-08-01T05:44:30.117Z,1533102270.117 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-08-01T05:44:30.118Z,1533102270.118 [CommandLine](INFO): Join timeout helper Thread ID is 2799
2018-08-01T05:44:30.118Z,1533102270.118 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-08-01T05:44:30.118Z,1533102270.118 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-08-01T05:44:30.119Z,1533102270.119 [NavChartDb](INFO): Join timeout helper Thread ID is 2800
2018-08-01T05:44:30.253Z,1533102270.253 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-08-01T05:44:30.253Z,1533102270.253 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-08-01T05:44:30.254Z,1533102270.254 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-08-01T05:44:30.254Z,1533102270.254 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-08-01T05:44:30.254Z,1533102270.254 [Radio_Surface](INFO): Join timeout helper Thread ID is 2801
2018-08-01T05:44:30.553Z,1533102270.553 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-08-01T05:44:30.553Z,1533102270.553 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-08-01T05:44:30.569Z,1533102270.569 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2018-08-01T05:44:30.569Z,1533102270.569 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-08-01T05:44:30.570Z,1533102270.570 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 2802
2018-08-01T05:44:30.581Z,1533102270.581 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2018-08-01T05:44:30.581Z,1533102270.581 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-08-01T05:44:30.589Z,1533102270.589 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-08-01T05:44:30.589Z,1533102270.589 [logger ThreadHandler](INFO): Thread cancelled.
2018-08-01T05:44:30.589Z,1533102270.589 [logger](INFO): Join timeout helper Thread ID is 2803
2018-08-01T05:44:30.613Z,1533102270.613 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-08-01T05:44:30.613Z,1533102270.613 [logger ThreadHandler](INFO): Thread cancelled.
2018-08-01T05:44:30.630Z,1533102270.630 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-08-01T05:44:30.630Z,1533102270.630 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-08-01T05:44:30.630Z,1533102270.630 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-08-01T05:44:30.630Z,1533102270.630 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-08-01T05:44:30.630Z,1533102270.630 [controlThread](INFO): Join timeout helper Thread ID is 2804
2018-08-01T05:44:30.633Z,1533102270.633 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-08-01T05:44:30.633Z,1533102270.633 [controlThread](DEBUG): Uninitializing ControlThread
2018-08-01T05:44:30.634Z,1533102270.634 [Aanderaa_O2](INFO): Powering down
2018-08-01T05:44:30.635Z,1533102270.635 [AHRS_M2](INFO): Powering down
2018-08-01T05:44:30.708Z,1533102270.708 [NAL9602](INFO): Powering down
2018-08-01T05:44:30.781Z,1533102270.781 [RDI_Pathfinder](INFO): Powering down
2018-08-01T05:44:30.782Z,1533102270.782 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-08-01T05:44:30.784Z,1533102270.784 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2018-08-01T05:44:30.784Z,1533102270.784 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-08-01T05:44:30.785Z,1533102270.785 [MissionManager](INFO): Uninitializing Mission Default
2018-08-01T05:44:30.785Z,1533102270.785 [Default] Stopped
2018-08-01T05:44:30.785Z,1533102270.785 [Default](DEBUG): Aggregate::uninitialize Default
2018-08-01T05:44:30.785Z,1533102270.785 [Default:B.GoToSurface] Stopped
2018-08-01T05:44:30.786Z,1533102270.786 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-08-01T05:44:30.786Z,1533102270.786 [Default:CheckIn] Stopped
2018-08-01T05:44:30.786Z,1533102270.786 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-01T05:44:30.786Z,1533102270.786 [Default:CheckIn:Read_GPS] Stopped
2018-08-01T05:44:30.789Z,1533102270.789 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-08-01T05:44:30.790Z,1533102270.790 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-08-01T05:44:30.790Z,1533102270.790 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-08-01T05:44:30.790Z,1533102270.790 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-08-01T05:44:30.791Z,1533102270.791 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-08-01T05:44:30.791Z,1533102270.791 [BuoyancyServo](INFO): Powering down
2018-08-01T05:44:30.805Z,1533102270.805 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-08-01T05:44:30.805Z,1533102270.805 [ElevatorServo](INFO): Powering down
2018-08-01T05:44:30.806Z,1533102270.806 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-08-01T05:44:30.806Z,1533102270.806 [MassServo](INFO): Powering down
2018-08-01T05:44:30.807Z,1533102270.807 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-08-01T05:44:30.807Z,1533102270.807 [RudderServo](INFO): Powering down
2018-08-01T05:44:30.808Z,1533102270.808 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-08-01T05:44:30.808Z,1533102270.808 [ThrusterServo](INFO): Powering down
2018-08-01T05:44:30.809Z,1533102270.809 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-08-01T05:44:30.809Z,1533102270.809 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-08-01T05:44:30.810Z,1533102270.810 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-08-01T05:44:30.811Z,1533102270.811 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-08-01T05:44:30.876Z,1533102270.876 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-08-01T05:44:30.934Z,1533102270.934 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-08-01T05:44:30.976Z,1533102270.976 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-08-01T05:44:31.044Z,1533102271.044 [logger ThreadHandler](INFO): Thread cancelled.