2018-06-01T18:39:44.193Z,1527878384.193 [Supervisor](DEBUG): Initializing supervisor.
2018-06-01T18:39:44.202Z,1527878384.202 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-06-01T18:39:44.202Z,1527878384.202 [SyncHandler](INFO): Protected caller Thread ID is 5266
2018-06-01T18:39:44.203Z,1527878384.203 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-06-01T18:39:44.203Z,1527878384.203 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-06-01T18:39:44.204Z,1527878384.204 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 5267
2018-06-01T18:39:44.207Z,1527878384.207 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-06-01T18:39:44.219Z,1527878384.219 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-06-01T18:39:44.220Z,1527878384.220 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-06-01T18:39:44.220Z,1527878384.220 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 5268
2018-06-01T18:39:44.221Z,1527878384.221 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-06-01T18:39:44.222Z,1527878384.222 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-06-01T18:39:44.222Z,1527878384.222 [logger ThreadHandler](INFO): Protected caller Thread ID is 5269
2018-06-01T18:39:44.224Z,1527878384.224 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-06-01T18:39:44.225Z,1527878384.225 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-06-01T18:39:44.226Z,1527878384.226 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-06-01T18:39:44.636Z,1527878384.636 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-06-01T18:39:44.636Z,1527878384.636 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-06-01T18:39:44.844Z,1527878384.844 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-06-01T18:39:44.844Z,1527878384.844 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-06-01T18:39:45.143Z,1527878385.143 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-06-01T18:39:45.144Z,1527878385.144 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-06-01T18:39:45.287Z,1527878385.287 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-06-01T18:39:45.288Z,1527878385.288 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-06-01T18:39:45.389Z,1527878385.389 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-06-01T18:39:45.390Z,1527878385.390 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-06-01T18:39:45.869Z,1527878385.869 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-06-01T18:39:45.869Z,1527878385.869 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-06-01T18:39:46.267Z,1527878386.267 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-06-01T18:39:46.268Z,1527878386.268 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-06-01T18:39:46.731Z,1527878386.731 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-06-01T18:39:46.731Z,1527878386.731 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-06-01T18:39:46.839Z,1527878386.839 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-06-01T18:39:46.840Z,1527878386.840 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-06-01T18:39:46.940Z,1527878386.940 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-06-01T18:39:46.941Z,1527878386.941 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-06-01T18:39:47.153Z,1527878387.153 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-06-01T18:39:47.154Z,1527878387.154 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-06-01T18:39:47.370Z,1527878387.370 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-06-01T18:39:47.371Z,1527878387.371 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-06-01T18:39:47.755Z,1527878387.755 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-06-01T18:39:47.755Z,1527878387.755 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-06-01T18:39:47.900Z,1527878387.900 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-06-01T18:39:47.901Z,1527878387.901 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-06-01T18:39:47.986Z,1527878387.986 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2018-06-01T18:39:47.987Z,1527878387.987 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2018-06-01T18:39:48.096Z,1527878388.096 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2018-06-01T18:39:48.218Z,1527878388.218 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2018-06-01T18:39:48.353Z,1527878388.353 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2018-06-01T18:39:48.442Z,1527878388.442 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2018-06-01T18:39:48.599Z,1527878388.599 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2018-06-01T18:39:48.810Z,1527878388.810 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2018-06-01T18:39:49.157Z,1527878389.157 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2018-06-01T18:39:49.955Z,1527878389.955 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-06-01T18:39:49.955Z,1527878389.955 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2018-06-01T18:39:50.042Z,1527878390.042 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2018-06-01T18:39:50.134Z,1527878390.134 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2018-06-01T18:39:50.237Z,1527878390.237 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2018-06-01T18:39:50.366Z,1527878390.366 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-06-01T18:39:50.378Z,1527878390.378 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-06-01T18:39:50.617Z,1527878390.617 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-06-01T18:39:50.618Z,1527878390.618 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-06-01T18:39:50.659Z,1527878390.659 [DepthRateCalculator] Loaded
2018-06-01T18:39:50.659Z,1527878390.659 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-06-01T18:39:50.665Z,1527878390.665 [PitchRateCalculator] Loaded
2018-06-01T18:39:50.665Z,1527878390.665 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-06-01T18:39:50.682Z,1527878390.682 [SpeedCalculator] Loaded
2018-06-01T18:39:50.682Z,1527878390.682 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-06-01T18:39:50.703Z,1527878390.703 [TempGradientCalculator] Loaded
2018-06-01T18:39:50.703Z,1527878390.703 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-06-01T18:39:50.718Z,1527878390.718 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2018-06-01T18:39:50.719Z,1527878390.719 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2018-06-01T18:39:50.724Z,1527878390.724 [YawRateCalculator] Loaded
2018-06-01T18:39:50.724Z,1527878390.724 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-06-01T18:39:50.763Z,1527878390.763 [ElevatorOffsetCalculator] Loaded
2018-06-01T18:39:50.764Z,1527878390.764 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-06-01T18:39:50.764Z,1527878390.764 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-06-01T18:39:50.765Z,1527878390.765 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-06-01T18:39:50.851Z,1527878390.851 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2018-06-01T18:39:50.851Z,1527878390.851 [StratificationFrontDetector](DEBUG): (re)initializing
2018-06-01T18:39:50.852Z,1527878390.852 [StratificationFrontDetector] Loaded
2018-06-01T18:39:50.852Z,1527878390.852 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2018-06-01T18:39:50.852Z,1527878390.852 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-06-01T18:39:50.853Z,1527878390.853 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-06-01T18:39:50.970Z,1527878390.970 [BuoyancyServo] Loaded
2018-06-01T18:39:50.970Z,1527878390.970 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-06-01T18:39:50.985Z,1527878390.985 [ElevatorServo] Loaded
2018-06-01T18:39:50.986Z,1527878390.986 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-06-01T18:39:51.000Z,1527878391.000 [MassServo] Loaded
2018-06-01T18:39:51.000Z,1527878391.000 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-06-01T18:39:51.016Z,1527878391.016 [RudderServo] Loaded
2018-06-01T18:39:51.016Z,1527878391.016 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-06-01T18:39:51.030Z,1527878391.030 [ThrusterServo] Loaded
2018-06-01T18:39:51.031Z,1527878391.031 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-06-01T18:39:51.031Z,1527878391.031 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-06-01T18:39:51.031Z,1527878391.031 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-06-01T18:39:51.045Z,1527878391.045 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-06-01T18:39:51.046Z,1527878391.046 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-06-01T18:39:51.146Z,1527878391.146 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-06-01T18:39:51.147Z,1527878391.147 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-06-01T18:39:51.477Z,1527878391.477 [DataOverHttps] Loaded
2018-06-01T18:39:51.478Z,1527878391.478 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-06-01T18:39:51.491Z,1527878391.491 [Depth_Keller] Loaded
2018-06-01T18:39:51.491Z,1527878391.491 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-06-01T18:39:51.496Z,1527878391.496 [DropWeight] Loaded
2018-06-01T18:39:51.496Z,1527878391.496 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-06-01T18:39:51.593Z,1527878391.593 [NAL9602] Loaded
2018-06-01T18:39:51.593Z,1527878391.593 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-06-01T18:39:51.609Z,1527878391.609 [Onboard] Loaded
2018-06-01T18:39:51.609Z,1527878391.609 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-06-01T18:39:51.619Z,1527878391.619 [Radio_Surface] Loaded
2018-06-01T18:39:51.620Z,1527878391.620 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-06-01T18:39:51.621Z,1527878391.621 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408844E0
2018-06-01T18:39:51.621Z,1527878391.621 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 5351
2018-06-01T18:39:51.668Z,1527878391.668 [PNI_TCM] Loaded
2018-06-01T18:39:51.669Z,1527878391.669 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-06-01T18:39:53.452Z,1527878393.452 [BPC1] Loaded
2018-06-01T18:39:53.452Z,1527878393.452 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-06-01T18:39:53.452Z,1527878393.452 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-06-01T18:39:53.453Z,1527878393.453 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-06-01T18:39:53.581Z,1527878393.581 [SBIT](DEBUG): Construct Startup Built In Test.
2018-06-01T18:39:53.603Z,1527878393.603 [SBIT] Loaded
2018-06-01T18:39:53.603Z,1527878393.603 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-06-01T18:39:53.604Z,1527878393.604 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-06-01T18:39:53.615Z,1527878393.615 [IBIT] Loaded
2018-06-01T18:39:53.615Z,1527878393.615 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-06-01T18:39:53.618Z,1527878393.618 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-06-01T18:39:53.766Z,1527878393.766 [CBIT] Loaded
2018-06-01T18:39:53.766Z,1527878393.766 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-06-01T18:39:53.767Z,1527878393.767 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-06-01T18:39:53.767Z,1527878393.767 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-06-01T18:39:53.914Z,1527878393.914 [Aanderaa_O2] Loaded
2018-06-01T18:39:53.914Z,1527878393.914 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-06-01T18:39:53.926Z,1527878393.926 [CANONSampler] Loaded
2018-06-01T18:39:53.926Z,1527878393.926 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2018-06-01T18:39:54.003Z,1527878394.003 [CTD_NeilBrown] Loaded
2018-06-01T18:39:54.003Z,1527878394.003 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2018-06-01T18:39:54.004Z,1527878394.004 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 409454E0
2018-06-01T18:39:54.005Z,1527878394.005 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 5353
2018-06-01T18:39:54.051Z,1527878394.051 [CTD_Seabird] Loaded
2018-06-01T18:39:54.051Z,1527878394.051 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2018-06-01T18:39:54.052Z,1527878394.052 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409754E0
2018-06-01T18:39:54.053Z,1527878394.053 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 5354
2018-06-01T18:39:54.069Z,1527878394.069 [ESPComponent] Loaded
2018-06-01T18:39:54.069Z,1527878394.069 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2018-06-01T18:39:54.083Z,1527878394.083 [PAR_Licor] Loaded
2018-06-01T18:39:54.083Z,1527878394.083 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-06-01T18:39:54.132Z,1527878394.132 [WetLabsBB2FL] Loaded
2018-06-01T18:39:54.132Z,1527878394.132 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-06-01T18:39:54.133Z,1527878394.133 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409A54E0
2018-06-01T18:39:54.134Z,1527878394.134 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 5355
2018-06-01T18:39:54.134Z,1527878394.134 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-06-01T18:39:54.135Z,1527878394.135 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-06-01T18:39:54.424Z,1527878394.424 [VerticalControl](DEBUG): Construct VerticalControl.
2018-06-01T18:39:54.591Z,1527878394.591 [VerticalControl] Loaded
2018-06-01T18:39:54.591Z,1527878394.591 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-06-01T18:39:54.592Z,1527878394.592 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-06-01T18:39:54.649Z,1527878394.649 [HorizontalControl] Loaded
2018-06-01T18:39:54.649Z,1527878394.649 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-06-01T18:39:54.650Z,1527878394.650 [SpeedControl](DEBUG): Construct SpeedControl.
2018-06-01T18:39:54.651Z,1527878394.651 [SpeedControl] Loaded
2018-06-01T18:39:54.651Z,1527878394.651 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-06-01T18:39:54.652Z,1527878394.652 [LoopControl](DEBUG): Construct LoopControl.
2018-06-01T18:39:54.653Z,1527878394.653 [LoopControl] Loaded
2018-06-01T18:39:54.653Z,1527878394.653 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-06-01T18:39:54.653Z,1527878394.653 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-06-01T18:39:54.654Z,1527878394.654 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-06-01T18:39:54.680Z,1527878394.680 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-06-01T18:39:54.681Z,1527878394.681 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-06-01T18:39:54.772Z,1527878394.772 [DeadReckonUsingSpeedCalculator] Loaded
2018-06-01T18:39:54.772Z,1527878394.772 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-06-01T18:39:54.788Z,1527878394.788 [NavChart] Loaded
2018-06-01T18:39:54.788Z,1527878394.788 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-06-01T18:39:54.792Z,1527878394.792 [UniversalFixResidualReporter] Loaded
2018-06-01T18:39:54.793Z,1527878394.793 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-06-01T18:39:54.793Z,1527878394.793 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-06-01T18:39:54.797Z,1527878394.797 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-06-01T18:39:54.798Z,1527878394.798 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-06-01T18:39:54.804Z,1527878394.804 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-06-01T18:39:54.805Z,1527878394.805 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A314E0
2018-06-01T18:39:54.806Z,1527878394.806 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 5356
2018-06-01T18:39:54.810Z,1527878394.810 [Supervisor](INFO): Main Thread ID is 1709
2018-06-01T18:39:54.811Z,1527878394.811 [Supervisor](DEBUG): Running supervisor.
2018-06-01T18:39:54.811Z,1527878394.811 [CommandLine ThreadHandler](INFO): Handler Thread ID is 5357
2018-06-01T18:39:54.814Z,1527878394.814 [controlThread ThreadHandler](INFO): Handler Thread ID is 5358
2018-06-01T18:39:54.814Z,1527878394.814 [controlThread](DEBUG): Initializing ControlThread
2018-06-01T18:39:54.815Z,1527878394.815 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-06-01T18:39:54.816Z,1527878394.816 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-06-01T18:39:54.816Z,1527878394.816 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-06-01T18:39:54.816Z,1527878394.816 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-06-01T18:39:54.817Z,1527878394.817 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2018-06-01T18:39:54.818Z,1527878394.818 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-06-01T18:39:54.818Z,1527878394.818 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-06-01T18:39:54.823Z,1527878394.823 [SBIT](INFO): Initialize SBIT Component.
2018-06-01T18:39:54.824Z,1527878394.824 [SBIT](IMPORTANT): git: 2018-06-01
2018-06-01T18:39:54.824Z,1527878394.824 [SBIT](INFO): git hash: b6e7f1a8450cf7df34d1c73e9128248be671e45d
2018-06-01T18:39:54.824Z,1527878394.824 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-06-01T18:39:54.826Z,1527878394.826 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
Kernel Reported: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-06-01T18:39:54.827Z,1527878394.827 [SBIT](INFO): Beginning SBIT in 23.000000 seconds.
2018-06-01T18:39:54.827Z,1527878394.827 [IBIT](INFO): Initialize IBIT Component.
2018-06-01T18:39:54.828Z,1527878394.828 [CBIT](DEBUG): Initialize CBIT Component.
2018-06-01T18:39:54.828Z,1527878394.828 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-06-01T18:39:54.829Z,1527878394.829 [logger ThreadHandler](INFO): Handler Thread ID is 5359
2018-06-01T18:39:54.849Z,1527878394.849 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 5360
2018-06-01T18:39:54.855Z,1527878394.855 [Radio_Surface](INFO): Powering up
2018-06-01T18:39:54.861Z,1527878394.861 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 5361
2018-06-01T18:39:54.862Z,1527878394.862 [CTD_NeilBrown](INFO): Powering down
2018-06-01T18:39:54.886Z,1527878394.886 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 5362
2018-06-01T18:39:54.887Z,1527878394.887 [CTD_Seabird](INFO): Initializing
2018-06-01T18:39:54.889Z,1527878394.889 [CTD_Seabird](INFO): Checking LCM
2018-06-01T18:39:54.902Z,1527878394.902 [CTD_Seabird](INFO): LCM OK
2018-06-01T18:39:54.902Z,1527878394.902 [CTD_Seabird](INFO): Powering up
2018-06-01T18:39:54.909Z,1527878394.909 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 5363
2018-06-01T18:39:54.911Z,1527878394.911 [WetLabsBB2FL](INFO): Powering down
2018-06-01T18:39:54.949Z,1527878394.949 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-06-01T18:39:54.951Z,1527878394.951 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-06-01T18:39:54.952Z,1527878394.952 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-06-01T18:39:54.952Z,1527878394.952 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-06-01T18:39:54.953Z,1527878394.953 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-06-01T18:39:54.954Z,1527878394.954 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-06-01T18:39:54.954Z,1527878394.954 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-06-01T18:39:54.955Z,1527878394.955 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-06-01T18:39:54.955Z,1527878394.955 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-06-01T18:39:54.956Z,1527878394.956 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-06-01T18:39:54.962Z,1527878394.962 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 5364
2018-06-01T18:39:54.975Z,1527878394.975 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-06-01T18:39:54.975Z,1527878394.975 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-06-01T18:39:54.975Z,1527878394.975 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-06-01T18:39:54.975Z,1527878394.975 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-06-01T18:39:54.976Z,1527878394.976 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-06-01T18:39:54.976Z,1527878394.976 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-06-01T18:39:54.976Z,1527878394.976 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-06-01T18:39:54.976Z,1527878394.976 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-06-01T18:39:54.976Z,1527878394.976 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-06-01T18:39:54.977Z,1527878394.977 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-06-01T18:39:54.977Z,1527878394.977 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-06-01T18:39:54.977Z,1527878394.977 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-06-01T18:39:54.978Z,1527878394.978 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-06-01T18:39:54.978Z,1527878394.978 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-06-01T18:39:54.978Z,1527878394.978 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-06-01T18:39:54.978Z,1527878394.978 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-06-01T18:39:55.009Z,1527878395.009 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-06-01T18:39:55.051Z,1527878395.051 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2018-06-01T18:39:55.052Z,1527878395.052 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-06-01T18:39:55.134Z,1527878395.134 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-06-01T18:39:55.135Z,1527878395.135 [Default:A.Wait](DEBUG): Construct Wait.
2018-06-01T18:39:55.153Z,1527878395.153 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-06-01T18:39:55.190Z,1527878395.190 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-06-01T18:39:55.192Z,1527878395.192 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-06-01T18:39:55.222Z,1527878395.222 [Default:E.Execute](DEBUG): Construct Execute.
2018-06-01T18:39:55.226Z,1527878395.226 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2018-06-01T18:39:55.233Z,1527878395.233 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,Aanderaa_O2,CANONSampler,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-06-01T18:39:55.264Z,1527878395.264 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-06-01T18:39:55.289Z,1527878395.289 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2018-06-01T18:39:55.527Z,1527878395.527 [CANONSampler](INFO): Powering down
2018-06-01T18:39:55.658Z,1527878395.658 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-06-01T18:39:55.771Z,1527878395.771 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-06-01T18:39:55.901Z,1527878395.901 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-06-01T18:39:55.909Z,1527878395.909 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-06-01T18:39:55.924Z,1527878395.924 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-06-01T18:39:55.930Z,1527878395.930 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-06-01T18:39:55.945Z,1527878395.945 [MassServo](DEBUG): Initializing EZServoServo.
2018-06-01T18:39:55.953Z,1527878395.953 [MassServo](DEBUG): Initializing MassServo.
2018-06-01T18:39:55.975Z,1527878395.975 [RudderServo](DEBUG): Initializing EZServoServo.
2018-06-01T18:39:55.981Z,1527878395.981 [RudderServo](DEBUG): Initializing RudderServo.
2018-06-01T18:39:56.005Z,1527878396.005 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-06-01T18:39:56.013Z,1527878396.013 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-06-01T18:39:56.255Z,1527878396.255 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2018-06-01T18:39:56.255Z,1527878396.255 [DropWeight] Hardware Fault, FailCount= 1
2018-06-01T18:39:56.255Z,1527878396.255 [DropWeight](ERROR): Hardware Fault
2018-06-01T18:39:56.325Z,1527878396.325 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-06-01T18:39:56.350Z,1527878396.350 [CommandLine](FAULT): Scheduling is paused
2018-06-01T18:39:56.351Z,1527878396.351 [CBIT](INFO): Critical error at 20180601T183956
2018-06-01T18:39:56.351Z,1527878396.351 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2018-06-01T18:39:56.354Z,1527878396.354 [CBIT](ERROR): Hardware Fault in component: DropWeight
2018-06-01T18:39:56.354Z,1527878396.354 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2018-06-01T18:39:56.563Z,1527878396.563 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-06-01T18:39:57.003Z,1527878397.003 [CBIT](INFO): Critical error at 20180601T183956
2018-06-01T18:39:57.079Z,1527878397.079 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-06-01T18:39:57.481Z,1527878397.481 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-06-01T18:39:57.893Z,1527878397.893 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-06-01T18:39:58.285Z,1527878398.285 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-06-01T18:39:58.769Z,1527878398.769 [Aanderaa_O2](INFO): Powering down
2018-06-01T18:39:58.867Z,1527878398.867 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-06-01T18:40:00.538Z,1527878400.538 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-06-01T18:40:00.636Z,1527878400.636 [CTD_Seabird](INFO): Started Seabird LCM interface with command:nohup ./lrauv-framework/onboard/bin/gpctd -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyC6 -b 9600 >& /dev/null &
2018-06-01T18:40:00.719Z,1527878400.719 [CTD_Seabird](INFO): LCM subscribed to channel:ctd_t.seabird-gpctd
2018-06-01T18:40:01.121Z,1527878401.121 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-06-01T18:40:01.121Z,1527878401.121 [CTD_Seabird](INFO): Powering down
2018-06-01T18:40:18.451Z,1527878418.451 [SBIT](IMPORTANT): Beginning Startup BIT
2018-06-01T18:40:18.455Z,1527878418.455 [CBIT](IMPORTANT): Beginning ground fault scan
2018-06-01T18:40:21.606Z,1527878421.606 [NAL9602](INFO): Powering up NAL9602
2018-06-01T18:40:29.743Z,1527878429.743 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.004724
CHAN A1 (24V): -0.008237
CHAN A2 (12V): -0.002286
CHAN A3 (5V): -0.001525
CHAN B0 (3.3V): -0.000343
CHAN B1 (3.15aV): -0.000711
CHAN B2 (3.15bV): -0.000126
CHAN B3 (GND): 0.000043
OPEN: -0.000538
Full Scale Calc: 4.765 mA, -1.589 mA
2018-06-01T18:40:32.406Z,1527878432.406 [NAL9602](INFO): NAL9602 initialized
2018-06-01T18:40:59.833Z,1527878459.833 [NAL9602](INFO): SBD MO Status=2, MOMSN=6092, MT Status=2, MTMSN=0
2018-06-01T18:40:59.833Z,1527878459.833 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T18:41:12.425Z,1527878472.425 [SBIT](IMPORTANT): SBIT PASSED
2018-06-01T18:41:12.468Z,1527878472.468 [CommandLine](IMPORTANT): got command configSet list
2018-06-01T18:41:12.469Z,1527878472.469 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-06-01T18:41:12.470Z,1527878472.470 [CommandLine](IMPORTANT): ESPComponent.loadAtStartup=1 bool;

