2019-05-30T21:00:52.224Z,1559250052.224 [Supervisor](DEBUG): Initializing supervisor.
2019-05-30T21:00:52.227Z,1559250052.227 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-05-30T21:00:52.228Z,1559250052.228 [SyncHandler](INFO): Protected caller Thread ID is 2626
2019-05-30T21:00:52.228Z,1559250052.228 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-05-30T21:00:52.229Z,1559250052.229 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-05-30T21:00:52.229Z,1559250052.229 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2627
2019-05-30T21:00:52.232Z,1559250052.232 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-05-30T21:00:52.244Z,1559250052.244 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-05-30T21:00:52.245Z,1559250052.245 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-05-30T21:00:52.246Z,1559250052.246 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2628
2019-05-30T21:00:52.246Z,1559250052.246 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-05-30T21:00:52.247Z,1559250052.247 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-05-30T21:00:52.248Z,1559250052.248 [logger ThreadHandler](INFO): Protected caller Thread ID is 2629
2019-05-30T21:00:52.250Z,1559250052.250 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-05-30T21:00:52.250Z,1559250052.250 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-05-30T21:00:52.252Z,1559250052.252 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-05-30T21:00:52.733Z,1559250052.733 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-05-30T21:00:52.733Z,1559250052.733 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-05-30T21:00:52.832Z,1559250052.832 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-05-30T21:00:52.832Z,1559250052.832 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-05-30T21:00:53.263Z,1559250053.263 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-05-30T21:00:53.264Z,1559250053.264 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-05-30T21:00:53.407Z,1559250053.407 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-05-30T21:00:53.408Z,1559250053.408 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-05-30T21:00:53.602Z,1559250053.602 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-05-30T21:00:53.603Z,1559250053.603 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-05-30T21:00:54.069Z,1559250054.069 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-05-30T21:00:54.070Z,1559250054.070 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-05-30T21:00:54.284Z,1559250054.284 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-05-30T21:00:54.284Z,1559250054.284 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-05-30T21:00:54.432Z,1559250054.432 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-05-30T21:00:54.432Z,1559250054.432 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-05-30T21:00:54.632Z,1559250054.632 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-05-30T21:00:54.633Z,1559250054.633 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-05-30T21:00:54.729Z,1559250054.729 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-05-30T21:00:54.729Z,1559250054.729 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-05-30T21:00:55.056Z,1559250055.056 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-05-30T21:00:55.057Z,1559250055.057 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-05-30T21:00:55.138Z,1559250055.138 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-05-30T21:00:55.241Z,1559250055.241 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-05-30T21:00:55.242Z,1559250055.242 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-05-30T21:00:55.836Z,1559250055.836 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-05-30T21:00:55.837Z,1559250055.837 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-05-30T21:00:56.231Z,1559250056.231 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-05-30T21:00:56.233Z,1559250056.233 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2019-05-30T21:00:56.234Z,1559250056.234 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2019-05-30T21:00:56.446Z,1559250056.446 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2019-05-30T21:00:56.572Z,1559250056.572 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2019-05-30T21:00:56.725Z,1559250056.725 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2019-05-30T21:00:57.123Z,1559250057.123 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-05-30T21:00:57.124Z,1559250057.124 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2019-05-30T21:00:57.275Z,1559250057.275 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2019-05-30T21:00:57.461Z,1559250057.461 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2019-05-30T21:00:57.558Z,1559250057.558 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2019-05-30T21:00:57.640Z,1559250057.640 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2019-05-30T21:00:57.748Z,1559250057.748 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2019-05-30T21:00:57.920Z,1559250057.920 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2019-05-30T21:00:58.053Z,1559250058.053 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/root/
2019-05-30T21:00:58.053Z,1559250058.053 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-05-30T21:00:58.070Z,1559250058.070 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-05-30T21:00:58.625Z,1559250058.625 [AHRS_M2] Loaded
2019-05-30T21:00:58.625Z,1559250058.625 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-05-30T21:00:58.697Z,1559250058.697 [DataOverHttps] Loaded
2019-05-30T21:00:58.697Z,1559250058.697 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-05-30T21:00:58.698Z,1559250058.698 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4075A4E0
2019-05-30T21:00:58.699Z,1559250058.699 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 2709
2019-05-30T21:00:58.712Z,1559250058.712 [Depth_Keller] Loaded
2019-05-30T21:00:58.712Z,1559250058.712 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-05-30T21:00:58.717Z,1559250058.717 [DropWeight] Loaded
2019-05-30T21:00:58.717Z,1559250058.717 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-05-30T21:00:58.773Z,1559250058.773 [DUSBL_Hydroid] Loaded
2019-05-30T21:00:58.773Z,1559250058.773 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2019-05-30T21:00:58.813Z,1559250058.813 [Micromodem] Loaded
2019-05-30T21:00:58.813Z,1559250058.813 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2019-05-30T21:00:58.911Z,1559250058.911 [NAL9602] Loaded
2019-05-30T21:00:58.911Z,1559250058.911 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-05-30T21:00:58.926Z,1559250058.926 [Onboard] Loaded
2019-05-30T21:00:58.927Z,1559250058.927 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-05-30T21:00:58.932Z,1559250058.932 [PowerOnly] Loaded
2019-05-30T21:00:58.933Z,1559250058.933 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2019-05-30T21:00:58.939Z,1559250058.939 [Radio_Surface] Loaded
2019-05-30T21:00:58.939Z,1559250058.939 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-05-30T21:00:58.940Z,1559250058.940 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4078A4E0
2019-05-30T21:00:58.941Z,1559250058.941 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2710
2019-05-30T21:00:58.987Z,1559250058.987 [RDI_Pathfinder] Loaded
2019-05-30T21:00:58.988Z,1559250058.988 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2019-05-30T21:01:00.464Z,1559250060.464 [BPC1] Loaded
2019-05-30T21:01:00.464Z,1559250060.464 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-05-30T21:01:00.465Z,1559250060.465 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-05-30T21:01:00.465Z,1559250060.465 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-05-30T21:01:00.489Z,1559250060.489 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-05-30T21:01:00.489Z,1559250060.489 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-05-30T21:01:00.610Z,1559250060.610 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-05-30T21:01:00.611Z,1559250060.611 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-05-30T21:01:00.631Z,1559250060.631 [NavChart] Loaded
2019-05-30T21:01:00.631Z,1559250060.631 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-05-30T21:01:00.635Z,1559250060.635 [UniversalFixResidualReporter] Loaded
2019-05-30T21:01:00.635Z,1559250060.635 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-05-30T21:01:00.636Z,1559250060.636 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-05-30T21:01:00.636Z,1559250060.636 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-05-30T21:01:00.769Z,1559250060.769 [BuoyancyServo] Loaded
2019-05-30T21:01:00.769Z,1559250060.769 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-05-30T21:01:00.784Z,1559250060.784 [ElevatorServo] Loaded
2019-05-30T21:01:00.784Z,1559250060.784 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-05-30T21:01:00.799Z,1559250060.799 [MassServo] Loaded
2019-05-30T21:01:00.799Z,1559250060.799 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-05-30T21:01:00.814Z,1559250060.814 [RudderServo] Loaded
2019-05-30T21:01:00.814Z,1559250060.814 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-05-30T21:01:00.829Z,1559250060.829 [ThrusterServo] Loaded
2019-05-30T21:01:00.829Z,1559250060.829 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-05-30T21:01:00.830Z,1559250060.830 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-05-30T21:01:00.830Z,1559250060.830 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-05-30T21:01:01.160Z,1559250061.160 [CTD_NeilBrown] Loaded
2019-05-30T21:01:01.160Z,1559250061.160 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-05-30T21:01:01.161Z,1559250061.161 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408CC4E0
2019-05-30T21:01:01.162Z,1559250061.162 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 2711
2019-05-30T21:01:01.205Z,1559250061.205 [WetLabsSeaOWL_UV_A] Loaded
2019-05-30T21:01:01.206Z,1559250061.206 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2019-05-30T21:01:01.207Z,1559250061.207 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 408FC4E0
2019-05-30T21:01:01.207Z,1559250061.207 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 2712
2019-05-30T21:01:01.208Z,1559250061.208 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-05-30T21:01:01.208Z,1559250061.208 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-05-30T21:01:01.546Z,1559250061.546 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-05-30T21:01:01.546Z,1559250061.546 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-05-30T21:01:01.674Z,1559250061.674 [DepthRateCalculator] Loaded
2019-05-30T21:01:01.674Z,1559250061.674 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-05-30T21:01:01.679Z,1559250061.679 [PitchRateCalculator] Loaded
2019-05-30T21:01:01.680Z,1559250061.680 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-05-30T21:01:01.692Z,1559250061.692 [SpeedCalculator] Loaded
2019-05-30T21:01:01.693Z,1559250061.693 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-05-30T21:01:01.713Z,1559250061.713 [TempGradientCalculator] Loaded
2019-05-30T21:01:01.713Z,1559250061.713 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-05-30T21:01:01.719Z,1559250061.719 [YawRateCalculator] Loaded
2019-05-30T21:01:01.719Z,1559250061.719 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-05-30T21:01:01.842Z,1559250061.842 [ElevatorOffsetCalculator] Loaded
2019-05-30T21:01:01.842Z,1559250061.842 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-05-30T21:01:01.842Z,1559250061.842 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-05-30T21:01:01.843Z,1559250061.843 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-05-30T21:01:02.000Z,1559250062.000 [SBIT](DEBUG): Construct Startup Built In Test.
2019-05-30T21:01:02.022Z,1559250062.022 [SBIT] Loaded
2019-05-30T21:01:02.022Z,1559250062.022 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-05-30T21:01:02.023Z,1559250062.023 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-05-30T21:01:02.034Z,1559250062.034 [IBIT] Loaded
2019-05-30T21:01:02.035Z,1559250062.035 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-05-30T21:01:02.038Z,1559250062.038 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-05-30T21:01:02.173Z,1559250062.173 [CBIT] Loaded
2019-05-30T21:01:02.174Z,1559250062.174 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-05-30T21:01:02.174Z,1559250062.174 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-05-30T21:01:02.175Z,1559250062.175 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-05-30T21:01:02.297Z,1559250062.297 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-05-30T21:01:02.297Z,1559250062.297 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-05-30T21:01:02.420Z,1559250062.420 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-05-30T21:01:02.421Z,1559250062.421 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-05-30T21:01:02.506Z,1559250062.506 [VerticalControl](DEBUG): Construct VerticalControl.
2019-05-30T21:01:02.589Z,1559250062.589 [VerticalControl] Loaded
2019-05-30T21:01:02.589Z,1559250062.589 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-05-30T21:01:02.590Z,1559250062.590 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-05-30T21:01:02.647Z,1559250062.647 [HorizontalControl] Loaded
2019-05-30T21:01:02.647Z,1559250062.647 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-05-30T21:01:02.648Z,1559250062.648 [SpeedControl](DEBUG): Construct SpeedControl.
2019-05-30T21:01:02.649Z,1559250062.649 [SpeedControl] Loaded
2019-05-30T21:01:02.650Z,1559250062.650 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-05-30T21:01:02.650Z,1559250062.650 [LoopControl](DEBUG): Construct LoopControl.
2019-05-30T21:01:02.651Z,1559250062.651 [LoopControl] Loaded
2019-05-30T21:01:02.651Z,1559250062.651 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-05-30T21:01:02.652Z,1559250062.652 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-05-30T21:01:02.652Z,1559250062.652 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-05-30T21:01:02.692Z,1559250062.692 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-05-30T21:01:02.696Z,1559250062.696 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-05-30T21:01:02.697Z,1559250062.697 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-05-30T21:01:02.704Z,1559250062.704 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-05-30T21:01:02.705Z,1559250062.705 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AD54E0
2019-05-30T21:01:02.705Z,1559250062.705 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2713
2019-05-30T21:01:02.710Z,1559250062.710 [Supervisor](INFO): Main Thread ID is 2625
2019-05-30T21:01:02.710Z,1559250062.710 [Supervisor](DEBUG): Running supervisor.
2019-05-30T21:01:02.711Z,1559250062.711 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2714
2019-05-30T21:01:02.714Z,1559250062.714 [controlThread ThreadHandler](INFO): Handler Thread ID is 2715
2019-05-30T21:01:02.714Z,1559250062.714 [controlThread](DEBUG): Initializing ControlThread
2019-05-30T21:01:02.722Z,1559250062.722 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-05-30T21:01:02.723Z,1559250062.723 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-05-30T21:01:02.724Z,1559250062.724 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-05-30T21:01:02.724Z,1559250062.724 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-05-30T21:01:02.724Z,1559250062.724 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-05-30T21:01:02.725Z,1559250062.725 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-05-30T21:01:02.725Z,1559250062.725 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-05-30T21:01:02.726Z,1559250062.726 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-05-30T21:01:02.726Z,1559250062.726 [SBIT](INFO): Initialize SBIT Component.
2019-05-30T21:01:02.726Z,1559250062.726 [SBIT](IMPORTANT): git: 2019-05-29
2019-05-30T21:01:02.727Z,1559250062.727 [SBIT](INFO): git hash: 3a408d161d85e02f941062c72493668314c507d3
2019-05-30T21:01:02.727Z,1559250062.727 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-05-30T21:01:02.728Z,1559250062.728 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-05-30T21:01:02.729Z,1559250062.729 [SBIT](INFO): Beginning SBIT in 39.000000 seconds.
2019-05-30T21:01:02.730Z,1559250062.730 [IBIT](INFO): Initialize IBIT Component.
2019-05-30T21:01:02.731Z,1559250062.731 [CBIT](DEBUG): Initialize CBIT Component.
2019-05-30T21:01:02.732Z,1559250062.732 [logger ThreadHandler](INFO): Handler Thread ID is 2716
2019-05-30T21:01:02.743Z,1559250062.743 [CBIT](DEBUG): Initialized mux pins.
2019-05-30T21:01:02.743Z,1559250062.743 [CBIT](DEBUG): Initializing the watchdog timer.
2019-05-30T21:01:02.752Z,1559250062.752 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 2717
2019-05-30T21:01:02.753Z,1559250062.753 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-05-30T21:01:02.764Z,1559250062.764 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2718
2019-05-30T21:01:02.767Z,1559250062.767 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-05-30T21:01:02.768Z,1559250062.768 [CBIT](DEBUG): Initializing heartbeat.
2019-05-30T21:01:02.783Z,1559250062.783 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 2719
2019-05-30T21:01:02.784Z,1559250062.784 [CTD_NeilBrown](INFO): Powering down
2019-05-30T21:01:02.819Z,1559250062.819 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 2720
2019-05-30T21:01:02.820Z,1559250062.820 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-05-30T21:01:02.839Z,1559250062.839 [CBIT](DEBUG): Deactivating GF circuits.
2019-05-30T21:01:02.839Z,1559250062.839 [CBIT](DEBUG): Deactivating emergency mode.
2019-05-30T21:01:02.852Z,1559250062.852 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2721
2019-05-30T21:01:02.859Z,1559250062.859 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-05-30T21:01:02.859Z,1559250062.859 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-05-30T21:01:02.859Z,1559250062.859 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-05-30T21:01:02.860Z,1559250062.860 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-05-30T21:01:02.860Z,1559250062.860 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-05-30T21:01:02.860Z,1559250062.860 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-05-30T21:01:02.860Z,1559250062.860 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-05-30T21:01:02.860Z,1559250062.860 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-05-30T21:01:02.861Z,1559250062.861 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-05-30T21:01:02.861Z,1559250062.861 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-05-30T21:01:02.861Z,1559250062.861 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-05-30T21:01:02.861Z,1559250062.861 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-05-30T21:01:02.861Z,1559250062.861 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-05-30T21:01:02.861Z,1559250062.861 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-05-30T21:01:02.862Z,1559250062.862 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-05-30T21:01:02.862Z,1559250062.862 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-05-30T21:01:02.875Z,1559250062.875 [CBIT](DEBUG): Backplane powered.
2019-05-30T21:01:02.875Z,1559250062.875 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-05-30T21:01:02.877Z,1559250062.877 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-05-30T21:01:02.878Z,1559250062.878 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-05-30T21:01:02.878Z,1559250062.878 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-05-30T21:01:02.879Z,1559250062.879 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-05-30T21:01:02.893Z,1559250062.893 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-30T21:01:02.929Z,1559250062.929 [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>


2019-05-30T21:01:02.930Z,1559250062.930 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-05-30T21:01:02.992Z,1559250062.992 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-05-30T21:01:02.993Z,1559250062.993 [Default:A.Wait](DEBUG): Construct Wait.
2019-05-30T21:01:02.995Z,1559250062.995 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-30T21:01:03.029Z,1559250063.029 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-05-30T21:01:03.032Z,1559250063.032 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-05-30T21:01:03.046Z,1559250063.046 [Default:E.Execute](DEBUG): Construct Execute.
2019-05-30T21:01:03.049Z,1559250063.049 [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 on</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>


2019-05-30T21:01:03.071Z,1559250063.071 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-05-30T21:01:03.088Z,1559250063.088 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-05-30T21:01:03.167Z,1559250063.167 [Radio_Surface](INFO): Powering up
2019-05-30T21:01:03.242Z,1559250063.242 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2019-05-30T21:01:03.242Z,1559250063.242 [DUSBL_Hydroid](INFO): Powering up
2019-05-30T21:01:03.243Z,1559250063.243 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2019-05-30T21:01:03.327Z,1559250063.327 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-05-30T21:01:03.377Z,1559250063.377 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-05-30T21:01:03.379Z,1559250063.379 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-05-30T21:01:03.380Z,1559250063.380 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-05-30T21:01:03.387Z,1559250063.387 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-05-30T21:01:03.388Z,1559250063.388 [MassServo](DEBUG): Initializing EZServoServo.
2019-05-30T21:01:03.396Z,1559250063.396 [MassServo](DEBUG): Initializing MassServo.
2019-05-30T21:01:03.396Z,1559250063.396 [RudderServo](DEBUG): Initializing EZServoServo.
2019-05-30T21:01:03.403Z,1559250063.403 [RudderServo](DEBUG): Initializing RudderServo.
2019-05-30T21:01:03.404Z,1559250063.404 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-05-30T21:01:03.411Z,1559250063.411 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-05-30T21:01:03.509Z,1559250063.509 [Micromodem](INFO): Powering up
2019-05-30T21:01:03.509Z,1559250063.509 [Micromodem](DEBUG): Initializing Micromodem.
2019-05-30T21:01:03.543Z,1559250063.543 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-05-30T21:01:04.227Z,1559250064.227 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-05-30T21:01:04.227Z,1559250064.227 [RudderServo](FAULT): Rudder failed to initialize
2019-05-30T21:01:04.227Z,1559250064.227 [RudderServo] Communications Fault, FailCount= 1
2019-05-30T21:01:04.227Z,1559250064.227 [RudderServo](ERROR): Communications Fault
2019-05-30T21:01:04.351Z,1559250064.351 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-05-30T21:01:04.540Z,1559250064.540 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-05-30T21:01:04.540Z,1559250064.540 [RudderServo](INFO): Powering down
2019-05-30T21:01:05.195Z,1559250065.195 [RudderServo](DEBUG): Initializing EZServoServo.
2019-05-30T21:01:05.316Z,1559250065.316 [RudderServo](DEBUG): Initializing RudderServo.
2019-05-30T21:01:05.321Z,1559250065.321 [CBIT](INFO): Clearing failed state for component RudderServo
2019-05-30T21:01:05.321Z,1559250065.321 [RudderServo] No Fault, FailCount= 1
2019-05-30T21:01:14.702Z,1559250074.702 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005504
2019-05-30T21:01:16.559Z,1559250076.559 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-05-30T21:01:21.367Z,1559250081.367 [DUSBL_Hydroid](INFO): DUSBL Version:O
2019-05-30T21:01:29.089Z,1559250089.089 [NAL9602](INFO): Powering up NAL9602
2019-05-30T21:01:39.593Z,1559250099.593 [Micromodem](ERROR): Response from modem unexpected: $CADQF,191,1*59

2019-05-30T21:01:39.997Z,1559250099.997 [Micromodem](ERROR): Response from modem unexpected: $CAMSG,BAD_CRC,0*21

2019-05-30T21:01:39.998Z,1559250099.998 [NAL9602](INFO): NAL9602 initialized
2019-05-30T21:01:40.426Z,1559250100.426 [Micromodem](ERROR): Response from modem unexpected: $CACST,6,1,20190530210138.472135,05,177,10,0093,0150,246,00,00,02,01,0,-01,-01,3,2,1,1,-999,-99.9,-9.99,-999,-9.99,191,0.00,-999,9760,4000*50

2019-05-30T21:01:40.823Z,1559250100.823 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:01:41.209Z,1559250101.209 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CAREV,210139COROC,0.10.0.46*48

2019-05-30T21:01:42.461Z,1559250102.461 [SBIT](IMPORTANT): Beginning Startup BIT
2019-05-30T21:01:42.512Z,1559250102.512 [CBIT](IMPORTANT): Beginning ground fault scan
2019-05-30T21:01:53.556Z,1559250113.556 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.013714
CHAN A1 (24V): -0.025729
CHAN A2 (12V): -0.006003
CHAN A3 (5V): -0.002010
CHAN B0 (3.3V): 0.000423
CHAN B1 (3.15aV): 0.000223
CHAN B2 (3.15bV): 0.000130
CHAN B3 (GND): 0.001815
OPEN: 0.006969
Full Scale Calc: 4.765 mA, -1.589 mA
2019-05-30T21:02:35.822Z,1559250155.822 [SBIT](IMPORTANT): SBIT PASSED
2019-05-30T21:02:35.853Z,1559250155.853 [CommandLine](IMPORTANT): got command configSet list
2019-05-30T21:02:35.853Z,1559250155.853 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-05-30T21:02:35.854Z,1559250155.854 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=3 hour;

2019-05-30T21:02:35.854Z,1559250155.854 [CommandLine](IMPORTANT): BPC1.loadAtStartup=1 bool;

2019-05-30T21:02:35.854Z,1559250155.854 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold=40 count;

2019-05-30T21:02:35.854Z,1559250155.854 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.range 2.000000 meter;

2019-05-30T21:02:35.855Z,1559250155.855 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.xAngle 2.000000 angular_degree;

2019-05-30T21:02:35.855Z,1559250155.855 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.BottomVelocityFlag 0.000000 count;

2019-05-30T21:02:35.855Z,1559250155.855 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.height_above_sea_floor 2.000000 meter;

2019-05-30T21:02:35.855Z,1559250155.855 [CommandLine](IMPORTANT): Express none TrackAcousticContact.contact_latitude;

2019-05-30T21:02:35.855Z,1559250155.855 [CommandLine](IMPORTANT): Express none TrackAcousticContact.contact_longitude;

2019-05-30T21:02:35.855Z,1559250155.855 [CommandLine](IMPORTANT): Express linearApproximation acoustic_contact_range 1.000000 meter;

2019-05-30T21:02:35.855Z,1559250155.855 [CommandLine](IMPORTANT): Express linearApproximation mass_concentration_of_chlorophyll_in_sea_water 5.000000 microgram_per_liter;

2019-05-30T21:02:35.855Z,1559250155.855 [CommandLine](IMPORTANT): Express none mass_concentration_of_oxygen_in_sea_water;

2019-05-30T21:02:35.856Z,1559250155.856 [CommandLine](IMPORTANT): NAL9602.fastGPSFix=1 bool;

2019-05-30T21:02:35.856Z,1559250155.856 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=190 cubic_centimeter;

2019-05-30T21:02:35.856Z,1559250155.856 [CommandLine](IMPORTANT): VerticalControl.massDefault=5 millimeter;

2019-05-30T21:02:36.206Z,1559250156.206 [MissionManager](IMPORTANT): Started mission Startup
2019-05-30T21:02:36.207Z,1559250156.207 [Startup] Running Loop=1
2019-05-30T21:02:36.207Z,1559250156.207 [Startup](DEBUG): Aggregate::initialize Startup
2019-05-30T21:02:36.207Z,1559250156.207 [Startup:A.GoToSurface] Running Loop=1
2019-05-30T21:02:36.207Z,1559250156.207 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-30T21:02:36.208Z,1559250156.208 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-30T21:02:36.208Z,1559250156.208 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-30T21:02:36.208Z,1559250156.208 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-30T21:02:36.209Z,1559250156.209 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-30T21:02:36.209Z,1559250156.209 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-30T21:02:36.211Z,1559250156.211 [Startup:StartupSatComms] Running Loop=1
2019-05-30T21:02:36.211Z,1559250156.211 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-05-30T21:02:36.211Z,1559250156.211 [Startup:StartupSatComms:A] Running Loop=1
2019-05-30T21:02:36.749Z,1559250156.749 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-05-30T21:03:36.373Z,1559250216.373 [Startup:StartupSatComms:A](INFO): Timed out from 2019-05-30T21:02:36.2Z
2019-05-30T21:03:36.373Z,1559250216.373 [Startup:StartupSatComms:A] Stopped
2019-05-30T21:03:36.373Z,1559250216.373 [Startup:StartupSatComms:B] Running Loop=1
2019-05-30T21:03:36.786Z,1559250216.786 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-30T21:03:41.716Z,1559250221.716 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20190530T173243/Courier0004.lzma
2019-05-30T21:03:42.521Z,1559250222.521 [DataOverHttps](INFO): Moved sent file to Logs/20190530T173243/Courier0004.lzma.bak
2019-05-30T21:03:42.521Z,1559250222.521 [DataOverHttps](INFO): SBD MOMSN=11224941
2019-05-30T21:03:53.652Z,1559250233.652 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190530T173243/Courier0007.lzma
2019-05-30T21:03:54.457Z,1559250234.457 [DataOverHttps](INFO): Moved sent file to Logs/20190530T173243/Courier0007.lzma.bak
2019-05-30T21:03:54.457Z,1559250234.457 [DataOverHttps](INFO): SBD MOMSN=11224947
2019-05-30T21:04:03.048Z,1559250243.048 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-05-30T21:04:03.048Z,1559250243.048 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-30T21:04:03.058Z,1559250243.058 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-30T21:04:03.519Z,1559250243.519 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-30T21:04:03.519Z,1559250243.519 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-05-30T21:04:05.820Z,1559250245.820 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20190530T174237/Courier0004.lzma
2019-05-30T21:04:06.625Z,1559250246.625 [DataOverHttps](INFO): Moved sent file to Logs/20190530T174237/Courier0004.lzma.bak
2019-05-30T21:04:06.625Z,1559250246.625 [DataOverHttps](INFO): SBD MOMSN=11224950
2019-05-30T21:04:17.904Z,1559250257.904 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190530T174237/Courier0007.lzma
2019-05-30T21:04:18.709Z,1559250258.709 [DataOverHttps](INFO): Moved sent file to Logs/20190530T174237/Courier0007.lzma.bak
2019-05-30T21:04:18.709Z,1559250258.709 [DataOverHttps](INFO): SBD MOMSN=11224954
2019-05-30T21:04:30.660Z,1559250270.660 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20190530T181238/Courier0004.lzma
2019-05-30T21:04:31.465Z,1559250271.465 [DataOverHttps](INFO): Moved sent file to Logs/20190530T181238/Courier0004.lzma.bak
2019-05-30T21:04:31.465Z,1559250271.465 [DataOverHttps](INFO): SBD MOMSN=11224956
2019-05-30T21:04:36.620Z,1559250276.620 [Startup:StartupSatComms:B](INFO): Timed out from 2019-05-30T21:03:36.4Z
2019-05-30T21:04:36.620Z,1559250276.620 [Startup:StartupSatComms:B] Stopped
2019-05-30T21:04:36.621Z,1559250276.621 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-05-30T21:04:36.621Z,1559250276.621 [Startup:StartupSatComms] Stopped
2019-05-30T21:04:36.621Z,1559250276.621 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-05-30T21:04:36.622Z,1559250276.622 [Startup](INFO): Completed Startup
2019-05-30T21:04:36.622Z,1559250276.622 [MissionManager](INFO): Startup is completed.
2019-05-30T21:04:36.622Z,1559250276.622 [MissionManager](INFO): Uninitializing Mission Startup
2019-05-30T21:04:36.622Z,1559250276.622 [Startup] Stopped
2019-05-30T21:04:36.622Z,1559250276.622 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-05-30T21:04:36.622Z,1559250276.622 [Startup:A.GoToSurface] Stopped
2019-05-30T21:04:36.622Z,1559250276.622 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-30T21:04:37.060Z,1559250277.060 [MissionManager](IMPORTANT): Started mission Default
2019-05-30T21:04:37.060Z,1559250277.060 [Default] Running Loop=1
2019-05-30T21:04:37.060Z,1559250277.060 [Default](DEBUG): Aggregate::initialize Default
2019-05-30T21:04:37.060Z,1559250277.060 [Default:B.GoToSurface] Running Loop=1
2019-05-30T21:04:37.060Z,1559250277.060 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-30T21:04:37.061Z,1559250277.061 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-30T21:04:37.061Z,1559250277.061 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-30T21:04:37.061Z,1559250277.061 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-30T21:04:37.062Z,1559250277.062 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-30T21:04:37.062Z,1559250277.062 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-30T21:04:37.062Z,1559250277.062 [Default:A.Wait] Running Loop=1
2019-05-30T21:04:37.062Z,1559250277.062 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-30T21:04:42.656Z,1559250282.656 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190530T181238/Courier0007.lzma
2019-05-30T21:04:43.465Z,1559250283.465 [DataOverHttps](INFO): Moved sent file to Logs/20190530T181238/Courier0007.lzma.bak
2019-05-30T21:04:43.466Z,1559250283.466 [DataOverHttps](INFO): SBD MOMSN=11224960
2019-05-30T21:04:50.397Z,1559250290.397 [Default:A.Wait](INFO): Done Waiting.
2019-05-30T21:04:50.398Z,1559250290.398 [Default:A.Wait] Stopped
2019-05-30T21:04:50.398Z,1559250290.398 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-30T21:04:50.767Z,1559250290.767 [Default:CheckIn] Running Loop=1
2019-05-30T21:04:50.768Z,1559250290.768 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-30T21:04:50.768Z,1559250290.768 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-30T21:04:51.141Z,1559250291.141 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-05-30T21:05:44.023Z,1559250344.023 [NAL9602](INFO): SBD MO Status=2, MOMSN=5588, MT Status=2, MTMSN=0
2019-05-30T21:05:44.023Z,1559250344.023 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-30T21:06:22.812Z,1559250382.812 [NAL9602](INFO): SBD MO Status=2, MOMSN=5588, MT Status=2, MTMSN=0
2019-05-30T21:06:22.812Z,1559250382.812 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-30T21:06:52.298Z,1559250412.298 [NAL9602](INFO): SBD MO Status=0, MOMSN=5588, MT Status=0, MTMSN=0
2019-05-30T21:06:52.299Z,1559250412.299 [NAL9602](INFO): No messages in MT queue
2019-05-30T21:06:53.115Z,1559250413.115 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:06:53.507Z,1559250413.507 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210646.00,A,3648.16459,N,12147.28283,W,0.467,143.11,300519,,,A*72
2019-05-30T21:06:53.510Z,1559250413.510 [NAL9602](INFO): GPS fix at 20190530T210646: (36.802743, -121.788047)
2019-05-30T21:06:53.560Z,1559250413.560 [Default:CheckIn:Read_GPS] Stopped
2019-05-30T21:06:53.560Z,1559250413.560 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-30T21:06:53.996Z,1559250413.996 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-30T21:07:03.235Z,1559250423.235 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20190530T210052/Courier0004.lzma
2019-05-30T21:07:04.041Z,1559250424.041 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Courier0004.lzma.bak
2019-05-30T21:07:04.041Z,1559250424.041 [DataOverHttps](INFO): SBD MOMSN=11224983
2019-05-30T21:07:17.792Z,1559250437.792 [DataOverHttps](INFO): Sending 267 bytes from file Logs/20190530T160753/Express0005.lzma
2019-05-30T21:07:18.597Z,1559250438.597 [DataOverHttps](INFO): Moved sent file to Logs/20190530T160753/Express0005.lzma.bak
2019-05-30T21:07:18.597Z,1559250438.597 [DataOverHttps](INFO): SBD MOMSN=11224987
2019-05-30T21:07:25.497Z,1559250445.497 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-30T21:07:31.715Z,1559250451.715 [DataOverHttps](INFO): Sending 1378 bytes from file Logs/20190530T161453/Express0001.lzma
2019-05-30T21:07:32.517Z,1559250452.517 [DataOverHttps](INFO): Moved sent file to Logs/20190530T161453/Express0001.lzma.bak
2019-05-30T21:07:32.517Z,1559250452.517 [DataOverHttps](INFO): SBD MOMSN=11224991
2019-05-30T21:07:45.909Z,1559250465.909 [DataOverHttps](INFO): Sending 487 bytes from file Logs/20190530T161453/Express0005.lzma
2019-05-30T21:07:46.713Z,1559250466.713 [DataOverHttps](INFO): Moved sent file to Logs/20190530T161453/Express0005.lzma.bak
2019-05-30T21:07:46.713Z,1559250466.713 [DataOverHttps](INFO): SBD MOMSN=11225020
2019-05-30T21:07:59.564Z,1559250479.564 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20190530T161453/Express0008.lzma
2019-05-30T21:08:00.368Z,1559250480.368 [DataOverHttps](INFO): Moved sent file to Logs/20190530T161453/Express0008.lzma.bak
2019-05-30T21:08:00.369Z,1559250480.369 [DataOverHttps](INFO): SBD MOMSN=11225034
2019-05-30T21:08:12.826Z,1559250492.826 [DataOverHttps](INFO): Sending 1391 bytes from file Logs/20190530T162440/Express0001.lzma
2019-05-30T21:08:13.629Z,1559250493.629 [DataOverHttps](INFO): Moved sent file to Logs/20190530T162440/Express0001.lzma.bak
2019-05-30T21:08:13.629Z,1559250493.629 [DataOverHttps](INFO): SBD MOMSN=11225038
2019-05-30T21:08:18.859Z,1559250498.859 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-05-30T21:08:18.859Z,1559250498.859 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19053014174328,.1,   0.0,1448.9,  0
2019-05-30T21:08:26.361Z,1559250506.361 [DataOverHttps](INFO): Sending 707 bytes from file Logs/20190530T162440/Express0005.lzma
2019-05-30T21:08:27.165Z,1559250507.165 [DataOverHttps](INFO): Moved sent file to Logs/20190530T162440/Express0005.lzma.bak
2019-05-30T21:08:27.165Z,1559250507.165 [DataOverHttps](INFO): SBD MOMSN=11225066
2019-05-30T21:08:28.956Z,1559250508.956 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2019-05-30T21:08:28.967Z,1559250508.967 [BPC1](INFO): Received data from all battery sticks.
2019-05-30T21:08:32.194Z,1559250512.194 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-05-30T21:08:32.194Z,1559250512.194 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00
2019-05-30T21:08:39.412Z,1559250519.412 [DataOverHttps](INFO): Sending 443 bytes from file Logs/20190530T162440/Express0008.lzma
2019-05-30T21:08:40.216Z,1559250520.216 [DataOverHttps](INFO): Moved sent file to Logs/20190530T162440/Express0008.lzma.bak
2019-05-30T21:08:40.217Z,1559250520.217 [DataOverHttps](INFO): SBD MOMSN=11225077
2019-05-30T21:08:53.366Z,1559250533.366 [DataOverHttps](INFO): Sending 230 bytes from file Logs/20190530T162440/Express0011.lzma
2019-05-30T21:08:54.169Z,1559250534.169 [DataOverHttps](INFO): Moved sent file to Logs/20190530T162440/Express0011.lzma.bak
2019-05-30T21:08:54.169Z,1559250534.169 [DataOverHttps](INFO): SBD MOMSN=11225088
2019-05-30T21:09:06.567Z,1559250546.567 [DataOverHttps](INFO): Sending 1524 bytes from file Logs/20190530T164339/Express0001.lzma
2019-05-30T21:09:07.368Z,1559250547.368 [DataOverHttps](INFO): Moved sent file to Logs/20190530T164339/Express0001.lzma.bak
2019-05-30T21:09:07.369Z,1559250547.369 [DataOverHttps](INFO): SBD MOMSN=11225093
2019-05-30T21:09:19.640Z,1559250559.640 [DataOverHttps](INFO): Sending 236 bytes from file Logs/20190530T164339/Express0005.lzma
2019-05-30T21:09:20.445Z,1559250560.445 [DataOverHttps](INFO): Moved sent file to Logs/20190530T164339/Express0005.lzma.bak
2019-05-30T21:09:20.445Z,1559250560.445 [DataOverHttps](INFO): SBD MOMSN=11225125
2019-05-30T21:09:32.889Z,1559250572.889 [DataOverHttps](INFO): Sending 772 bytes from file Logs/20190530T164339/Express0008.lzma
2019-05-30T21:09:33.693Z,1559250573.693 [DataOverHttps](INFO): Moved sent file to Logs/20190530T164339/Express0008.lzma.bak
2019-05-30T21:09:33.693Z,1559250573.693 [DataOverHttps](INFO): SBD MOMSN=11225131
2019-05-30T21:09:45.924Z,1559250585.924 [DataOverHttps](INFO): Sending 384 bytes from file Logs/20190530T164339/Express0011.lzma
2019-05-30T21:09:46.728Z,1559250586.728 [DataOverHttps](INFO): Moved sent file to Logs/20190530T164339/Express0011.lzma.bak
2019-05-30T21:09:46.729Z,1559250586.729 [DataOverHttps](INFO): SBD MOMSN=11225143
2019-05-30T21:09:58.666Z,1559250598.666 [DataOverHttps](INFO): Sending 1357 bytes from file Logs/20190530T170003/Express0001.lzma
2019-05-30T21:10:00.032Z,1559250600.032 [DataOverHttps](INFO): Moved sent file to Logs/20190530T170003/Express0001.lzma.bak
2019-05-30T21:10:00.032Z,1559250600.032 [DataOverHttps](INFO): SBD MOMSN=11225150
2019-05-30T21:10:12.340Z,1559250612.340 [DataOverHttps](INFO): Sending 253 bytes from file Logs/20190530T170003/Express0005.lzma
2019-05-30T21:10:13.145Z,1559250613.145 [DataOverHttps](INFO): Moved sent file to Logs/20190530T170003/Express0005.lzma.bak
2019-05-30T21:10:13.145Z,1559250613.145 [DataOverHttps](INFO): SBD MOMSN=11225179
2019-05-30T21:10:25.562Z,1559250625.562 [DataOverHttps](INFO): Sending 1442 bytes from file Logs/20190530T172359/Express0001.lzma
2019-05-30T21:10:26.365Z,1559250626.365 [DataOverHttps](INFO): Moved sent file to Logs/20190530T172359/Express0001.lzma.bak
2019-05-30T21:10:26.365Z,1559250626.365 [DataOverHttps](INFO): SBD MOMSN=11225183
2019-05-30T21:10:32.171Z,1559250632.171 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-05-30T21:10:32.171Z,1559250632.171 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00
2019-05-30T21:10:38.756Z,1559250638.756 [DataOverHttps](INFO): Sending 227 bytes from file Logs/20190530T172359/Express0005.lzma
2019-05-30T21:10:40.114Z,1559250640.114 [DataOverHttps](INFO): Moved sent file to Logs/20190530T172359/Express0005.lzma.bak
2019-05-30T21:10:40.115Z,1559250640.115 [DataOverHttps](INFO): SBD MOMSN=11225212
2019-05-30T21:10:52.614Z,1559250652.614 [DataOverHttps](INFO): Sending 1282 bytes from file Logs/20190530T173243/Express0001.lzma
2019-05-30T21:10:53.419Z,1559250653.419 [DataOverHttps](INFO): Moved sent file to Logs/20190530T173243/Express0001.lzma.bak
2019-05-30T21:10:53.419Z,1559250653.419 [DataOverHttps](INFO): SBD MOMSN=11225216
2019-05-30T21:11:05.872Z,1559250665.872 [DataOverHttps](INFO): Sending 366 bytes from file Logs/20190530T173243/Express0005.lzma
2019-05-30T21:11:06.676Z,1559250666.676 [DataOverHttps](INFO): Moved sent file to Logs/20190530T173243/Express0005.lzma.bak
2019-05-30T21:11:06.677Z,1559250666.677 [DataOverHttps](INFO): SBD MOMSN=11225243
2019-05-30T21:11:18.957Z,1559250678.957 [DataOverHttps](INFO): Sending 460 bytes from file Logs/20190530T173243/Express0008.lzma
2019-05-30T21:11:19.760Z,1559250679.760 [DataOverHttps](INFO): Moved sent file to Logs/20190530T173243/Express0008.lzma.bak
2019-05-30T21:11:19.761Z,1559250679.761 [DataOverHttps](INFO): SBD MOMSN=11225246
2019-05-30T21:11:32.574Z,1559250692.574 [DataOverHttps](INFO): Sending 1407 bytes from file Logs/20190530T174237/Express0001.lzma
2019-05-30T21:11:33.376Z,1559250693.376 [DataOverHttps](INFO): Moved sent file to Logs/20190530T174237/Express0001.lzma.bak
2019-05-30T21:11:33.377Z,1559250693.377 [DataOverHttps](INFO): SBD MOMSN=11225249
2019-05-30T21:11:49.604Z,1559250709.604 [DataOverHttps](INFO): Sending 448 bytes from file Logs/20190530T174237/Express0005.lzma
2019-05-30T21:11:50.404Z,1559250710.404 [DataOverHttps](INFO): Moved sent file to Logs/20190530T174237/Express0005.lzma.bak
2019-05-30T21:11:50.405Z,1559250710.405 [DataOverHttps](INFO): SBD MOMSN=11225276
2019-05-30T21:12:02.729Z,1559250722.729 [DataOverHttps](INFO): Sending 634 bytes from file Logs/20190530T174237/Express0008.lzma
2019-05-30T21:12:03.533Z,1559250723.533 [DataOverHttps](INFO): Moved sent file to Logs/20190530T174237/Express0008.lzma.bak
2019-05-30T21:12:03.533Z,1559250723.533 [DataOverHttps](INFO): SBD MOMSN=11225279
2019-05-30T21:12:16.590Z,1559250736.590 [DataOverHttps](INFO): Sending 1318 bytes from file Logs/20190530T181238/Express0001.lzma
2019-05-30T21:12:17.395Z,1559250737.395 [DataOverHttps](INFO): Moved sent file to Logs/20190530T181238/Express0001.lzma.bak
2019-05-30T21:12:17.396Z,1559250737.396 [DataOverHttps](INFO): SBD MOMSN=11225282
2019-05-30T21:12:29.841Z,1559250749.841 [DataOverHttps](INFO): Sending 625 bytes from file Logs/20190530T181238/Express0005.lzma
2019-05-30T21:12:30.645Z,1559250750.645 [DataOverHttps](INFO): Moved sent file to Logs/20190530T181238/Express0005.lzma.bak
2019-05-30T21:12:30.645Z,1559250750.645 [DataOverHttps](INFO): SBD MOMSN=11225309
2019-05-30T21:12:43.016Z,1559250763.016 [DataOverHttps](INFO): Sending 195 bytes from file Logs/20190530T181238/Express0008.lzma
2019-05-30T21:12:43.820Z,1559250763.820 [DataOverHttps](INFO): Moved sent file to Logs/20190530T181238/Express0008.lzma.bak
2019-05-30T21:12:43.821Z,1559250763.821 [DataOverHttps](INFO): SBD MOMSN=11225313
2019-05-30T21:12:57.425Z,1559250777.425 [DataOverHttps](INFO): Sending 1378 bytes from file Logs/20190530T210052/Express0001.lzma
2019-05-30T21:12:58.228Z,1559250778.228 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Express0001.lzma.bak
2019-05-30T21:12:58.229Z,1559250778.229 [DataOverHttps](INFO): SBD MOMSN=11225316
2019-05-30T21:13:10.824Z,1559250790.824 [DataOverHttps](INFO): Sending 618 bytes from file Logs/20190530T210052/Express0005.lzma
2019-05-30T21:13:11.628Z,1559250791.628 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Express0005.lzma.bak
2019-05-30T21:13:11.629Z,1559250791.629 [DataOverHttps](INFO): SBD MOMSN=11225344
2019-05-30T21:13:13.021Z,1559250793.021 [Default:CheckIn:Read_Iridium] Stopped
2019-05-30T21:13:13.021Z,1559250793.021 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-30T21:13:13.021Z,1559250793.021 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-30T21:18:13.574Z,1559251093.574 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-30T21:18:13.574Z,1559251093.574 [Default:CheckIn:C.Wait] Stopped
2019-05-30T21:18:13.574Z,1559251093.574 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-30T21:18:13.574Z,1559251093.574 [Default:CheckIn:D] Running Loop=1
2019-05-30T21:18:13.990Z,1559251093.990 [Default:CheckIn:D] Stopped
2019-05-30T21:18:13.990Z,1559251093.990 [Default:CheckIn:E] Running Loop=1
2019-05-30T21:18:14.394Z,1559251094.394 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 13.615491 min 
2019-05-30T21:18:14.394Z,1559251094.394 [Default:CheckIn:E] Stopped
2019-05-30T21:18:14.395Z,1559251094.395 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-30T21:18:14.395Z,1559251094.395 [Default:CheckIn] Stopped
2019-05-30T21:18:14.399Z,1559251094.399 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-30T21:18:14.399Z,1559251094.399 [Default:CheckIn](INFO): Running loop #2
2019-05-30T21:18:14.399Z,1559251094.399 [Default:CheckIn] Running Loop=2
2019-05-30T21:18:14.399Z,1559251094.399 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-30T21:18:14.399Z,1559251094.399 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-30T21:18:15.983Z,1559251095.983 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:18:16.375Z,1559251096.375 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211810.00,A,3648.16933,N,12147.28352,W,0.039,143.11,300519,,,A*7D
2019-05-30T21:18:16.377Z,1559251096.377 [NAL9602](INFO): GPS fix at 20190530T211810: (36.802822, -121.788059)
2019-05-30T21:18:16.412Z,1559251096.412 [Default:CheckIn:Read_GPS] Stopped
2019-05-30T21:18:16.412Z,1559251096.412 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-30T21:18:22.719Z,1559251102.719 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20190530T210052/Courier0007.lzma
2019-05-30T21:18:23.524Z,1559251103.524 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Courier0007.lzma.bak
2019-05-30T21:18:23.525Z,1559251103.525 [DataOverHttps](INFO): SBD MOMSN=11225350
2019-05-30T21:18:36.026Z,1559251116.026 [DataOverHttps](INFO): Sending 1355 bytes from file Logs/20190530T210052/Express0008.lzma
2019-05-30T21:18:36.829Z,1559251116.829 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Express0008.lzma.bak
2019-05-30T21:18:36.829Z,1559251116.829 [DataOverHttps](INFO): SBD MOMSN=11225353
2019-05-30T21:18:38.034Z,1559251118.034 [Default:CheckIn:Read_Iridium] Stopped
2019-05-30T21:18:38.034Z,1559251118.034 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-30T21:18:38.034Z,1559251118.034 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-30T21:21:26.099Z,1559251286.099 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-05-30T21:21:26.099Z,1559251286.099 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19053014305028,35.0, -0.1,   0.0,144

2019-05-30T21:21:35.808Z,1559251295.808 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-05-30T21:21:35.809Z,1559251295.809 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-32768,-32768,-32BE,-32768,-32768,-32768,V
2019-05-30T21:21:45.507Z,1559251305.507 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2019-05-30T21:21:45.507Z,1559251305.507 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-32768,-3268,V
2019-05-30T21:21:48.686Z,1559251308.686 [NAL9602](INFO): SBD MO Status=2, MOMSN=5589, MT Status=2, MTMSN=0
2019-05-30T21:21:48.686Z,1559251308.686 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-30T21:22:47.675Z,1559251367.675 [NAL9602](INFO): SBD MO Status=2, MOMSN=5589, MT Status=2, MTMSN=0
2019-05-30T21:22:47.675Z,1559251367.675 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-30T21:23:14.335Z,1559251394.335 [NAL9602](INFO): SBD MO Status=2, MOMSN=5589, MT Status=2, MTMSN=0
2019-05-30T21:23:14.335Z,1559251394.335 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-30T21:23:18.369Z,1559251398.369 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-05-30T21:23:38.621Z,1559251418.621 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-30T21:23:38.621Z,1559251418.621 [Default:CheckIn:C.Wait] Stopped
2019-05-30T21:23:38.621Z,1559251418.621 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-30T21:23:38.621Z,1559251418.621 [Default:CheckIn:D] Running Loop=1
2019-05-30T21:23:39.001Z,1559251419.001 [Default:CheckIn:D] Stopped
2019-05-30T21:23:39.001Z,1559251419.001 [Default:CheckIn:E] Running Loop=1
2019-05-30T21:23:39.413Z,1559251419.413 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 19.032351 min 
2019-05-30T21:23:39.413Z,1559251419.413 [Default:CheckIn:E] Stopped
2019-05-30T21:23:39.414Z,1559251419.414 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-30T21:23:39.414Z,1559251419.414 [Default:CheckIn] Stopped
2019-05-30T21:23:39.414Z,1559251419.414 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-30T21:23:39.415Z,1559251419.415 [Default:CheckIn](INFO): Running loop #3
2019-05-30T21:23:39.415Z,1559251419.415 [Default:CheckIn] Running Loop=3
2019-05-30T21:23:39.416Z,1559251419.416 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-30T21:23:39.416Z,1559251419.416 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-30T21:23:41.007Z,1559251421.007 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:23:41.406Z,1559251421.406 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212335.00,A,3648.16919,N,12147.28737,W,0.214,0.00,300519,,,A*76
2019-05-30T21:23:41.408Z,1559251421.408 [NAL9602](INFO): GPS fix at 20190530T212335: (36.802820, -121.788123)
2019-05-30T21:23:41.442Z,1559251421.442 [Default:CheckIn:Read_GPS] Stopped
2019-05-30T21:23:41.442Z,1559251421.442 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-30T21:23:47.315Z,1559251427.315 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190530T210052/Courier0010.lzma
2019-05-30T21:23:48.120Z,1559251428.120 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Courier0010.lzma.bak
2019-05-30T21:23:48.121Z,1559251428.121 [DataOverHttps](INFO): SBD MOMSN=11225356
2019-05-30T21:24:00.580Z,1559251440.580 [DataOverHttps](INFO): Sending 888 bytes from file Logs/20190530T210052/Express0011.lzma
2019-05-30T21:24:01.384Z,1559251441.384 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Express0011.lzma.bak
2019-05-30T21:24:01.385Z,1559251441.385 [DataOverHttps](INFO): SBD MOMSN=11225359
2019-05-30T21:24:02.440Z,1559251442.440 [Default:CheckIn:Read_Iridium] Stopped
2019-05-30T21:24:02.440Z,1559251442.440 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-30T21:24:02.440Z,1559251442.440 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-30T21:24:13.721Z,1559251453.721 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-30T21:26:10.906Z,1559251570.906 [RDI_Pathfinder](ERROR): Failed to parse:
68,-32768,-32768,V
2019-05-30T21:27:21.633Z,1559251641.633 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2019-05-30T21:27:21.633Z,1559251641.633 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-32768,32768,V
2019-05-30T21:29:03.031Z,1559251743.031 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-30T21:29:03.031Z,1559251743.031 [Default:CheckIn:C.Wait] Stopped
2019-05-30T21:29:03.031Z,1559251743.031 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-30T21:29:03.031Z,1559251743.031 [Default:CheckIn:D] Running Loop=1
2019-05-30T21:29:03.410Z,1559251743.410 [Default:CheckIn:D] Stopped
2019-05-30T21:29:03.410Z,1559251743.410 [Default:CheckIn:E] Running Loop=1
2019-05-30T21:29:03.842Z,1559251743.842 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 24.439164 min 
2019-05-30T21:29:03.842Z,1559251743.842 [Default:CheckIn:E] Stopped
2019-05-30T21:29:03.842Z,1559251743.842 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-30T21:29:03.842Z,1559251743.842 [Default:CheckIn] Stopped
2019-05-30T21:29:03.842Z,1559251743.842 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-30T21:29:03.842Z,1559251743.842 [Default:CheckIn](INFO): Running loop #4
2019-05-30T21:29:03.842Z,1559251743.842 [Default:CheckIn] Running Loop=4
2019-05-30T21:29:03.842Z,1559251743.842 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-30T21:29:03.843Z,1559251743.843 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-30T21:29:05.427Z,1559251745.427 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:29:05.815Z,1559251745.815 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212859.00,A,3648.16585,N,12147.28026,W,0.214,0.00,300519,,,A*79
2019-05-30T21:29:05.817Z,1559251745.817 [NAL9602](INFO): GPS fix at 20190530T212859: (36.802764, -121.788004)
2019-05-30T21:29:05.840Z,1559251745.840 [Default:CheckIn:Read_GPS] Stopped
2019-05-30T21:29:05.840Z,1559251745.840 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-30T21:29:12.442Z,1559251752.442 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190530T210052/Courier0013.lzma
2019-05-30T21:29:13.248Z,1559251753.248 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Courier0013.lzma.bak
2019-05-30T21:29:13.249Z,1559251753.249 [DataOverHttps](INFO): SBD MOMSN=11225371
2019-05-30T21:29:25.784Z,1559251765.784 [DataOverHttps](INFO): Sending 582 bytes from file Logs/20190530T210052/Express0014.lzma
2019-05-30T21:29:26.589Z,1559251766.589 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Express0014.lzma.bak
2019-05-30T21:29:26.589Z,1559251766.589 [DataOverHttps](INFO): SBD MOMSN=11225374
2019-05-30T21:29:28.066Z,1559251768.066 [Default:CheckIn:Read_Iridium] Stopped
2019-05-30T21:29:28.066Z,1559251768.066 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-30T21:29:28.066Z,1559251768.066 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-30T21:29:36.513Z,1559251776.513 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2019-05-30T21:29:36.587Z,1559251776.587 [NAL9602](FAULT): received: 
+SBDI: 2, 5589, 2, 0, 0, 0

OK
2019-05-30T21:29:36.587Z,1559251776.587 [NAL9602] Data Fault, FailCount= 1
2019-05-30T21:29:36.587Z,1559251776.587 [NAL9602](ERROR): Data Fault
2019-05-30T21:29:36.693Z,1559251776.693 [CBIT](ERROR): Data Fault in component: NAL9602
2019-05-30T21:29:36.921Z,1559251776.921 [NAL9602](INFO): Powering down
2019-05-30T21:29:37.793Z,1559251777.793 [CBIT](INFO): Clearing failed state for component NAL9602
2019-05-30T21:29:37.793Z,1559251777.793 [NAL9602] No Fault, FailCount= 1
2019-05-30T21:30:07.217Z,1559251807.217 [NAL9602](INFO): Powering up NAL9602
2019-05-30T21:30:18.125Z,1559251818.125 [NAL9602](INFO): NAL9602 initialized
2019-05-30T21:30:49.254Z,1559251849.254 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-30T21:32:42.807Z,1559251962.807 [RDI_Pathfinder](ERROR): only read -1 of 1 data item for BIT error
2019-05-30T21:32:42.807Z,1559251962.807 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19053014420728,

2019-05-30T21:33:04.611Z,1559251984.611 [RDI_Pathfinder](ERROR): Failed to parse:     +0.65,       -0.05,        +0.56,   0.00,547.99
2019-05-30T21:34:08.507Z,1559252048.507 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout
2019-05-30T21:34:08.507Z,1559252048.507 [RDI_Pathfinder] Communications Fault, FailCount= 1
2019-05-30T21:34:08.507Z,1559252048.507 [RDI_Pathfinder](ERROR): Communications Fault
2019-05-30T21:34:08.508Z,1559252048.508 [RDI_Pathfinder](ERROR): Failed to parse:
2019-05-30T21:34:08.531Z,1559252048.531 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2019-05-30T21:34:08.895Z,1559252048.895 [RDI_Pathfinder](INFO): Powering down
2019-05-30T21:34:09.655Z,1559252049.655 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2019-05-30T21:34:09.655Z,1559252049.655 [RDI_Pathfinder] No Fault, FailCount= 1
2019-05-30T21:34:22.987Z,1559252062.987 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-05-30T21:34:28.632Z,1559252068.632 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-30T21:34:28.632Z,1559252068.632 [Default:CheckIn:C.Wait] Stopped
2019-05-30T21:34:28.632Z,1559252068.632 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-30T21:34:28.632Z,1559252068.632 [Default:CheckIn:D] Running Loop=1
2019-05-30T21:34:29.050Z,1559252069.050 [Default:CheckIn:D] Stopped
2019-05-30T21:34:29.050Z,1559252069.050 [Default:CheckIn:E] Running Loop=1
2019-05-30T21:34:29.443Z,1559252069.443 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.866492 min 
2019-05-30T21:34:29.443Z,1559252069.443 [Default:CheckIn:E] Stopped
2019-05-30T21:34:29.443Z,1559252069.443 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-30T21:34:29.444Z,1559252069.444 [Default:CheckIn] Stopped
2019-05-30T21:34:29.444Z,1559252069.444 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-30T21:34:29.444Z,1559252069.444 [Default:CheckIn](INFO): Running loop #5
2019-05-30T21:34:29.444Z,1559252069.444 [Default:CheckIn] Running Loop=5
2019-05-30T21:34:29.444Z,1559252069.444 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-30T21:34:29.444Z,1559252069.444 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-30T21:34:31.047Z,1559252071.047 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:34:33.049Z,1559252073.049 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-05-30T21:34:33.875Z,1559252073.875 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:34:36.699Z,1559252076.699 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:34:39.531Z,1559252079.531 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:34:42.763Z,1559252082.763 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:34:45.595Z,1559252085.595 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:34:48.827Z,1559252088.827 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:34:51.647Z,1559252091.647 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:34:54.879Z,1559252094.879 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:34:56.945Z,1559252096.945 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2019-05-30T21:34:56.946Z,1559252096.946 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-32768,32768,V
2019-05-30T21:34:57.727Z,1559252097.727 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:35:00.943Z,1559252100.943 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:35:03.771Z,1559252103.771 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:35:07.003Z,1559252107.003 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:35:09.831Z,1559252109.831 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:35:12.659Z,1559252112.659 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:35:15.483Z,1559252115.483 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:35:18.723Z,1559252118.723 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:35:21.547Z,1559252121.547 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:35:24.783Z,1559252124.783 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:35:27.603Z,1559252127.603 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:35:30.835Z,1559252130.835 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:35:33.663Z,1559252133.663 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:35:36.491Z,1559252136.491 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:35:39.723Z,1559252139.723 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:35:42.551Z,1559252142.551 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:35:45.783Z,1559252145.783 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:35:48.615Z,1559252148.615 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:35:51.843Z,1559252151.843 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:35:54.671Z,1559252154.671 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:35:57.503Z,1559252157.503 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:36:00.735Z,1559252160.735 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:36:03.559Z,1559252163.559 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:36:06.795Z,1559252166.795 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:36:09.635Z,1559252169.635 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:36:12.855Z,1559252172.855 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:36:15.683Z,1559252175.683 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:36:18.507Z,1559252178.507 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:36:21.743Z,1559252181.743 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:36:24.567Z,1559252184.567 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:36:27.803Z,1559252187.803 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:36:30.631Z,1559252190.631 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:36:33.455Z,1559252193.455 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:36:36.687Z,1559252196.687 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:36:39.515Z,1559252199.515 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:36:42.751Z,1559252202.751 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:36:45.579Z,1559252205.579 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:36:48.811Z,1559252208.811 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:36:51.639Z,1559252211.639 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:36:54.467Z,1559252214.467 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:36:57.699Z,1559252217.699 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:37:00.527Z,1559252220.527 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:37:03.755Z,1559252223.755 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:37:06.587Z,1559252226.587 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:37:09.819Z,1559252229.819 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:37:12.647Z,1559252232.647 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:37:15.875Z,1559252235.875 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:37:18.703Z,1559252238.703 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:37:21.531Z,1559252241.531 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:37:24.767Z,1559252244.767 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:37:27.595Z,1559252247.595 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:37:30.827Z,1559252250.827 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:37:33.651Z,1559252253.651 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:37:36.483Z,1559252256.483 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:37:39.715Z,1559252259.715 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:37:42.543Z,1559252262.543 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:37:45.779Z,1559252265.779 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:37:48.599Z,1559252268.599 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:37:51.831Z,1559252271.831 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:37:54.663Z,1559252274.663 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:37:57.895Z,1559252277.895 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:38:00.723Z,1559252280.723 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:38:03.551Z,1559252283.551 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:38:06.779Z,1559252286.779 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:38:09.611Z,1559252289.611 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:38:12.843Z,1559252292.843 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:38:15.671Z,1559252295.671 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:38:18.903Z,1559252298.903 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:38:21.731Z,1559252301.731 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:38:24.555Z,1559252304.555 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:38:27.787Z,1559252307.787 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:38:28.179Z,1559252308.179 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213821.00,A,3648.17929,N,12147.27385,W,1.808,163.65,300519,,,A*78
2019-05-30T21:38:28.181Z,1559252308.181 [NAL9602](INFO): GPS fix at 20190530T213821: (36.802988, -121.787897)
2019-05-30T21:38:28.245Z,1559252308.245 [Default:CheckIn:Read_GPS] Stopped
2019-05-30T21:38:28.245Z,1559252308.245 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-30T21:38:34.538Z,1559252314.538 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190530T210052/Courier0016.lzma
2019-05-30T21:38:35.345Z,1559252315.345 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Courier0016.lzma.bak
2019-05-30T21:38:35.345Z,1559252315.345 [DataOverHttps](INFO): SBD MOMSN=11225426
2019-05-30T21:38:52.488Z,1559252332.488 [DataOverHttps](INFO): Sending 998 bytes from file Logs/20190530T210052/Express0017.lzma
2019-05-30T21:38:53.293Z,1559252333.293 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Express0017.lzma.bak
2019-05-30T21:38:53.293Z,1559252333.293 [DataOverHttps](INFO): SBD MOMSN=11225430
2019-05-30T21:38:55.053Z,1559252335.053 [Default:CheckIn:Read_Iridium] Stopped
2019-05-30T21:38:55.053Z,1559252335.053 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-30T21:38:55.053Z,1559252335.053 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-30T21:39:00.270Z,1559252340.270 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-30T21:41:25.824Z,1559252485.824 [CommandLine](IMPORTANT): got command burn on
2019-05-30T21:41:25.824Z,1559252485.824 [CommandLine](IMPORTANT): Activating dropweight wire
2019-05-30T21:41:31.425Z,1559252491.425 [CommandLine](IMPORTANT): got command burn off
2019-05-30T21:41:31.425Z,1559252491.425 [CommandLine](IMPORTANT): Deactivating dropweight wire
2019-05-30T21:43:55.642Z,1559252635.642 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-30T21:43:55.642Z,1559252635.642 [Default:CheckIn:C.Wait] Stopped
2019-05-30T21:43:55.642Z,1559252635.642 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-30T21:43:55.642Z,1559252635.642 [Default:CheckIn:D] Running Loop=1
2019-05-30T21:43:56.062Z,1559252636.062 [Default:CheckIn:D] Stopped
2019-05-30T21:43:56.062Z,1559252636.062 [Default:CheckIn:E] Running Loop=1
2019-05-30T21:43:56.454Z,1559252636.454 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.316699 min 
2019-05-30T21:43:56.455Z,1559252636.455 [Default:CheckIn:E] Stopped
2019-05-30T21:43:56.455Z,1559252636.455 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-30T21:43:56.455Z,1559252636.455 [Default:CheckIn] Stopped
2019-05-30T21:43:56.455Z,1559252636.455 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-30T21:43:56.455Z,1559252636.455 [Default:CheckIn](INFO): Running loop #6
2019-05-30T21:43:56.455Z,1559252636.455 [Default:CheckIn] Running Loop=6
2019-05-30T21:43:56.456Z,1559252636.455 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-30T21:43:56.456Z,1559252636.456 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-30T21:43:58.055Z,1559252638.055 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:43:58.447Z,1559252638.447 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214352.00,A,3648.16409,N,12147.27481,W,0.097,163.65,300519,,,A*72
2019-05-30T21:43:58.449Z,1559252638.449 [NAL9602](INFO): GPS fix at 20190530T214352: (36.802735, -121.787914)
2019-05-30T21:43:58.486Z,1559252638.486 [Default:CheckIn:Read_GPS] Stopped
2019-05-30T21:43:58.486Z,1559252638.486 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-30T21:44:04.554Z,1559252644.554 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190530T210052/Courier0019.lzma
2019-05-30T21:44:05.360Z,1559252645.360 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Courier0019.lzma.bak
2019-05-30T21:44:05.361Z,1559252645.361 [DataOverHttps](INFO): SBD MOMSN=11225436
2019-05-30T21:44:21.360Z,1559252661.360 [DataOverHttps](INFO): Sending 650 bytes from file Logs/20190530T210052/Express0020.lzma
2019-05-30T21:44:22.165Z,1559252662.165 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Express0020.lzma.bak
2019-05-30T21:44:22.165Z,1559252662.165 [DataOverHttps](INFO): SBD MOMSN=11225440
2019-05-30T21:44:23.254Z,1559252663.254 [Default:CheckIn:Read_Iridium] Stopped
2019-05-30T21:44:23.254Z,1559252663.254 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-30T21:44:23.254Z,1559252663.254 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-30T21:44:25.643Z,1559252665.643 [NAL9602](INFO): SBD MO Status=0, MOMSN=5589, MT Status=0, MTMSN=0
2019-05-30T21:44:25.643Z,1559252665.643 [NAL9602](INFO): No messages in MT queue
2019-05-30T21:44:56.349Z,1559252696.349 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-30T21:49:23.830Z,1559252963.830 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-30T21:49:23.831Z,1559252963.831 [Default:CheckIn:C.Wait] Stopped
2019-05-30T21:49:23.831Z,1559252963.831 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-30T21:49:23.831Z,1559252963.831 [Default:CheckIn:D] Running Loop=1
2019-05-30T21:49:24.243Z,1559252964.243 [Default:CheckIn:D] Stopped
2019-05-30T21:49:24.247Z,1559252964.247 [Default:CheckIn:E] Running Loop=1
2019-05-30T21:49:24.627Z,1559252964.627 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 44.786112 min 
2019-05-30T21:49:24.628Z,1559252964.628 [Default:CheckIn:E] Stopped
2019-05-30T21:49:24.628Z,1559252964.628 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-30T21:49:24.628Z,1559252964.628 [Default:CheckIn] Stopped
2019-05-30T21:49:24.628Z,1559252964.628 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-30T21:49:24.628Z,1559252964.628 [Default:CheckIn](INFO): Running loop #7
2019-05-30T21:49:24.628Z,1559252964.628 [Default:CheckIn] Running Loop=7
2019-05-30T21:49:24.628Z,1559252964.628 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-30T21:49:24.628Z,1559252964.628 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-30T21:49:26.239Z,1559252966.239 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:49:26.623Z,1559252966.623 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214920.00,A,3648.16750,N,12147.28181,W,0.914,294.80,300519,,,A*7A
2019-05-30T21:49:26.626Z,1559252966.626 [NAL9602](INFO): GPS fix at 20190530T214920: (36.802792, -121.788030)
2019-05-30T21:49:26.662Z,1559252966.662 [Default:CheckIn:Read_GPS] Stopped
2019-05-30T21:49:26.663Z,1559252966.663 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-30T21:49:32.991Z,1559252972.991 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190530T210052/Courier0022.lzma
2019-05-30T21:49:33.797Z,1559252973.797 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Courier0022.lzma.bak
2019-05-30T21:49:33.797Z,1559252973.797 [DataOverHttps](INFO): SBD MOMSN=11225449
2019-05-30T21:49:46.335Z,1559252986.335 [DataOverHttps](INFO): Sending 576 bytes from file Logs/20190530T210052/Express0023.lzma
2019-05-30T21:49:47.141Z,1559252987.141 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Express0023.lzma.bak
2019-05-30T21:49:47.141Z,1559252987.141 [DataOverHttps](INFO): SBD MOMSN=11225452
2019-05-30T21:49:48.636Z,1559252988.636 [Default:CheckIn:Read_Iridium] Stopped
2019-05-30T21:49:48.636Z,1559252988.636 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-30T21:49:48.636Z,1559252988.636 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-30T21:50:56.446Z,1559253056.446 [NAL9602](INFO): SBD MO Status=0, MOMSN=5590, MT Status=0, MTMSN=0
2019-05-30T21:50:56.447Z,1559253056.447 [NAL9602](INFO): No messages in MT queue
2019-05-30T21:51:27.145Z,1559253087.145 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-30T21:53:40.110Z,1559253220.110 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2019-05-30T21:53:40.110Z,1559253220.110 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-32768,-32768,
2019-05-30T21:53:48.993Z,1559253228.993 [RDI_Pathfinder](ERROR): Failed to parse:
:8,-32768,-32768,V
2019-05-30T21:54:49.192Z,1559253289.192 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-30T21:54:49.192Z,1559253289.192 [Default:CheckIn:C.Wait] Stopped
2019-05-30T21:54:49.192Z,1559253289.192 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-30T21:54:49.192Z,1559253289.192 [Default:CheckIn:D] Running Loop=1
2019-05-30T21:54:49.578Z,1559253289.578 [Default:CheckIn:D] Stopped
2019-05-30T21:54:49.579Z,1559253289.579 [Default:CheckIn:E] Running Loop=1
2019-05-30T21:54:49.976Z,1559253289.976 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 50.208639 min 
2019-05-30T21:54:49.976Z,1559253289.976 [Default:CheckIn:E] Stopped
2019-05-30T21:54:49.976Z,1559253289.976 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-30T21:54:49.976Z,1559253289.976 [Default:CheckIn] Stopped
2019-05-30T21:54:49.976Z,1559253289.976 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-30T21:54:49.977Z,1559253289.977 [Default:CheckIn](INFO): Running loop #8
2019-05-30T21:54:49.977Z,1559253289.977 [Default:CheckIn] Running Loop=8
2019-05-30T21:54:49.977Z,1559253289.977 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-30T21:54:49.977Z,1559253289.977 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-30T21:54:51.587Z,1559253291.587 [NAL9602](DEBUG): Fix Requested
2019-05-30T21:54:51.975Z,1559253291.975 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215446.00,A,3648.14588,N,12147.23081,W,0.039,47.25,300519,,,A*4C
2019-05-30T21:54:51.977Z,1559253291.977 [NAL9602](INFO): GPS fix at 20190530T215446: (36.802431, -121.787180)
2019-05-30T21:54:52.024Z,1559253292.024 [Default:CheckIn:Read_GPS] Stopped
2019-05-30T21:54:52.024Z,1559253292.024 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-30T21:54:58.382Z,1559253298.382 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190530T210052/Courier0025.lzma
2019-05-30T21:54:59.189Z,1559253299.189 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Courier0025.lzma.bak
2019-05-30T21:54:59.189Z,1559253299.189 [DataOverHttps](INFO): SBD MOMSN=11225574
2019-05-30T21:55:02.890Z,1559253302.890 [NAL9602](INFO): SBD MO Status=0, MOMSN=5591, MT Status=0, MTMSN=0
2019-05-30T21:55:02.890Z,1559253302.890 [NAL9602](INFO): No messages in MT queue
2019-05-30T21:55:12.307Z,1559253312.307 [DataOverHttps](INFO): Sending 560 bytes from file Logs/20190530T210052/Express0026.lzma
2019-05-30T21:55:13.113Z,1559253313.113 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Express0026.lzma.bak
2019-05-30T21:55:13.113Z,1559253313.113 [DataOverHttps](INFO): SBD MOMSN=11225577
2019-05-30T21:55:14.234Z,1559253314.234 [Default:CheckIn:Read_Iridium] Stopped
2019-05-30T21:55:14.234Z,1559253314.234 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-30T21:55:14.234Z,1559253314.234 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-30T21:55:33.585Z,1559253333.585 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-30T22:00:14.798Z,1559253614.798 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-30T22:00:14.798Z,1559253614.798 [Default:CheckIn:C.Wait] Stopped
2019-05-30T22:00:14.798Z,1559253614.798 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-30T22:00:14.798Z,1559253614.798 [Default:CheckIn:D] Running Loop=1
2019-05-30T22:00:15.210Z,1559253615.210 [Default:CheckIn:D] Stopped
2019-05-30T22:00:15.210Z,1559253615.210 [Default:CheckIn:E] Running Loop=1
2019-05-30T22:00:15.601Z,1559253615.601 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 55.635832 min 
2019-05-30T22:00:15.601Z,1559253615.601 [Default:CheckIn:E] Stopped
2019-05-30T22:00:15.601Z,1559253615.601 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-30T22:00:15.601Z,1559253615.601 [Default:CheckIn] Stopped
2019-05-30T22:00:15.601Z,1559253615.601 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-30T22:00:15.601Z,1559253615.601 [Default:CheckIn](INFO): Running loop #9
2019-05-30T22:00:15.602Z,1559253615.602 [Default:CheckIn] Running Loop=9
2019-05-30T22:00:15.602Z,1559253615.602 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-30T22:00:15.602Z,1559253615.602 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-30T22:00:17.211Z,1559253617.211 [NAL9602](DEBUG): Fix Requested
2019-05-30T22:00:17.603Z,1559253617.603 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220011.00,A,3648.14462,N,12147.22925,W,0.039,47.25,300519,,,D*4A
2019-05-30T22:00:17.605Z,1559253617.605 [NAL9602](INFO): GPS fix at 20190530T220011: (36.802410, -121.787154)
2019-05-30T22:00:17.628Z,1559253617.628 [Default:CheckIn:Read_GPS] Stopped
2019-05-30T22:00:17.629Z,1559253617.629 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-30T22:00:23.950Z,1559253623.950 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190530T210052/Courier0028.lzma
2019-05-30T22:00:24.757Z,1559253624.757 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Courier0028.lzma.bak
2019-05-30T22:00:24.757Z,1559253624.757 [DataOverHttps](INFO): SBD MOMSN=11225582
2019-05-30T22:00:33.834Z,1559253633.834 [NAL9602](INFO): SBD MO Status=0, MOMSN=5592, MT Status=0, MTMSN=0
2019-05-30T22:00:33.834Z,1559253633.834 [NAL9602](INFO): No messages in MT queue
2019-05-30T22:00:37.719Z,1559253637.719 [DataOverHttps](INFO): Sending 558 bytes from file Logs/20190530T210052/Express0029.lzma
2019-05-30T22:00:38.525Z,1559253638.525 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Express0029.lzma.bak
2019-05-30T22:00:38.525Z,1559253638.525 [DataOverHttps](INFO): SBD MOMSN=11225586
2019-05-30T22:00:39.914Z,1559253639.914 [Default:CheckIn:Read_Iridium] Stopped
2019-05-30T22:00:39.914Z,1559253639.914 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-30T22:00:39.914Z,1559253639.914 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-30T22:00:57.286Z,1559253657.286 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-05-30T22:00:57.286Z,1559253657.286 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19053015102177,31,   0.0,1448.9,  0
2019-05-30T22:01:04.533Z,1559253664.533 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-30T22:01:56.268Z,1559253716.268 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00,   0.00
2019-05-30T22:05:40.498Z,1559253940.498 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-30T22:05:40.498Z,1559253940.498 [Default:CheckIn:C.Wait] Stopped
2019-05-30T22:05:40.498Z,1559253940.498 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-30T22:05:40.498Z,1559253940.498 [Default:CheckIn:D] Running Loop=1
2019-05-30T22:05:40.898Z,1559253940.898 [Default:CheckIn:D] Stopped
2019-05-30T22:05:40.898Z,1559253940.898 [Default:CheckIn:E] Running Loop=1
2019-05-30T22:05:41.315Z,1559253941.315 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 61.063965 min 
2019-05-30T22:05:41.315Z,1559253941.315 [Default:CheckIn:E] Stopped
2019-05-30T22:05:41.315Z,1559253941.315 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-30T22:05:41.315Z,1559253941.315 [Default:CheckIn] Stopped
2019-05-30T22:05:41.315Z,1559253941.315 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-30T22:05:41.316Z,1559253941.316 [Default:CheckIn](INFO): Running loop #10
2019-05-30T22:05:41.316Z,1559253941.316 [Default:CheckIn] Running Loop=10
2019-05-30T22:05:41.316Z,1559253941.316 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-30T22:05:41.316Z,1559253941.316 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-30T22:05:42.911Z,1559253942.911 [NAL9602](DEBUG): Fix Requested
2019-05-30T22:05:43.299Z,1559253943.299 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220537.00,A,3648.16587,N,12147.21584,W,0.058,24.35,300519,,,D*44
2019-05-30T22:05:43.301Z,1559253943.301 [NAL9602](INFO): GPS fix at 20190530T220537: (36.802765, -121.786931)
2019-05-30T22:05:43.325Z,1559253943.325 [Default:CheckIn:Read_GPS] Stopped
2019-05-30T22:05:43.325Z,1559253943.325 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-30T22:05:49.655Z,1559253949.655 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190530T210052/Courier0031.lzma
2019-05-30T22:05:50.461Z,1559253950.461 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Courier0031.lzma.bak
2019-05-30T22:05:50.461Z,1559253950.461 [DataOverHttps](INFO): SBD MOMSN=11225593
2019-05-30T22:05:56.626Z,1559253956.626 [NAL9602](INFO): SBD MO Status=0, MOMSN=5593, MT Status=0, MTMSN=0
2019-05-30T22:05:56.626Z,1559253956.626 [NAL9602](INFO): No messages in MT queue
2019-05-30T22:06:03.807Z,1559253963.807 [DataOverHttps](INFO): Sending 559 bytes from file Logs/20190530T210052/Express0032.lzma
2019-05-30T22:06:04.613Z,1559253964.613 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Express0032.lzma.bak
2019-05-30T22:06:04.613Z,1559253964.613 [DataOverHttps](INFO): SBD MOMSN=11225596
2019-05-30T22:06:05.989Z,1559253965.989 [Default:CheckIn:Read_Iridium] Stopped
2019-05-30T22:06:05.989Z,1559253965.989 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-30T22:06:05.989Z,1559253965.989 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-30T22:06:27.345Z,1559253987.345 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-30T22:08:42.028Z,1559254122.028 [DataOverHttps](IMPORTANT): SBD MTMSN=20190530T220835
2019-05-30T22:08:47.568Z,1559254127.568 [DataOverHttps](INFO): Received command:Ibit
2019-05-30T22:08:47.636Z,1559254127.636 [CommandLine](IMPORTANT): got command ibit
2019-05-30T22:08:47.996Z,1559254127.996 [IBIT](IMPORTANT): Beginning Initiated BIT
2019-05-30T22:08:47.996Z,1559254127.996 [IBIT](IMPORTANT): Beginning control surface checks.
2019-05-30T22:08:47.999Z,1559254127.999 [CBIT](IMPORTANT): Beginning ground fault scan
2019-05-30T22:08:49.159Z,1559254129.159 [NAL9602](DEBUG): Fix Requested
2019-05-30T22:08:49.551Z,1559254129.551 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220843.00,A,3648.16419,N,12147.21511,W,0.039,142.52,300519,,,D*77
2019-05-30T22:08:49.553Z,1559254129.553 [NAL9602](INFO): GPS fix at 20190530T220843: (36.802737, -121.786918)
2019-05-30T22:08:58.878Z,1559254138.878 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.120060
CHAN A1 (24V): -0.027380
CHAN A2 (12V): -0.006711
CHAN A3 (5V): -0.001492
CHAN B0 (3.3V): 0.000391
CHAN B1 (3.15aV): -0.000010
CHAN B2 (3.15bV): 0.000102
CHAN B3 (GND): 0.002177
OPEN: 0.005241
Full Scale Calc: 4.765 mA, -1.589 mA
2019-05-30T22:09:00.866Z,1559254140.866 [NAL9602](INFO): SBD MO Status=0, MOMSN=5594, MT Status=0, MTMSN=0
2019-05-30T22:09:00.867Z,1559254140.867 [NAL9602](INFO): No messages in MT queue
2019-05-30T22:09:01.683Z,1559254141.683 [NAL9602](DEBUG): Fix Requested
2019-05-30T22:09:02.079Z,1559254142.079 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220856.00,A,3648.16432,N,12147.21462,W,0.058,142.52,300519,,,D*78
2019-05-30T22:09:02.081Z,1559254142.081 [NAL9602](INFO): GPS fix at 20190530T220856: (36.802739, -121.786910)
2019-05-30T22:09:04.936Z,1559254144.936 [NAL9602](DEBUG): Fix Requested
2019-05-30T22:09:05.322Z,1559254145.322 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220859.00,A,3648.16421,N,12147.21474,W,0.097,142.52,300519,,,D*71
2019-05-30T22:09:05.325Z,1559254145.325 [NAL9602](INFO): GPS fix at 20190530T220859: (36.802737, -121.786912)
2019-05-30T22:09:07.739Z,1559254147.739 [NAL9602](DEBUG): Fix Requested
2019-05-30T22:09:08.139Z,1559254148.139 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220902.00,A,3648.16393,N,12147.21481,W,0.019,142.52,300519,,,D*7C
2019-05-30T22:09:08.141Z,1559254148.141 [NAL9602](INFO): GPS fix at 20190530T220902: (36.802732, -121.786913)
2019-05-30T22:09:10.987Z,1559254150.987 [NAL9602](DEBUG): Fix Requested
2019-05-30T22:09:11.364Z,1559254151.364 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220905.00,A,3648.16394,N,12147.21489,W,0.019,142.52,300519,,,D*74
2019-05-30T22:09:11.366Z,1559254151.366 [NAL9602](INFO): GPS fix at 20190530T220905: (36.802732, -121.786915)
2019-05-30T22:09:13.807Z,1559254153.807 [NAL9602](DEBUG): Fix Requested
2019-05-30T22:09:14.199Z,1559254154.199 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220908.00,A,3648.16390,N,12147.21510,W,0.117,142.52,300519,,,D*73
2019-05-30T22:09:14.201Z,1559254154.201 [NAL9602](INFO): GPS fix at 20190530T220908: (36.802732, -121.786918)
2019-05-30T22:09:17.039Z,1559254157.039 [NAL9602](DEBUG): Fix Requested
2019-05-30T22:09:17.427Z,1559254157.427 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220911.00,A,3648.16391,N,12147.21516,W,0.097,142.52,300519,,,D*75
2019-05-30T22:09:17.429Z,1559254157.429 [NAL9602](INFO): GPS fix at 20190530T220911: (36.802732, -121.786919)
2019-05-30T22:09:19.863Z,1559254159.863 [NAL9602](DEBUG): Fix Requested
2019-05-30T22:09:20.255Z,1559254160.255 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220914.00,A,3648.16397,N,12147.21513,W,0.019,142.52,300519,,,D*75
2019-05-30T22:09:20.257Z,1559254160.257 [NAL9602](INFO): GPS fix at 20190530T220914: (36.802733, -121.786919)
2019-05-30T22:09:22.691Z,1559254162.691 [NAL9602](DEBUG): Fix Requested
2019-05-30T22:09:23.083Z,1559254163.083 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220917.00,A,3648.16393,N,12147.21512,W,0.019,142.52,300519,,,D*73
2019-05-30T22:09:23.085Z,1559254163.085 [NAL9602](INFO): GPS fix at 20190530T220917: (36.802732, -121.786919)
2019-05-30T22:09:25.931Z,1559254165.931 [NAL9602](DEBUG): Fix Requested
2019-05-30T22:09:26.320Z,1559254166.320 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220920.00,A,3648.16388,N,12147.21515,W,0.175,142.52,300519,,,D*71
2019-05-30T22:09:26.322Z,1559254166.322 [NAL9602](INFO): GPS fix at 20190530T220920: (36.802731, -121.786919)
2019-05-30T22:09:28.755Z,1559254168.755 [NAL9602](DEBUG): Fix Requested
2019-05-30T22:09:29.143Z,1559254169.143 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220923.00,A,3648.16395,N,12147.21525,W,0.058,142.52,300519,,,D*73
2019-05-30T22:09:29.145Z,1559254169.145 [NAL9602](INFO): GPS fix at 20190530T220923: (36.802732, -121.786921)
2019-05-30T22:09:31.983Z,1559254171.983 [NAL9602](DEBUG): Fix Requested
2019-05-30T22:09:32.379Z,1559254172.379 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220926.00,A,3648.16376,N,12147.21528,W,0.097,142.52,300519,,,D*75
2019-05-30T22:09:32.381Z,1559254172.381 [NAL9602](INFO): GPS fix at 20190530T220926: (36.802729, -121.786921)
2019-05-30T22:09:34.035Z,1559254174.035 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 2
Latitude: 36.802731 Longitude: -121.786919
2019-05-30T22:09:34.429Z,1559254174.429 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 0.000000
2019-05-30T22:09:34.429Z,1559254174.429 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2019-05-30T22:09:34.429Z,1559254174.429 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2019-05-30T22:09:34.842Z,1559254174.842 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2019-05-30T22:09:34.842Z,1559254174.842 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2019-05-30T22:09:34.842Z,1559254174.842 [IBIT](IMPORTANT): Pressure:9.393606 PSI
2019-05-30T22:09:34.843Z,1559254174.843 [IBIT](IMPORTANT): Humidity:7.166402 %
2019-05-30T22:09:35.249Z,1559254175.249 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2019-05-30T22:09:35.249Z,1559254175.249 [IBIT](IMPORTANT): buoyancyNeutral: 190.000000 cc
2019-05-30T22:09:35.250Z,1559254175.250 [IBIT](IMPORTANT): massDefault: 0.500000 cm
2019-05-30T22:09:35.250Z,1559254175.250 [IBIT](IMPORTANT): stopDepth: 215.000000 m
2019-05-30T22:09:35.250Z,1559254175.250 [IBIT](IMPORTANT): abortDepth: 255.000000 m
2019-05-30T22:09:35.250Z,1559254175.250 [IBIT](IMPORTANT): IBIT PASSED
2019-05-30T22:09:48.982Z,1559254188.982 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-05-30T22:09:48.982Z,1559254188.982 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00
2019-05-30T22:10:04.693Z,1559254204.693 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-30T22:11:00.093Z,1559254260.093 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-05-30T22:11:00.093Z,1559254260.093 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19053015202477,35.0,-32768,-32768,-32768,V
2019-05-30T22:11:06.538Z,1559254266.538 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-30T22:11:06.538Z,1559254266.538 [Default:CheckIn:C.Wait] Stopped
2019-05-30T22:11:06.538Z,1559254266.538 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-30T22:11:06.538Z,1559254266.538 [Default:CheckIn:D] Running Loop=1
2019-05-30T22:11:06.982Z,1559254266.982 [Default:CheckIn:D] Stopped
2019-05-30T22:11:06.982Z,1559254266.982 [Default:CheckIn:E] Running Loop=1
2019-05-30T22:11:07.363Z,1559254267.363 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 66.498698 min 
2019-05-30T22:11:07.363Z,1559254267.363 [Default:CheckIn:E] Stopped
2019-05-30T22:11:07.364Z,1559254267.364 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-30T22:11:07.364Z,1559254267.364 [Default:CheckIn] Stopped
2019-05-30T22:11:07.364Z,1559254267.364 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-30T22:11:07.364Z,1559254267.364 [Default:CheckIn](INFO): Running loop #11
2019-05-30T22:11:07.364Z,1559254267.364 [Default:CheckIn] Running Loop=11
2019-05-30T22:11:07.364Z,1559254267.364 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-30T22:11:07.364Z,1559254267.364 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-30T22:11:08.943Z,1559254268.943 [NAL9602](DEBUG): Fix Requested
2019-05-30T22:11:09.343Z,1559254269.343 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221103.00,A,3648.16484,N,12147.21435,W,0.078,142.52,300519,,,D*7D
2019-05-30T22:11:09.345Z,1559254269.345 [NAL9602](INFO): GPS fix at 20190530T221103: (36.802747, -121.786906)
2019-05-30T22:11:09.378Z,1559254269.378 [Default:CheckIn:Read_GPS] Stopped
2019-05-30T22:11:09.379Z,1559254269.379 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-30T22:11:16.358Z,1559254276.358 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190530T210052/Courier0034.lzma
2019-05-30T22:11:17.165Z,1559254277.165 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Courier0034.lzma.bak
2019-05-30T22:11:17.165Z,1559254277.165 [DataOverHttps](INFO): SBD MOMSN=11225631
2019-05-30T22:11:29.322Z,1559254289.322 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190530T210052/Courier0037.lzma
2019-05-30T22:11:30.129Z,1559254290.129 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Courier0037.lzma.bak
2019-05-30T22:11:30.129Z,1559254290.129 [DataOverHttps](INFO): SBD MOMSN=11225635
2019-05-30T22:11:33.978Z,1559254293.978 [NAL9602](INFO): SBD MO Status=2, MOMSN=5595, MT Status=2, MTMSN=0
2019-05-30T22:11:33.979Z,1559254293.979 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-30T22:11:42.577Z,1559254302.577 [DataOverHttps](INFO): Sending 1217 bytes from file Logs/20190530T210052/Express0035.lzma
2019-05-30T22:11:43.381Z,1559254303.381 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Express0035.lzma.bak
2019-05-30T22:11:43.381Z,1559254303.381 [DataOverHttps](INFO): SBD MOMSN=11225644
2019-05-30T22:11:51.354Z,1559254311.354 [NAL9602](INFO): SBD MO Status=2, MOMSN=5595, MT Status=2, MTMSN=0
2019-05-30T22:11:51.354Z,1559254311.354 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-30T22:11:55.887Z,1559254315.887 [DataOverHttps](INFO): Sending 53 bytes from file Logs/20190530T210052/Express0038.lzma
2019-05-30T22:11:56.685Z,1559254316.685 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Express0038.lzma.bak
2019-05-30T22:11:56.685Z,1559254316.685 [DataOverHttps](INFO): SBD MOMSN=11225667
2019-05-30T22:11:57.862Z,1559254317.862 [Default:CheckIn:Read_Iridium] Stopped
2019-05-30T22:11:57.862Z,1559254317.862 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-30T22:11:57.867Z,1559254317.867 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-30T22:12:11.183Z,1559254331.183 [NAL9602](INFO): SBD MO Status=2, MOMSN=5595, MT Status=2, MTMSN=0
2019-05-30T22:12:11.184Z,1559254331.184 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-30T22:12:37.026Z,1559254357.026 [NAL9602](INFO): SBD MO Status=2, MOMSN=5595, MT Status=2, MTMSN=0
2019-05-30T22:12:37.027Z,1559254357.027 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-30T22:13:03.313Z,1559254383.313 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2019-05-30T22:13:03.314Z,1559254383.314 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-32768,-32768,
2019-05-30T22:13:20.656Z,1559254400.656 [NAL9602](INFO): SBD MO Status=2, MOMSN=5595, MT Status=2, MTMSN=0
2019-05-30T22:13:20.656Z,1559254400.656 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-30T22:13:37.213Z,1559254417.213 [NAL9602](INFO): SBD MO Status=2, MOMSN=5595, MT Status=2, MTMSN=0
2019-05-30T22:13:37.213Z,1559254417.213 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-30T22:14:01.863Z,1559254441.863 [NAL9602](INFO): SBD MO Status=2, MOMSN=5595, MT Status=2, MTMSN=0
2019-05-30T22:14:01.863Z,1559254441.863 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-30T22:14:33.776Z,1559254473.776 [NAL9602](INFO): SBD MO Status=0, MOMSN=5595, MT Status=0, MTMSN=0
2019-05-30T22:14:33.777Z,1559254473.777 [NAL9602](INFO): No messages in MT queue
2019-05-30T22:15:04.481Z,1559254504.481 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-30T22:16:58.438Z,1559254618.438 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-30T22:16:58.438Z,1559254618.438 [Default:CheckIn:C.Wait] Stopped
2019-05-30T22:16:58.438Z,1559254618.438 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-30T22:16:58.438Z,1559254618.438 [Default:CheckIn:D] Running Loop=1
2019-05-30T22:16:58.842Z,1559254618.842 [Default:CheckIn:D] Stopped
2019-05-30T22:16:58.842Z,1559254618.842 [Default:CheckIn:E] Running Loop=1
2019-05-30T22:16:59.254Z,1559254619.254 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 72.363029 min 
2019-05-30T22:16:59.254Z,1559254619.254 [Default:CheckIn:E] Stopped
2019-05-30T22:16:59.254Z,1559254619.254 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-30T22:16:59.254Z,1559254619.254 [Default:CheckIn] Stopped
2019-05-30T22:16:59.255Z,1559254619.255 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-30T22:16:59.255Z,1559254619.255 [Default:CheckIn](INFO): Running loop #12
2019-05-30T22:16:59.255Z,1559254619.255 [Default:CheckIn] Running Loop=12
2019-05-30T22:16:59.255Z,1559254619.255 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-30T22:16:59.255Z,1559254619.255 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-30T22:17:00.847Z,1559254620.847 [NAL9602](DEBUG): Fix Requested
2019-05-30T22:17:01.266Z,1559254621.266 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221655.00,A,3648.28586,N,12147.12052,W,4.587,2.43,300519,,,D*76
2019-05-30T22:17:01.279Z,1559254621.279 [NAL9602](INFO): GPS fix at 20190530T221655: (36.804764, -121.785342)
2019-05-30T22:17:01.312Z,1559254621.312 [Default:CheckIn:Read_GPS] Stopped
2019-05-30T22:17:01.312Z,1559254621.312 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-30T22:17:07.590Z,1559254627.590 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190530T210052/Courier0040.lzma
2019-05-30T22:17:08.397Z,1559254628.397 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Courier0040.lzma.bak
2019-05-30T22:17:08.397Z,1559254628.397 [DataOverHttps](INFO): SBD MOMSN=11225705
2019-05-30T22:17:16.678Z,1559254636.678 [NAL9602](INFO): SBD MO Status=0, MOMSN=5596, MT Status=0, MTMSN=0
2019-05-30T22:17:16.679Z,1559254636.679 [NAL9602](INFO): No messages in MT queue
2019-05-30T22:17:20.984Z,1559254640.984 [DataOverHttps](INFO): Sending 590 bytes from file Logs/20190530T210052/Express0041.lzma
2019-05-30T22:17:21.789Z,1559254641.789 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Express0041.lzma.bak
2019-05-30T22:17:21.789Z,1559254641.789 [DataOverHttps](INFO): SBD MOMSN=11225708
2019-05-30T22:17:23.194Z,1559254643.194 [Default:CheckIn:Read_Iridium] Stopped
2019-05-30T22:17:23.194Z,1559254643.194 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-30T22:17:23.194Z,1559254643.194 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-30T22:17:47.389Z,1559254667.389 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-30T22:19:53.052Z,1559254793.052 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2019-05-30T22:19:53.052Z,1559254793.052 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.0D,        +0.00,        +0.00,        +0.00,   0.00,2728.67
2019-05-30T22:20:57.289Z,1559254857.289 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-05-30T22:20:57.289Z,1559254857.289 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00
2019-05-30T22:21:52.648Z,1559254912.648 [RDI_Pathfinder](ERROR): only read 0 of 4 data items
2019-05-30T22:21:52.649Z,1559254912.649 [RDI_Pathfinder](ERROR): Failed to parse:
:RA   0.00,   0.00,   0.00,   0.00
2019-05-30T22:22:23.754Z,1559254943.754 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-30T22:22:23.754Z,1559254943.754 [Default:CheckIn:C.Wait] Stopped
2019-05-30T22:22:23.755Z,1559254943.755 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-30T22:22:23.755Z,1559254943.755 [Default:CheckIn:D] Running Loop=1
2019-05-30T22:22:24.154Z,1559254944.154 [Default:CheckIn:D] Stopped
2019-05-30T22:22:24.154Z,1559254944.154 [Default:CheckIn:E] Running Loop=1
2019-05-30T22:22:24.550Z,1559254944.550 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 77.784896 min 
2019-05-30T22:22:24.550Z,1559254944.550 [Default:CheckIn:E] Stopped
2019-05-30T22:22:24.551Z,1559254944.551 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-30T22:22:24.551Z,1559254944.551 [Default:CheckIn] Stopped
2019-05-30T22:22:24.551Z,1559254944.551 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-30T22:22:24.551Z,1559254944.551 [Default:CheckIn](INFO): Running loop #13
2019-05-30T22:22:24.551Z,1559254944.551 [Default:CheckIn] Running Loop=13
2019-05-30T22:22:24.551Z,1559254944.551 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-30T22:22:24.551Z,1559254944.551 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-30T22:22:26.163Z,1559254946.163 [NAL9602](DEBUG): Fix Requested
2019-05-30T22:22:26.547Z,1559254946.547 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222220.00,A,3648.34931,N,12147.61443,W,7.814,269.93,300519,,,A*7D
2019-05-30T22:22:26.549Z,1559254946.549 [NAL9602](INFO): GPS fix at 20190530T222220: (36.805822, -121.793574)
2019-05-30T22:22:26.598Z,1559254946.598 [Default:CheckIn:Read_GPS] Stopped
2019-05-30T22:22:26.598Z,1559254946.598 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-30T22:22:33.583Z,1559254953.583 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190530T210052/Courier0043.lzma
2019-05-30T22:22:34.389Z,1559254954.389 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Courier0043.lzma.bak
2019-05-30T22:22:34.389Z,1559254954.389 [DataOverHttps](INFO): SBD MOMSN=11225719
2019-05-30T22:22:46.927Z,1559254966.927 [DataOverHttps](INFO): Sending 570 bytes from file Logs/20190530T210052/Express0044.lzma
2019-05-30T22:22:47.733Z,1559254967.733 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Express0044.lzma.bak
2019-05-30T22:22:47.733Z,1559254967.733 [DataOverHttps](INFO): SBD MOMSN=11225722
2019-05-30T22:22:48.794Z,1559254968.794 [Default:CheckIn:Read_Iridium] Stopped
2019-05-30T22:22:48.795Z,1559254968.795 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-30T22:22:48.795Z,1559254968.795 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-30T22:23:19.471Z,1559254999.471 [NAL9602](INFO): SBD MO Status=2, MOMSN=5597, MT Status=2, MTMSN=0
2019-05-30T22:23:19.471Z,1559254999.471 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-30T22:23:26.339Z,1559255006.339 [NAL9602](INFO): SBD MO Status=0, MOMSN=5597, MT Status=0, MTMSN=0
2019-05-30T22:23:26.339Z,1559255006.339 [NAL9602](INFO): No messages in MT queue
2019-05-30T22:23:57.045Z,1559255037.045 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-30T22:27:49.371Z,1559255269.371 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-30T22:27:49.371Z,1559255269.371 [Default:CheckIn:C.Wait] Stopped
2019-05-30T22:27:49.371Z,1559255269.371 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-30T22:27:49.371Z,1559255269.371 [Default:CheckIn:D] Running Loop=1
2019-05-30T22:27:49.778Z,1559255269.778 [Default:CheckIn:D] Stopped
2019-05-30T22:27:49.778Z,1559255269.778 [Default:CheckIn:E] Running Loop=1
2019-05-30T22:27:50.190Z,1559255270.190 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 83.211963 min 
2019-05-30T22:27:50.190Z,1559255270.190 [Default:CheckIn:E] Stopped
2019-05-30T22:27:50.190Z,1559255270.190 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-30T22:27:50.190Z,1559255270.190 [Default:CheckIn] Stopped
2019-05-30T22:27:50.190Z,1559255270.190 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-30T22:27:50.190Z,1559255270.190 [Default:CheckIn](INFO): Running loop #14
2019-05-30T22:27:50.190Z,1559255270.190 [Default:CheckIn] Running Loop=14
2019-05-30T22:27:50.190Z,1559255270.190 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-30T22:27:50.191Z,1559255270.191 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-30T22:27:51.787Z,1559255271.787 [NAL9602](DEBUG): Fix Requested
2019-05-30T22:27:52.179Z,1559255272.179 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222746.00,A,3648.56537,N,12148.39781,W,8.086,298.53,300519,,,A*77
2019-05-30T22:27:52.181Z,1559255272.181 [NAL9602](INFO): GPS fix at 20190530T222746: (36.809423, -121.806630)
2019-05-30T22:27:52.245Z,1559255272.245 [Default:CheckIn:Read_GPS] Stopped
2019-05-30T22:27:52.245Z,1559255272.245 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-30T22:27:58.318Z,1559255278.318 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190530T210052/Courier0046.lzma
2019-05-30T22:27:59.125Z,1559255279.125 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Courier0046.lzma.bak
2019-05-30T22:27:59.125Z,1559255279.125 [DataOverHttps](INFO): SBD MOMSN=11225736
2019-05-30T22:28:05.674Z,1559255285.674 [NAL9602](INFO): SBD MO Status=0, MOMSN=5598, MT Status=0, MTMSN=0
2019-05-30T22:28:05.674Z,1559255285.674 [NAL9602](INFO): No messages in MT queue
2019-05-30T22:28:14.755Z,1559255294.755 [DataOverHttps](INFO): Sending 570 bytes from file Logs/20190530T210052/Express0047.lzma
2019-05-30T22:28:15.561Z,1559255295.561 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Express0047.lzma.bak
2019-05-30T22:28:15.561Z,1559255295.561 [DataOverHttps](INFO): SBD MOMSN=11225739
2019-05-30T22:28:17.050Z,1559255297.050 [Default:CheckIn:Read_Iridium] Stopped
2019-05-30T22:28:17.051Z,1559255297.051 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-30T22:28:17.051Z,1559255297.051 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-30T22:28:36.377Z,1559255316.377 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-30T22:28:44.914Z,1559255324.914 [RDI_Pathfinder](ERROR): Failed to parse:
68,-32768,-32768,V
2019-05-30T22:30:45.267Z,1559255445.267 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-05-30T22:30:45.267Z,1559255445.267 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19053015400977,35.0, -0.1,   0.0,10
2019-05-30T22:32:06.902Z,1559255526.902 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2019-05-30T22:32:06.902Z,1559255526.902 [RDI_Pathfinder](ERROR): Failed to parse:
:BD,        +     +0.00,        +0.00,   0.00,3463.49
2019-05-30T22:33:17.580Z,1559255597.580 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-30T22:33:17.580Z,1559255597.580 [Default:CheckIn:C.Wait] Stopped
2019-05-30T22:33:17.580Z,1559255597.580 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-30T22:33:17.580Z,1559255597.580 [Default:CheckIn:D] Running Loop=1
2019-05-30T22:33:17.994Z,1559255597.994 [Default:CheckIn:D] Stopped
2019-05-30T22:33:17.994Z,1559255597.994 [Default:CheckIn:E] Running Loop=1
2019-05-30T22:33:18.394Z,1559255598.394 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 88.682235 min 
2019-05-30T22:33:18.394Z,1559255598.394 [Default:CheckIn:E] Stopped
2019-05-30T22:33:18.395Z,1559255598.395 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-30T22:33:18.395Z,1559255598.395 [Default:CheckIn] Stopped
2019-05-30T22:33:18.395Z,1559255598.395 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-30T22:33:18.395Z,1559255598.395 [Default:CheckIn](INFO): Running loop #15
2019-05-30T22:33:18.395Z,1559255598.395 [Default:CheckIn] Running Loop=15
2019-05-30T22:33:18.395Z,1559255598.395 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-30T22:33:18.395Z,1559255598.395 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-30T22:33:19.995Z,1559255599.995 [NAL9602](DEBUG): Fix Requested
2019-05-30T22:33:20.391Z,1559255600.391 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223314.00,A,3648.79954,N,12149.12773,W,4.043,302.55,300519,,,A*75
2019-05-30T22:33:20.393Z,1559255600.393 [NAL9602](INFO): GPS fix at 20190530T223314: (36.813326, -121.818795)
2019-05-30T22:33:20.461Z,1559255600.461 [Default:CheckIn:Read_GPS] Stopped
2019-05-30T22:33:20.461Z,1559255600.461 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-30T22:33:26.578Z,1559255606.578 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190530T210052/Courier0049.lzma
2019-05-30T22:33:27.385Z,1559255607.385 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Courier0049.lzma.bak
2019-05-30T22:33:27.385Z,1559255607.385 [DataOverHttps](INFO): SBD MOMSN=11225774
2019-05-30T22:33:33.486Z,1559255613.486 [NAL9602](INFO): SBD MO Status=0, MOMSN=5599, MT Status=0, MTMSN=0
2019-05-30T22:33:33.487Z,1559255613.487 [NAL9602](INFO): No messages in MT queue
2019-05-30T22:33:39.908Z,1559255619.908 [DataOverHttps](INFO): Sending 572 bytes from file Logs/20190530T210052/Express0050.lzma
2019-05-30T22:33:40.713Z,1559255620.713 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Express0050.lzma.bak
2019-05-30T22:33:40.713Z,1559255620.713 [DataOverHttps](INFO): SBD MOMSN=11225777
2019-05-30T22:33:41.994Z,1559255621.994 [Default:CheckIn:Read_Iridium] Stopped
2019-05-30T22:33:41.994Z,1559255621.994 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-30T22:33:41.994Z,1559255621.994 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-30T22:34:04.186Z,1559255644.186 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-30T22:35:58.967Z,1559255758.967 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2019-05-30T22:35:58.968Z,1559255758.968 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-32768,-3278,V
2019-05-30T22:38:42.581Z,1559255922.581 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-30T22:38:42.581Z,1559255922.581 [Default:CheckIn:C.Wait] Stopped
2019-05-30T22:38:42.581Z,1559255922.581 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-30T22:38:42.582Z,1559255922.582 [Default:CheckIn:D] Running Loop=1
2019-05-30T22:38:42.982Z,1559255922.982 [Default:CheckIn:D] Stopped
2019-05-30T22:38:42.982Z,1559255922.982 [Default:CheckIn:E] Running Loop=1
2019-05-30T22:38:43.382Z,1559255923.382 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 94.098698 min 
2019-05-30T22:38:43.382Z,1559255923.382 [Default:CheckIn:E] Stopped
2019-05-30T22:38:43.383Z,1559255923.383 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-30T22:38:43.383Z,1559255923.383 [Default:CheckIn] Stopped
2019-05-30T22:38:43.383Z,1559255923.383 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-30T22:38:43.383Z,1559255923.383 [Default:CheckIn](INFO): Running loop #16
2019-05-30T22:38:43.383Z,1559255923.383 [Default:CheckIn] Running Loop=16
2019-05-30T22:38:43.383Z,1559255923.383 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-30T22:38:43.384Z,1559255923.384 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-30T22:38:44.987Z,1559255924.987 [NAL9602](DEBUG): Fix Requested
2019-05-30T22:38:45.375Z,1559255925.375 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223839.00,A,3648.99366,N,12149.41731,W,1.847,97.48,300519,,,D*4B
2019-05-30T22:38:45.377Z,1559255925.377 [NAL9602](INFO): GPS fix at 20190530T223839: (36.816561, -121.823622)
2019-05-30T22:38:45.406Z,1559255925.406 [Default:CheckIn:Read_GPS] Stopped
2019-05-30T22:38:45.406Z,1559255925.406 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-30T22:38:51.790Z,1559255931.790 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190530T210052/Courier0052.lzma
2019-05-30T22:38:52.597Z,1559255932.597 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Courier0052.lzma.bak
2019-05-30T22:38:52.597Z,1559255932.597 [DataOverHttps](INFO): SBD MOMSN=11225783
2019-05-30T22:39:05.023Z,1559255945.023 [DataOverHttps](INFO): Sending 560 bytes from file Logs/20190530T210052/Express0053.lzma
2019-05-30T22:39:05.829Z,1559255945.829 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Express0053.lzma.bak
2019-05-30T22:39:05.829Z,1559255945.829 [DataOverHttps](INFO): SBD MOMSN=11225787
2019-05-30T22:39:06.938Z,1559255946.938 [Default:CheckIn:Read_Iridium] Stopped
2019-05-30T22:39:06.938Z,1559255946.938 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-30T22:39:06.938Z,1559255946.938 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-30T22:39:08.067Z,1559255948.067 [NAL9602](INFO): SBD MO Status=0, MOMSN=5600, MT Status=0, MTMSN=0
2019-05-30T22:39:08.067Z,1559255948.067 [NAL9602](INFO): No messages in MT queue
2019-05-30T22:39:38.769Z,1559255978.769 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-30T22:41:07.266Z,1559256067.266 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-05-30T22:41:07.267Z,1559256067.267 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19053015503177,35.0, -0.1,  8.9,  0
2019-05-30T22:44:07.454Z,1559256247.454 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-30T22:44:07.454Z,1559256247.454 [Default:CheckIn:C.Wait] Stopped
2019-05-30T22:44:07.454Z,1559256247.454 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-30T22:44:07.454Z,1559256247.454 [Default:CheckIn:D] Running Loop=1
2019-05-30T22:44:07.862Z,1559256247.862 [Default:CheckIn:D] Stopped
2019-05-30T22:44:07.862Z,1559256247.862 [Default:CheckIn:E] Running Loop=1
2019-05-30T22:44:08.271Z,1559256248.271 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 99.513371 min 
2019-05-30T22:44:08.272Z,1559256248.272 [Default:CheckIn:E] Stopped
2019-05-30T22:44:08.272Z,1559256248.272 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-30T22:44:08.272Z,1559256248.272 [Default:CheckIn] Stopped
2019-05-30T22:44:08.272Z,1559256248.272 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-30T22:44:08.272Z,1559256248.272 [Default:CheckIn](INFO): Running loop #17
2019-05-30T22:44:08.272Z,1559256248.272 [Default:CheckIn] Running Loop=17
2019-05-30T22:44:08.272Z,1559256248.272 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-30T22:44:08.272Z,1559256248.272 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-30T22:44:09.867Z,1559256249.867 [NAL9602](DEBUG): Fix Requested
2019-05-30T22:44:10.259Z,1559256250.259 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224404.00,A,3648.98161,N,12149.33930,W,1.147,61.08,300519,,,D*44
2019-05-30T22:44:10.261Z,1559256250.261 [NAL9602](INFO): GPS fix at 20190530T224404: (36.816360, -121.822322)
2019-05-30T22:44:10.345Z,1559256250.345 [Default:CheckIn:Read_GPS] Stopped
2019-05-30T22:44:10.345Z,1559256250.345 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-30T22:44:16.534Z,1559256256.534 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190530T210052/Courier0055.lzma
2019-05-30T22:44:17.745Z,1559256257.745 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Courier0055.lzma.bak
2019-05-30T22:44:17.745Z,1559256257.745 [DataOverHttps](INFO): SBD MOMSN=11225803
2019-05-30T22:44:31.868Z,1559256271.868 [DataOverHttps](INFO): Sending 558 bytes from file Logs/20190530T210052/Express0056.lzma
2019-05-30T22:44:32.673Z,1559256272.673 [DataOverHttps](INFO): Moved sent file to Logs/20190530T210052/Express0056.lzma.bak
2019-05-30T22:44:32.673Z,1559256272.673 [DataOverHttps](INFO): SBD MOMSN=11225806
2019-05-30T22:44:34.014Z,1559256274.014 [Default:CheckIn:Read_Iridium] Stopped
2019-05-30T22:44:34.014Z,1559256274.014 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-30T22:44:34.014Z,1559256274.014 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-30T22:44:44.910Z,1559256284.910 [NAL9602](INFO): SBD MO Status=2, MOMSN=5601, MT Status=2, MTMSN=0
2019-05-30T22:44:44.910Z,1559256284.910 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-30T22:44:59.030Z,1559256299.030 [NAL9602](INFO): SBD MO Status=0, MOMSN=5601, MT Status=0, MTMSN=0
2019-05-30T22:44:59.030Z,1559256299.030 [NAL9602](INFO): No messages in MT queue
2019-05-30T22:45:29.729Z,1559256329.729 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-30T22:49:17.211Z,1559256557.211 [RDI_Pathfinder](ERROR): only read 0 of 4 data items
2019-05-30T22:49:17.212Z,1559256557.212 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.        +5.12,       -0.62,  30.60,  0.00
2019-05-30T22:49:27.804Z,1559256567.804 [DataOverHttps](IMPORTANT): SBD MTMSN=20190530T224921