2018-06-01T18:41:12.470Z,1527878472.470 [CommandLine](IMPORTANT): ESPComponent.simulateHardware=1 bool;

2018-06-01T18:41:12.470Z,1527878472.470 [CommandLine](IMPORTANT): NAL9602.loadAtStartup=1 bool;

2018-06-01T18:41:12.470Z,1527878472.470 [CommandLine](IMPORTANT): Normal linearApproximation CTD_NeilBrown.bin_mean_sea_water_salinity 0.020000 practical_salinity_unit;

2018-06-01T18:41:12.470Z,1527878472.470 [CommandLine](IMPORTANT): Normal linearApproximation CTD_NeilBrown.bin_mean_sea_water_temperature 0.150000 kelvin;

2018-06-01T18:41:12.470Z,1527878472.470 [CommandLine](IMPORTANT): Normal linearApproximation CTD_Seabird.bin_median_sea_water_salinity 0.020000 practical_salinity_unit;

2018-06-01T18:41:12.471Z,1527878472.471 [CommandLine](IMPORTANT): Normal linearApproximation CTD_Seabird.bin_median_sea_water_temperature 0.150000 kelvin;

2018-06-01T18:41:12.471Z,1527878472.471 [CommandLine](IMPORTANT): Normal linearApproximation WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water 0.100000 microgram_per_liter;

2018-06-01T18:41:12.471Z,1527878472.471 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=0 bool;

2018-06-01T18:41:12.760Z,1527878472.760 [NAL9602](INFO): SBD MO Status=2, MOMSN=6092, MT Status=2, MTMSN=0
2018-06-01T18:41:12.760Z,1527878472.760 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T18:41:12.830Z,1527878472.830 [MissionManager](IMPORTANT): Started mission Startup
2018-06-01T18:41:12.830Z,1527878472.830 [Startup] Running Loop=1
2018-06-01T18:41:12.830Z,1527878472.830 [Startup](DEBUG): Aggregate::initialize Startup
2018-06-01T18:41:12.831Z,1527878472.831 [Startup:A.GoToSurface] Running Loop=1
2018-06-01T18:41:12.831Z,1527878472.831 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-06-01T18:41:12.831Z,1527878472.831 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-06-01T18:41:12.832Z,1527878472.832 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-06-01T18:41:12.832Z,1527878472.832 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-06-01T18:41:12.833Z,1527878472.833 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-06-01T18:41:12.833Z,1527878472.833 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-06-01T18:41:12.839Z,1527878472.839 [Startup:StartupSatComms] Running Loop=1
2018-06-01T18:41:12.839Z,1527878472.839 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-06-01T18:41:12.839Z,1527878472.839 [Startup:StartupSatComms:A] Running Loop=1
2018-06-01T18:41:13.231Z,1527878473.231 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-06-01T18:41:47.160Z,1527878507.160 [NAL9602](INFO): SBD MO Status=2, MOMSN=6092, MT Status=2, MTMSN=0
2018-06-01T18:41:47.160Z,1527878507.160 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T18:42:13.204Z,1527878533.204 [Startup:StartupSatComms:A](INFO): Timed out from 2018-06-01T18:41:12.8Z
2018-06-01T18:42:13.204Z,1527878533.204 [Startup:StartupSatComms:A] Stopped
2018-06-01T18:42:13.204Z,1527878533.204 [Startup:StartupSatComms:B] Running Loop=1
2018-06-01T18:42:13.604Z,1527878533.604 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-06-01T18:42:55.201Z,1527878575.201 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-06-01T18:42:55.201Z,1527878575.201 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2018-06-01T18:42:55.201Z,1527878575.201 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-06-01T18:42:55.214Z,1527878575.214 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-06-01T18:42:55.613Z,1527878575.613 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-06-01T18:42:55.613Z,1527878575.613 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2018-06-01T18:42:56.011Z,1527878576.011 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-06-01T18:42:56.012Z,1527878576.012 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-06-01T18:42:56.012Z,1527878576.012 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-06-01T18:43:00.379Z,1527878580.379 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004278
2018-06-01T18:43:09.215Z,1527878589.215 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180531T201639/Courier0390.lzma
2018-06-01T18:43:10.008Z,1527878590.008 [DataOverHttps](INFO): Moved sent file to Logs/20180531T201639/Courier0390.lzma.bak
2018-06-01T18:43:10.008Z,1527878590.008 [DataOverHttps](INFO): SBD MOMSN=8303434
2018-06-01T18:43:14.004Z,1527878594.004 [Startup:StartupSatComms:B](INFO): Timed out from 2018-06-01T18:42:13.2Z
2018-06-01T18:43:14.004Z,1527878594.004 [Startup:StartupSatComms:B] Stopped
2018-06-01T18:43:14.004Z,1527878594.004 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-06-01T18:43:14.004Z,1527878594.004 [Startup:StartupSatComms] Stopped
2018-06-01T18:43:14.004Z,1527878594.004 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-06-01T18:43:14.005Z,1527878594.005 [Startup](INFO): Completed Startup
2018-06-01T18:43:14.006Z,1527878594.006 [MissionManager](INFO): Startup is completed.
2018-06-01T18:43:14.006Z,1527878594.006 [MissionManager](INFO): Uninitializing Mission Startup
2018-06-01T18:43:14.006Z,1527878594.006 [Startup] Stopped
2018-06-01T18:43:14.006Z,1527878594.006 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-06-01T18:43:14.006Z,1527878594.006 [Startup:A.GoToSurface] Stopped
2018-06-01T18:43:14.006Z,1527878594.006 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-06-01T18:43:14.134Z,1527878594.134 [MissionManager](IMPORTANT): Started mission Default
2018-06-01T18:43:14.134Z,1527878594.134 [Default] Running Loop=1
2018-06-01T18:43:14.134Z,1527878594.134 [Default](DEBUG): Aggregate::initialize Default
2018-06-01T18:43:14.134Z,1527878594.134 [Default:B.GoToSurface] Running Loop=1
2018-06-01T18:43:14.134Z,1527878594.134 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-06-01T18:43:14.135Z,1527878594.135 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-06-01T18:43:14.135Z,1527878594.135 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-06-01T18:43:14.135Z,1527878594.135 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-06-01T18:43:14.136Z,1527878594.136 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-06-01T18:43:14.136Z,1527878594.136 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-06-01T18:43:14.136Z,1527878594.136 [Default:A.Wait] Running Loop=1
2018-06-01T18:43:14.142Z,1527878594.142 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-06-01T18:43:18.840Z,1527878598.840 [DataOverHttps](INFO): Sending 136 bytes from file Logs/20180601T183943/Courier0000.lzma
2018-06-01T18:43:19.639Z,1527878599.639 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Courier0000.lzma.bak
2018-06-01T18:43:19.640Z,1527878599.640 [DataOverHttps](INFO): SBD MOMSN=8303445
2018-06-01T18:43:27.288Z,1527878607.288 [Default:A.Wait](INFO): Done Waiting.
2018-06-01T18:43:27.288Z,1527878607.288 [Default:A.Wait] Stopped
2018-06-01T18:43:27.288Z,1527878607.288 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-06-01T18:43:27.710Z,1527878607.710 [Default:CheckIn] Running Loop=1
2018-06-01T18:43:27.710Z,1527878607.710 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-06-01T18:43:27.711Z,1527878607.711 [Default:CheckIn:Read_GPS] Running Loop=1
2018-06-01T18:43:28.109Z,1527878608.109 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-06-01T18:45:35.626Z,1527878735.626 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-06-01T18:45:42.431Z,1527878742.431 [NAL9602](INFO): GPS fix at 20180601T184458: (36.802571, -121.787889)
2018-06-01T18:45:42.504Z,1527878742.504 [Default:CheckIn:Read_GPS] Stopped
2018-06-01T18:45:42.504Z,1527878742.504 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-06-01T18:45:42.884Z,1527878742.884 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-06-01T18:45:49.563Z,1527878749.563 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20180601T183943/Courier0004.lzma
2018-06-01T18:45:50.340Z,1527878750.340 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Courier0004.lzma.bak
2018-06-01T18:45:50.340Z,1527878750.340 [DataOverHttps](INFO): SBD MOMSN=8303465
2018-06-01T18:46:07.313Z,1527878767.313 [DataOverHttps](INFO): Sending 231 bytes from file Logs/20180531T201639/Express0391.lzma
2018-06-01T18:46:08.092Z,1527878768.092 [DataOverHttps](INFO): Moved sent file to Logs/20180531T201639/Express0391.lzma.bak
2018-06-01T18:46:08.093Z,1527878768.093 [DataOverHttps](INFO): SBD MOMSN=8303468
2018-06-01T18:46:20.276Z,1527878780.276 [NAL9602](INFO): Powering down
2018-06-01T18:46:20.388Z,1527878780.388 [DataOverHttps](INFO): Sending 835 bytes from file Logs/20180601T183943/Express0001.lzma
2018-06-01T18:46:21.187Z,1527878781.187 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Express0001.lzma.bak
2018-06-01T18:46:21.188Z,1527878781.188 [DataOverHttps](INFO): SBD MOMSN=8303473
2018-06-01T18:46:30.502Z,1527878790.502 [DataOverHttps](INFO): Sending 302 bytes from file Logs/20180601T183943/Express0005.lzma
2018-06-01T18:46:31.267Z,1527878791.267 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Express0005.lzma.bak
2018-06-01T18:46:31.267Z,1527878791.267 [DataOverHttps](INFO): SBD MOMSN=8303495
2018-06-01T18:46:32.376Z,1527878792.376 [Default:CheckIn:Read_Iridium] Stopped
2018-06-01T18:46:32.376Z,1527878792.376 [Default:CheckIn:C.Wait] Running Loop=1
2018-06-01T18:46:32.376Z,1527878792.376 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-06-01T18:47:21.274Z,1527878841.274 [BPC1](ERROR): Failed to receive data from both battery packs
2018-06-01T18:47:21.274Z,1527878841.274 [BPC1] Communications Fault, FailCount= 1
2018-06-01T18:47:21.274Z,1527878841.274 [BPC1](ERROR): Communications Fault
2018-06-01T18:47:21.301Z,1527878841.301 [CBIT](ERROR): Communications Fault in component: BPC1
2018-06-01T18:47:22.503Z,1527878842.503 [CBIT](INFO): Clearing failed state for component BPC1
2018-06-01T18:47:22.504Z,1527878842.504 [BPC1] No Fault, FailCount= 1
2018-06-01T18:49:25.822Z,1527878965.822 [BPC1](ERROR): Failed to parse message.
2018-06-01T18:49:25.822Z,1527878965.822 [BPC1](ERROR): Failed to parse Bank A battery data
2018-06-01T18:49:37.257Z,1527878977.257 [BPC1](ERROR): Failed to parse message.
2018-06-01T18:49:37.257Z,1527878977.257 [BPC1](ERROR): Failed to parse Bank A battery data
2018-06-01T18:51:32.519Z,1527879092.519 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-06-01T18:51:32.519Z,1527879092.519 [Default:CheckIn:C.Wait] Stopped
2018-06-01T18:51:32.519Z,1527879092.519 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-06-01T18:51:32.519Z,1527879092.519 [Default:CheckIn:D] Running Loop=1
2018-06-01T18:51:32.945Z,1527879092.945 [Default:CheckIn:D] Stopped
2018-06-01T18:51:32.945Z,1527879092.945 [Default:CheckIn:E] Running Loop=1
2018-06-01T18:51:33.320Z,1527879093.320 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 8.313362 min 
2018-06-01T18:51:33.322Z,1527879093.322 [Default:CheckIn:E] Stopped
2018-06-01T18:51:33.322Z,1527879093.322 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-06-01T18:51:33.322Z,1527879093.322 [Default:CheckIn] Stopped
2018-06-01T18:51:33.322Z,1527879093.322 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-06-01T18:51:33.322Z,1527879093.322 [Default:CheckIn](INFO): Running loop #2
2018-06-01T18:51:33.322Z,1527879093.322 [Default:CheckIn] Running Loop=2
2018-06-01T18:51:33.322Z,1527879093.322 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-06-01T18:51:33.323Z,1527879093.323 [Default:CheckIn:Read_GPS] Running Loop=1
2018-06-01T18:51:36.518Z,1527879096.518 [NAL9602](INFO): Powering up
2018-06-01T18:51:47.706Z,1527879107.706 [NAL9602](INFO): NAL9602 initialized
2018-06-01T18:52:19.706Z,1527879139.706 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2018-06-01T18:52:19.781Z,1527879139.781 [NAL9602](FAULT): received: 
+CSQ:0

OK92, 2, 0, 0, 0

OK
2018-06-01T18:52:19.781Z,1527879139.781 [NAL9602] Data Fault, FailCount= 1
2018-06-01T18:52:19.781Z,1527879139.781 [NAL9602](ERROR): Data Fault
2018-06-01T18:52:19.864Z,1527879139.864 [CBIT](ERROR): Data Fault in component: NAL9602
2018-06-01T18:52:20.106Z,1527879140.106 [NAL9602](INFO): Powering down
2018-06-01T18:52:20.972Z,1527879140.972 [CBIT](INFO): Clearing failed state for component NAL9602
2018-06-01T18:52:20.972Z,1527879140.972 [NAL9602] No Fault, FailCount= 1
2018-06-01T18:52:50.174Z,1527879170.174 [NAL9602](INFO): Powering up NAL9602
2018-06-01T18:53:00.974Z,1527879180.974 [NAL9602](INFO): NAL9602 initialized
2018-06-01T18:54:56.310Z,1527879296.310 [CBIT](INFO): Clearing failed state for component DropWeight
2018-06-01T18:54:56.311Z,1527879296.311 [DropWeight] No Fault, FailCount= 1
2018-06-01T18:56:33.712Z,1527879393.712 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-06-01T18:51:33.3Z
2018-06-01T18:56:33.712Z,1527879393.712 [Default:CheckIn:Read_GPS] Stopped
2018-06-01T18:56:33.712Z,1527879393.712 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-06-01T18:56:37.418Z,1527879397.418 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180601T183943/Courier0007.lzma
2018-06-01T18:56:37.935Z,1527879397.935 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Courier0007.lzma.bak
2018-06-01T18:56:37.935Z,1527879397.935 [DataOverHttps](INFO): SBD MOMSN=8303508
2018-06-01T18:56:47.268Z,1527879407.268 [DataOverHttps](INFO): Sending 194 bytes from file Logs/20180601T183943/Express0008.lzma
2018-06-01T18:56:48.035Z,1527879408.035 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Express0008.lzma.bak
2018-06-01T18:56:48.036Z,1527879408.036 [DataOverHttps](INFO): SBD MOMSN=8303510
2018-06-01T18:56:49.165Z,1527879409.165 [Default:CheckIn:Read_Iridium] Stopped
2018-06-01T18:56:49.165Z,1527879409.165 [Default:CheckIn:C.Wait] Running Loop=1
2018-06-01T18:56:49.165Z,1527879409.165 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-06-01T18:56:52.330Z,1527879412.330 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-06-01T18:57:22.806Z,1527879442.806 [NAL9602](INFO): Powering down
2018-06-01T18:58:28.461Z,1527879508.461 [BPC1](ERROR): Failed to receive data from both battery packs
2018-06-01T18:58:28.461Z,1527879508.461 [BPC1] Communications Fault, FailCount= 2
2018-06-01T18:58:28.461Z,1527879508.461 [BPC1](ERROR): Communications Fault
2018-06-01T18:58:28.529Z,1527879508.529 [CBIT](ERROR): Communications Fault in component: BPC1
2018-06-01T18:58:29.698Z,1527879509.698 [CBIT](INFO): Clearing failed state for component BPC1
2018-06-01T18:58:29.698Z,1527879509.698 [BPC1] No Fault, FailCount= 2
2018-06-01T19:01:49.432Z,1527879709.432 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-06-01T19:01:49.432Z,1527879709.432 [Default:CheckIn:C.Wait] Stopped
2018-06-01T19:01:49.433Z,1527879709.433 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-06-01T19:01:49.433Z,1527879709.433 [Default:CheckIn:D] Running Loop=1
2018-06-01T19:01:49.821Z,1527879709.821 [Default:CheckIn:D] Stopped
2018-06-01T19:01:49.821Z,1527879709.821 [Default:CheckIn:E] Running Loop=1
2018-06-01T19:01:50.240Z,1527879710.240 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.594779 min 
2018-06-01T19:01:50.240Z,1527879710.240 [Default:CheckIn:E] Stopped
2018-06-01T19:01:50.240Z,1527879710.240 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-06-01T19:01:50.240Z,1527879710.240 [Default:CheckIn] Stopped
2018-06-01T19:01:50.240Z,1527879710.240 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-06-01T19:01:50.241Z,1527879710.241 [Default:CheckIn](INFO): Running loop #3
2018-06-01T19:01:50.241Z,1527879710.241 [Default:CheckIn] Running Loop=3
2018-06-01T19:01:50.241Z,1527879710.241 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-06-01T19:01:50.241Z,1527879710.241 [Default:CheckIn:Read_GPS] Running Loop=1
2018-06-01T19:01:53.426Z,1527879713.426 [NAL9602](INFO): Powering up
2018-06-01T19:02:04.574Z,1527879724.574 [NAL9602](INFO): NAL9602 initialized
2018-06-01T19:02:05.382Z,1527879725.382 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-06-01T19:02:05.382Z,1527879725.382 [NAL9602] Data Fault, FailCount= 2
2018-06-01T19:02:05.382Z,1527879725.382 [NAL9602](ERROR): Data Fault
2018-06-01T19:02:05.460Z,1527879725.460 [CBIT](ERROR): Data Fault in component: NAL9602
2018-06-01T19:02:05.774Z,1527879725.774 [NAL9602](INFO): Powering down
2018-06-01T19:02:06.629Z,1527879726.629 [CBIT](INFO): Clearing failed state for component NAL9602
2018-06-01T19:02:06.630Z,1527879726.630 [NAL9602] No Fault, FailCount= 2
2018-06-01T19:02:36.174Z,1527879756.174 [NAL9602](INFO): Powering up NAL9602
2018-06-01T19:02:47.374Z,1527879767.374 [NAL9602](INFO): NAL9602 initialized
2018-06-01T19:05:59.963Z,1527879959.963 [BPC1](ERROR): Failed to receive data from both battery packs
2018-06-01T19:05:59.963Z,1527879959.963 [BPC1] Communications Fault, FailCount= 3
2018-06-01T19:05:59.963Z,1527879959.963 [BPC1](ERROR): Communications Fault
2018-06-01T19:06:00.030Z,1527879960.030 [CBIT](ERROR): Communications Fault in component: BPC1
2018-06-01T19:06:01.213Z,1527879961.213 [CBIT](INFO): Clearing failed state for component BPC1
2018-06-01T19:06:01.213Z,1527879961.213 [BPC1] No Fault, FailCount= 3
2018-06-01T19:06:50.381Z,1527880010.381 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-06-01T19:01:50.2Z
2018-06-01T19:06:50.381Z,1527880010.381 [Default:CheckIn:Read_GPS] Stopped
2018-06-01T19:06:50.382Z,1527880010.382 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-06-01T19:06:54.116Z,1527880014.116 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180601T183943/Courier0010.lzma
2018-06-01T19:06:54.603Z,1527880014.603 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Courier0010.lzma.bak
2018-06-01T19:06:54.604Z,1527880014.604 [DataOverHttps](INFO): SBD MOMSN=8303522
2018-06-01T19:07:04.067Z,1527880024.067 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20180601T183943/Express0011.lzma
2018-06-01T19:07:04.843Z,1527880024.843 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Express0011.lzma.bak
2018-06-01T19:07:04.844Z,1527880024.844 [DataOverHttps](INFO): SBD MOMSN=8303524
2018-06-01T19:07:05.980Z,1527880025.980 [Default:CheckIn:Read_Iridium] Stopped
2018-06-01T19:07:05.980Z,1527880025.980 [Default:CheckIn:C.Wait] Running Loop=1
2018-06-01T19:07:05.981Z,1527880025.981 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-06-01T19:07:20.264Z,1527880040.264 [NAL9602](INFO): SBD MO Status=2, MOMSN=6092, MT Status=2, MTMSN=0
2018-06-01T19:07:20.264Z,1527880040.264 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T19:07:37.868Z,1527880057.868 [NAL9602](INFO): SBD MO Status=0, MOMSN=6092, MT Status=0, MTMSN=0
2018-06-01T19:07:37.868Z,1527880057.868 [NAL9602](INFO): No messages in MT queue
2018-06-01T19:08:09.794Z,1527880089.794 [NAL9602](INFO): Powering down
2018-06-01T19:12:04.062Z,1527880324.062 [BPC1](ERROR): Failed to receive data from both battery packs
2018-06-01T19:12:04.062Z,1527880324.062 [BPC1] Communications Fault, FailCount= 4
2018-06-01T19:12:04.062Z,1527880324.062 [BPC1](ERROR): Communications Fault
2018-06-01T19:12:04.120Z,1527880324.120 [CBIT](ERROR): Communications Fault in component: BPC1
2018-06-01T19:12:05.303Z,1527880325.303 [CBIT](INFO): Clearing failed state for component BPC1
2018-06-01T19:12:05.303Z,1527880325.303 [BPC1] No Fault, FailCount= 4
2018-06-01T19:12:06.467Z,1527880326.467 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-06-01T19:12:06.467Z,1527880326.467 [Default:CheckIn:C.Wait] Stopped
2018-06-01T19:12:06.467Z,1527880326.467 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-06-01T19:12:06.467Z,1527880326.467 [Default:CheckIn:D] Running Loop=1
2018-06-01T19:12:06.895Z,1527880326.895 [Default:CheckIn:D] Stopped
2018-06-01T19:12:06.895Z,1527880326.895 [Default:CheckIn:E] Running Loop=1
2018-06-01T19:12:10.107Z,1527880330.107 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.879338 min 
2018-06-01T19:12:10.107Z,1527880330.107 [Default:CheckIn:E] Stopped
2018-06-01T19:12:10.107Z,1527880330.107 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-06-01T19:12:10.107Z,1527880330.107 [Default:CheckIn] Stopped
2018-06-01T19:12:10.108Z,1527880330.108 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-06-01T19:12:10.108Z,1527880330.108 [Default:CheckIn](INFO): Running loop #4
2018-06-01T19:12:10.108Z,1527880330.108 [Default:CheckIn] Running Loop=4
2018-06-01T19:12:10.108Z,1527880330.108 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-06-01T19:12:10.108Z,1527880330.108 [Default:CheckIn:Read_GPS] Running Loop=1
2018-06-01T19:12:10.538Z,1527880330.538 [NAL9602](INFO): Powering up
2018-06-01T19:12:21.734Z,1527880341.734 [NAL9602](INFO): NAL9602 initialized
2018-06-01T19:12:47.336Z,1527880367.336 [NAL9602](INFO): SBD MO Status=2, MOMSN=6093, MT Status=2, MTMSN=0
2018-06-01T19:12:47.336Z,1527880367.336 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T19:13:14.608Z,1527880394.608 [NAL9602](INFO): SBD MO Status=2, MOMSN=6093, MT Status=2, MTMSN=0
2018-06-01T19:13:14.608Z,1527880394.608 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T19:17:10.489Z,1527880630.489 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-06-01T19:12:10.1Z
2018-06-01T19:17:10.489Z,1527880630.489 [Default:CheckIn:Read_GPS] Stopped
2018-06-01T19:17:10.490Z,1527880630.490 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-06-01T19:17:15.571Z,1527880635.571 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180601T183943/Courier0013.lzma
2018-06-01T19:17:16.376Z,1527880636.376 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Courier0013.lzma.bak
2018-06-01T19:17:16.377Z,1527880636.377 [DataOverHttps](INFO): SBD MOMSN=8303544
2018-06-01T19:17:25.578Z,1527880645.578 [DataOverHttps](INFO): Sending 122 bytes from file Logs/20180601T183943/Express0014.lzma
2018-06-01T19:17:26.367Z,1527880646.367 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Express0014.lzma.bak
2018-06-01T19:17:26.368Z,1527880646.368 [DataOverHttps](INFO): SBD MOMSN=8303546
2018-06-01T19:17:27.506Z,1527880647.506 [Default:CheckIn:Read_Iridium] Stopped
2018-06-01T19:17:27.506Z,1527880647.506 [Default:CheckIn:C.Wait] Running Loop=1
2018-06-01T19:17:27.506Z,1527880647.506 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-06-01T19:17:30.857Z,1527880650.857 [NAL9602](INFO): SBD MO Status=2, MOMSN=6093, MT Status=2, MTMSN=0
2018-06-01T19:17:30.857Z,1527880650.857 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T19:17:30.975Z,1527880650.975 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-06-01T19:18:01.366Z,1527880681.366 [NAL9602](INFO): Powering down
2018-06-01T19:18:12.995Z,1527880692.995 [BPC1](ERROR): Failed to receive data from both battery packs
2018-06-01T19:18:12.995Z,1527880692.995 [BPC1] Communications Fault, FailCount= 5
2018-06-01T19:18:12.995Z,1527880692.995 [BPC1](ERROR): Communications Fault
2018-06-01T19:18:13.023Z,1527880693.023 [CBIT](ERROR): Communications Fault in component: BPC1
2018-06-01T19:18:14.231Z,1527880694.231 [CBIT](INFO): Clearing failed state for component BPC1
2018-06-01T19:18:14.231Z,1527880694.231 [BPC1] No Fault, FailCount= 5
2018-06-01T19:22:27.865Z,1527880947.865 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-06-01T19:22:27.865Z,1527880947.865 [Default:CheckIn:C.Wait] Stopped
2018-06-01T19:22:27.865Z,1527880947.865 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-06-01T19:22:27.865Z,1527880947.865 [Default:CheckIn:D] Running Loop=1
2018-06-01T19:22:28.297Z,1527880948.297 [Default:CheckIn:D] Stopped
2018-06-01T19:22:28.297Z,1527880948.297 [Default:CheckIn:E] Running Loop=1
2018-06-01T19:22:28.637Z,1527880948.637 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.235905 min 
2018-06-01T19:22:28.638Z,1527880948.638 [Default:CheckIn:E] Stopped
2018-06-01T19:22:28.638Z,1527880948.638 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-06-01T19:22:28.638Z,1527880948.638 [Default:CheckIn] Stopped
2018-06-01T19:22:28.638Z,1527880948.638 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-06-01T19:22:28.638Z,1527880948.638 [Default:CheckIn](INFO): Running loop #5
2018-06-01T19:22:28.638Z,1527880948.638 [Default:CheckIn] Running Loop=5
2018-06-01T19:22:28.638Z,1527880948.638 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-06-01T19:22:28.638Z,1527880948.638 [Default:CheckIn:Read_GPS] Running Loop=1
2018-06-01T19:22:31.919Z,1527880951.919 [NAL9602](INFO): Powering up
2018-06-01T19:22:43.110Z,1527880963.110 [NAL9602](INFO): NAL9602 initialized
2018-06-01T19:22:43.906Z,1527880963.906 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-06-01T19:22:43.906Z,1527880963.906 [NAL9602] Data Fault, FailCount= 1
2018-06-01T19:22:43.907Z,1527880963.907 [NAL9602](ERROR): Data Fault
2018-06-01T19:22:43.990Z,1527880963.990 [CBIT](ERROR): Data Fault in component: NAL9602
2018-06-01T19:22:44.314Z,1527880964.314 [NAL9602](INFO): Powering down
2018-06-01T19:22:45.181Z,1527880965.181 [CBIT](INFO): Clearing failed state for component NAL9602
2018-06-01T19:22:45.181Z,1527880965.181 [NAL9602] No Fault, FailCount= 1
2018-06-01T19:23:14.706Z,1527880994.706 [NAL9602](INFO): Powering up NAL9602
2018-06-01T19:23:25.906Z,1527881005.906 [NAL9602](INFO): NAL9602 initialized
2018-06-01T19:24:57.650Z,1527881097.650 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2018-06-01T19:24:57.650Z,1527881097.650 [DropWeight] Hardware Fault, FailCount= 1
2018-06-01T19:24:57.650Z,1527881097.650 [DropWeight](ERROR): Hardware Fault
2018-06-01T19:24:57.747Z,1527881097.747 [CBIT](INFO): Critical error at 20180601T192457
2018-06-01T19:24:57.753Z,1527881097.753 [CBIT](ERROR): Hardware Fault in component: DropWeight
2018-06-01T19:24:57.754Z,1527881097.754 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2018-06-01T19:24:58.116Z,1527881098.116 [CBIT](INFO): Critical error at 20180601T192457
2018-06-01T19:25:58.908Z,1527881158.908 [BPC1](ERROR): Failed to receive data from both battery packs
2018-06-01T19:25:58.908Z,1527881158.908 [BPC1] Communications Fault, FailCount= 6
2018-06-01T19:25:58.909Z,1527881158.909 [BPC1](ERROR): Communications Fault
2018-06-01T19:25:59.005Z,1527881159.005 [CBIT](ERROR): Communications Fault in component: BPC1
2018-06-01T19:26:00.230Z,1527881160.230 [CBIT](INFO): Clearing failed state for component BPC1
2018-06-01T19:26:00.230Z,1527881160.230 [BPC1] No Fault, FailCount= 6
2018-06-01T19:26:20.483Z,1527881180.483 [NAL9602](INFO): SBD MO Status=2, MOMSN=6093, MT Status=2, MTMSN=0
2018-06-01T19:26:20.484Z,1527881180.484 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T19:26:38.188Z,1527881198.188 [NAL9602](INFO): SBD MO Status=0, MOMSN=6093, MT Status=0, MTMSN=0
2018-06-01T19:26:38.188Z,1527881198.188 [NAL9602](INFO): No messages in MT queue
2018-06-01T19:26:39.390Z,1527881199.390 [NAL9602](INFO): GPS fix at 20180601T192553: (36.802786, -121.787664)
2018-06-01T19:26:39.447Z,1527881199.447 [Default:CheckIn:Read_GPS] Stopped
2018-06-01T19:26:39.447Z,1527881199.447 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-06-01T19:26:43.890Z,1527881203.890 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20180601T183943/Courier0016.lzma
2018-06-01T19:26:44.691Z,1527881204.691 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Courier0016.lzma.bak
2018-06-01T19:26:44.692Z,1527881204.692 [DataOverHttps](INFO): SBD MOMSN=8303574
2018-06-01T19:26:53.943Z,1527881213.943 [DataOverHttps](INFO): Sending 229 bytes from file Logs/20180601T183943/Express0017.lzma
2018-06-01T19:26:54.735Z,1527881214.735 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Express0017.lzma.bak
2018-06-01T19:26:54.736Z,1527881214.736 [DataOverHttps](INFO): SBD MOMSN=8303579
2018-06-01T19:26:55.832Z,1527881215.832 [Default:CheckIn:Read_Iridium] Stopped
2018-06-01T19:26:55.832Z,1527881215.832 [Default:CheckIn:C.Wait] Running Loop=1
2018-06-01T19:26:55.832Z,1527881215.832 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-06-01T19:27:12.494Z,1527881232.494 [BPC1](ERROR): Failed to parse message.
2018-06-01T19:27:12.494Z,1527881232.494 [BPC1](ERROR): Failed to parse Bank A battery data
2018-06-01T19:27:14.062Z,1527881234.062 [NAL9602](INFO): Powering down
2018-06-01T19:31:56.045Z,1527881516.045 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-06-01T19:31:56.045Z,1527881516.045 [Default:CheckIn:C.Wait] Stopped
2018-06-01T19:31:56.045Z,1527881516.045 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-06-01T19:31:56.046Z,1527881516.046 [Default:CheckIn:D] Running Loop=1
2018-06-01T19:31:56.446Z,1527881516.446 [Default:CheckIn:D] Stopped
2018-06-01T19:31:56.446Z,1527881516.446 [Default:CheckIn:E] Running Loop=1
2018-06-01T19:31:56.856Z,1527881516.856 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.705196 min 
2018-06-01T19:31:56.856Z,1527881516.856 [Default:CheckIn:E] Stopped
2018-06-01T19:31:56.856Z,1527881516.856 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-06-01T19:31:56.857Z,1527881516.857 [Default:CheckIn] Stopped
2018-06-01T19:31:56.857Z,1527881516.857 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-06-01T19:31:56.857Z,1527881516.857 [Default:CheckIn](INFO): Running loop #6
2018-06-01T19:31:56.857Z,1527881516.857 [Default:CheckIn] Running Loop=6
2018-06-01T19:31:56.857Z,1527881516.857 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-06-01T19:31:56.857Z,1527881516.857 [Default:CheckIn:Read_GPS] Running Loop=1
2018-06-01T19:32:00.039Z,1527881520.039 [NAL9602](INFO): Powering up
2018-06-01T19:32:11.230Z,1527881531.230 [NAL9602](INFO): NAL9602 initialized
2018-06-01T19:33:07.686Z,1527881587.686 [BPC1](ERROR): Failed to receive data from both battery packs
2018-06-01T19:33:07.686Z,1527881587.686 [BPC1] Communications Fault, FailCount= 7
2018-06-01T19:33:07.686Z,1527881587.686 [BPC1](ERROR): Communications Fault
2018-06-01T19:33:07.748Z,1527881587.748 [CBIT](ERROR): Communications Fault in component: BPC1
2018-06-01T19:33:08.923Z,1527881588.923 [CBIT](INFO): Clearing failed state for component BPC1
2018-06-01T19:33:08.923Z,1527881588.923 [BPC1] No Fault, FailCount= 7
2018-06-01T19:33:40.863Z,1527881620.863 [NAL9602](INFO): SBD MO Status=2, MOMSN=6094, MT Status=2, MTMSN=0
2018-06-01T19:33:40.864Z,1527881620.864 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T19:34:19.443Z,1527881659.443 [NAL9602](INFO): SBD MO Status=2, MOMSN=6094, MT Status=2, MTMSN=0
2018-06-01T19:34:19.443Z,1527881659.443 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T19:35:16.323Z,1527881716.323 [NAL9602](INFO): SBD MO Status=2, MOMSN=6094, MT Status=2, MTMSN=0
2018-06-01T19:35:16.324Z,1527881716.324 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T19:36:51.999Z,1527881811.999 [NAL9602](INFO): SBD MO Status=2, MOMSN=6094, MT Status=2, MTMSN=0
2018-06-01T19:36:51.000Z,1527881812.000 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T19:36:57.257Z,1527881817.257 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-06-01T19:31:56.9Z
2018-06-01T19:36:57.257Z,1527881817.257 [Default:CheckIn:Read_GPS] Stopped
2018-06-01T19:36:57.257Z,1527881817.257 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-06-01T19:37:01.035Z,1527881821.035 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180601T183943/Courier0019.lzma
2018-06-01T19:37:01.551Z,1527881821.551 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Courier0019.lzma.bak
2018-06-01T19:37:01.552Z,1527881821.552 [DataOverHttps](INFO): SBD MOMSN=8303598
2018-06-01T19:37:10.923Z,1527881830.923 [DataOverHttps](INFO): Sending 123 bytes from file Logs/20180601T183943/Express0020.lzma
2018-06-01T19:37:11.715Z,1527881831.715 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Express0020.lzma.bak
2018-06-01T19:37:11.716Z,1527881831.716 [DataOverHttps](INFO): SBD MOMSN=8303600
2018-06-01T19:37:12.874Z,1527881832.874 [Default:CheckIn:Read_Iridium] Stopped
2018-06-01T19:37:12.874Z,1527881832.874 [Default:CheckIn:C.Wait] Running Loop=1
2018-06-01T19:37:12.874Z,1527881832.874 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-06-01T19:37:16.129Z,1527881836.129 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-06-01T19:37:46.635Z,1527881866.635 [NAL9602](INFO): Powering down
2018-06-01T19:39:57.756Z,1527881997.756 [CBIT](INFO): Clearing failed state for component DropWeight
2018-06-01T19:39:57.756Z,1527881997.756 [DropWeight] No Fault, FailCount= 1
2018-06-01T19:40:46.133Z,1527882046.133 [BPC1](ERROR): Failed to receive data from both battery packs
2018-06-01T19:40:46.133Z,1527882046.133 [BPC1] Communications Fault, FailCount= 8
2018-06-01T19:40:46.133Z,1527882046.133 [BPC1](ERROR): Communications Fault
2018-06-01T19:40:46.197Z,1527882046.197 [CBIT](ERROR): Communications Fault in component: BPC1
2018-06-01T19:40:47.367Z,1527882047.367 [CBIT](INFO): Clearing failed state for component BPC1
2018-06-01T19:40:47.367Z,1527882047.367 [BPC1] No Fault, FailCount= 8
2018-06-01T19:42:13.071Z,1527882133.071 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-06-01T19:42:13.071Z,1527882133.071 [Default:CheckIn:C.Wait] Stopped
2018-06-01T19:42:13.071Z,1527882133.071 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-06-01T19:42:13.071Z,1527882133.071 [Default:CheckIn:D] Running Loop=1
2018-06-01T19:42:13.489Z,1527882133.489 [Default:CheckIn:D] Stopped
2018-06-01T19:42:13.489Z,1527882133.489 [Default:CheckIn:E] Running Loop=1
2018-06-01T19:42:13.872Z,1527882133.872 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 58.989246 min 
2018-06-01T19:42:13.873Z,1527882133.873 [Default:CheckIn:E] Stopped
2018-06-01T19:42:13.873Z,1527882133.873 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-06-01T19:42:13.873Z,1527882133.873 [Default:CheckIn] Stopped
2018-06-01T19:42:13.873Z,1527882133.873 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-06-01T19:42:13.873Z,1527882133.873 [Default:CheckIn](INFO): Running loop #7
2018-06-01T19:42:13.874Z,1527882133.874 [Default:CheckIn] Running Loop=7
2018-06-01T19:42:13.874Z,1527882133.874 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-06-01T19:42:13.874Z,1527882133.874 [Default:CheckIn:Read_GPS] Running Loop=1
2018-06-01T19:42:17.290Z,1527882137.290 [NAL9602](INFO): Powering up
2018-06-01T19:42:28.442Z,1527882148.442 [NAL9602](INFO): NAL9602 initialized
2018-06-01T19:42:29.242Z,1527882149.242 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-06-01T19:42:29.243Z,1527882149.243 [NAL9602] Data Fault, FailCount= 1
2018-06-01T19:42:29.243Z,1527882149.243 [NAL9602](ERROR): Data Fault
2018-06-01T19:42:29.340Z,1527882149.340 [CBIT](ERROR): Data Fault in component: NAL9602
2018-06-01T19:42:29.642Z,1527882149.642 [NAL9602](INFO): Powering down
2018-06-01T19:42:30.517Z,1527882150.517 [CBIT](INFO): Clearing failed state for component NAL9602
2018-06-01T19:42:30.517Z,1527882150.517 [NAL9602] No Fault, FailCount= 1
2018-06-01T19:43:00.042Z,1527882180.042 [NAL9602](INFO): Powering up NAL9602
2018-06-01T19:43:11.242Z,1527882191.242 [NAL9602](INFO): NAL9602 initialized
2018-06-01T19:45:04.092Z,1527882304.092 [NAL9602](INFO): SBD MO Status=2, MOMSN=6094, MT Status=2, MTMSN=0
2018-06-01T19:45:04.092Z,1527882304.092 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T19:45:17.284Z,1527882317.284 [NAL9602](INFO): SBD MO Status=2, MOMSN=6094, MT Status=2, MTMSN=0
2018-06-01T19:45:17.284Z,1527882317.284 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T19:45:49.804Z,1527882349.804 [NAL9602](INFO): SBD MO Status=2, MOMSN=6094, MT Status=2, MTMSN=0
2018-06-01T19:45:49.804Z,1527882349.804 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T19:46:19.431Z,1527882379.431 [NAL9602](INFO): SBD MO Status=2, MOMSN=6094, MT Status=2, MTMSN=0
2018-06-01T19:46:19.432Z,1527882379.432 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T19:46:36.624Z,1527882396.624 [NAL9602](INFO): SBD MO Status=2, MOMSN=6094, MT Status=2, MTMSN=0
2018-06-01T19:46:36.624Z,1527882396.624 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T19:46:58.225Z,1527882418.225 [NAL9602](INFO): SBD MO Status=0, MOMSN=6094, MT Status=0, MTMSN=0
2018-06-01T19:46:58.225Z,1527882418.225 [NAL9602](INFO): No messages in MT queue
2018-06-01T19:46:59.431Z,1527882419.431 [NAL9602](INFO): GPS fix at 20180601T194614: (36.802778, -121.787928)
2018-06-01T19:46:59.503Z,1527882419.503 [Default:CheckIn:Read_GPS] Stopped
2018-06-01T19:46:59.503Z,1527882419.503 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-06-01T19:47:04.067Z,1527882424.067 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20180601T183943/Courier0022.lzma
2018-06-01T19:47:04.867Z,1527882424.867 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Courier0022.lzma.bak
2018-06-01T19:47:04.868Z,1527882424.868 [DataOverHttps](INFO): SBD MOMSN=8303616
2018-06-01T19:47:14.355Z,1527882434.355 [DataOverHttps](INFO): Sending 227 bytes from file Logs/20180601T183943/Express0023.lzma
2018-06-01T19:47:15.124Z,1527882435.124 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Express0023.lzma.bak
2018-06-01T19:47:15.124Z,1527882435.124 [DataOverHttps](INFO): SBD MOMSN=8303619
2018-06-01T19:47:16.224Z,1527882436.224 [Default:CheckIn:Read_Iridium] Stopped
2018-06-01T19:47:16.224Z,1527882436.224 [Default:CheckIn:C.Wait] Running Loop=1
2018-06-01T19:47:16.224Z,1527882436.224 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-06-01T19:47:34.502Z,1527882454.502 [NAL9602](INFO): Powering down
2018-06-01T19:47:57.754Z,1527882477.754 [BPC1](ERROR): Failed to receive data from both battery packs
2018-06-01T19:47:57.754Z,1527882477.754 [BPC1] Communications Fault, FailCount= 9
2018-06-01T19:47:57.754Z,1527882477.754 [BPC1](ERROR): Communications Fault
2018-06-01T19:47:57.857Z,1527882477.857 [CBIT](ERROR): Communications Fault in component: BPC1
2018-06-01T19:47:58.978Z,1527882478.978 [CBIT](INFO): Clearing failed state for component BPC1
2018-06-01T19:47:58.978Z,1527882478.978 [BPC1] No Fault, FailCount= 9
2018-06-01T19:52:16.572Z,1527882736.572 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-06-01T19:52:16.573Z,1527882736.573 [Default:CheckIn:C.Wait] Stopped
2018-06-01T19:52:16.573Z,1527882736.573 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-06-01T19:52:16.573Z,1527882736.573 [Default:CheckIn:D] Running Loop=1
2018-06-01T19:52:16.975Z,1527882736.975 [Default:CheckIn:D] Stopped
2018-06-01T19:52:16.975Z,1527882736.975 [Default:CheckIn:E] Running Loop=1
2018-06-01T19:52:17.381Z,1527882737.381 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 69.047339 min 
2018-06-01T19:52:17.381Z,1527882737.381 [Default:CheckIn:E] Stopped
2018-06-01T19:52:17.381Z,1527882737.381 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-06-01T19:52:17.382Z,1527882737.382 [Default:CheckIn] Stopped
2018-06-01T19:52:17.382Z,1527882737.382 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-06-01T19:52:17.382Z,1527882737.382 [Default:CheckIn](INFO): Running loop #8
2018-06-01T19:52:17.382Z,1527882737.382 [Default:CheckIn] Running Loop=8
2018-06-01T19:52:17.382Z,1527882737.382 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-06-01T19:52:17.382Z,1527882737.382 [Default:CheckIn:Read_GPS] Running Loop=1
2018-06-01T19:52:20.622Z,1527882740.622 [NAL9602](INFO): Powering up
2018-06-01T19:52:31.814Z,1527882751.814 [NAL9602](INFO): NAL9602 initialized
2018-06-01T19:54:00.023Z,1527882840.023 [BPC1](ERROR): Failed to receive data from both battery packs
2018-06-01T19:54:00.023Z,1527882840.023 [BPC1] Communications Fault, FailCount= 10
2018-06-01T19:54:00.023Z,1527882840.023 [BPC1](ERROR): Communications Fault
2018-06-01T19:54:00.067Z,1527882840.067 [CBIT](ERROR): Communications Fault in component: BPC1
2018-06-01T19:54:00.068Z,1527882840.068 [CBIT](CRITICAL): Communications Fault in component: BPC1
2018-06-01T19:54:00.483Z,1527882840.483 [CBIT](INFO): Critical error at 20180601T195400
2018-06-01T19:55:20.853Z,1527882920.853 [NAL9602](INFO): SBD MO Status=2, MOMSN=6095, MT Status=2, MTMSN=0
2018-06-01T19:55:20.853Z,1527882920.853 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T19:55:36.576Z,1527882936.576 [NAL9602](INFO): SBD MO Status=2, MOMSN=6095, MT Status=2, MTMSN=0
2018-06-01T19:55:36.576Z,1527882936.576 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T19:56:08.175Z,1527882968.175 [NAL9602](INFO): SBD MO Status=2, MOMSN=6095, MT Status=2, MTMSN=0
2018-06-01T19:56:08.176Z,1527882968.176 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T19:56:37.000Z,1527882998.000 [NAL9602](INFO): SBD MO Status=2, MOMSN=6095, MT Status=2, MTMSN=0
2018-06-01T19:56:38.000Z,1527882998.000 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T19:57:17.646Z,1527883037.646 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-06-01T19:52:17.4Z
2018-06-01T19:57:17.646Z,1527883037.646 [Default:CheckIn:Read_GPS] Stopped
2018-06-01T19:57:17.646Z,1527883037.646 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-06-01T19:57:21.568Z,1527883041.568 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20180601T183943/Courier0025.lzma
2018-06-01T19:57:22.360Z,1527883042.360 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Courier0025.lzma.bak
2018-06-01T19:57:22.360Z,1527883042.360 [DataOverHttps](INFO): SBD MOMSN=8303631
2018-06-01T19:57:31.763Z,1527883051.763 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20180601T183943/Express0026.lzma
2018-06-01T19:57:32.563Z,1527883052.563 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Express0026.lzma.bak
2018-06-01T19:57:32.564Z,1527883052.564 [DataOverHttps](INFO): SBD MOMSN=8303634
2018-06-01T19:57:33.676Z,1527883053.676 [Default:CheckIn:Read_Iridium] Stopped
2018-06-01T19:57:33.676Z,1527883053.676 [Default:CheckIn:C.Wait] Running Loop=1
2018-06-01T19:57:33.676Z,1527883053.676 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-06-01T19:57:36.863Z,1527883056.863 [NAL9602](INFO): SBD MO Status=2, MOMSN=6095, MT Status=2, MTMSN=0
2018-06-01T19:57:36.863Z,1527883056.863 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T19:57:36.994Z,1527883056.994 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-06-01T19:58:07.418Z,1527883087.418 [NAL9602](INFO): Powering down
2018-06-01T19:59:00.325Z,1527883140.325 [CBIT](INFO): Clearing failed state for component BPC1
2018-06-01T19:59:00.325Z,1527883140.325 [BPC1] No Fault, FailCount= 10
2018-06-01T20:02:34.198Z,1527883354.198 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-06-01T20:02:34.198Z,1527883354.198 [Default:CheckIn:C.Wait] Stopped
2018-06-01T20:02:34.198Z,1527883354.198 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-06-01T20:02:34.198Z,1527883354.198 [Default:CheckIn:D] Running Loop=1
2018-06-01T20:02:34.608Z,1527883354.608 [Default:CheckIn:D] Stopped
2018-06-01T20:02:34.608Z,1527883354.608 [Default:CheckIn:E] Running Loop=1
2018-06-01T20:02:37.722Z,1527883357.722 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 79.341227 min 
2018-06-01T20:02:37.722Z,1527883357.722 [Default:CheckIn:E] Stopped
2018-06-01T20:02:37.723Z,1527883357.723 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-06-01T20:02:37.723Z,1527883357.723 [Default:CheckIn] Stopped
2018-06-01T20:02:37.723Z,1527883357.723 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-06-01T20:02:37.723Z,1527883357.723 [Default:CheckIn](INFO): Running loop #9
2018-06-01T20:02:37.723Z,1527883357.723 [Default:CheckIn] Running Loop=9
2018-06-01T20:02:37.723Z,1527883357.723 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-06-01T20:02:37.723Z,1527883357.723 [Default:CheckIn:Read_GPS] Running Loop=1
2018-06-01T20:02:38.174Z,1527883358.174 [NAL9602](INFO): Powering up
2018-06-01T20:02:49.374Z,1527883369.374 [NAL9602](INFO): NAL9602 initialized
2018-06-01T20:02:50.174Z,1527883370.174 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-06-01T20:02:50.174Z,1527883370.174 [NAL9602] Data Fault, FailCount= 1
2018-06-01T20:02:50.174Z,1527883370.174 [NAL9602](ERROR): Data Fault
2018-06-01T20:02:50.278Z,1527883370.278 [CBIT](ERROR): Data Fault in component: NAL9602
2018-06-01T20:02:50.575Z,1527883370.575 [NAL9602](INFO): Powering down
2018-06-01T20:02:51.464Z,1527883371.464 [CBIT](INFO): Clearing failed state for component NAL9602
2018-06-01T20:02:51.464Z,1527883371.464 [NAL9602] No Fault, FailCount= 1
2018-06-01T20:03:20.974Z,1527883400.974 [NAL9602](INFO): Powering up NAL9602
2018-06-01T20:03:32.174Z,1527883412.174 [NAL9602](INFO): NAL9602 initialized
2018-06-01T20:05:03.646Z,1527883503.646 [NAL9602](INFO): SBD MO Status=2, MOMSN=6095, MT Status=2, MTMSN=0
2018-06-01T20:05:03.646Z,1527883503.646 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T20:05:43.360Z,1527883543.360 [NAL9602](INFO): SBD MO Status=2, MOMSN=6095, MT Status=2, MTMSN=0
2018-06-01T20:05:43.360Z,1527883543.360 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T20:05:45.797Z,1527883545.797 [BPC1](ERROR): Failed to receive data from both battery packs
2018-06-01T20:05:45.797Z,1527883545.797 [BPC1] Communications Fault, FailCount= 1
2018-06-01T20:05:45.797Z,1527883545.797 [BPC1](ERROR): Communications Fault
2018-06-01T20:05:45.854Z,1527883545.854 [CBIT](ERROR): Communications Fault in component: BPC1
2018-06-01T20:05:47.026Z,1527883547.026 [CBIT](INFO): Clearing failed state for component BPC1
2018-06-01T20:05:47.026Z,1527883547.026 [BPC1] No Fault, FailCount= 1
2018-06-01T20:06:34.964Z,1527883594.964 [NAL9602](INFO): SBD MO Status=2, MOMSN=6095, MT Status=2, MTMSN=0
2018-06-01T20:06:34.964Z,1527883594.964 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T20:06:58.248Z,1527883618.248 [NAL9602](INFO): SBD MO Status=2, MOMSN=6095, MT Status=2, MTMSN=0
2018-06-01T20:06:58.248Z,1527883618.248 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T20:07:00.273Z,1527883620.273 [BPC1](ERROR): Failed to parse Bank B battery data
2018-06-01T20:07:38.358Z,1527883658.358 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-06-01T20:02:37.7Z
2018-06-01T20:07:38.358Z,1527883658.358 [Default:CheckIn:Read_GPS] Stopped
2018-06-01T20:07:38.358Z,1527883658.358 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-06-01T20:07:43.458Z,1527883663.458 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180601T183943/Courier0028.lzma
2018-06-01T20:07:44.236Z,1527883664.236 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Courier0028.lzma.bak
2018-06-01T20:07:44.236Z,1527883664.236 [DataOverHttps](INFO): SBD MOMSN=8303650
2018-06-01T20:07:48.524Z,1527883668.524 [NAL9602](INFO): SBD MO Status=2, MOMSN=6095, MT Status=2, MTMSN=0
2018-06-01T20:07:48.524Z,1527883668.524 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T20:07:53.827Z,1527883673.827 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20180601T183943/Express0029.lzma
2018-06-01T20:07:54.628Z,1527883674.628 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Express0029.lzma.bak
2018-06-01T20:07:54.628Z,1527883674.628 [DataOverHttps](INFO): SBD MOMSN=8303652
2018-06-01T20:07:55.848Z,1527883675.848 [Default:CheckIn:Read_Iridium] Stopped
2018-06-01T20:07:55.848Z,1527883675.848 [Default:CheckIn:C.Wait] Running Loop=1
2018-06-01T20:07:55.848Z,1527883675.848 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-06-01T20:08:34.815Z,1527883714.815 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-06-01T20:09:05.413Z,1527883745.413 [NAL9602](INFO): Powering down
2018-06-01T20:10:00.242Z,1527883800.242 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2018-06-01T20:10:00.242Z,1527883800.242 [DropWeight] Hardware Fault, FailCount= 1
2018-06-01T20:10:00.243Z,1527883800.243 [DropWeight](ERROR): Hardware Fault
2018-06-01T20:10:00.317Z,1527883800.317 [CBIT](INFO): Critical error at 20180601T201000
2018-06-01T20:10:00.319Z,1527883800.319 [CBIT](ERROR): Hardware Fault in component: DropWeight
2018-06-01T20:10:00.320Z,1527883800.320 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2018-06-01T20:10:00.696Z,1527883800.696 [CBIT](INFO): Critical error at 20180601T201000
2018-06-01T20:10:14.291Z,1527883814.291 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.406812 seconds old.
2018-06-01T20:10:14.692Z,1527883814.692 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.808352 seconds old.
2018-06-01T20:10:15.068Z,1527883815.068 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.184598 seconds old.
2018-06-01T20:10:15.495Z,1527883815.495 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.611659 seconds old.
2018-06-01T20:10:15.898Z,1527883815.898 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 2.014622 seconds old.
2018-06-01T20:10:16.268Z,1527883816.268 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 2.384380 seconds old.
2018-06-01T20:10:16.680Z,1527883816.680 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 2.796658 seconds old.
2018-06-01T20:10:17.076Z,1527883817.076 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 3.192248 seconds old.
2018-06-01T20:10:17.477Z,1527883817.477 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 3.593176 seconds old.
2018-06-01T20:10:17.880Z,1527883817.880 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 3.996868 seconds old.
2018-06-01T20:10:18.279Z,1527883818.279 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 4.395686 seconds old.
2018-06-01T20:10:18.676Z,1527883818.676 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 4.792525 seconds old.
2018-06-01T20:10:19.088Z,1527883819.088 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 5.204114 seconds old.
2018-06-01T20:10:19.474Z,1527883819.474 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 5.590723 seconds old.
2018-06-01T20:10:19.875Z,1527883819.875 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 5.991401 seconds old.
2018-06-01T20:10:20.278Z,1527883820.278 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 6.394007 seconds old.
2018-06-01T20:10:20.675Z,1527883820.675 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 6.791854 seconds old.
2018-06-01T20:10:21.087Z,1527883821.087 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 7.202984 seconds old.
2018-06-01T20:10:21.475Z,1527883821.475 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 7.591547 seconds old.
2018-06-01T20:10:21.883Z,1527883821.883 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 7.999712 seconds old.
2018-06-01T20:10:36.678Z,1527883836.678 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.393564 seconds old.
2018-06-01T20:10:37.082Z,1527883837.082 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.797124 seconds old.
2018-06-01T20:10:37.484Z,1527883837.484 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.198719 seconds old.
2018-06-01T20:10:37.888Z,1527883837.888 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.602788 seconds old.
2018-06-01T20:10:38.284Z,1527883838.284 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.998777 seconds old.
2018-06-01T20:10:38.680Z,1527883838.680 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 2.395469 seconds old.
2018-06-01T20:10:39.077Z,1527883839.077 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 2.792417 seconds old.
2018-06-01T20:10:39.482Z,1527883839.482 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 3.196977 seconds old.
2018-06-01T20:10:39.880Z,1527883839.880 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 3.594723 seconds old.
2018-06-01T20:10:40.287Z,1527883840.287 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 4.002081 seconds old.
2018-06-01T20:10:40.677Z,1527883840.677 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 4.392472 seconds old.
2018-06-01T20:10:41.083Z,1527883841.083 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 4.798520 seconds old.
2018-06-01T20:10:41.479Z,1527883841.479 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 5.194052 seconds old.
2018-06-01T20:10:41.878Z,1527883841.878 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 5.593556 seconds old.
2018-06-01T20:10:42.281Z,1527883842.281 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 5.996590 seconds old.
2018-06-01T20:10:42.680Z,1527883842.680 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 6.395309 seconds old.
2018-06-01T20:10:43.088Z,1527883843.088 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 6.803386 seconds old.
2018-06-01T20:10:43.489Z,1527883843.489 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 7.204589 seconds old.
2018-06-01T20:10:43.889Z,1527883843.889 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 7.604276 seconds old.
2018-06-01T20:10:44.285Z,1527883844.285 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 8.000635 seconds old.
2018-06-01T20:10:44.687Z,1527883844.687 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 8.401844 seconds old.
2018-06-01T20:10:45.079Z,1527883845.079 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 8.794228 seconds old.
2018-06-01T20:10:45.486Z,1527883845.486 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 9.201595 seconds old.
2018-06-01T20:10:45.887Z,1527883845.887 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 9.602506 seconds old.
2018-06-01T20:10:46.277Z,1527883846.277 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 9.992359 seconds old.
2018-06-01T20:10:46.688Z,1527883846.688 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 10.403041 seconds old.
2018-06-01T20:10:47.083Z,1527883847.083 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 10.798338 seconds old.
2018-06-01T20:10:47.491Z,1527883847.491 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 11.206131 seconds old.
2018-06-01T20:10:47.886Z,1527883847.886 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 11.601594 seconds old.
2018-06-01T20:10:48.287Z,1527883848.287 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 12.001926 seconds old.
2018-06-01T20:10:48.689Z,1527883848.689 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 12.403899 seconds old.
2018-06-01T20:10:49.082Z,1527883849.082 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 12.796993 seconds old.
2018-06-01T20:10:49.491Z,1527883849.491 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 13.205746 seconds old.
2018-06-01T20:10:49.885Z,1527883849.885 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 13.583733 seconds old.
2018-06-01T20:10:50.268Z,1527883850.268 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 13.982892 seconds old.
2018-06-01T20:10:50.693Z,1527883850.693 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 14.391709 seconds old.
2018-06-01T20:10:51.119Z,1527883851.119 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 14.834296 seconds old.
2018-06-01T20:10:51.488Z,1527883851.488 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 15.202867 seconds old.
2018-06-01T20:10:51.887Z,1527883851.887 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 15.601857 seconds old.
2018-06-01T20:10:52.277Z,1527883852.277 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 15.991951 seconds old.
2018-06-01T20:10:52.677Z,1527883852.677 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 16.392334 seconds old.
2018-06-01T20:10:53.075Z,1527883853.075 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 16.790214 seconds old.
2018-06-01T20:10:53.476Z,1527883853.476 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 17.191008 seconds old.
2018-06-01T20:10:53.877Z,1527883853.877 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 17.591731 seconds old.
2018-06-01T20:10:54.282Z,1527883854.282 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 17.996714 seconds old.
2018-06-01T20:10:54.673Z,1527883854.673 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 18.387828 seconds old.
2018-06-01T20:10:55.074Z,1527883855.074 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 18.789540 seconds old.
2018-06-01T20:10:55.484Z,1527883855.484 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 19.199311 seconds old.
2018-06-01T20:10:55.877Z,1527883855.877 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 19.592366 seconds old.
2018-06-01T20:10:56.278Z,1527883856.278 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 19.993003 seconds old.
2018-06-01T20:10:56.683Z,1527883856.683 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 20.398365 seconds old.
2018-06-01T20:10:59.818Z,1527883859.818 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 23.532804 seconds old.
2018-06-01T20:10:59.935Z,1527883859.935 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 23.650305 seconds old.
2018-06-01T20:11:00.296Z,1527883860.296 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 24.011204 seconds old.
2018-06-01T20:11:00.692Z,1527883860.692 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 24.407246 seconds old.
2018-06-01T20:11:01.090Z,1527883861.090 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 24.804886 seconds old.
2018-06-01T20:11:01.493Z,1527883861.493 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 25.208115 seconds old.
2018-06-01T20:11:01.892Z,1527883861.892 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 25.606702 seconds old.
2018-06-01T20:11:02.291Z,1527883862.291 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 26.005654 seconds old.
2018-06-01T20:11:02.689Z,1527883862.689 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 26.403661 seconds old.
2018-06-01T20:11:03.093Z,1527883863.093 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 26.808357 seconds old.
2018-06-01T20:11:03.492Z,1527883863.492 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 27.206865 seconds old.
2018-06-01T20:11:03.893Z,1527883863.893 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 27.608540 seconds old.
2018-06-01T20:11:04.289Z,1527883864.289 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 28.004487 seconds old.
2018-06-01T20:11:04.690Z,1527883864.690 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 28.404766 seconds old.
2018-06-01T20:11:05.092Z,1527883865.092 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 28.807320 seconds old.
2018-06-01T20:11:05.490Z,1527883865.490 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 29.205303 seconds old.
2018-06-01T20:11:05.890Z,1527883865.890 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 29.604880 seconds old.
2018-06-01T20:11:06.293Z,1527883866.293 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 30.007907 seconds old.
2018-06-01T20:11:06.691Z,1527883866.691 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 30.406368 seconds old.
2018-06-01T20:11:07.100Z,1527883867.100 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 30.815127 seconds old.
2018-06-01T20:11:07.496Z,1527883867.496 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 31.210778 seconds old.
2018-06-01T20:11:07.893Z,1527883867.893 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 31.607741 seconds old.
2018-06-01T20:11:08.292Z,1527883868.292 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 32.007402 seconds old.
2018-06-01T20:11:08.705Z,1527883868.705 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 32.419716 seconds old.
2018-06-01T20:11:09.100Z,1527883869.100 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 32.815616 seconds old.
2018-06-01T20:11:09.499Z,1527883869.499 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 33.214084 seconds old.
2018-06-01T20:11:09.894Z,1527883869.894 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 33.609120 seconds old.
2018-06-01T20:11:10.302Z,1527883870.302 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 34.017163 seconds old.
2018-06-01T20:11:10.691Z,1527883870.691 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 34.406475 seconds old.
2018-06-01T20:11:11.098Z,1527883871.098 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 34.812931 seconds old.
2018-06-01T20:11:11.502Z,1527883871.502 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 35.217196 seconds old.
2018-06-01T20:11:11.893Z,1527883871.893 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 35.607968 seconds old.
2018-06-01T20:11:12.304Z,1527883872.304 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 36.018810 seconds old.
2018-06-01T20:11:12.701Z,1527883872.701 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 36.416507 seconds old.
2018-06-01T20:11:13.092Z,1527883873.092 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 36.807216 seconds old.
2018-06-01T20:11:13.496Z,1527883873.496 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 37.210732 seconds old.
2018-06-01T20:11:13.900Z,1527883873.900 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 37.615423 seconds old.
2018-06-01T20:11:14.299Z,1527883874.299 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 38.014504 seconds old.
2018-06-01T20:11:14.694Z,1527883874.694 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 38.408994 seconds old.
2018-06-01T20:11:15.102Z,1527883875.102 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 38.816763 seconds old.
2018-06-01T20:11:15.499Z,1527883875.499 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 39.214486 seconds old.
2018-06-01T20:11:15.895Z,1527883875.895 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 39.610273 seconds old.
2018-06-01T20:11:16.302Z,1527883876.302 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 40.016921 seconds old.
2018-06-01T20:11:16.693Z,1527883876.693 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 40.408293 seconds old.
2018-06-01T20:11:17.095Z,1527883877.095 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 40.810254 seconds old.
2018-06-01T20:11:17.496Z,1527883877.496 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 41.210724 seconds old.
2018-06-01T20:11:17.892Z,1527883877.892 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 41.607469 seconds old.
2018-06-01T20:11:18.302Z,1527883878.302 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 42.017078 seconds old.
2018-06-01T20:11:18.700Z,1527883878.700 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 42.415487 seconds old.
2018-06-01T20:11:19.099Z,1527883879.099 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 42.814112 seconds old.
2018-06-01T20:11:19.498Z,1527883879.498 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 43.212761 seconds old.
2018-06-01T20:11:19.902Z,1527883879.902 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 43.616971 seconds old.
2018-06-01T20:11:20.299Z,1527883880.299 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 44.014352 seconds old.
2018-06-01T20:11:20.703Z,1527883880.703 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 44.418338 seconds old.
2018-06-01T20:11:21.103Z,1527883881.103 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 44.818074 seconds old.
2018-06-01T20:11:21.496Z,1527883881.496 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 45.211494 seconds old.
2018-06-01T20:11:21.908Z,1527883881.908 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 45.622732 seconds old.
2018-06-01T20:11:22.303Z,1527883882.303 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 46.018518 seconds old.
2018-06-01T20:11:22.693Z,1527883882.693 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 46.407714 seconds old.
2018-06-01T20:11:23.104Z,1527883883.104 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 46.819460 seconds old.
2018-06-01T20:11:23.488Z,1527883883.488 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 47.202825 seconds old.
2018-06-01T20:11:23.887Z,1527883883.887 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 47.602634 seconds old.
2018-06-01T20:11:24.295Z,1527883884.295 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 48.009747 seconds old.
2018-06-01T20:11:24.696Z,1527883884.696 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 48.410726 seconds old.
2018-06-01T20:11:25.091Z,1527883885.091 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 48.805933 seconds old.
2018-06-01T20:11:25.496Z,1527883885.496 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 49.210950 seconds old.
2018-06-01T20:11:25.891Z,1527883885.891 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 49.606500 seconds old.
2018-06-01T20:11:26.292Z,1527883886.292 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 50.007187 seconds old.
2018-06-01T20:11:26.691Z,1527883886.691 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 50.405791 seconds old.
2018-06-01T20:11:27.092Z,1527883887.092 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 50.807083 seconds old.
2018-06-01T20:11:27.492Z,1527883887.492 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 51.206873 seconds old.
2018-06-01T20:11:27.890Z,1527883887.890 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 51.605414 seconds old.
2018-06-01T20:11:28.296Z,1527883888.296 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 52.010736 seconds old.
2018-06-01T20:11:28.690Z,1527883888.690 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 52.405025 seconds old.
2018-06-01T20:11:29.096Z,1527883889.096 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 52.811618 seconds old.
2018-06-01T20:11:29.496Z,1527883889.496 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 53.210726 seconds old.
2018-06-01T20:11:29.890Z,1527883889.890 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 53.604980 seconds old.
2018-06-01T20:11:30.296Z,1527883890.296 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 54.010739 seconds old.
2018-06-01T20:11:30.696Z,1527883890.696 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 54.410729 seconds old.
2018-06-01T20:11:31.091Z,1527883891.091 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 54.806601 seconds old.
2018-06-01T20:11:31.491Z,1527883891.491 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 55.206339 seconds old.
2018-06-01T20:11:31.894Z,1527883891.894 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 55.609452 seconds old.
2018-06-01T20:11:32.301Z,1527883892.301 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 56.016482 seconds old.
2018-06-01T20:11:32.700Z,1527883892.700 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 56.415055 seconds old.
2018-06-01T20:11:33.109Z,1527883893.109 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 56.823973 seconds old.
2018-06-01T20:11:33.493Z,1527883893.493 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 57.208431 seconds old.
2018-06-01T20:11:33.903Z,1527883893.903 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 57.617850 seconds old.
2018-06-01T20:11:34.310Z,1527883894.310 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 58.025634 seconds old.
2018-06-01T20:11:34.700Z,1527883894.700 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 58.415533 seconds old.
2018-06-01T20:11:35.100Z,1527883895.100 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 58.815368 seconds old.
2018-06-01T20:11:35.508Z,1527883895.508 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 59.223118 seconds old.
2018-06-01T20:11:35.888Z,1527883895.888 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 59.603530 seconds old.
2018-06-01T20:11:36.291Z,1527883896.291 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 60.006523 seconds old.
2018-06-01T20:11:36.684Z,1527883896.684 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 60.399223 seconds old.
2018-06-01T20:11:37.090Z,1527883897.090 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 60.805331 seconds old.
2018-06-01T20:11:37.510Z,1527883897.510 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 61.225616 seconds old.
2018-06-01T20:11:37.896Z,1527883897.896 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 61.611213 seconds old.
2018-06-01T20:11:38.289Z,1527883898.289 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 62.003679 seconds old.
2018-06-01T20:11:38.692Z,1527883898.692 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 62.407185 seconds old.
2018-06-01T20:11:39.096Z,1527883899.096 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 62.810746 seconds old.
2018-06-01T20:11:39.490Z,1527883899.490 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 63.204824 seconds old.
2018-06-01T20:11:39.888Z,1527883899.888 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 63.603606 seconds old.
2018-06-01T20:11:40.291Z,1527883900.291 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 64.005894 seconds old.
2018-06-01T20:11:40.691Z,1527883900.691 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 64.406298 seconds old.
2018-06-01T20:11:41.096Z,1527883901.096 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 64.810719 seconds old.
2018-06-01T20:11:41.496Z,1527883901.496 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 65.210697 seconds old.
2018-06-01T20:11:41.892Z,1527883901.892 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 65.606723 seconds old.
2018-06-01T20:11:42.296Z,1527883902.296 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 66.010746 seconds old.
2018-06-01T20:11:42.690Z,1527883902.690 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 66.405654 seconds old.
2018-06-01T20:11:43.090Z,1527883903.090 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 66.805470 seconds old.
2018-06-01T20:11:43.496Z,1527883903.496 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 67.210725 seconds old.
2018-06-01T20:11:43.896Z,1527883903.896 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 67.610751 seconds old.
2018-06-01T20:11:44.290Z,1527883904.290 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 68.005027 seconds old.
2018-06-01T20:11:44.696Z,1527883904.696 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 68.410745 seconds old.
2018-06-01T20:11:45.094Z,1527883905.094 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 68.809104 seconds old.
2018-06-01T20:11:45.491Z,1527883905.491 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 69.206213 seconds old.
2018-06-01T20:11:45.896Z,1527883905.896 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 69.610719 seconds old.
2018-06-01T20:11:46.295Z,1527883906.295 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 70.010033 seconds old.
2018-06-01T20:11:46.691Z,1527883906.691 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 70.405928 seconds old.
2018-06-01T20:11:47.096Z,1527883907.096 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 70.810742 seconds old.
2018-06-01T20:11:47.495Z,1527883907.495 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 71.209910 seconds old.
2018-06-01T20:11:47.891Z,1527883907.891 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 71.605683 seconds old.
2018-06-01T20:11:48.291Z,1527883908.291 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 72.006193 seconds old.
2018-06-01T20:11:48.693Z,1527883908.693 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 72.408396 seconds old.
2018-06-01T20:11:49.091Z,1527883909.091 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 72.806147 seconds old.
2018-06-01T20:11:49.496Z,1527883909.496 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 73.210729 seconds old.
2018-06-01T20:11:49.899Z,1527883909.899 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 73.614282 seconds old.
2018-06-01T20:11:50.291Z,1527883910.291 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 74.006163 seconds old.
2018-06-01T20:11:50.696Z,1527883910.696 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 74.410749 seconds old.
2018-06-01T20:11:51.095Z,1527883911.095 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 74.810136 seconds old.
2018-06-01T20:11:51.491Z,1527883911.491 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 75.205667 seconds old.
2018-06-01T20:11:51.896Z,1527883911.896 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 75.610694 seconds old.
2018-06-01T20:11:52.295Z,1527883912.295 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 76.010521 seconds old.
2018-06-01T20:11:52.690Z,1527883912.690 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 76.405488 seconds old.
2018-06-01T20:11:53.096Z,1527883913.096 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 76.810724 seconds old.
2018-06-01T20:11:53.494Z,1527883913.494 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 77.209026 seconds old.
2018-06-01T20:11:53.891Z,1527883913.891 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 77.605697 seconds old.
2018-06-01T20:11:54.296Z,1527883914.296 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 78.010716 seconds old.
2018-06-01T20:11:54.695Z,1527883914.695 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 78.410555 seconds old.
2018-06-01T20:11:55.103Z,1527883915.103 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 78.817875 seconds old.
2018-06-01T20:11:55.495Z,1527883915.495 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 79.210012 seconds old.
2018-06-01T20:11:55.904Z,1527883915.904 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 79.619360 seconds old.
2018-06-01T20:11:56.293Z,1527883916.293 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 80.007813 seconds old.
2018-06-01T20:11:56.700Z,1527883916.700 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 80.415625 seconds old.
2018-06-01T20:11:59.897Z,1527883919.897 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 83.612548 seconds old.
2018-06-01T20:12:00.039Z,1527883920.039 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 83.754059 seconds old.
2018-06-01T20:12:56.372Z,1527883976.372 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-06-01T20:12:56.372Z,1527883976.372 [Default:CheckIn:C.Wait] Stopped
2018-06-01T20:12:56.372Z,1527883976.372 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-06-01T20:12:56.372Z,1527883976.372 [Default:CheckIn:D] Running Loop=1
2018-06-01T20:12:56.784Z,1527883976.784 [Default:CheckIn:D] Stopped
2018-06-01T20:12:56.784Z,1527883976.784 [Default:CheckIn:E] Running Loop=1
2018-06-01T20:13:00.082Z,1527883980.082 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 89.710824 min 
2018-06-01T20:13:00.082Z,1527883980.082 [Default:CheckIn:E] Stopped
2018-06-01T20:13:00.082Z,1527883980.082 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-06-01T20:13:00.082Z,1527883980.082 [Default:CheckIn] Stopped
2018-06-01T20:13:00.082Z,1527883980.082 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-06-01T20:13:00.082Z,1527883980.082 [Default:CheckIn](INFO): Running loop #10
2018-06-01T20:13:00.083Z,1527883980.083 [Default:CheckIn] Running Loop=10
2018-06-01T20:13:00.083Z,1527883980.083 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-06-01T20:13:00.083Z,1527883980.083 [Default:CheckIn:Read_GPS] Running Loop=1
2018-06-01T20:13:00.513Z,1527883980.513 [NAL9602](INFO): Powering up
2018-06-01T20:13:11.710Z,1527883991.710 [NAL9602](INFO): NAL9602 initialized
2018-06-01T20:13:19.338Z,1527883999.338 [BPC1](ERROR): Failed to receive data from both battery packs
2018-06-01T20:13:19.339Z,1527883999.339 [BPC1] Communications Fault, FailCount= 2
2018-06-01T20:13:19.339Z,1527883999.339 [BPC1](ERROR): Communications Fault
2018-06-01T20:13:19.430Z,1527883999.430 [CBIT](ERROR): Communications Fault in component: BPC1
2018-06-01T20:13:20.596Z,1527884000.596 [CBIT](INFO): Clearing failed state for component BPC1
2018-06-01T20:13:20.596Z,1527884000.596 [BPC1] No Fault, FailCount= 2
2018-06-01T20:13:43.706Z,1527884023.706 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2018-06-01T20:13:43.781Z,1527884023.781 [NAL9602](FAULT): received: 
+CSQ:0

OK95, 2, 0, 0, 0

OK
2018-06-01T20:13:43.781Z,1527884023.781 [NAL9602] Data Fault, FailCount= 2
2018-06-01T20:13:43.781Z,1527884023.781 [NAL9602](ERROR): Data Fault
2018-06-01T20:13:43.863Z,1527884023.863 [CBIT](ERROR): Data Fault in component: NAL9602
2018-06-01T20:13:44.106Z,1527884024.106 [NAL9602](INFO): Powering down
2018-06-01T20:13:44.974Z,1527884024.974 [CBIT](INFO): Clearing failed state for component NAL9602
2018-06-01T20:13:44.974Z,1527884024.974 [NAL9602] No Fault, FailCount= 2
2018-06-01T20:14:14.138Z,1527884054.138 [NAL9602](INFO): Powering up NAL9602
2018-06-01T20:14:25.342Z,1527884065.342 [NAL9602](INFO): NAL9602 initialized
2018-06-01T20:14:26.134Z,1527884066.134 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-06-01T20:14:26.134Z,1527884066.134 [NAL9602] Data Fault, FailCount= 3
2018-06-01T20:14:26.134Z,1527884066.134 [NAL9602](ERROR): Data Fault
2018-06-01T20:14:26.225Z,1527884066.225 [CBIT](ERROR): Data Fault in component: NAL9602
2018-06-01T20:14:26.534Z,1527884066.534 [NAL9602](INFO): Powering down
2018-06-01T20:14:27.408Z,1527884067.408 [CBIT](INFO): Clearing failed state for component NAL9602
2018-06-01T20:14:27.408Z,1527884067.408 [NAL9602] No Fault, FailCount= 3
2018-06-01T20:14:56.538Z,1527884096.538 [NAL9602](INFO): Powering up NAL9602
2018-06-01T20:15:07.466Z,1527884107.466 [NAL9602](INFO): NAL9602 initialized
2018-06-01T20:16:09.215Z,1527884169.215 [NAL9602](INFO): SBD MO Status=2, MOMSN=6095, MT Status=2, MTMSN=0
2018-06-01T20:16:09.215Z,1527884169.215 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T20:18:00.423Z,1527884280.423 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-06-01T20:13:00.1Z
2018-06-01T20:18:00.423Z,1527884280.423 [Default:CheckIn:Read_GPS] Stopped
2018-06-01T20:18:00.423Z,1527884280.423 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-06-01T20:18:05.343Z,1527884285.343 [DataOverHttps](INFO): Sending 267 bytes from file Logs/20180601T183943/Courier0031.lzma
2018-06-01T20:18:06.135Z,1527884286.135 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Courier0031.lzma.bak
2018-06-01T20:18:06.136Z,1527884286.136 [DataOverHttps](INFO): SBD MOMSN=8303770
2018-06-01T20:18:14.378Z,1527884294.378 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-06-01T20:18:18.419Z,1527884298.419 [DataOverHttps](INFO): Sending 254 bytes from file Logs/20180601T183943/Express0032.lzma
2018-06-01T20:18:19.187Z,1527884299.187 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Express0032.lzma.bak
2018-06-01T20:18:19.188Z,1527884299.188 [DataOverHttps](INFO): SBD MOMSN=8303774
2018-06-01T20:18:20.371Z,1527884300.371 [Default:CheckIn:Read_Iridium] Stopped
2018-06-01T20:18:20.371Z,1527884300.371 [Default:CheckIn:C.Wait] Running Loop=1
2018-06-01T20:18:20.371Z,1527884300.371 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-06-01T20:18:44.806Z,1527884324.806 [NAL9602](INFO): Powering down
2018-06-01T20:23:20.592Z,1527884600.592 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-06-01T20:23:20.592Z,1527884600.592 [Default:CheckIn:C.Wait] Stopped
2018-06-01T20:23:20.592Z,1527884600.592 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-06-01T20:23:20.592Z,1527884600.592 [Default:CheckIn:D] Running Loop=1
2018-06-01T20:23:20.996Z,1527884600.996 [Default:CheckIn:D] Stopped
2018-06-01T20:23:20.996Z,1527884600.996 [Default:CheckIn:E] Running Loop=1
2018-06-01T20:23:24.100Z,1527884604.100 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 100.114364 min 
2018-06-01T20:23:24.133Z,1527884604.133 [Default:CheckIn:E] Stopped
2018-06-01T20:23:24.133Z,1527884604.133 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-06-01T20:23:24.133Z,1527884604.133 [Default:CheckIn] Stopped
2018-06-01T20:23:24.133Z,1527884604.133 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-06-01T20:23:24.134Z,1527884604.134 [Default:CheckIn](INFO): Running loop #11
2018-06-01T20:23:24.134Z,1527884604.134 [Default:CheckIn] Running Loop=11
2018-06-01T20:23:24.134Z,1527884604.134 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-06-01T20:23:24.134Z,1527884604.134 [Default:CheckIn:Read_GPS] Running Loop=1
2018-06-01T20:23:24.583Z,1527884604.583 [NAL9602](INFO): Powering up
2018-06-01T20:23:35.378Z,1527884615.378 [NAL9602](INFO): NAL9602 initialized
2018-06-01T20:24:07.378Z,1527884647.378 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2018-06-01T20:24:07.453Z,1527884647.453 [NAL9602](FAULT): received: 
+CSQ:0

OK95, 2, 0, 0, 0

OK
2018-06-01T20:24:07.453Z,1527884647.453 [NAL9602] Data Fault, FailCount= 4
2018-06-01T20:24:07.453Z,1527884647.453 [NAL9602](ERROR): Data Fault
2018-06-01T20:24:07.552Z,1527884647.552 [CBIT](ERROR): Data Fault in component: NAL9602
2018-06-01T20:24:07.785Z,1527884647.785 [NAL9602](INFO): Powering down
2018-06-01T20:24:08.673Z,1527884648.673 [CBIT](INFO): Clearing failed state for component NAL9602
2018-06-01T20:24:08.673Z,1527884648.673 [NAL9602] No Fault, FailCount= 4
2018-06-01T20:24:37.850Z,1527884677.850 [NAL9602](INFO): Powering up NAL9602
2018-06-01T20:24:49.051Z,1527884689.051 [NAL9602](INFO): NAL9602 initialized
2018-06-01T20:25:00.340Z,1527884700.340 [CBIT](INFO): Clearing failed state for component DropWeight
2018-06-01T20:25:00.340Z,1527884700.340 [DropWeight] No Fault, FailCount= 1
2018-06-01T20:28:24.624Z,1527884904.624 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-06-01T20:23:24.1Z
2018-06-01T20:28:24.624Z,1527884904.624 [Default:CheckIn:Read_GPS] Stopped
2018-06-01T20:28:24.624Z,1527884904.624 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-06-01T20:28:29.638Z,1527884909.638 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180601T183943/Courier0034.lzma
2018-06-01T20:28:30.408Z,1527884910.408 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Courier0034.lzma.bak
2018-06-01T20:28:30.408Z,1527884910.408 [DataOverHttps](INFO): SBD MOMSN=8303806
2018-06-01T20:28:39.499Z,1527884919.499 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-06-01T20:28:39.606Z,1527884919.606 [DataOverHttps](INFO): Sending 238 bytes from file Logs/20180601T183943/Express0035.lzma
2018-06-01T20:28:40.395Z,1527884920.395 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Express0035.lzma.bak
2018-06-01T20:28:40.396Z,1527884920.396 [DataOverHttps](INFO): SBD MOMSN=8303808
2018-06-01T20:28:41.504Z,1527884921.504 [Default:CheckIn:Read_Iridium] Stopped
2018-06-01T20:28:41.504Z,1527884921.504 [Default:CheckIn:C.Wait] Running Loop=1
2018-06-01T20:28:41.504Z,1527884921.504 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-06-01T20:29:10.030Z,1527884950.030 [NAL9602](INFO): Powering down
2018-06-01T20:33:41.995Z,1527885221.995 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-06-01T20:33:41.995Z,1527885221.995 [Default:CheckIn:C.Wait] Stopped
2018-06-01T20:33:41.996Z,1527885221.996 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-06-01T20:33:41.996Z,1527885221.996 [Default:CheckIn:D] Running Loop=1
2018-06-01T20:33:42.399Z,1527885222.399 [Default:CheckIn:D] Stopped
2018-06-01T20:33:42.399Z,1527885222.399 [Default:CheckIn:E] Running Loop=1
2018-06-01T20:33:45.536Z,1527885225.536 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 110.471077 min 
2018-06-01T20:33:45.536Z,1527885225.536 [Default:CheckIn:E] Stopped
2018-06-01T20:33:45.536Z,1527885225.536 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-06-01T20:33:45.536Z,1527885225.536 [Default:CheckIn] Stopped
2018-06-01T20:33:45.536Z,1527885225.536 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-06-01T20:33:45.541Z,1527885225.541 [Default:CheckIn](INFO): Running loop #12
2018-06-01T20:33:45.541Z,1527885225.541 [Default:CheckIn] Running Loop=12
2018-06-01T20:33:45.541Z,1527885225.541 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-06-01T20:33:45.541Z,1527885225.541 [Default:CheckIn:Read_GPS] Running Loop=1
2018-06-01T20:33:45.978Z,1527885225.978 [NAL9602](INFO): Powering up
2018-06-01T20:33:57.179Z,1527885237.179 [NAL9602](INFO): NAL9602 initialized
2018-06-01T20:33:57.979Z,1527885237.979 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-06-01T20:33:57.979Z,1527885237.979 [NAL9602] Data Fault, FailCount= 5
2018-06-01T20:33:57.979Z,1527885237.979 [NAL9602](ERROR): Data Fault
2018-06-01T20:33:58.059Z,1527885238.059 [CBIT](ERROR): Data Fault in component: NAL9602
2018-06-01T20:33:58.060Z,1527885238.060 [CBIT](CRITICAL): Data Fault in component: NAL9602
2018-06-01T20:33:58.386Z,1527885238.386 [NAL9602](INFO): Powering down
2018-06-01T20:33:58.461Z,1527885238.461 [CBIT](INFO): Critical error at 20180601T203358
2018-06-01T20:35:58.209Z,1527885358.209 [CBIT](INFO): Clearing failed state for component NAL9602
2018-06-01T20:35:58.209Z,1527885358.209 [NAL9602] No Fault, FailCount= 5
2018-06-01T20:35:58.482Z,1527885358.482 [NAL9602](INFO): Powering up NAL9602
2018-06-01T20:36:09.682Z,1527885369.682 [NAL9602](INFO): NAL9602 initialized
2018-06-01T20:36:47.884Z,1527885407.884 [NAL9602](INFO): SBD MO Status=0, MOMSN=6095, MT Status=0, MTMSN=0
2018-06-01T20:36:47.884Z,1527885407.884 [NAL9602](INFO): No messages in MT queue
2018-06-01T20:36:47.884Z,1527885407.884 [NAL9602](INFO): Failure count cleared after critical for NAL9602
2018-06-01T20:38:45.920Z,1527885525.920 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-06-01T20:33:45.5Z
2018-06-01T20:38:45.921Z,1527885525.921 [Default:CheckIn:Read_GPS] Stopped
2018-06-01T20:38:45.921Z,1527885525.921 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-06-01T20:38:50.815Z,1527885530.815 [DataOverHttps](INFO): Sending 69 bytes from file Logs/20180601T183943/Courier0037.lzma
2018-06-01T20:38:51.608Z,1527885531.608 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Courier0037.lzma.bak
2018-06-01T20:38:51.608Z,1527885531.608 [DataOverHttps](INFO): SBD MOMSN=8303821
2018-06-01T20:39:17.963Z,1527885557.963 [NAL9602](INFO): Powering down
2018-06-01T20:39:22.758Z,1527885562.758 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-06-01T20:39:53.158Z,1527885593.158 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-06-01T20:40:23.958Z,1527885623.958 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-06-01T20:40:54.758Z,1527885654.758 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-06-01T20:41:25.158Z,1527885685.158 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-06-01T20:41:51.959Z,1527885711.959 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.351837
2018-06-01T20:41:51.962Z,1527885711.962 [NAL9602](INFO): Powering up
2018-06-01T20:42:02.766Z,1527885722.766 [NAL9602](INFO): NAL9602 initialized
2018-06-01T20:42:23.109Z,1527885743.109 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-06-01T20:42:41.196Z,1527885761.196 [NAL9602](INFO): SBD MO Status=1, MOMSN=6096, MT Status=0, MTMSN=0
2018-06-01T20:42:41.249Z,1527885761.249 [NAL9602](INFO): Sent 216 bytes from file Logs/20180601T183943/Express0038.lzma
2018-06-01T20:42:41.249Z,1527885761.249 [NAL9602](INFO): Packets left to send: 0
2018-06-01T20:42:41.251Z,1527885761.251 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180601T183943/Express0038.lzma.parts/0000.sbd
2018-06-01T20:42:41.251Z,1527885761.251 [NAL9602](DEBUG): Completed sending Logs/20180601T183943/Express0038.lzma
2018-06-01T20:42:58.760Z,1527885778.760 [NAL9602](INFO): SBD MO Status=2, MOMSN=6097, MT Status=2, MTMSN=0
2018-06-01T20:42:58.760Z,1527885778.760 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T20:43:09.696Z,1527885789.696 [NAL9602](INFO): SBD MO Status=0, MOMSN=6097, MT Status=0, MTMSN=0
2018-06-01T20:43:09.797Z,1527885789.797 [Default:CheckIn:Read_Iridium] Stopped
2018-06-01T20:43:09.797Z,1527885789.797 [Default:CheckIn:C.Wait] Running Loop=1
2018-06-01T20:43:09.797Z,1527885789.797 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-06-01T20:43:22.890Z,1527885802.890 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-06-01T20:43:40.494Z,1527885820.494 [NAL9602](INFO): Powering down
2018-06-01T20:44:22.890Z,1527885862.890 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-06-01T20:44:57.726Z,1527885897.726 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002819
2018-06-01T20:48:10.419Z,1527886090.419 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-06-01T20:48:10.419Z,1527886090.419 [Default:CheckIn:C.Wait] Stopped
2018-06-01T20:48:10.419Z,1527886090.419 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-06-01T20:48:10.420Z,1527886090.420 [Default:CheckIn:D] Running Loop=1
2018-06-01T20:48:10.824Z,1527886090.824 [Default:CheckIn:D] Stopped
2018-06-01T20:48:10.824Z,1527886090.824 [Default:CheckIn:E] Running Loop=1
2018-06-01T20:48:11.231Z,1527886091.231 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 124.944824 min 
2018-06-01T20:48:11.231Z,1527886091.231 [Default:CheckIn:E] Stopped
2018-06-01T20:48:11.231Z,1527886091.231 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-06-01T20:48:11.231Z,1527886091.231 [Default:CheckIn] Stopped
2018-06-01T20:48:11.232Z,1527886091.232 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-06-01T20:48:11.232Z,1527886091.232 [Default:CheckIn](INFO): Running loop #13
2018-06-01T20:48:11.232Z,1527886091.232 [Default:CheckIn] Running Loop=13
2018-06-01T20:48:11.232Z,1527886091.232 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-06-01T20:48:11.232Z,1527886091.232 [Default:CheckIn:Read_GPS] Running Loop=1
2018-06-01T20:48:11.974Z,1527886091.974 [NAL9602](INFO): Powering up
2018-06-01T20:48:22.774Z,1527886102.774 [NAL9602](INFO): NAL9602 initialized
2018-06-01T20:48:23.574Z,1527886103.574 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-06-01T20:48:23.574Z,1527886103.574 [NAL9602] Data Fault, FailCount= 1
2018-06-01T20:48:23.575Z,1527886103.575 [NAL9602](ERROR): Data Fault
2018-06-01T20:48:23.669Z,1527886103.669 [CBIT](ERROR): Data Fault in component: NAL9602
2018-06-01T20:48:23.974Z,1527886103.974 [NAL9602](INFO): Powering down
2018-06-01T20:48:24.855Z,1527886104.855 [CBIT](INFO): Clearing failed state for component NAL9602
2018-06-01T20:48:24.855Z,1527886104.855 [NAL9602] No Fault, FailCount= 1
2018-06-01T20:48:53.978Z,1527886133.978 [NAL9602](INFO): Powering up NAL9602
2018-06-01T20:48:57.987Z,1527886137.987 [DataOverHttps](IMPORTANT): SBD MTMSN=20180601T204813
2018-06-01T20:49:01.995Z,1527886141.995 [DataOverHttps](INFO): Received command:ibit
2018-06-01T20:49:02.058Z,1527886142.058 [CommandLine](IMPORTANT): got command ibit
2018-06-01T20:49:02.137Z,1527886142.137 [IBIT](IMPORTANT): Beginning Initiated BIT
2018-06-01T20:49:02.137Z,1527886142.137 [IBIT](IMPORTANT): Beginning control surface checks.
2018-06-01T20:49:02.141Z,1527886142.141 [CBIT](IMPORTANT): Beginning ground fault scan
2018-06-01T20:49:04.802Z,1527886144.802 [NAL9602](INFO): NAL9602 initialized
2018-06-01T20:49:12.904Z,1527886152.904 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.125575
CHAN A1 (24V): -0.012496
CHAN A2 (12V): -0.002039
CHAN A3 (5V): -0.001577
CHAN B0 (3.3V): 0.000207
CHAN B1 (3.15aV): -0.000175
CHAN B2 (3.15bV): -0.000184
CHAN B3 (GND): 0.000565
OPEN: -0.000311
Full Scale Calc: 4.765 mA, -1.589 mA
2018-06-01T20:49:19.220Z,1527886159.220 [NAL9602](INFO): SBD MO Status=0, MOMSN=6098, MT Status=0, MTMSN=0
2018-06-01T20:49:19.220Z,1527886159.220 [NAL9602](INFO): No messages in MT queue
2018-06-01T20:49:47.618Z,1527886187.618 [NAL9602](INFO): GPS fix at 20180601T204902: (36.802967, -121.788059)
2018-06-01T20:49:48.092Z,1527886188.092 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 5
Latitude: 36.802967 Longitude: -121.788055
2018-06-01T20:49:48.486Z,1527886188.486 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 0.000000
2018-06-01T20:49:48.486Z,1527886188.486 [IBIT](IMPORTANT): batteryCapacityThreshold: 5.000000 Ah
2018-06-01T20:49:48.487Z,1527886188.487 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.500000 V
2018-06-01T20:49:48.880Z,1527886188.880 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2018-06-01T20:49:48.880Z,1527886188.880 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2018-06-01T20:49:48.885Z,1527886188.885 [IBIT](IMPORTANT): Pressure:9.509684 PSI
2018-06-01T20:49:48.885Z,1527886188.885 [IBIT](IMPORTANT): Humidity:14.552557 %
2018-06-01T20:49:49.301Z,1527886189.301 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2018-06-01T20:49:49.301Z,1527886189.301 [IBIT](IMPORTANT): buoyancyNeutral: 315.000000 cc
2018-06-01T20:49:49.302Z,1527886189.302 [IBIT](IMPORTANT): massDefault: -0.075000 cm
2018-06-01T20:49:49.302Z,1527886189.302 [IBIT](IMPORTANT): stopDepth: 205.000000 m
2018-06-01T20:49:49.302Z,1527886189.302 [IBIT](IMPORTANT): abortDepth: 250.000000 m
2018-06-01T20:49:49.302Z,1527886189.302 [IBIT](IMPORTANT): IBIT PASSED
2018-06-01T20:49:49.691Z,1527886189.691 [Default:CheckIn:Read_GPS] Stopped
2018-06-01T20:49:49.691Z,1527886189.691 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-06-01T20:49:50.925Z,1527886190.925 [NAL9602](INFO): GPS fix at 20180601T204905: (36.802965, -121.788059)
2018-06-01T20:49:54.856Z,1527886194.856 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20180601T183943/Courier0040.lzma
2018-06-01T20:49:55.648Z,1527886195.648 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Courier0040.lzma.bak
2018-06-01T20:49:55.648Z,1527886195.648 [DataOverHttps](INFO): SBD MOMSN=8303870
2018-06-01T20:50:04.874Z,1527886204.874 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180601T183943/Courier0043.lzma
2018-06-01T20:50:05.671Z,1527886205.671 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Courier0043.lzma.bak
2018-06-01T20:50:05.672Z,1527886205.672 [DataOverHttps](INFO): SBD MOMSN=8303873
2018-06-01T20:50:15.502Z,1527886215.502 [DataOverHttps](INFO): Sending 777 bytes from file Logs/20180601T183943/Express0041.lzma
2018-06-01T20:50:16.272Z,1527886216.272 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Express0041.lzma.bak
2018-06-01T20:50:16.272Z,1527886216.272 [DataOverHttps](INFO): SBD MOMSN=8303876
2018-06-01T20:50:26.255Z,1527886226.255 [NAL9602](INFO): Powering down
2018-06-01T20:50:26.355Z,1527886226.355 [DataOverHttps](INFO): Sending 53 bytes from file Logs/20180601T183943/Express0044.lzma
2018-06-01T20:50:27.144Z,1527886227.144 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Express0044.lzma.bak
2018-06-01T20:50:27.144Z,1527886227.144 [DataOverHttps](INFO): SBD MOMSN=8303900
2018-06-01T20:50:28.400Z,1527886228.400 [Default:CheckIn:Read_Iridium] Stopped
2018-06-01T20:50:28.400Z,1527886228.400 [Default:CheckIn:C.Wait] Running Loop=1
2018-06-01T20:50:28.400Z,1527886228.400 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-06-01T20:55:28.922Z,1527886528.922 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-06-01T20:55:28.922Z,1527886528.922 [Default:CheckIn:C.Wait] Stopped
2018-06-01T20:55:28.922Z,1527886528.922 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-06-01T20:55:28.922Z,1527886528.922 [Default:CheckIn:D] Running Loop=1
2018-06-01T20:55:29.332Z,1527886529.332 [Default:CheckIn:D] Stopped
2018-06-01T20:55:29.332Z,1527886529.332 [Default:CheckIn:E] Running Loop=1
2018-06-01T20:55:32.682Z,1527886532.682 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 132.253296 min 
2018-06-01T20:55:32.682Z,1527886532.682 [Default:CheckIn:E] Stopped
2018-06-01T20:55:32.682Z,1527886532.682 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-06-01T20:55:32.682Z,1527886532.682 [Default:CheckIn] Stopped
2018-06-01T20:55:32.683Z,1527886532.683 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-06-01T20:55:32.683Z,1527886532.683 [Default:CheckIn](INFO): Running loop #14
2018-06-01T20:55:32.683Z,1527886532.683 [Default:CheckIn] Running Loop=14
2018-06-01T20:55:32.683Z,1527886532.683 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-06-01T20:55:32.683Z,1527886532.683 [Default:CheckIn:Read_GPS] Running Loop=1
2018-06-01T20:55:33.106Z,1527886533.106 [NAL9602](INFO): Powering up
2018-06-01T20:55:44.306Z,1527886544.306 [NAL9602](INFO): NAL9602 initialized
2018-06-01T21:00:33.278Z,1527886833.278 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-06-01T20:55:32.7Z
2018-06-01T21:00:33.278Z,1527886833.278 [Default:CheckIn:Read_GPS] Stopped
2018-06-01T21:00:33.278Z,1527886833.278 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-06-01T21:00:34.046Z,1527886834.046 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20180601T183943/Courier0046.lzma
2018-06-01T21:00:34.959Z,1527886834.959 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Courier0046.lzma.bak
2018-06-01T21:00:34.960Z,1527886834.960 [DataOverHttps](INFO): SBD MOMSN=8303938
2018-06-01T21:00:45.094Z,1527886845.094 [DataOverHttps](INFO): Sending 122 bytes from file Logs/20180601T183943/Express0047.lzma
2018-06-01T21:00:45.891Z,1527886845.891 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Express0047.lzma.bak
2018-06-01T21:00:45.892Z,1527886845.892 [DataOverHttps](INFO): SBD MOMSN=8303941
2018-06-01T21:00:46.955Z,1527886846.955 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-06-01T21:00:47.010Z,1527886847.010 [Default:CheckIn:Read_Iridium] Stopped
2018-06-01T21:00:47.010Z,1527886847.010 [Default:CheckIn:C.Wait] Running Loop=1
2018-06-01T21:00:47.010Z,1527886847.010 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-06-01T21:01:17.114Z,1527886877.114 [NAL9602](INFO): Powering down
2018-06-01T21:05:47.308Z,1527887147.308 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-06-01T21:05:47.308Z,1527887147.308 [Default:CheckIn:C.Wait] Stopped
2018-06-01T21:05:47.308Z,1527887147.308 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-06-01T21:05:47.308Z,1527887147.308 [Default:CheckIn:D] Running Loop=1
2018-06-01T21:05:47.719Z,1527887147.719 [Default:CheckIn:D] Stopped
2018-06-01T21:05:47.719Z,1527887147.719 [Default:CheckIn:E] Running Loop=1
2018-06-01T21:05:50.826Z,1527887150.826 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 142.559749 min 
2018-06-01T21:05:50.827Z,1527887150.827 [Default:CheckIn:E] Stopped
2018-06-01T21:05:50.827Z,1527887150.827 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-06-01T21:05:50.827Z,1527887150.827 [Default:CheckIn] Stopped
2018-06-01T21:05:50.827Z,1527887150.827 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-06-01T21:05:50.827Z,1527887150.827 [Default:CheckIn](INFO): Running loop #15
2018-06-01T21:05:50.827Z,1527887150.827 [Default:CheckIn] Running Loop=15
2018-06-01T21:05:50.827Z,1527887150.827 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-06-01T21:05:50.828Z,1527887150.828 [Default:CheckIn:Read_GPS] Running Loop=1
2018-06-01T21:05:51.262Z,1527887151.262 [NAL9602](INFO): Powering up
2018-06-01T21:06:02.450Z,1527887162.450 [NAL9602](INFO): NAL9602 initialized
2018-06-01T21:06:03.250Z,1527887163.250 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-06-01T21:06:03.251Z,1527887163.251 [NAL9602] Data Fault, FailCount= 1
2018-06-01T21:06:03.251Z,1527887163.251 [NAL9602](ERROR): Data Fault
2018-06-01T21:06:03.345Z,1527887163.345 [CBIT](ERROR): Data Fault in component: NAL9602
2018-06-01T21:06:03.650Z,1527887163.650 [NAL9602](INFO): Powering down
2018-06-01T21:06:04.540Z,1527887164.540 [CBIT](INFO): Clearing failed state for component NAL9602
2018-06-01T21:06:04.540Z,1527887164.540 [NAL9602] No Fault, FailCount= 1
2018-06-01T21:06:34.050Z,1527887194.050 [NAL9602](INFO): Powering up NAL9602
2018-06-01T21:06:45.250Z,1527887205.250 [NAL9602](INFO): NAL9602 initialized
2018-06-01T21:10:51.622Z,1527887451.622 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-06-01T21:05:50.8Z
2018-06-01T21:10:51.623Z,1527887451.623 [Default:CheckIn:Read_GPS] Stopped
2018-06-01T21:10:51.623Z,1527887451.623 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-06-01T21:10:52.403Z,1527887452.403 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180601T183943/Courier0049.lzma
2018-06-01T21:10:53.295Z,1527887453.295 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Courier0049.lzma.bak
2018-06-01T21:10:53.296Z,1527887453.296 [DataOverHttps](INFO): SBD MOMSN=8303958
2018-06-01T21:11:03.982Z,1527887463.982 [DataOverHttps](INFO): Sending 217 bytes from file Logs/20180601T183943/Express0050.lzma
2018-06-01T21:11:04.756Z,1527887464.756 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Express0050.lzma.bak
2018-06-01T21:11:04.756Z,1527887464.756 [DataOverHttps](INFO): SBD MOMSN=8303966
2018-06-01T21:11:05.887Z,1527887465.887 [Default:CheckIn:Read_Iridium] Stopped
2018-06-01T21:11:05.887Z,1527887465.887 [Default:CheckIn:C.Wait] Running Loop=1
2018-06-01T21:11:05.887Z,1527887465.887 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-06-01T21:11:24.832Z,1527887484.832 [NAL9602](INFO): SBD MO Status=2, MOMSN=6099, MT Status=2, MTMSN=0
2018-06-01T21:11:24.832Z,1527887484.832 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T21:11:48.034Z,1527887508.034 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-06-01T21:12:18.735Z,1527887538.735 [NAL9602](INFO): Powering down
2018-06-01T21:15:37.010Z,1527887737.010 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-06-01T21:16:06.260Z,1527887766.260 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-06-01T21:16:06.260Z,1527887766.260 [Default:CheckIn:C.Wait] Stopped
2018-06-01T21:16:06.260Z,1527887766.260 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-06-01T21:16:06.261Z,1527887766.261 [Default:CheckIn:D] Running Loop=1
2018-06-01T21:16:06.670Z,1527887766.670 [Default:CheckIn:D] Stopped
2018-06-01T21:16:06.670Z,1527887766.670 [Default:CheckIn:E] Running Loop=1
2018-06-01T21:16:07.071Z,1527887767.071 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 152.875602 min 
2018-06-01T21:16:07.072Z,1527887767.072 [Default:CheckIn:E] Stopped
2018-06-01T21:16:07.072Z,1527887767.072 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-06-01T21:16:07.072Z,1527887767.072 [Default:CheckIn] Stopped
2018-06-01T21:16:07.072Z,1527887767.072 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-06-01T21:16:07.072Z,1527887767.072 [Default:CheckIn](INFO): Running loop #16
2018-06-01T21:16:07.072Z,1527887767.072 [Default:CheckIn] Running Loop=16
2018-06-01T21:16:07.072Z,1527887767.072 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-06-01T21:16:07.073Z,1527887767.073 [Default:CheckIn:Read_GPS] Running Loop=1
2018-06-01T21:16:07.815Z,1527887767.815 [NAL9602](INFO): Powering up
2018-06-01T21:16:19.015Z,1527887779.015 [NAL9602](INFO): NAL9602 initialized
2018-06-01T21:16:37.011Z,1527887797.011 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-06-01T21:16:51.023Z,1527887811.023 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2018-06-01T21:16:51.105Z,1527887811.105 [NAL9602](FAULT): received: 
+CSQ:0

OK99, 2, 0, 0, 0

OK
2018-06-01T21:16:51.106Z,1527887811.106 [NAL9602] Data Fault, FailCount= 2
2018-06-01T21:16:51.106Z,1527887811.106 [NAL9602](ERROR): Data Fault
2018-06-01T21:16:51.192Z,1527887811.192 [CBIT](ERROR): Data Fault in component: NAL9602
2018-06-01T21:16:51.414Z,1527887811.414 [NAL9602](INFO): Powering down
2018-06-01T21:16:52.292Z,1527887812.292 [CBIT](INFO): Clearing failed state for component NAL9602
2018-06-01T21:16:52.292Z,1527887812.292 [NAL9602] No Fault, FailCount= 2
2018-06-01T21:17:11.811Z,1527887831.811 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.398346
2018-06-01T21:17:21.814Z,1527887841.814 [NAL9602](INFO): Powering up NAL9602
2018-06-01T21:17:33.014Z,1527887853.014 [NAL9602](INFO): NAL9602 initialized
2018-06-01T21:17:33.814Z,1527887853.814 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-06-01T21:17:33.814Z,1527887853.814 [NAL9602] Data Fault, FailCount= 3
2018-06-01T21:17:33.815Z,1527887853.815 [NAL9602](ERROR): Data Fault
2018-06-01T21:17:33.900Z,1527887853.900 [CBIT](ERROR): Data Fault in component: NAL9602
2018-06-01T21:17:34.222Z,1527887854.222 [NAL9602](INFO): Powering down
2018-06-01T21:17:35.094Z,1527887855.094 [CBIT](INFO): Clearing failed state for component NAL9602
2018-06-01T21:17:35.094Z,1527887855.094 [NAL9602] No Fault, FailCount= 3
2018-06-01T21:18:04.619Z,1527887884.619 [NAL9602](INFO): Powering up NAL9602
2018-06-01T21:18:11.966Z,1527887891.966 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003039
2018-06-01T21:18:15.566Z,1527887895.566 [NAL9602](INFO): NAL9602 initialized
2018-06-01T21:20:16.360Z,1527888016.360 [NAL9602](INFO): SBD MO Status=2, MOMSN=6099, MT Status=2, MTMSN=0
2018-06-01T21:20:16.360Z,1527888016.360 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T21:21:07.266Z,1527888067.266 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-06-01T21:16:07.1Z
2018-06-01T21:21:07.266Z,1527888067.266 [Default:CheckIn:Read_GPS] Stopped
2018-06-01T21:21:07.266Z,1527888067.266 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-06-01T21:21:13.047Z,1527888073.047 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180601T183943/Courier0052.lzma
2018-06-01T21:21:13.848Z,1527888073.848 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Courier0052.lzma.bak
2018-06-01T21:21:13.848Z,1527888073.848 [DataOverHttps](INFO): SBD MOMSN=8303982
2018-06-01T21:21:23.419Z,1527888083.419 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-06-01T21:21:23.914Z,1527888083.914 [DataOverHttps](INFO): Sending 256 bytes from file Logs/20180601T183943/Express0053.lzma
2018-06-01T21:21:25.104Z,1527888085.104 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Express0053.lzma.bak
2018-06-01T21:21:25.108Z,1527888085.108 [DataOverHttps](INFO): SBD MOMSN=8303984
2018-06-01T21:21:26.234Z,1527888086.234 [Default:CheckIn:Read_Iridium] Stopped
2018-06-01T21:21:26.234Z,1527888086.234 [Default:CheckIn:C.Wait] Running Loop=1
2018-06-01T21:21:26.234Z,1527888086.234 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-06-01T21:21:53.875Z,1527888113.875 [NAL9602](INFO): Powering down
2018-06-01T21:25:03.054Z,1527888303.054 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2018-06-01T21:25:03.054Z,1527888303.054 [DropWeight] Hardware Fault, FailCount= 1
2018-06-01T21:25:03.054Z,1527888303.054 [DropWeight](ERROR): Hardware Fault
2018-06-01T21:25:03.134Z,1527888303.134 [CBIT](INFO): Critical error at 20180601T212503
2018-06-01T21:25:03.141Z,1527888303.141 [CBIT](ERROR): Hardware Fault in component: DropWeight
2018-06-01T21:25:03.141Z,1527888303.141 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2018-06-01T21:25:03.530Z,1527888303.530 [CBIT](INFO): Critical error at 20180601T212503
2018-06-01T21:26:26.385Z,1527888386.385 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-06-01T21:26:26.385Z,1527888386.385 [Default:CheckIn:C.Wait] Stopped
2018-06-01T21:26:26.385Z,1527888386.385 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-06-01T21:26:26.385Z,1527888386.385 [Default:CheckIn:D] Running Loop=1
2018-06-01T21:26:26.790Z,1527888386.790 [Default:CheckIn:D] Stopped
2018-06-01T21:26:26.790Z,1527888386.790 [Default:CheckIn:E] Running Loop=1
2018-06-01T21:26:27.192Z,1527888387.192 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 163.210938 min 
2018-06-01T21:26:27.193Z,1527888387.193 [Default:CheckIn:E] Stopped
2018-06-01T21:26:27.193Z,1527888387.193 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-06-01T21:26:27.193Z,1527888387.193 [Default:CheckIn] Stopped
2018-06-01T21:26:27.193Z,1527888387.193 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-06-01T21:26:27.193Z,1527888387.193 [Default:CheckIn](INFO): Running loop #17
2018-06-01T21:26:27.193Z,1527888387.193 [Default:CheckIn] Running Loop=17
2018-06-01T21:26:27.194Z,1527888387.194 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-06-01T21:26:27.194Z,1527888387.194 [Default:CheckIn:Read_GPS] Running Loop=1
2018-06-01T21:26:30.666Z,1527888390.666 [NAL9602](INFO): Powering up
2018-06-01T21:26:41.814Z,1527888401.814 [NAL9602](INFO): NAL9602 initialized
2018-06-01T21:27:13.818Z,1527888433.818 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2018-06-01T21:27:13.901Z,1527888433.901 [NAL9602](FAULT): received: 
+CSQ:0

OK99, 2, 0, 0, 0

OK
2018-06-01T21:27:13.901Z,1527888433.901 [NAL9602] Data Fault, FailCount= 4
2018-06-01T21:27:13.901Z,1527888433.901 [NAL9602](ERROR): Data Fault
2018-06-01T21:27:14.006Z,1527888434.006 [CBIT](ERROR): Data Fault in component: NAL9602
2018-06-01T21:27:14.221Z,1527888434.221 [NAL9602](INFO): Powering down
2018-06-01T21:27:15.072Z,1527888435.072 [CBIT](INFO): Clearing failed state for component NAL9602
2018-06-01T21:27:15.072Z,1527888435.072 [NAL9602] No Fault, FailCount= 4
2018-06-01T21:27:44.254Z,1527888464.254 [NAL9602](INFO): Powering up NAL9602
2018-06-01T21:27:55.458Z,1527888475.458 [NAL9602](INFO): NAL9602 initialized
2018-06-01T21:31:27.369Z,1527888687.369 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-06-01T21:26:27.2Z
2018-06-01T21:31:27.369Z,1527888687.369 [Default:CheckIn:Read_GPS] Stopped
2018-06-01T21:31:27.369Z,1527888687.369 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-06-01T21:31:31.277Z,1527888691.277 [DataOverHttps](INFO): Sending 103 bytes from file Logs/20180601T183943/Courier0055.lzma
2018-06-01T21:31:32.076Z,1527888692.076 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Courier0055.lzma.bak
2018-06-01T21:31:32.076Z,1527888692.076 [DataOverHttps](INFO): SBD MOMSN=8303996
2018-06-01T21:31:41.662Z,1527888701.662 [DataOverHttps](INFO): Sending 239 bytes from file Logs/20180601T183943/Express0056.lzma
2018-06-01T21:31:42.464Z,1527888702.464 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Express0056.lzma.bak
2018-06-01T21:31:42.464Z,1527888702.464 [DataOverHttps](INFO): SBD MOMSN=8304000
2018-06-01T21:31:43.596Z,1527888703.596 [Default:CheckIn:Read_Iridium] Stopped
2018-06-01T21:31:43.596Z,1527888703.596 [Default:CheckIn:C.Wait] Running Loop=1
2018-06-01T21:31:43.596Z,1527888703.596 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-06-01T21:31:46.777Z,1527888706.777 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-06-01T21:32:17.266Z,1527888737.266 [NAL9602](INFO): Powering down
2018-06-01T21:32:20.614Z,1527888740.614 [CommandLine](IMPORTANT): got command burn 5.000000
2018-06-01T21:32:25.625Z,1527888745.625 [CommandLine](IMPORTANT): Deactivating dropweight wire
2018-06-01T21:36:43.990Z,1527889003.990 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-06-01T21:36:43.990Z,1527889003.990 [Default:CheckIn:C.Wait] Stopped
2018-06-01T21:36:43.991Z,1527889003.991 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-06-01T21:36:43.991Z,1527889003.991 [Default:CheckIn:D] Running Loop=1
2018-06-01T21:36:44.400Z,1527889004.400 [Default:CheckIn:D] Stopped
2018-06-01T21:36:44.400Z,1527889004.400 [Default:CheckIn:E] Running Loop=1
2018-06-01T21:36:47.694Z,1527889007.694 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 173.504427 min 
2018-06-01T21:36:47.694Z,1527889007.694 [Default:CheckIn:E] Stopped
2018-06-01T21:36:47.695Z,1527889007.695 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-06-01T21:36:47.695Z,1527889007.695 [Default:CheckIn] Stopped
2018-06-01T21:36:47.695Z,1527889007.695 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-06-01T21:36:47.695Z,1527889007.695 [Default:CheckIn](INFO): Running loop #18
2018-06-01T21:36:47.695Z,1527889007.695 [Default:CheckIn] Running Loop=18
2018-06-01T21:36:47.695Z,1527889007.695 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-06-01T21:36:47.695Z,1527889007.695 [Default:CheckIn:Read_GPS] Running Loop=1
2018-06-01T21:36:48.134Z,1527889008.134 [NAL9602](INFO): Powering up
2018-06-01T21:36:59.339Z,1527889019.339 [NAL9602](INFO): NAL9602 initialized
2018-06-01T21:37:00.143Z,1527889020.143 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-06-01T21:37:00.143Z,1527889020.143 [NAL9602] Data Fault, FailCount= 5
2018-06-01T21:37:00.143Z,1527889020.143 [NAL9602](ERROR): Data Fault
2018-06-01T21:37:00.221Z,1527889020.221 [CBIT](ERROR): Data Fault in component: NAL9602
2018-06-01T21:37:00.222Z,1527889020.222 [CBIT](CRITICAL): Data Fault in component: NAL9602
2018-06-01T21:37:00.534Z,1527889020.534 [NAL9602](INFO): Powering down
2018-06-01T21:37:00.626Z,1527889020.626 [CBIT](INFO): Critical error at 20180601T213700
2018-06-01T21:39:00.251Z,1527889140.251 [CBIT](INFO): Clearing failed state for component NAL9602
2018-06-01T21:39:00.251Z,1527889140.251 [NAL9602] No Fault, FailCount= 5
2018-06-01T21:39:00.582Z,1527889140.582 [NAL9602](INFO): Powering up NAL9602
2018-06-01T21:39:11.382Z,1527889151.382 [NAL9602](INFO): NAL9602 initialized
2018-06-01T21:40:03.229Z,1527889203.229 [CBIT](INFO): Clearing failed state for component DropWeight
2018-06-01T21:40:03.229Z,1527889203.229 [DropWeight] No Fault, FailCount= 1
2018-06-01T21:41:47.934Z,1527889307.934 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-06-01T21:36:47.7Z
2018-06-01T21:41:47.934Z,1527889307.934 [Default:CheckIn:Read_GPS] Stopped
2018-06-01T21:41:47.934Z,1527889307.934 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-06-01T21:41:53.166Z,1527889313.166 [DataOverHttps](INFO): Sending 69 bytes from file Logs/20180601T183943/Courier0058.lzma
2018-06-01T21:41:53.963Z,1527889313.963 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Courier0058.lzma.bak
2018-06-01T21:41:53.964Z,1527889313.964 [DataOverHttps](INFO): SBD MOMSN=8304013
2018-06-01T21:42:03.289Z,1527889323.289 [DataOverHttps](INFO): Sending 269 bytes from file Logs/20180601T183943/Express0059.lzma
2018-06-01T21:42:04.080Z,1527889324.080 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Express0059.lzma.bak
2018-06-01T21:42:04.083Z,1527889324.083 [DataOverHttps](INFO): SBD MOMSN=8304016
2018-06-01T21:42:05.195Z,1527889325.195 [Default:CheckIn:Read_Iridium] Stopped
2018-06-01T21:42:05.195Z,1527889325.195 [Default:CheckIn:C.Wait] Running Loop=1
2018-06-01T21:42:05.195Z,1527889325.195 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-06-01T21:44:14.326Z,1527889454.326 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-06-01T21:44:45.126Z,1527889485.126 [NAL9602](INFO): Powering down
2018-06-01T21:47:05.531Z,1527889625.531 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-06-01T21:47:05.531Z,1527889625.531 [Default:CheckIn:C.Wait] Stopped
2018-06-01T21:47:05.531Z,1527889625.531 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-06-01T21:47:05.531Z,1527889625.531 [Default:CheckIn:D] Running Loop=1
2018-06-01T21:47:05.956Z,1527889625.956 [Default:CheckIn:D] Stopped
2018-06-01T21:47:05.956Z,1527889625.956 [Default:CheckIn:E] Running Loop=1
2018-06-01T21:47:06.340Z,1527889626.340 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 183.863704 min 
2018-06-01T21:47:06.340Z,1527889626.340 [Default:CheckIn:E] Stopped
2018-06-01T21:47:06.340Z,1527889626.340 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-06-01T21:47:06.340Z,1527889626.340 [Default:CheckIn] Stopped
2018-06-01T21:47:06.340Z,1527889626.340 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-06-01T21:47:06.340Z,1527889626.340 [Default:CheckIn](INFO): Running loop #19
2018-06-01T21:47:06.369Z,1527889626.369 [Default:CheckIn] Running Loop=19
2018-06-01T21:47:06.369Z,1527889626.369 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-06-01T21:47:06.369Z,1527889626.369 [Default:CheckIn:Read_GPS] Running Loop=1
2018-06-01T21:47:09.546Z,1527889629.546 [NAL9602](INFO): Powering up
2018-06-01T21:47:20.698Z,1527889640.698 [NAL9602](INFO): NAL9602 initialized
2018-06-01T21:52:06.428Z,1527889926.428 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-06-01T21:47:06.4Z
2018-06-01T21:52:06.428Z,1527889926.428 [Default:CheckIn:Read_GPS] Stopped
2018-06-01T21:52:06.428Z,1527889926.428 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-06-01T21:52:10.896Z,1527889930.896 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180601T183943/Courier0061.lzma
2018-06-01T21:52:11.684Z,1527889931.684 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Courier0061.lzma.bak
2018-06-01T21:52:11.684Z,1527889931.684 [DataOverHttps](INFO): SBD MOMSN=8304032
2018-06-01T21:52:22.314Z,1527889942.314 [DataOverHttps](INFO): Sending 200 bytes from file Logs/20180601T183943/Express0062.lzma
2018-06-01T21:52:23.115Z,1527889943.115 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Express0062.lzma.bak
2018-06-01T21:52:23.115Z,1527889943.115 [DataOverHttps](INFO): SBD MOMSN=8304034
2018-06-01T21:52:24.320Z,1527889944.320 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-06-01T21:52:24.357Z,1527889944.357 [Default:CheckIn:Read_Iridium] Stopped
2018-06-01T21:52:24.357Z,1527889944.357 [Default:CheckIn:C.Wait] Running Loop=1
2018-06-01T21:52:24.358Z,1527889944.358 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-06-01T21:52:54.826Z,1527889974.826 [NAL9602](INFO): Powering down
2018-06-01T21:57:24.560Z,1527890244.560 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-06-01T21:57:24.560Z,1527890244.560 [Default:CheckIn:C.Wait] Stopped
2018-06-01T21:57:24.561Z,1527890244.561 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-06-01T21:57:24.561Z,1527890244.561 [Default:CheckIn:D] Running Loop=1
2018-06-01T21:57:24.963Z,1527890244.963 [Default:CheckIn:D] Stopped
2018-06-01T21:57:24.963Z,1527890244.963 [Default:CheckIn:E] Running Loop=1
2018-06-01T21:57:25.368Z,1527890245.368 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 194.180469 min 
2018-06-01T21:57:25.368Z,1527890245.368 [Default:CheckIn:E] Stopped
2018-06-01T21:57:25.368Z,1527890245.368 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-06-01T21:57:25.369Z,1527890245.369 [Default:CheckIn] Stopped
2018-06-01T21:57:25.369Z,1527890245.369 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-06-01T21:57:25.369Z,1527890245.369 [Default:CheckIn](INFO): Running loop #20
2018-06-01T21:57:25.369Z,1527890245.369 [Default:CheckIn] Running Loop=20
2018-06-01T21:57:25.369Z,1527890245.369 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-06-01T21:57:25.370Z,1527890245.370 [Default:CheckIn:Read_GPS] Running Loop=1
2018-06-01T21:57:28.638Z,1527890248.638 [NAL9602](INFO): Powering up
2018-06-01T21:57:39.786Z,1527890259.786 [NAL9602](INFO): NAL9602 initialized
2018-06-01T21:57:40.582Z,1527890260.582 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-06-01T21:57:40.582Z,1527890260.582 [NAL9602] Data Fault, FailCount= 1
2018-06-01T21:57:40.582Z,1527890260.582 [NAL9602](ERROR): Data Fault
2018-06-01T21:57:40.677Z,1527890260.677 [CBIT](ERROR): Data Fault in component: NAL9602
2018-06-01T21:57:40.984Z,1527890260.984 [NAL9602](INFO): Powering down
2018-06-01T21:57:41.859Z,1527890261.859 [CBIT](INFO): Clearing failed state for component NAL9602
2018-06-01T21:57:41.859Z,1527890261.859 [NAL9602] No Fault, FailCount= 1
2018-06-01T21:58:11.383Z,1527890291.383 [NAL9602](INFO): Powering up NAL9602
2018-06-01T21:58:22.590Z,1527890302.590 [NAL9602](INFO): NAL9602 initialized
2018-06-01T21:58:44.212Z,1527890324.212 [NAL9602](INFO): SBD MO Status=2, MOMSN=6099, MT Status=2, MTMSN=0
2018-06-01T21:58:44.212Z,1527890324.212 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T22:02:25.528Z,1527890545.528 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-06-01T21:57:25.4Z
2018-06-01T22:02:25.528Z,1527890545.528 [Default:CheckIn:Read_GPS] Stopped
2018-06-01T22:02:25.528Z,1527890545.528 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-06-01T22:02:29.830Z,1527890549.830 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180601T183943/Courier0064.lzma
2018-06-01T22:02:30.628Z,1527890550.628 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Courier0064.lzma.bak
2018-06-01T22:02:30.628Z,1527890550.628 [DataOverHttps](INFO): SBD MOMSN=8304046
2018-06-01T22:02:40.922Z,1527890560.922 [DataOverHttps](INFO): Sending 217 bytes from file Logs/20180601T183943/Express0065.lzma
2018-06-01T22:02:41.720Z,1527890561.720 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Express0065.lzma.bak
2018-06-01T22:02:41.720Z,1527890561.720 [DataOverHttps](INFO): SBD MOMSN=8304048
2018-06-01T22:02:42.868Z,1527890562.868 [Default:CheckIn:Read_Iridium] Stopped
2018-06-01T22:02:42.868Z,1527890562.868 [Default:CheckIn:C.Wait] Running Loop=1
2018-06-01T22:02:42.869Z,1527890562.869 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-06-01T22:03:07.740Z,1527890587.740 [NAL9602](INFO): SBD MO Status=2, MOMSN=6099, MT Status=2, MTMSN=0
2018-06-01T22:03:07.740Z,1527890587.740 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T22:03:24.940Z,1527890604.940 [NAL9602](INFO): SBD MO Status=2, MOMSN=6099, MT Status=2, MTMSN=0
2018-06-01T22:03:24.940Z,1527890604.940 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T22:03:25.339Z,1527890605.339 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-06-01T22:03:55.838Z,1527890635.838 [NAL9602](INFO): Powering down
2018-06-01T22:07:43.297Z,1527890863.297 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-06-01T22:07:43.297Z,1527890863.297 [Default:CheckIn:C.Wait] Stopped
2018-06-01T22:07:43.297Z,1527890863.297 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-06-01T22:07:43.297Z,1527890863.297 [Default:CheckIn:D] Running Loop=1
2018-06-01T22:07:43.709Z,1527890863.709 [Default:CheckIn:D] Stopped
2018-06-01T22:07:43.709Z,1527890863.709 [Default:CheckIn:E] Running Loop=1
2018-06-01T22:07:46.908Z,1527890866.908 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 204.492920 min 
2018-06-01T22:07:46.908Z,1527890866.908 [Default:CheckIn:E] Stopped
2018-06-01T22:07:46.908Z,1527890866.908 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-06-01T22:07:46.908Z,1527890866.908 [Default:CheckIn] Stopped
2018-06-01T22:07:46.908Z,1527890866.908 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-06-01T22:07:46.909Z,1527890866.909 [Default:CheckIn](INFO): Running loop #21
2018-06-01T22:07:46.909Z,1527890866.909 [Default:CheckIn] Running Loop=21
2018-06-01T22:07:46.909Z,1527890866.909 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-06-01T22:07:46.909Z,1527890866.909 [Default:CheckIn:Read_GPS] Running Loop=1
2018-06-01T22:07:47.338Z,1527890867.338 [NAL9602](INFO): Powering up
2018-06-01T22:07:58.534Z,1527890878.534 [NAL9602](INFO): NAL9602 initialized
2018-06-01T22:08:36.136Z,1527890916.136 [NAL9602](INFO): SBD MO Status=0, MOMSN=6099, MT Status=0, MTMSN=0
2018-06-01T22:08:36.136Z,1527890916.136 [NAL9602](INFO): No messages in MT queue
2018-06-01T22:08:36.934Z,1527890916.934 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-06-01T22:08:36.934Z,1527890916.934 [NAL9602] Data Fault, FailCount= 1
2018-06-01T22:08:36.935Z,1527890916.935 [NAL9602](ERROR): Data Fault
2018-06-01T22:08:37.043Z,1527890917.043 [CBIT](ERROR): Data Fault in component: NAL9602
2018-06-01T22:08:37.334Z,1527890917.334 [NAL9602](INFO): Powering down
2018-06-01T22:08:38.227Z,1527890918.227 [CBIT](INFO): Clearing failed state for component NAL9602
2018-06-01T22:08:38.227Z,1527890918.227 [NAL9602] No Fault, FailCount= 1
2018-06-01T22:09:07.526Z,1527890947.526 [NAL9602](INFO): Powering up NAL9602
2018-06-01T22:09:18.326Z,1527890958.326 [NAL9602](INFO): NAL9602 initialized
2018-06-01T22:10:49.555Z,1527891049.555 [NAL9602](INFO): GPS fix at 20180601T221004: (36.802921, -121.787963)
2018-06-01T22:10:49.628Z,1527891049.628 [Default:CheckIn:Read_GPS] Stopped
2018-06-01T22:10:49.633Z,1527891049.633 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-06-01T22:10:54.113Z,1527891054.113 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20180601T183943/Courier0067.lzma
2018-06-01T22:10:54.880Z,1527891054.880 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Courier0067.lzma.bak
2018-06-01T22:10:54.880Z,1527891054.880 [DataOverHttps](INFO): SBD MOMSN=8304055
2018-06-01T22:11:06.104Z,1527891066.104 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20180601T183943/Express0068.lzma
2018-06-01T22:11:06.884Z,1527891066.884 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Express0068.lzma.bak
2018-06-01T22:11:06.884Z,1527891066.884 [DataOverHttps](INFO): SBD MOMSN=8304061
2018-06-01T22:11:08.298Z,1527891068.298 [Default:CheckIn:Read_Iridium] Stopped
2018-06-01T22:11:08.298Z,1527891068.298 [Default:CheckIn:C.Wait] Running Loop=1
2018-06-01T22:11:08.298Z,1527891068.298 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-06-01T22:11:24.286Z,1527891084.286 [NAL9602](INFO): Powering down
2018-06-01T22:16:08.545Z,1527891368.545 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-06-01T22:16:08.545Z,1527891368.545 [Default:CheckIn:C.Wait] Stopped
2018-06-01T22:16:08.545Z,1527891368.545 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-06-01T22:16:08.545Z,1527891368.545 [Default:CheckIn:D] Running Loop=1
2018-06-01T22:16:08.954Z,1527891368.954 [Default:CheckIn:D] Stopped
2018-06-01T22:16:08.954Z,1527891368.954 [Default:CheckIn:E] Running Loop=1
2018-06-01T22:16:09.352Z,1527891369.352 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 212.913656 min 
2018-06-01T22:16:09.353Z,1527891369.353 [Default:CheckIn:E] Stopped
2018-06-01T22:16:09.353Z,1527891369.353 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-06-01T22:16:09.353Z,1527891369.353 [Default:CheckIn] Stopped
2018-06-01T22:16:09.353Z,1527891369.353 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-06-01T22:16:09.353Z,1527891369.353 [Default:CheckIn](INFO): Running loop #22
2018-06-01T22:16:09.353Z,1527891369.353 [Default:CheckIn] Running Loop=22
2018-06-01T22:16:09.354Z,1527891369.354 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-06-01T22:16:09.354Z,1527891369.354 [Default:CheckIn:Read_GPS] Running Loop=1
2018-06-01T22:16:12.618Z,1527891372.618 [NAL9602](INFO): Powering up
2018-06-01T22:16:23.774Z,1527891383.774 [NAL9602](INFO): NAL9602 initialized
2018-06-01T22:17:03.376Z,1527891423.376 [NAL9602](INFO): SBD MO Status=0, MOMSN=6100, MT Status=0, MTMSN=0
2018-06-01T22:17:03.376Z,1527891423.376 [NAL9602](INFO): No messages in MT queue
2018-06-01T22:17:45.395Z,1527891465.395 [NAL9602](INFO): GPS fix at 20180601T221700: (36.802408, -121.787089)
2018-06-01T22:17:45.461Z,1527891465.461 [Default:CheckIn:Read_GPS] Stopped
2018-06-01T22:17:45.461Z,1527891465.461 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-06-01T22:17:50.968Z,1527891470.968 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20180601T183943/Courier0070.lzma
2018-06-01T22:17:51.764Z,1527891471.764 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Courier0070.lzma.bak
2018-06-01T22:17:51.764Z,1527891471.764 [DataOverHttps](INFO): SBD MOMSN=8304076
2018-06-01T22:18:01.698Z,1527891481.698 [DataOverHttps](INFO): Sending 136 bytes from file Logs/20180601T183943/Express0071.lzma
2018-06-01T22:18:02.496Z,1527891482.496 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Express0071.lzma.bak
2018-06-01T22:18:02.496Z,1527891482.496 [DataOverHttps](INFO): SBD MOMSN=8304079
2018-06-01T22:18:03.713Z,1527891483.713 [Default:CheckIn:Read_Iridium] Stopped
2018-06-01T22:18:03.713Z,1527891483.713 [Default:CheckIn:C.Wait] Running Loop=1
2018-06-01T22:18:03.713Z,1527891483.713 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-06-01T22:18:20.698Z,1527891500.698 [NAL9602](INFO): Powering down
2018-06-01T22:23:04.010Z,1527891784.010 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-06-01T22:23:04.010Z,1527891784.010 [Default:CheckIn:C.Wait] Stopped
2018-06-01T22:23:04.010Z,1527891784.010 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-06-01T22:23:04.010Z,1527891784.010 [Default:CheckIn:D] Running Loop=1
2018-06-01T22:23:04.422Z,1527891784.422 [Default:CheckIn:D] Stopped
2018-06-01T22:23:04.422Z,1527891784.422 [Default:CheckIn:E] Running Loop=1
2018-06-01T22:23:04.831Z,1527891784.831 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 219.838118 min 
2018-06-01T22:23:04.831Z,1527891784.831 [Default:CheckIn:E] Stopped
2018-06-01T22:23:04.832Z,1527891784.832 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-06-01T22:23:04.832Z,1527891784.832 [Default:CheckIn] Stopped
2018-06-01T22:23:04.832Z,1527891784.832 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-06-01T22:23:04.832Z,1527891784.832 [Default:CheckIn](INFO): Running loop #23
2018-06-01T22:23:04.832Z,1527891784.832 [Default:CheckIn] Running Loop=23
2018-06-01T22:23:04.832Z,1527891784.832 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-06-01T22:23:04.832Z,1527891784.832 [Default:CheckIn:Read_GPS] Running Loop=1
2018-06-01T22:23:10.238Z,1527891790.238 [NAL9602](INFO): Powering up
2018-06-01T22:23:21.438Z,1527891801.438 [NAL9602](INFO): NAL9602 initialized
2018-06-01T22:23:38.644Z,1527891818.644 [NAL9602](INFO): SBD MO Status=0, MOMSN=6101, MT Status=0, MTMSN=0
2018-06-01T22:23:38.644Z,1527891818.644 [NAL9602](INFO): No messages in MT queue
2018-06-01T22:23:38.644Z,1527891818.644 [NAL9602](INFO): Failure count cleared after critical for NAL9602
2018-06-01T22:24:47.538Z,1527891887.538 [NAL9602](INFO): GPS fix at 20180601T222402: (36.802762, -121.786871)
2018-06-01T22:24:47.607Z,1527891887.607 [Default:CheckIn:Read_GPS] Stopped
2018-06-01T22:24:47.607Z,1527891887.607 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-06-01T22:24:52.683Z,1527891892.683 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20180601T183943/Courier0073.lzma
2018-06-01T22:24:53.484Z,1527891893.484 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Courier0073.lzma.bak
2018-06-01T22:24:53.484Z,1527891893.484 [DataOverHttps](INFO): SBD MOMSN=8304095
2018-06-01T22:25:03.072Z,1527891903.072 [DataOverHttps](INFO): Sending 136 bytes from file Logs/20180601T183943/Express0074.lzma
2018-06-01T22:25:03.863Z,1527891903.863 [DataOverHttps](INFO): Moved sent file to Logs/20180601T183943/Express0074.lzma.bak
2018-06-01T22:25:03.864Z,1527891903.864 [DataOverHttps](INFO): SBD MOMSN=8304109
2018-06-01T22:25:05.166Z,1527891905.166 [Default:CheckIn:Read_Iridium] Stopped
2018-06-01T22:25:05.166Z,1527891905.166 [Default:CheckIn:C.Wait] Running Loop=1
2018-06-01T22:25:05.167Z,1527891905.167 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-06-01T22:25:22.638Z,1527891922.638 [NAL9602](INFO): Powering down
2018-06-01T22:26:35.834Z,1527891995.834 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-06-01T22:27:35.436Z,1527892055.436 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-06-01T22:28:19.435Z,1527892099.435 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.399597
2018-06-01T22:29:36.234Z,1527892176.234 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-06-01T22:30:05.485Z,1527892205.485 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-06-01T22:30:05.486Z,1527892205.486 [Default:CheckIn:C.Wait] Stopped
2018-06-01T22:30:05.486Z,1527892205.486 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-06-01T22:30:05.486Z,1527892205.486 [Default:CheckIn:D] Running Loop=1
2018-06-01T22:30:05.889Z,1527892205.889 [Default:CheckIn:D] Stopped
2018-06-01T22:30:05.889Z,1527892205.889 [Default:CheckIn:E] Running Loop=1
2018-06-01T22:30:06.285Z,1527892206.285 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 226.862581 min 
2018-06-01T22:30:06.285Z,1527892206.285 [Default:CheckIn:E] Stopped
2018-06-01T22:30:06.286Z,1527892206.286 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-06-01T22:30:06.286Z,1527892206.286 [Default:CheckIn] Stopped
2018-06-01T22:30:06.286Z,1527892206.286 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-06-01T22:30:06.286Z,1527892206.286 [Default:CheckIn](INFO): Running loop #24
2018-06-01T22:30:06.286Z,1527892206.286 [Default:CheckIn] Running Loop=24
2018-06-01T22:30:06.286Z,1527892206.286 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-06-01T22:30:06.286Z,1527892206.286 [Default:CheckIn:Read_GPS] Running Loop=1
2018-06-01T22:30:07.038Z,1527892207.038 [NAL9602](INFO): Powering up
2018-06-01T22:30:18.238Z,1527892218.238 [NAL9602](INFO): NAL9602 initialized
2018-06-01T22:30:34.641Z,1527892234.641 [NAL9602](INFO): SBD MO Status=0, MOMSN=6102, MT Status=0, MTMSN=0
2018-06-01T22:30:34.641Z,1527892234.641 [NAL9602](INFO): No messages in MT queue
2018-06-01T22:30:36.234Z,1527892236.234 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-06-01T22:31:36.235Z,1527892296.235 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-06-01T22:32:17.446Z,1527892337.446 [NAL9602](INFO): GPS fix at 20180601T223132: (36.802836, -121.786797)
2018-06-01T22:32:17.484Z,1527892337.484 [Default:CheckIn:Read_GPS] Stopped
2018-06-01T22:32:17.484Z,1527892337.484 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-06-01T22:32:36.950Z,1527892356.950 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-06-01T22:32:45.357Z,1527892365.357 [NAL9602](INFO): SBD MO Status=2, MOMSN=6103, MT Status=2, MTMSN=0
2018-06-01T22:32:45.357Z,1527892365.357 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T22:33:04.816Z,1527892384.816 [NAL9602](INFO): SBD MO Status=1, MOMSN=6103, MT Status=0, MTMSN=0
2018-06-01T22:33:04.865Z,1527892384.865 [NAL9602](INFO): Sent 61 bytes from file Logs/20180601T183943/Courier0076.lzma
2018-06-01T22:33:04.865Z,1527892384.865 [NAL9602](INFO): Packets left to send: 0
2018-06-01T22:33:04.867Z,1527892384.867 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180601T183943/Courier0076.lzma.parts/0000.sbd
2018-06-01T22:33:04.867Z,1527892384.867 [NAL9602](DEBUG): Completed sending Logs/20180601T183943/Courier0076.lzma
2018-06-01T22:33:11.360Z,1527892391.360 [NAL9602](INFO): SBD MO Status=1, MOMSN=6104, MT Status=0, MTMSN=0
2018-06-01T22:33:11.413Z,1527892391.413 [NAL9602](INFO): Sent 123 bytes from file Logs/20180601T183943/Express0077.lzma
2018-06-01T22:33:11.413Z,1527892391.413 [NAL9602](INFO): Packets left to send: 0
2018-06-01T22:33:11.415Z,1527892391.415 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180601T183943/Express0077.lzma.parts/0000.sbd
2018-06-01T22:33:11.415Z,1527892391.415 [NAL9602](DEBUG): Completed sending Logs/20180601T183943/Express0077.lzma
2018-06-01T22:33:20.124Z,1527892400.124 [NAL9602](INFO): SBD MO Status=0, MOMSN=6105, MT Status=0, MTMSN=0
2018-06-01T22:33:20.231Z,1527892400.231 [Default:CheckIn:Read_Iridium] Stopped
2018-06-01T22:33:20.231Z,1527892400.231 [Default:CheckIn:C.Wait] Running Loop=1
2018-06-01T22:33:20.231Z,1527892400.231 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-06-01T22:33:38.914Z,1527892418.914 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-06-01T22:33:50.920Z,1527892430.920 [NAL9602](INFO): Powering down
2018-06-01T22:34:38.914Z,1527892478.914 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-06-01T22:35:39.714Z,1527892539.714 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-06-01T22:36:40.114Z,1527892600.114 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-06-01T22:37:40.514Z,1527892660.514 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-06-01T22:38:20.577Z,1527892700.577 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-06-01T22:38:20.577Z,1527892700.577 [Default:CheckIn:C.Wait] Stopped
2018-06-01T22:38:20.577Z,1527892700.577 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-06-01T22:38:20.577Z,1527892700.577 [Default:CheckIn:D] Running Loop=1
2018-06-01T22:38:20.970Z,1527892700.970 [Default:CheckIn:D] Stopped
2018-06-01T22:38:20.970Z,1527892700.970 [Default:CheckIn:E] Running Loop=1
2018-06-01T22:38:21.376Z,1527892701.376 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 235.113932 min 
2018-06-01T22:38:21.376Z,1527892701.376 [Default:CheckIn:E] Stopped
2018-06-01T22:38:21.376Z,1527892701.376 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-06-01T22:38:21.376Z,1527892701.376 [Default:CheckIn] Stopped
2018-06-01T22:38:21.377Z,1527892701.377 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-06-01T22:38:21.377Z,1527892701.377 [Default:CheckIn](INFO): Running loop #25
2018-06-01T22:38:21.377Z,1527892701.377 [Default:CheckIn] Running Loop=25
2018-06-01T22:38:21.377Z,1527892701.377 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-06-01T22:38:21.377Z,1527892701.377 [Default:CheckIn:Read_GPS] Running Loop=1
2018-06-01T22:38:22.120Z,1527892702.120 [NAL9602](INFO): Powering up
2018-06-01T22:38:32.922Z,1527892712.922 [NAL9602](INFO): NAL9602 initialized
2018-06-01T22:38:40.914Z,1527892720.914 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-06-01T22:38:45.324Z,1527892725.324 [NAL9602](INFO): SBD MO Status=0, MOMSN=6106, MT Status=0, MTMSN=0
2018-06-01T22:38:45.324Z,1527892725.324 [NAL9602](INFO): No messages in MT queue
2018-06-01T22:39:03.731Z,1527892743.731 [NAL9602](INFO): GPS fix at 20180601T223818: (36.802730, -121.786874)
2018-06-01T22:39:03.801Z,1527892743.801 [Default:CheckIn:Read_GPS] Stopped
2018-06-01T22:39:03.801Z,1527892743.801 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-06-01T22:39:18.368Z,1527892758.368 [NAL9602](INFO): SBD MO Status=1, MOMSN=6107, MT Status=0, MTMSN=0
2018-06-01T22:39:18.417Z,1527892758.417 [NAL9602](INFO): Sent 62 bytes from file Logs/20180601T183943/Courier0079.lzma
2018-06-01T22:39:18.418Z,1527892758.418 [NAL9602](INFO): Packets left to send: 0
2018-06-01T22:39:18.419Z,1527892758.419 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180601T183943/Courier0079.lzma.parts/0000.sbd
2018-06-01T22:39:18.420Z,1527892758.420 [NAL9602](DEBUG): Completed sending Logs/20180601T183943/Courier0079.lzma
2018-06-01T22:39:28.504Z,1527892768.504 [NAL9602](INFO): SBD MO Status=1, MOMSN=6108, MT Status=0, MTMSN=0
2018-06-01T22:39:28.573Z,1527892768.573 [NAL9602](INFO): Sent 121 bytes from file Logs/20180601T183943/Express0080.lzma
2018-06-01T22:39:28.573Z,1527892768.573 [NAL9602](INFO): Packets left to send: 0
2018-06-01T22:39:28.575Z,1527892768.575 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180601T183943/Express0080.lzma.parts/0000.sbd
2018-06-01T22:39:28.575Z,1527892768.575 [NAL9602](DEBUG): Completed sending Logs/20180601T183943/Express0080.lzma
2018-06-01T22:39:41.254Z,1527892781.254 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-06-01T22:39:50.064Z,1527892790.064 [NAL9602](INFO): SBD MO Status=2, MOMSN=6109, MT Status=2, MTMSN=0
2018-06-01T22:39:50.064Z,1527892790.064 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-06-01T22:40:02.204Z,1527892802.204 [NAL9602](INFO): SBD MO Status=0, MOMSN=6109, MT Status=0, MTMSN=0
2018-06-01T22:40:02.307Z,1527892802.307 [Default:CheckIn:Read_Iridium] Stopped
2018-06-01T22:40:02.307Z,1527892802.307 [Default:CheckIn:C.Wait] Running Loop=1
2018-06-01T22:40:02.308Z,1527892802.308 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-06-01T22:40:32.599Z,1527892832.599 [NAL9602](INFO): Powering down
2018-06-01T22:40:40.994Z,1527892840.994 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-06-01T22:41:41.394Z,1527892901.394 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-06-01T22:42:41.794Z,1527892961.794 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-06-01T22:43:41.794Z,1527893021.794 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-06-01T22:44:41.794Z,1527893081.794 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-06-01T22:45:03.044Z,1527893103.044 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-06-01T22:45:03.044Z,1527893103.044 [Default:CheckIn:C.Wait] Stopped
2018-06-01T22:45:03.044Z,1527893103.044 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-06-01T22:45:03.044Z,1527893103.044 [Default:CheckIn:D] Running Loop=1
2018-06-01T22:45:03.444Z,1527893103.444 [Default:CheckIn:D] Stopped
2018-06-01T22:45:03.444Z,1527893103.444 [Default:CheckIn:E] Running Loop=1
2018-06-01T22:45:03.844Z,1527893103.844 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 241.821826 min 
2018-06-01T22:45:03.844Z,1527893103.844 [Default:CheckIn:E] Stopped
2018-06-01T22:45:03.844Z,1527893103.844 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-06-01T22:45:03.844Z,1527893103.844 [Default:CheckIn] Stopped
2018-06-01T22:45:03.845Z,1527893103.845 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-06-01T22:45:03.845Z,1527893103.845 [Default:CheckIn](INFO): Running loop #26
2018-06-01T22:45:03.845Z,1527893103.845 [Default:CheckIn] Running Loop=26
2018-06-01T22:45:03.845Z,1527893103.845 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-06-01T22:45:03.845Z,1527893103.845 [Default:CheckIn:Read_GPS] Running Loop=1
2018-06-01T22:45:04.598Z,1527893104.598 [NAL9602](INFO): Powering up
2018-06-01T22:45:15.799Z,1527893115.799 [NAL9602](INFO): NAL9602 initialized
2018-06-01T22:45:41.794Z,1527893141.794 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-06-01T22:45:57.400Z,1527893157.400 [NAL9602](INFO): SBD MO Status=0, MOMSN=6110, MT Status=0, MTMSN=0
2018-06-01T22:45:57.400Z,1527893157.400 [NAL9602](INFO): No messages in MT queue
2018-06-01T22:45:58.602Z,1527893158.602 [NAL9602](INFO): GPS fix at 20180601T224513: (36.802767, -121.786800)
2018-06-01T22:45:58.660Z,1527893158.660 [Default:CheckIn:Read_GPS] Stopped
2018-06-01T22:45:58.660Z,1527893158.660 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-06-01T22:46:16.060Z,1527893176.060 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=6111, MT Status=1, MTMSN=1388
2018-06-01T22:46:16.109Z,1527893176.109 [NAL9602](INFO): Sent 62 bytes from file Logs/20180601T183943/Courier0082.lzma
2018-06-01T22:46:16.109Z,1527893176.109 [NAL9602](INFO): Packets left to send: 0
2018-06-01T22:46:16.111Z,1527893176.111 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180601T183943/Courier0082.lzma.parts/0000.sbd
2018-06-01T22:46:16.111Z,1527893176.111 [NAL9602](DEBUG): Completed sending Logs/20180601T183943/Courier0082.lzma
2018-06-01T22:46:16.546Z,1527893176.546 [NAL9602](INFO): Received command:restart app
2018-06-01T22:46:16.569Z,1527893176.569 [CommandLine](IMPORTANT): got command restart application
2018-06-01T22:46:17.573Z,1527893177.573 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-06-01T22:46:17.573Z,1527893177.573 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-06-01T22:46:17.589Z,1527893177.589 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2018-06-01T22:46:17.589Z,1527893177.589 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-06-01T22:46:17.590Z,1527893177.590 [CommandLine](INFO): Join timeout helper Thread ID is 5674
2018-06-01T22:46:17.590Z,1527893177.590 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-06-01T22:46:17.590Z,1527893177.590 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-06-01T22:46:17.591Z,1527893177.591 [NavChartDb](INFO): Join timeout helper Thread ID is 5675
2018-06-01T22:46:17.717Z,1527893177.717 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-06-01T22:46:17.717Z,1527893177.717 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-06-01T22:46:17.737Z,1527893177.737 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2018-06-01T22:46:17.737Z,1527893177.737 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-06-01T22:46:17.737Z,1527893177.737 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 5676
2018-06-01T22:46:17.833Z,1527893177.833 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2018-06-01T22:46:17.833Z,1527893177.833 [WetLabsBB2FL](INFO): Powering down
2018-06-01T22:46:17.834Z,1527893177.834 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-06-01T22:46:17.849Z,1527893177.849 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2018-06-01T22:46:17.849Z,1527893177.849 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-06-01T22:46:17.849Z,1527893177.849 [CTD_Seabird](INFO): Join timeout helper Thread ID is 5677
2018-06-01T22:46:18.235Z,1527893178.235 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2018-06-01T22:46:18.332Z,1527893178.332 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-06-01T22:46:18.332Z,1527893178.332 [CTD_Seabird](INFO): Powering down
2018-06-01T22:46:18.337Z,1527893178.337 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-06-01T22:46:18.338Z,1527893178.338 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2018-06-01T22:46:18.338Z,1527893178.338 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-06-01T22:46:18.338Z,1527893178.338 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 5679
2018-06-01T22:46:18.441Z,1527893178.441 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2018-06-01T22:46:18.441Z,1527893178.441 [CTD_NeilBrown](INFO): Powering down
2018-06-01T22:46:18.442Z,1527893178.442 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-06-01T22:46:18.463Z,1527893178.463 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-06-01T22:46:18.464Z,1527893178.464 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-06-01T22:46:18.464Z,1527893178.464 [Radio_Surface](INFO): Join timeout helper Thread ID is 5680
2018-06-01T22:46:18.557Z,1527893178.557 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-06-01T22:46:18.558Z,1527893178.558 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-06-01T22:46:18.570Z,1527893178.570 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-06-01T22:46:18.570Z,1527893178.570 [logger ThreadHandler](INFO): Thread cancelled.
2018-06-01T22:46:18.570Z,1527893178.570 [logger](INFO): Join timeout helper Thread ID is 5681
2018-06-01T22:46:18.585Z,1527893178.585 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-06-01T22:46:18.585Z,1527893178.585 [logger ThreadHandler](INFO): Thread cancelled.
2018-06-01T22:46:18.598Z,1527893178.598 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-06-01T22:46:18.598Z,1527893178.598 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-06-01T22:46:18.598Z,1527893178.598 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-06-01T22:46:18.598Z,1527893178.598 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-06-01T22:46:18.599Z,1527893178.599 [controlThread](INFO): Join timeout helper Thread ID is 5682
2018-06-01T22:46:18.849Z,1527893178.849 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-06-01T22:46:18.849Z,1527893178.849 [controlThread](DEBUG): Uninitializing ControlThread
2018-06-01T22:46:18.850Z,1527893178.850 [NAL9602](INFO): Powering down
2018-06-01T22:46:18.852Z,1527893178.852 [PNI_TCM](INFO): Powering down
2018-06-01T22:46:18.941Z,1527893178.941 [Aanderaa_O2](INFO): Powering down
2018-06-01T22:46:18.944Z,1527893178.944 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-06-01T22:46:18.945Z,1527893178.945 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2018-06-01T22:46:18.946Z,1527893178.946 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-06-01T22:46:18.947Z,1527893178.947 [MissionManager](INFO): Uninitializing Mission Default
2018-06-01T22:46:18.947Z,1527893178.947 [Default] Stopped
2018-06-01T22:46:18.947Z,1527893178.947 [Default](DEBUG): Aggregate::uninitialize Default
2018-06-01T22:46:18.947Z,1527893178.947 [Default:B.GoToSurface] Stopped
2018-06-01T22:46:18.947Z,1527893178.947 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-06-01T22:46:18.947Z,1527893178.947 [Default:CheckIn] Stopped
2018-06-01T22:46:18.947Z,1527893178.947 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-06-01T22:46:18.948Z,1527893178.948 [Default:CheckIn:Read_Iridium] Stopped
2018-06-01T22:46:18.952Z,1527893178.952 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-06-01T22:46:18.952Z,1527893178.952 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-06-01T22:46:18.952Z,1527893178.952 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-06-01T22:46:18.953Z,1527893178.953 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-06-01T22:46:18.953Z,1527893178.953 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-06-01T22:46:18.954Z,1527893178.954 [BuoyancyServo](INFO): Powering down
2018-06-01T22:46:18.969Z,1527893178.969 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-06-01T22:46:18.969Z,1527893178.969 [ElevatorServo](INFO): Powering down
2018-06-01T22:46:18.970Z,1527893178.970 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-06-01T22:46:18.970Z,1527893178.970 [MassServo](INFO): Powering down
2018-06-01T22:46:18.971Z,1527893178.971 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-06-01T22:46:18.971Z,1527893178.971 [RudderServo](INFO): Powering down
2018-06-01T22:46:18.972Z,1527893178.972 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-06-01T22:46:18.972Z,1527893178.972 [ThrusterServo](INFO): Powering down
2018-06-01T22:46:18.974Z,1527893178.974 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-06-01T22:46:18.974Z,1527893178.974 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-06-01T22:46:18.974Z,1527893178.974 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-06-01T22:46:18.976Z,1527893178.976 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-06-01T22:46:19.083Z,1527893179.083 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-06-01T22:46:19.125Z,1527893179.125 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-06-01T22:46:19.129Z,1527893179.129 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-06-01T22:46:19.132Z,1527893179.132 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-06-01T22:46:19.161Z,1527893179.161 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-06-01T22:46:19.240Z,1527893179.240 [logger ThreadHandler](INFO): Thread cancelled.