2018-07-30T16:49:32.692Z,1532969372.692 [Supervisor](DEBUG): Initializing supervisor.
2018-07-30T16:49:32.695Z,1532969372.695 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-07-30T16:49:32.696Z,1532969372.696 [SyncHandler](INFO): Protected caller Thread ID is 1004
2018-07-30T16:49:32.696Z,1532969372.696 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-07-30T16:49:32.697Z,1532969372.697 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-07-30T16:49:32.698Z,1532969372.698 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1005
2018-07-30T16:49:32.701Z,1532969372.701 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-07-30T16:49:32.713Z,1532969372.713 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-07-30T16:49:32.714Z,1532969372.714 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-07-30T16:49:32.714Z,1532969372.714 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1006
2018-07-30T16:49:32.715Z,1532969372.715 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-07-30T16:49:32.716Z,1532969372.716 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-07-30T16:49:32.717Z,1532969372.717 [logger ThreadHandler](INFO): Protected caller Thread ID is 1007
2018-07-30T16:49:32.718Z,1532969372.718 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-07-30T16:49:32.719Z,1532969372.719 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-07-30T16:49:32.720Z,1532969372.720 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-07-30T16:49:32.934Z,1532969372.934 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-07-30T16:49:32.935Z,1532969372.935 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-07-30T16:49:33.085Z,1532969373.085 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-07-30T16:49:33.085Z,1532969373.085 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-07-30T16:49:33.469Z,1532969373.469 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-07-30T16:49:33.470Z,1532969373.470 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-07-30T16:49:33.616Z,1532969373.616 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-07-30T16:49:33.616Z,1532969373.616 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-07-30T16:49:33.699Z,1532969373.699 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-07-30T16:49:33.918Z,1532969373.918 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-07-30T16:49:33.919Z,1532969373.919 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-07-30T16:49:34.021Z,1532969374.021 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-07-30T16:49:34.022Z,1532969374.022 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-07-30T16:49:34.392Z,1532969374.392 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-07-30T16:49:34.393Z,1532969374.393 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-07-30T16:49:34.866Z,1532969374.866 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-07-30T16:49:34.867Z,1532969374.867 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-07-30T16:49:35.201Z,1532969375.201 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-07-30T16:49:35.202Z,1532969375.202 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-07-30T16:49:35.763Z,1532969375.763 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-07-30T16:49:35.764Z,1532969375.764 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-07-30T16:49:36.058Z,1532969376.058 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-07-30T16:49:36.058Z,1532969376.058 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-07-30T16:49:36.160Z,1532969376.160 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-07-30T16:49:36.161Z,1532969376.161 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-07-30T16:49:36.706Z,1532969376.706 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-07-30T16:49:36.706Z,1532969376.706 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-07-30T16:49:36.819Z,1532969376.819 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-07-30T16:49:36.821Z,1532969376.821 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2018-07-30T16:49:36.822Z,1532969376.822 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2018-07-30T16:49:37.066Z,1532969377.066 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-07-30T16:49:37.067Z,1532969377.067 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2018-07-30T16:49:37.170Z,1532969377.170 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2018-07-30T16:49:37.267Z,1532969377.267 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2018-07-30T16:49:37.375Z,1532969377.375 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2018-07-30T16:49:37.463Z,1532969377.463 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2018-07-30T16:49:37.604Z,1532969377.604 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2018-07-30T16:49:37.784Z,1532969377.784 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2018-07-30T16:49:37.900Z,1532969377.900 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2018-07-30T16:49:37.988Z,1532969377.988 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2018-07-30T16:49:38.074Z,1532969378.074 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2018-07-30T16:49:38.304Z,1532969378.304 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-07-30T16:49:38.310Z,1532969378.310 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-07-30T16:49:38.457Z,1532969378.457 [SBIT](DEBUG): Construct Startup Built In Test.
2018-07-30T16:49:38.489Z,1532969378.489 [SBIT] Loaded
2018-07-30T16:49:38.490Z,1532969378.490 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-07-30T16:49:38.490Z,1532969378.490 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-07-30T16:49:38.520Z,1532969378.520 [IBIT] Loaded
2018-07-30T16:49:38.520Z,1532969378.520 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-07-30T16:49:38.524Z,1532969378.524 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-07-30T16:49:38.690Z,1532969378.690 [CBIT] Loaded
2018-07-30T16:49:38.690Z,1532969378.690 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-07-30T16:49:38.690Z,1532969378.690 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-07-30T16:49:38.691Z,1532969378.691 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-07-30T16:49:38.767Z,1532969378.767 [VerticalControl](DEBUG): Construct VerticalControl.
2018-07-30T16:49:38.872Z,1532969378.872 [VerticalControl] Loaded
2018-07-30T16:49:38.873Z,1532969378.873 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-07-30T16:49:38.873Z,1532969378.873 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-07-30T16:49:38.938Z,1532969378.938 [HorizontalControl] Loaded
2018-07-30T16:49:38.939Z,1532969378.939 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-07-30T16:49:38.939Z,1532969378.939 [SpeedControl](DEBUG): Construct SpeedControl.
2018-07-30T16:49:38.945Z,1532969378.945 [SpeedControl] Loaded
2018-07-30T16:49:38.946Z,1532969378.946 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-07-30T16:49:38.946Z,1532969378.946 [LoopControl](DEBUG): Construct LoopControl.
2018-07-30T16:49:38.947Z,1532969378.947 [LoopControl] Loaded
2018-07-30T16:49:38.947Z,1532969378.947 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-07-30T16:49:38.947Z,1532969378.947 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-07-30T16:49:38.948Z,1532969378.948 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-07-30T16:49:38.994Z,1532969378.994 [DepthRateCalculator] Loaded
2018-07-30T16:49:38.994Z,1532969378.994 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-07-30T16:49:38.999Z,1532969378.999 [PitchRateCalculator] Loaded
2018-07-30T16:49:38.000Z,1532969379.000 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-07-30T16:49:39.017Z,1532969379.017 [SpeedCalculator] Loaded
2018-07-30T16:49:39.017Z,1532969379.017 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-07-30T16:49:39.040Z,1532969379.040 [TempGradientCalculator] Loaded
2018-07-30T16:49:39.040Z,1532969379.040 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-07-30T16:49:39.057Z,1532969379.057 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2018-07-30T16:49:39.057Z,1532969379.057 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2018-07-30T16:49:39.062Z,1532969379.062 [YawRateCalculator] Loaded
2018-07-30T16:49:39.063Z,1532969379.063 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-07-30T16:49:39.094Z,1532969379.094 [ElevatorOffsetCalculator] Loaded
2018-07-30T16:49:39.094Z,1532969379.094 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-07-30T16:49:39.094Z,1532969379.095 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-07-30T16:49:39.095Z,1532969379.095 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-07-30T16:49:39.188Z,1532969379.188 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2018-07-30T16:49:39.189Z,1532969379.189 [StratificationFrontDetector](DEBUG): (re)initializing
2018-07-30T16:49:39.189Z,1532969379.189 [StratificationFrontDetector] Loaded
2018-07-30T16:49:39.189Z,1532969379.189 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2018-07-30T16:49:39.190Z,1532969379.190 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-07-30T16:49:39.190Z,1532969379.190 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-07-30T16:49:39.466Z,1532969379.466 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-07-30T16:49:39.466Z,1532969379.466 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-07-30T16:49:39.592Z,1532969379.592 [DeadReckonUsingMultipleVelocitySources] Loaded
2018-07-30T16:49:39.593Z,1532969379.593 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2018-07-30T16:49:39.651Z,1532969379.651 [DeadReckonUsingSpeedCalculator] Loaded
2018-07-30T16:49:39.652Z,1532969379.652 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-07-30T16:49:39.669Z,1532969379.669 [NavChart] Loaded
2018-07-30T16:49:39.670Z,1532969379.670 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-07-30T16:49:39.674Z,1532969379.674 [UniversalFixResidualReporter] Loaded
2018-07-30T16:49:39.674Z,1532969379.674 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-07-30T16:49:39.675Z,1532969379.675 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-07-30T16:49:39.675Z,1532969379.675 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-07-30T16:49:45.055Z,1532969385.055 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-07-30T16:49:45.055Z,1532969385.055 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-07-30T16:49:45.415Z,1532969385.415 [Aanderaa_O2] Loaded
2018-07-30T16:49:45.416Z,1532969385.416 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-07-30T16:49:45.470Z,1532969385.470 [WetLabsBB2FL] Loaded
2018-07-30T16:49:45.470Z,1532969385.470 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-07-30T16:49:45.471Z,1532969385.471 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406D34E0
2018-07-30T16:49:45.472Z,1532969385.472 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1086
2018-07-30T16:49:45.472Z,1532969385.472 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-07-30T16:49:45.473Z,1532969385.473 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-07-30T16:49:49.707Z,1532969389.707 [AHRS_M2] Loaded
2018-07-30T16:49:49.707Z,1532969389.707 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2018-07-30T16:49:49.775Z,1532969389.775 [DataOverHttps] Loaded
2018-07-30T16:49:49.775Z,1532969389.775 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-07-30T16:49:49.789Z,1532969389.789 [Depth_Keller] Loaded
2018-07-30T16:49:49.790Z,1532969389.790 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-07-30T16:49:49.795Z,1532969389.795 [DropWeight] Loaded
2018-07-30T16:49:49.795Z,1532969389.795 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-07-30T16:49:49.893Z,1532969389.893 [NAL9602] Loaded
2018-07-30T16:49:49.893Z,1532969389.893 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-07-30T16:49:49.898Z,1532969389.898 [Onboard] Loaded
2018-07-30T16:49:49.899Z,1532969389.899 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-07-30T16:49:49.906Z,1532969389.906 [Radio_Surface] Loaded
2018-07-30T16:49:49.906Z,1532969389.906 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-07-30T16:49:49.908Z,1532969389.908 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409294E0
2018-07-30T16:49:49.908Z,1532969389.908 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1087
2018-07-30T16:49:49.939Z,1532969389.939 [RDI_Pathfinder] Loaded
2018-07-30T16:49:49.939Z,1532969389.939 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2018-07-30T16:49:49.946Z,1532969389.946 [SCPI] Loaded
2018-07-30T16:49:49.946Z,1532969389.946 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread.
2018-07-30T16:49:51.881Z,1532969391.881 [BPC1] Loaded
2018-07-30T16:49:51.881Z,1532969391.881 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-07-30T16:49:51.882Z,1532969391.882 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-07-30T16:49:51.882Z,1532969391.882 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-07-30T16:49:52.012Z,1532969392.012 [BuoyancyServo] Loaded
2018-07-30T16:49:52.012Z,1532969392.012 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-07-30T16:49:52.025Z,1532969392.025 [ElevatorServo] Loaded
2018-07-30T16:49:52.025Z,1532969392.025 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-07-30T16:49:52.036Z,1532969392.036 [MassServo] Loaded
2018-07-30T16:49:52.037Z,1532969392.037 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-07-30T16:49:52.048Z,1532969392.048 [RudderServo] Loaded
2018-07-30T16:49:52.049Z,1532969392.049 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-07-30T16:49:52.060Z,1532969392.060 [ThrusterServo] Loaded
2018-07-30T16:49:52.060Z,1532969392.060 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-07-30T16:49:52.061Z,1532969392.061 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-07-30T16:49:52.061Z,1532969392.061 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-07-30T16:49:52.201Z,1532969392.201 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-07-30T16:49:52.202Z,1532969392.202 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-07-30T16:49:52.241Z,1532969392.241 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-07-30T16:49:52.245Z,1532969392.245 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-07-30T16:49:52.246Z,1532969392.246 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-07-30T16:49:52.252Z,1532969392.252 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-07-30T16:49:52.253Z,1532969392.253 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 409D24E0
2018-07-30T16:49:52.254Z,1532969392.254 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1088
2018-07-30T16:49:52.259Z,1532969392.259 [Supervisor](INFO): Main Thread ID is 796
2018-07-30T16:49:52.259Z,1532969392.259 [Supervisor](DEBUG): Running supervisor.
2018-07-30T16:49:52.259Z,1532969392.259 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1089
2018-07-30T16:49:52.262Z,1532969392.262 [controlThread ThreadHandler](INFO): Handler Thread ID is 1090
2018-07-30T16:49:52.262Z,1532969392.262 [controlThread](DEBUG): Initializing ControlThread
2018-07-30T16:49:52.263Z,1532969392.263 [SBIT](INFO): Initialize SBIT Component.
2018-07-30T16:49:52.264Z,1532969392.264 [SBIT](IMPORTANT): git: 2017-07-30
2018-07-30T16:49:52.264Z,1532969392.264 [SBIT](INFO): git hash: d4f8f0da1cb083ba9f96282d65d9cbbd19acaad4
2018-07-30T16:49:52.264Z,1532969392.264 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-07-30T16:49:52.266Z,1532969392.266 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
Kernel Reported: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-07-30T16:49:52.267Z,1532969392.267 [SBIT](INFO): Beginning SBIT in 24.000000 seconds.
2018-07-30T16:49:52.267Z,1532969392.267 [IBIT](INFO): Initialize IBIT Component.
2018-07-30T16:49:52.268Z,1532969392.268 [CBIT](DEBUG): Initialize CBIT Component.
2018-07-30T16:49:52.269Z,1532969392.269 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-07-30T16:49:52.269Z,1532969392.269 [logger ThreadHandler](INFO): Handler Thread ID is 1091
2018-07-30T16:49:52.296Z,1532969392.296 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1092
2018-07-30T16:49:52.316Z,1532969392.316 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1093
2018-07-30T16:49:52.321Z,1532969392.321 [Radio_Surface](INFO): Powering up
2018-07-30T16:49:52.340Z,1532969392.340 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1094
2018-07-30T16:49:52.346Z,1532969392.346 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-07-30T16:49:52.346Z,1532969392.346 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-07-30T16:49:52.346Z,1532969392.346 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-07-30T16:49:52.346Z,1532969392.346 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-07-30T16:49:52.346Z,1532969392.346 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-07-30T16:49:52.347Z,1532969392.347 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-07-30T16:49:52.347Z,1532969392.347 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-07-30T16:49:52.347Z,1532969392.347 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-07-30T16:49:52.347Z,1532969392.347 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-07-30T16:49:52.347Z,1532969392.347 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-07-30T16:49:52.348Z,1532969392.348 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-07-30T16:49:52.348Z,1532969392.348 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-07-30T16:49:52.348Z,1532969392.348 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-07-30T16:49:52.348Z,1532969392.348 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-07-30T16:49:52.348Z,1532969392.348 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-07-30T16:49:52.348Z,1532969392.348 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-07-30T16:49:52.375Z,1532969392.375 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-07-30T16:49:52.377Z,1532969392.377 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-07-30T16:49:52.378Z,1532969392.378 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-07-30T16:49:52.379Z,1532969392.379 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-07-30T16:49:52.379Z,1532969392.379 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-07-30T16:49:52.379Z,1532969392.379 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-07-30T16:49:52.380Z,1532969392.380 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-07-30T16:49:52.380Z,1532969392.380 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-07-30T16:49:52.381Z,1532969392.381 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2018-07-30T16:49:52.381Z,1532969392.381 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-07-30T16:49:52.382Z,1532969392.382 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-07-30T16:49:52.382Z,1532969392.382 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2018-07-30T16:49:52.383Z,1532969392.383 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2018-07-30T16:49:52.384Z,1532969392.384 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2018-07-30T16:49:52.384Z,1532969392.384 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-07-30T16:49:52.385Z,1532969392.385 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-07-30T16:49:52.385Z,1532969392.385 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-07-30T16:49:52.385Z,1532969392.385 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-07-30T16:49:52.386Z,1532969392.386 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-07-30T16:49:52.412Z,1532969392.412 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-07-30T16:49:52.445Z,1532969392.445 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-07-30T16:49:52.465Z,1532969392.465 [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-07-30T16:49:52.466Z,1532969392.466 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-07-30T16:49:52.574Z,1532969392.574 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-07-30T16:49:52.576Z,1532969392.576 [Default:A.Wait](DEBUG): Construct Wait.
2018-07-30T16:49:52.577Z,1532969392.577 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-07-30T16:49:52.632Z,1532969392.632 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-07-30T16:49:52.635Z,1532969392.635 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-07-30T16:49:52.654Z,1532969392.654 [Default:E.Execute](DEBUG): Construct Execute.
2018-07-30T16:49:52.657Z,1532969392.657 [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-07-30T16:49:52.664Z,1532969392.664 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,AHRS_M2,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,RDI_Pathfinder,SCPI,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-07-30T16:49:52.730Z,1532969392.730 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2018-07-30T16:49:52.778Z,1532969392.778 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-07-30T16:49:53.232Z,1532969393.232 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:53.260Z,1532969393.260 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:53.386Z,1532969393.386 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-07-30T16:49:53.395Z,1532969393.395 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-07-30T16:49:53.410Z,1532969393.410 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-07-30T16:49:53.416Z,1532969393.416 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-07-30T16:49:53.430Z,1532969393.430 [MassServo](DEBUG): Initializing EZServoServo.
2018-07-30T16:49:53.436Z,1532969393.436 [MassServo](DEBUG): Initializing MassServo.
2018-07-30T16:49:53.457Z,1532969393.457 [RudderServo](DEBUG): Initializing EZServoServo.
2018-07-30T16:49:53.464Z,1532969393.464 [RudderServo](DEBUG): Initializing RudderServo.
2018-07-30T16:49:53.470Z,1532969393.470 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-07-30T16:49:53.476Z,1532969393.476 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-07-30T16:49:53.684Z,1532969393.684 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:53.686Z,1532969393.686 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:54.012Z,1532969394.012 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:54.013Z,1532969394.013 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:54.351Z,1532969394.351 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2018-07-30T16:49:54.351Z,1532969394.351 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2018-07-30T16:49:54.352Z,1532969394.352 [BuoyancyServo] Communications Fault, FailCount= 1
2018-07-30T16:49:54.352Z,1532969394.352 [BuoyancyServo](ERROR): Communications Fault
2018-07-30T16:49:54.563Z,1532969394.563 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2018-07-30T16:49:54.627Z,1532969394.627 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:54.629Z,1532969394.629 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:54.635Z,1532969394.635 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-07-30T16:49:54.651Z,1532969394.651 [BuoyancyServo](INFO): Powering down
2018-07-30T16:49:55.004Z,1532969395.004 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:55.005Z,1532969395.005 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:55.400Z,1532969395.400 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:55.401Z,1532969395.401 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:55.891Z,1532969395.891 [Aanderaa_O2](INFO): Powering down
2018-07-30T16:49:56.027Z,1532969396.027 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:56.029Z,1532969396.029 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:56.268Z,1532969396.268 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:56.269Z,1532969396.269 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:56.640Z,1532969396.640 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:56.641Z,1532969396.641 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:56.688Z,1532969396.688 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2018-07-30T16:49:56.689Z,1532969396.689 [BuoyancyServo] No Fault, FailCount= 1
2018-07-30T16:49:57.027Z,1532969397.027 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:57.029Z,1532969397.029 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:57.043Z,1532969397.043 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-07-30T16:49:57.164Z,1532969397.164 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-07-30T16:49:57.488Z,1532969397.488 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:57.489Z,1532969397.489 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:57.825Z,1532969397.825 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:57.826Z,1532969397.826 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:58.224Z,1532969398.224 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:58.225Z,1532969398.225 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:58.628Z,1532969398.628 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:58.629Z,1532969398.629 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:59.028Z,1532969399.028 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:59.029Z,1532969399.029 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:59.440Z,1532969399.440 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:59.441Z,1532969399.441 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:59.812Z,1532969399.812 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:49:59.813Z,1532969399.813 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:50:00.200Z,1532969400.200 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:50:00.201Z,1532969400.201 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:50:00.628Z,1532969400.628 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:50:00.629Z,1532969400.629 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-30T16:50:06.611Z,1532969406.611 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2018-07-30T16:50:17.035Z,1532969417.035 [SBIT](IMPORTANT): Beginning Startup BIT
2018-07-30T16:50:17.040Z,1532969417.040 [CBIT](IMPORTANT): Beginning ground fault scan
2018-07-30T16:50:19.897Z,1532969419.897 [NAL9602](INFO): Powering up NAL9602
2018-07-30T16:50:28.037Z,1532969428.037 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.019044
CHAN A1 (24V): -0.022065
CHAN A2 (12V): -0.007262
CHAN A3 (5V): -0.002086
CHAN B0 (3.3V): 0.000122
CHAN B1 (3.15aV): 0.000102
CHAN B2 (3.15bV): 0.000536
CHAN B3 (GND): 0.002197
OPEN: 0.004779
Full Scale Calc: 4.765 mA, -1.589 mA
2018-07-30T16:50:31.101Z,1532969431.101 [NAL9602](INFO): NAL9602 initialized
2018-07-30T16:50:45.303Z,1532969445.303 [NAL9602](INFO): SBD MO Status=0, MOMSN=507, MT Status=0, MTMSN=0
2018-07-30T16:50:45.303Z,1532969445.303 [NAL9602](INFO): No messages in MT queue
2018-07-30T16:51:06.693Z,1532969466.693 [NAL9602](INFO): GPS fix at 20180730T165105: (36.802175, -121.787088)
2018-07-30T16:51:11.172Z,1532969471.172 [SBIT](IMPORTANT): SBIT PASSED
2018-07-30T16:51:11.249Z,1532969471.249 [CommandLine](IMPORTANT): got command configSet list
2018-07-30T16:51:11.249Z,1532969471.249 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-07-30T16:51:11.250Z,1532969471.250 [CommandLine](IMPORTANT): AHRS_M2.readAccelerations=1 bool;

2018-07-30T16:51:11.250Z,1532969471.250 [CommandLine](IMPORTANT): AHRS_M2.readMagnetics=1 bool;

2018-07-30T16:51:11.250Z,1532969471.250 [CommandLine](IMPORTANT): Express linearApproximation height_above_sea_floor 5.000000 meter;

2018-07-30T16:51:11.250Z,1532969471.250 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=160 cubic_centimeter;

2018-07-30T16:51:11.250Z,1532969471.250 [CommandLine](IMPORTANT): VerticalControl.massDefault=-1 millimeter;

2018-07-30T16:51:11.568Z,1532969471.568 [MissionManager](IMPORTANT): Started mission Startup
2018-07-30T16:51:11.569Z,1532969471.569 [Startup] Running Loop=1
2018-07-30T16:51:11.569Z,1532969471.569 [Startup](DEBUG): Aggregate::initialize Startup
2018-07-30T16:51:11.569Z,1532969471.569 [Startup:A.GoToSurface] Running Loop=1
2018-07-30T16:51:11.569Z,1532969471.569 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-07-30T16:51:11.570Z,1532969471.570 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-07-30T16:51:11.570Z,1532969471.570 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-07-30T16:51:11.570Z,1532969471.570 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-07-30T16:51:11.571Z,1532969471.571 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-07-30T16:51:11.571Z,1532969471.571 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-07-30T16:51:11.593Z,1532969471.593 [Startup:StartupSatComms] Running Loop=1
2018-07-30T16:51:11.593Z,1532969471.593 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-07-30T16:51:11.594Z,1532969471.594 [Startup:StartupSatComms:A] Running Loop=1
2018-07-30T16:51:11.997Z,1532969471.997 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-07-30T16:51:13.481Z,1532969473.481 [NAL9602](INFO): GPS fix at 20180730T165111: (36.802189, -121.787049)
2018-07-30T16:51:13.543Z,1532969473.543 [Startup:StartupSatComms:A] Stopped
2018-07-30T16:51:13.544Z,1532969473.544 [Startup:StartupSatComms:B] Running Loop=1
2018-07-30T16:51:13.949Z,1532969473.949 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-07-30T16:51:47.641Z,1532969507.641 [NAL9602](INFO): SBD MO Status=1, MOMSN=508, MT Status=0, MTMSN=0
2018-07-30T16:51:47.696Z,1532969507.696 [NAL9602](INFO): Sent 25 bytes from file Logs/20180730T151944/Courier0034.lzma
2018-07-30T16:51:47.696Z,1532969507.696 [NAL9602](INFO): Packets left to send: 0
2018-07-30T16:51:47.698Z,1532969507.698 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180730T151944/Courier0034.lzma.parts/0000.sbd
2018-07-30T16:51:47.698Z,1532969507.698 [NAL9602](DEBUG): Completed sending Logs/20180730T151944/Courier0034.lzma
2018-07-30T16:51:55.850Z,1532969515.850 [NAL9602](INFO): SBD MO Status=1, MOMSN=509, MT Status=0, MTMSN=0
2018-07-30T16:51:55.912Z,1532969515.912 [NAL9602](INFO): Sent 212 bytes from file Logs/20180730T164932/Courier0000.lzma
2018-07-30T16:51:55.912Z,1532969515.912 [NAL9602](INFO): Packets left to send: 0
2018-07-30T16:51:55.913Z,1532969515.913 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180730T164932/Courier0000.lzma.parts/0000.sbd
2018-07-30T16:51:55.914Z,1532969515.914 [NAL9602](DEBUG): Completed sending Logs/20180730T164932/Courier0000.lzma
2018-07-30T16:52:03.986Z,1532969523.986 [NAL9602](INFO): SBD MO Status=1, MOMSN=510, MT Status=0, MTMSN=0
2018-07-30T16:52:04.048Z,1532969524.048 [NAL9602](INFO): Sent 154 bytes from file Logs/20180730T151944/Express0035.lzma
2018-07-30T16:52:04.048Z,1532969524.048 [NAL9602](INFO): Packets left to send: 0
2018-07-30T16:52:04.049Z,1532969524.049 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180730T151944/Express0035.lzma.parts/0000.sbd
2018-07-30T16:52:04.050Z,1532969524.050 [NAL9602](DEBUG): Completed sending Logs/20180730T151944/Express0035.lzma
2018-07-30T16:52:13.802Z,1532969533.802 [Startup:StartupSatComms:B](INFO): Timed out from 2018-07-30T16:51:13.5Z
2018-07-30T16:52:13.802Z,1532969533.802 [Startup:StartupSatComms:B] Stopped
2018-07-30T16:52:13.802Z,1532969533.802 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-07-30T16:52:13.802Z,1532969533.802 [Startup:StartupSatComms] Stopped
2018-07-30T16:52:13.802Z,1532969533.802 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-07-30T16:52:13.807Z,1532969533.807 [Startup](INFO): Completed Startup
2018-07-30T16:52:13.807Z,1532969533.807 [MissionManager](INFO): Startup is completed.
2018-07-30T16:52:13.808Z,1532969533.808 [MissionManager](INFO): Uninitializing Mission Startup
2018-07-30T16:52:13.808Z,1532969533.808 [Startup] Stopped
2018-07-30T16:52:13.808Z,1532969533.808 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-07-30T16:52:13.808Z,1532969533.808 [Startup:A.GoToSurface] Stopped
2018-07-30T16:52:13.808Z,1532969533.808 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-07-30T16:52:14.188Z,1532969534.188 [MissionManager](IMPORTANT): Started mission Default
2018-07-30T16:52:14.188Z,1532969534.188 [Default] Running Loop=1
2018-07-30T16:52:14.188Z,1532969534.188 [Default](DEBUG): Aggregate::initialize Default
2018-07-30T16:52:14.188Z,1532969534.188 [Default:B.GoToSurface] Running Loop=1
2018-07-30T16:52:14.188Z,1532969534.188 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-07-30T16:52:14.189Z,1532969534.189 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-07-30T16:52:14.189Z,1532969534.189 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-07-30T16:52:14.189Z,1532969534.189 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-07-30T16:52:14.190Z,1532969534.190 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-07-30T16:52:14.190Z,1532969534.190 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-07-30T16:52:14.190Z,1532969534.190 [Default:A.Wait] Running Loop=1
2018-07-30T16:52:14.190Z,1532969534.190 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-07-30T16:52:19.734Z,1532969539.734 [NAL9602](INFO): SBD MO Status=2, MOMSN=511, MT Status=2, MTMSN=0
2018-07-30T16:52:19.735Z,1532969539.735 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-07-30T16:52:27.391Z,1532969547.391 [Default:A.Wait](INFO): Done Waiting.
2018-07-30T16:52:27.391Z,1532969547.391 [Default:A.Wait] Stopped
2018-07-30T16:52:27.395Z,1532969547.395 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-07-30T16:52:27.814Z,1532969547.814 [Default:CheckIn] Running Loop=1
2018-07-30T16:52:27.814Z,1532969547.814 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-07-30T16:52:27.814Z,1532969547.814 [Default:CheckIn:Read_GPS] Running Loop=1
2018-07-30T16:52:28.209Z,1532969548.209 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-07-30T16:52:29.735Z,1532969549.735 [NAL9602](INFO): GPS fix at 20180730T165228: (36.802204, -121.787061)
2018-07-30T16:52:29.811Z,1532969549.811 [Default:CheckIn:Read_GPS] Stopped
2018-07-30T16:52:29.811Z,1532969549.811 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-07-30T16:52:30.189Z,1532969550.189 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-07-30T16:52:54.286Z,1532969574.286 [NAL9602](INFO): SBD MO Status=2, MOMSN=511, MT Status=2, MTMSN=0
2018-07-30T16:52:54.287Z,1532969574.287 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-07-30T16:53:05.890Z,1532969585.890 [NAL9602](INFO): SBD MO Status=1, MOMSN=511, MT Status=0, MTMSN=0
2018-07-30T16:53:05.948Z,1532969585.948 [NAL9602](INFO): Sent 61 bytes from file Logs/20180730T164932/Courier0004.lzma
2018-07-30T16:53:05.948Z,1532969585.948 [NAL9602](INFO): Packets left to send: 0
2018-07-30T16:53:05.949Z,1532969585.949 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180730T164932/Courier0004.lzma.parts/0000.sbd
2018-07-30T16:53:05.950Z,1532969585.950 [NAL9602](DEBUG): Completed sending Logs/20180730T164932/Courier0004.lzma
2018-07-30T16:53:06.868Z,1532969586.868 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004490
2018-07-30T16:53:12.796Z,1532969592.796 [DataOverHttps](INFO): Sending 849 bytes from file Logs/20180730T164932/Express0001.lzma
2018-07-30T16:53:13.552Z,1532969593.552 [DataOverHttps](INFO): Moved sent file to Logs/20180730T164932/Express0001.lzma.bak
2018-07-30T16:53:13.552Z,1532969593.552 [DataOverHttps](INFO): SBD MOMSN=8385564
2018-07-30T16:53:14.013Z,1532969594.013 [NAL9602](INFO): SBD MO Status=1, MOMSN=512, MT Status=0, MTMSN=0
2018-07-30T16:53:14.064Z,1532969594.064 [NAL9602](INFO): Sent 332 bytes from file Logs/20180730T164932/Express0001.lzma
2018-07-30T16:53:14.064Z,1532969594.064 [NAL9602](INFO): Packets left to send: 2
2018-07-30T16:53:14.065Z,1532969594.065 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180730T164932/Express0001.lzma.parts/0002.sbd
2018-07-30T16:53:14.136Z,1532969594.136 [Default:CheckIn:Read_Iridium] Stopped
2018-07-30T16:53:14.136Z,1532969594.136 [Default:CheckIn:C.Wait] Running Loop=1
2018-07-30T16:53:14.136Z,1532969594.136 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-07-30T16:53:44.529Z,1532969624.529 [NAL9602](INFO): Powering down
2018-07-30T16:54:17.893Z,1532969657.893 [DataOverHttps](INFO): Sending 95 bytes from file Logs/20180730T164932/Express0005.lzma
2018-07-30T16:54:18.656Z,1532969658.656 [DataOverHttps](INFO): Moved sent file to Logs/20180730T164932/Express0005.lzma.bak
2018-07-30T16:54:18.656Z,1532969658.656 [DataOverHttps](INFO): SBD MOMSN=8385593
2018-07-30T16:58:14.816Z,1532969894.816 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-07-30T16:58:14.817Z,1532969894.817 [Default:CheckIn:C.Wait] Stopped
2018-07-30T16:58:14.817Z,1532969894.817 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-07-30T16:58:14.817Z,1532969894.817 [Default:CheckIn:D] Running Loop=1
2018-07-30T16:58:15.232Z,1532969895.232 [Default:CheckIn:D] Stopped
2018-07-30T16:58:15.232Z,1532969895.232 [Default:CheckIn:E] Running Loop=1
2018-07-30T16:58:20.376Z,1532969900.376 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.017369 min 
2018-07-30T16:58:20.378Z,1532969900.378 [Default:CheckIn:E] Stopped
2018-07-30T16:58:20.378Z,1532969900.378 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-07-30T16:58:20.378Z,1532969900.378 [Default:CheckIn] Stopped
2018-07-30T16:58:20.378Z,1532969900.378 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-07-30T16:58:20.379Z,1532969900.379 [Default:CheckIn](INFO): Running loop #2
2018-07-30T16:58:20.379Z,1532969900.379 [Default:CheckIn] Running Loop=2
2018-07-30T16:58:20.379Z,1532969900.379 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-07-30T16:58:20.383Z,1532969900.383 [Default:CheckIn:Read_GPS] Running Loop=1
2018-07-30T16:58:20.897Z,1532969900.897 [NAL9602](INFO): Powering up
2018-07-30T16:58:32.088Z,1532969912.088 [NAL9602](INFO): NAL9602 initialized
2018-07-30T16:58:51.678Z,1532969931.678 [NAL9602](INFO): SBD MO Status=2, MOMSN=513, MT Status=2, MTMSN=0
2018-07-30T16:58:51.679Z,1532969931.679 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-07-30T16:59:09.678Z,1532969949.678 [NAL9602](INFO): SBD MO Status=0, MOMSN=513, MT Status=0, MTMSN=0
2018-07-30T16:59:09.679Z,1532969949.679 [NAL9602](INFO): No messages in MT queue
2018-07-30T16:59:10.878Z,1532969950.878 [NAL9602](INFO): GPS fix at 20180730T165909: (36.802181, -121.787012)
2018-07-30T16:59:10.926Z,1532969950.926 [Default:CheckIn:Read_GPS] Stopped
2018-07-30T16:59:10.926Z,1532969950.926 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-07-30T16:59:12.274Z,1532969952.274 [CommandLine](IMPORTANT): got command ibit
2018-07-30T16:59:15.482Z,1532969955.482 [IBIT](IMPORTANT): Beginning Initiated BIT
2018-07-30T16:59:15.483Z,1532969955.483 [IBIT](IMPORTANT): Beginning control surface checks.
2018-07-30T16:59:15.502Z,1532969955.502 [CBIT](IMPORTANT): Beginning ground fault scan
2018-07-30T16:59:15.558Z,1532969955.558 [DataOverHttps](INFO): Sending 229 bytes from file Logs/20180730T164932/Courier0007.lzma
2018-07-30T16:59:16.337Z,1532969956.337 [DataOverHttps](INFO): Moved sent file to Logs/20180730T164932/Courier0007.lzma.bak
2018-07-30T16:59:16.337Z,1532969956.337 [DataOverHttps](INFO): SBD MOMSN=8385645
2018-07-30T16:59:16.347Z,1532969956.347 [NAL9602](INFO): GPS fix at 20180730T165914: (36.802179, -121.787015)
2018-07-30T16:59:21.622Z,1532969961.622 [NAL9602](INFO): GPS fix at 20180730T165920: (36.802183, -121.787021)
2018-07-30T16:59:25.834Z,1532969965.834 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20180730T164932/Express0008.lzma
2018-07-30T16:59:26.608Z,1532969966.608 [DataOverHttps](INFO): Moved sent file to Logs/20180730T164932/Express0008.lzma.bak
2018-07-30T16:59:26.608Z,1532969966.608 [DataOverHttps](INFO): SBD MOMSN=8385649
2018-07-30T16:59:26.648Z,1532969966.648 [NAL9602](INFO): GPS fix at 20180730T165925: (36.802187, -121.787033)
2018-07-30T16:59:31.847Z,1532969971.847 [NAL9602](INFO): GPS fix at 20180730T165930: (36.802190, -121.787038)
2018-07-30T16:59:36.712Z,1532969976.712 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.115350
CHAN A1 (24V): -0.022345
CHAN A2 (12V): -0.007300
CHAN A3 (5V): -0.001863
CHAN B0 (3.3V): 0.000178
CHAN B1 (3.15aV): 0.000101
CHAN B2 (3.15bV): 0.000293
CHAN B3 (GND): 0.002166
OPEN: 0.004902
Full Scale Calc: 4.765 mA, -1.589 mA
2018-07-30T16:59:37.326Z,1532969977.326 [NAL9602](INFO): GPS fix at 20180730T165935: (36.802189, -121.787034)
2018-07-30T16:59:42.582Z,1532969982.582 [NAL9602](INFO): GPS fix at 20180730T165941: (36.802186, -121.787029)
2018-07-30T16:59:47.727Z,1532969987.727 [NAL9602](INFO): GPS fix at 20180730T165946: (36.802185, -121.787029)
2018-07-30T16:59:53.363Z,1532969993.363 [NAL9602](INFO): GPS fix at 20180730T165951: (36.802186, -121.787029)
2018-07-30T16:59:58.527Z,1532969998.527 [NAL9602](INFO): GPS fix at 20180730T165956: (36.802188, -121.787033)
2018-07-30T17:00:03.012Z,1532970003.012 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 3
Latitude: 36.802189 Longitude: -121.787033
2018-07-30T17:00:03.319Z,1532970003.319 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 0.000000
2018-07-30T17:00:03.320Z,1532970003.320 [IBIT](IMPORTANT): batteryCapacityThreshold: 5.000000 Ah
2018-07-30T17:00:03.320Z,1532970003.320 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.500000 V
2018-07-30T17:00:03.671Z,1532970003.671 [NAL9602](INFO): GPS fix at 20180730T170002: (36.802189, -121.787040)
2018-07-30T17:00:03.756Z,1532970003.756 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2018-07-30T17:00:03.757Z,1532970003.757 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2018-07-30T17:00:03.757Z,1532970003.757 [IBIT](IMPORTANT): Pressure:10.441716 PSI
2018-07-30T17:00:03.757Z,1532970003.757 [IBIT](IMPORTANT): Humidity:21.523624 %
2018-07-30T17:00:04.112Z,1532970004.112 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2018-07-30T17:00:04.112Z,1532970004.112 [IBIT](IMPORTANT): buoyancyNeutral: 160.000000 cc
2018-07-30T17:00:04.113Z,1532970004.113 [IBIT](IMPORTANT): massDefault: -0.100000 cm
2018-07-30T17:00:04.113Z,1532970004.113 [IBIT](IMPORTANT): stopDepth: 215.000000 m
2018-07-30T17:00:04.113Z,1532970004.113 [IBIT](IMPORTANT): abortDepth: 255.000000 m
2018-07-30T17:00:04.113Z,1532970004.113 [IBIT](IMPORTANT): IBIT PASSED
2018-07-30T17:00:04.474Z,1532970004.474 [Default:CheckIn:Read_Iridium] Stopped
2018-07-30T17:00:04.474Z,1532970004.474 [Default:CheckIn:C.Wait] Running Loop=1
2018-07-30T17:00:04.474Z,1532970004.474 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-07-30T17:00:37.930Z,1532970037.930 [NAL9602](INFO): Powering down
2018-07-30T17:01:39.229Z,1532970099.229 [CommandLine](IMPORTANT): got command get VerticalControl.buoyancyNeutral 
2018-07-30T17:01:39.230Z,1532970099.230 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral 159.999996 cc
2018-07-30T17:02:07.718Z,1532970127.718 [CommandLine](IMPORTANT): got command get BPC1.platform_battery_voltage
2018-07-30T17:02:07.718Z,1532970127.718 [CommandLine](IMPORTANT): BPC1.platform_battery_voltage 15.785129 _
2018-07-30T17:02:24.678Z,1532970144.678 [CommandLine](IMPORTANT): got command get BPC1.platform_battery_charge
2018-07-30T17:02:24.678Z,1532970144.678 [CommandLine](IMPORTANT): BPC1.platform_battery_charge 326.092986 Ah
2018-07-30T17:02:37.133Z,1532970157.134 [CommandLine](IMPORTANT): got command failComponent
2018-07-30T17:02:37.134Z,1532970157.134 [CommandLine](IMPORTANT): Failed components:
2018-07-30T17:02:37.134Z,1532970157.134 [CommandLine](IMPORTANT): No failed Components.
2018-07-30T17:05:07.864Z,1532970307.864 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-07-30T17:05:07.864Z,1532970307.864 [Default:CheckIn:C.Wait] Stopped
2018-07-30T17:05:07.864Z,1532970307.864 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-07-30T17:05:07.864Z,1532970307.864 [Default:CheckIn:D] Running Loop=1
2018-07-30T17:05:08.252Z,1532970308.252 [Default:CheckIn:D] Stopped
2018-07-30T17:05:08.252Z,1532970308.252 [Default:CheckIn:E] Running Loop=1
2018-07-30T17:05:08.670Z,1532970308.670 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.901057 min 
2018-07-30T17:05:08.670Z,1532970308.670 [Default:CheckIn:E] Stopped
2018-07-30T17:05:08.670Z,1532970308.670 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-07-30T17:05:08.670Z,1532970308.670 [Default:CheckIn] Stopped
2018-07-30T17:05:08.670Z,1532970308.670 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-07-30T17:05:08.671Z,1532970308.671 [Default:CheckIn](INFO): Running loop #3
2018-07-30T17:05:08.671Z,1532970308.671 [Default:CheckIn] Running Loop=3
2018-07-30T17:05:08.671Z,1532970308.671 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-07-30T17:05:08.675Z,1532970308.675 [Default:CheckIn:Read_GPS] Running Loop=1
2018-07-30T17:05:09.406Z,1532970309.406 [NAL9602](INFO): Powering up
2018-07-30T17:05:20.507Z,1532970320.507 [NAL9602](INFO): NAL9602 initialized
2018-07-30T17:05:57.298Z,1532970357.298 [NAL9602](INFO): SBD MO Status=0, MOMSN=514, MT Status=0, MTMSN=0
2018-07-30T17:05:57.299Z,1532970357.299 [NAL9602](INFO): No messages in MT queue
2018-07-30T17:05:58.497Z,1532970358.497 [NAL9602](INFO): GPS fix at 20180730T170556: (36.802192, -121.787033)
2018-07-30T17:05:58.580Z,1532970358.580 [Default:CheckIn:Read_GPS] Stopped
2018-07-30T17:05:58.580Z,1532970358.580 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-07-30T17:06:03.083Z,1532970363.083 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20180730T164932/Courier0010.lzma
2018-07-30T17:06:03.855Z,1532970363.855 [DataOverHttps](INFO): Moved sent file to Logs/20180730T164932/Courier0010.lzma.bak
2018-07-30T17:06:03.856Z,1532970363.856 [DataOverHttps](INFO): SBD MOMSN=8385670
2018-07-30T17:06:12.904Z,1532970372.904 [DataOverHttps](INFO): Sending 846 bytes from file Logs/20180730T164932/Express0011.lzma
2018-07-30T17:06:13.681Z,1532970373.681 [DataOverHttps](INFO): Moved sent file to Logs/20180730T164932/Express0011.lzma.bak
2018-07-30T17:06:13.681Z,1532970373.681 [DataOverHttps](INFO): SBD MOMSN=8385673
2018-07-30T17:06:14.174Z,1532970374.174 [Default:CheckIn:Read_Iridium] Stopped
2018-07-30T17:06:14.174Z,1532970374.174 [Default:CheckIn:C.Wait] Running Loop=1
2018-07-30T17:06:14.174Z,1532970374.174 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-07-30T17:06:33.181Z,1532970393.181 [NAL9602](INFO): Powering down
2018-07-30T17:11:14.879Z,1532970674.879 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-07-30T17:11:14.879Z,1532970674.879 [Default:CheckIn:C.Wait] Stopped
2018-07-30T17:11:14.883Z,1532970674.883 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-07-30T17:11:14.883Z,1532970674.883 [Default:CheckIn:D] Running Loop=1
2018-07-30T17:11:15.296Z,1532970675.296 [Default:CheckIn:D] Stopped
2018-07-30T17:11:15.296Z,1532970675.296 [Default:CheckIn:E] Running Loop=1
2018-07-30T17:11:18.503Z,1532970678.503 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 19.018461 min 
2018-07-30T17:11:18.503Z,1532970678.503 [Default:CheckIn:E] Stopped
2018-07-30T17:11:18.503Z,1532970678.503 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-07-30T17:11:18.503Z,1532970678.503 [Default:CheckIn] Stopped
2018-07-30T17:11:18.503Z,1532970678.503 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-07-30T17:11:18.504Z,1532970678.504 [Default:CheckIn](INFO): Running loop #4
2018-07-30T17:11:18.504Z,1532970678.504 [Default:CheckIn] Running Loop=4
2018-07-30T17:11:18.504Z,1532970678.504 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-07-30T17:11:18.504Z,1532970678.504 [Default:CheckIn:Read_GPS] Running Loop=1
2018-07-30T17:11:18.946Z,1532970678.946 [NAL9602](INFO): Powering up
2018-07-30T17:11:30.145Z,1532970690.145 [NAL9602](INFO): NAL9602 initialized
2018-07-30T17:11:57.339Z,1532970717.339 [NAL9602](INFO): SBD MO Status=2, MOMSN=515, MT Status=2, MTMSN=0
2018-07-30T17:11:57.339Z,1532970717.339 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-07-30T17:12:08.542Z,1532970728.542 [NAL9602](INFO): SBD MO Status=0, MOMSN=515, MT Status=0, MTMSN=0
2018-07-30T17:12:08.542Z,1532970728.542 [NAL9602](INFO): No messages in MT queue
2018-07-30T17:12:09.744Z,1532970729.744 [NAL9602](INFO): GPS fix at 20180730T171208: (36.802194, -121.787047)
2018-07-30T17:12:09.840Z,1532970729.840 [Default:CheckIn:Read_GPS] Stopped
2018-07-30T17:12:09.840Z,1532970729.840 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-07-30T17:12:14.338Z,1532970734.338 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20180730T164932/Courier0013.lzma
2018-07-30T17:12:15.116Z,1532970735.116 [DataOverHttps](INFO): Moved sent file to Logs/20180730T164932/Courier0013.lzma.bak
2018-07-30T17:12:15.116Z,1532970735.116 [DataOverHttps](INFO): SBD MOMSN=8385827
2018-07-30T17:12:29.622Z,1532970749.622 [DataOverHttps](INFO): Sending 237 bytes from file Logs/20180730T164932/Express0014.lzma
2018-07-30T17:12:30.405Z,1532970750.405 [DataOverHttps](INFO): Moved sent file to Logs/20180730T164932/Express0014.lzma.bak
2018-07-30T17:12:30.405Z,1532970750.405 [DataOverHttps](INFO): SBD MOMSN=8385832
2018-07-30T17:12:30.894Z,1532970750.894 [Default:CheckIn:Read_Iridium] Stopped
2018-07-30T17:12:30.895Z,1532970750.895 [Default:CheckIn:C.Wait] Running Loop=1
2018-07-30T17:12:30.895Z,1532970750.895 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-07-30T17:12:44.545Z,1532970764.545 [NAL9602](INFO): Powering down
2018-07-30T17:16:13.973Z,1532970973.973 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2018-07-30T17:16:13.973Z,1532970973.973 [RDI_Pathfinder](ERROR): Failed to parse:
:TS7172235,35.0, -0.1,   0.0,1448.9,  0
2018-07-30T17:17:31.369Z,1532971051.369 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-07-30T17:17:31.369Z,1532971051.369 [Default:CheckIn:C.Wait] Stopped
2018-07-30T17:17:31.369Z,1532971051.369 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-07-30T17:17:31.369Z,1532971051.369 [Default:CheckIn:D] Running Loop=1
2018-07-30T17:17:31.784Z,1532971051.784 [Default:CheckIn:D] Stopped
2018-07-30T17:17:31.784Z,1532971051.784 [Default:CheckIn:E] Running Loop=1
2018-07-30T17:17:32.179Z,1532971052.179 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 25.293264 min 
2018-07-30T17:17:32.179Z,1532971052.179 [Default:CheckIn:E] Stopped
2018-07-30T17:17:32.179Z,1532971052.179 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-07-30T17:17:32.179Z,1532971052.179 [Default:CheckIn] Stopped
2018-07-30T17:17:32.180Z,1532971052.180 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-07-30T17:17:32.180Z,1532971052.180 [Default:CheckIn](INFO): Running loop #5
2018-07-30T17:17:32.180Z,1532971052.180 [Default:CheckIn] Running Loop=5
2018-07-30T17:17:32.180Z,1532971052.180 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-07-30T17:17:32.180Z,1532971052.180 [Default:CheckIn:Read_GPS] Running Loop=1
2018-07-30T17:17:35.435Z,1532971055.435 [NAL9602](INFO): Powering up
2018-07-30T17:17:46.605Z,1532971066.605 [NAL9602](INFO): NAL9602 initialized
2018-07-30T17:18:01.807Z,1532971081.807 [NAL9602](INFO): SBD MO Status=0, MOMSN=516, MT Status=0, MTMSN=0
2018-07-30T17:18:01.807Z,1532971081.807 [NAL9602](INFO): No messages in MT queue
2018-07-30T17:18:05.829Z,1532971085.829 [NAL9602](INFO): GPS fix at 20180730T171804: (36.802222, -121.787055)
2018-07-30T17:18:05.899Z,1532971085.899 [Default:CheckIn:Read_GPS] Stopped
2018-07-30T17:18:05.899Z,1532971085.899 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-07-30T17:18:10.761Z,1532971090.761 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20180730T164932/Courier0016.lzma
2018-07-30T17:18:11.556Z,1532971091.556 [DataOverHttps](INFO): Moved sent file to Logs/20180730T164932/Courier0016.lzma.bak
2018-07-30T17:18:11.556Z,1532971091.556 [DataOverHttps](INFO): SBD MOMSN=8385843
2018-07-30T17:18:20.624Z,1532971100.624 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20180730T164932/Express0017.lzma
2018-07-30T17:18:21.393Z,1532971101.393 [DataOverHttps](INFO): Moved sent file to Logs/20180730T164932/Express0017.lzma.bak
2018-07-30T17:18:21.394Z,1532971101.394 [DataOverHttps](INFO): SBD MOMSN=8385847
2018-07-30T17:18:21.885Z,1532971101.885 [Default:CheckIn:Read_Iridium] Stopped
2018-07-30T17:18:21.885Z,1532971101.885 [Default:CheckIn:C.Wait] Running Loop=1
2018-07-30T17:18:21.885Z,1532971101.885 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-07-30T17:18:40.437Z,1532971120.437 [NAL9602](INFO): Powering down
2018-07-30T17:20:26.696Z,1532971226.696 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-32768,-32768,-32768,-32768,V
2018-07-30T17:23:22.293Z,1532971402.293 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-07-30T17:23:22.293Z,1532971402.293 [Default:CheckIn:C.Wait] Stopped
2018-07-30T17:23:22.293Z,1532971402.293 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-07-30T17:23:22.293Z,1532971402.293 [Default:CheckIn:D] Running Loop=1
2018-07-30T17:23:22.712Z,1532971402.712 [Default:CheckIn:D] Stopped
2018-07-30T17:23:22.712Z,1532971402.712 [Default:CheckIn:E] Running Loop=1
2018-07-30T17:23:23.066Z,1532971403.066 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.142063 min 
2018-07-30T17:23:23.066Z,1532971403.066 [Default:CheckIn:E] Stopped
2018-07-30T17:23:23.066Z,1532971403.066 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-07-30T17:23:23.066Z,1532971403.066 [Default:CheckIn] Stopped
2018-07-30T17:23:23.066Z,1532971403.066 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-07-30T17:23:23.066Z,1532971403.066 [Default:CheckIn](INFO): Running loop #6
2018-07-30T17:23:23.067Z,1532971403.067 [Default:CheckIn] Running Loop=6
2018-07-30T17:23:23.067Z,1532971403.067 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-07-30T17:23:23.067Z,1532971403.067 [Default:CheckIn:Read_GPS] Running Loop=1
2018-07-30T17:23:26.378Z,1532971406.378 [NAL9602](INFO): Powering up
2018-07-30T17:23:37.548Z,1532971417.548 [NAL9602](INFO): NAL9602 initialized
2018-07-30T17:23:50.750Z,1532971430.750 [NAL9602](INFO): SBD MO Status=0, MOMSN=517, MT Status=0, MTMSN=0
2018-07-30T17:23:50.751Z,1532971430.751 [NAL9602](INFO): No messages in MT queue
2018-07-30T17:24:18.765Z,1532971458.765 [NAL9602](INFO): GPS fix at 20180730T172417: (36.802180, -121.787101)
2018-07-30T17:24:18.838Z,1532971458.838 [Default:CheckIn:Read_GPS] Stopped
2018-07-30T17:24:18.838Z,1532971458.838 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-07-30T17:24:23.687Z,1532971463.687 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20180730T164932/Courier0019.lzma
2018-07-30T17:24:24.488Z,1532971464.488 [DataOverHttps](INFO): Moved sent file to Logs/20180730T164932/Courier0019.lzma.bak
2018-07-30T17:24:24.488Z,1532971464.488 [DataOverHttps](INFO): SBD MOMSN=8385859
2018-07-30T17:24:33.596Z,1532971473.596 [DataOverHttps](INFO): Sending 122 bytes from file Logs/20180730T164932/Express0020.lzma
2018-07-30T17:24:34.344Z,1532971474.344 [DataOverHttps](INFO): Moved sent file to Logs/20180730T164932/Express0020.lzma.bak
2018-07-30T17:24:34.344Z,1532971474.344 [DataOverHttps](INFO): SBD MOMSN=8385862
2018-07-30T17:24:34.858Z,1532971474.858 [Default:CheckIn:Read_Iridium] Stopped
2018-07-30T17:24:34.858Z,1532971474.858 [Default:CheckIn:C.Wait] Running Loop=1
2018-07-30T17:24:34.858Z,1532971474.858 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-07-30T17:24:53.441Z,1532971493.441 [NAL9602](INFO): Powering down
2018-07-30T17:29:35.459Z,1532971775.459 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-07-30T17:29:35.459Z,1532971775.459 [Default:CheckIn:C.Wait] Stopped
2018-07-30T17:29:35.460Z,1532971775.460 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-07-30T17:29:35.460Z,1532971775.460 [Default:CheckIn:D] Running Loop=1
2018-07-30T17:29:35.868Z,1532971775.868 [Default:CheckIn:D] Stopped
2018-07-30T17:29:35.868Z,1532971775.868 [Default:CheckIn:E] Running Loop=1
2018-07-30T17:29:36.259Z,1532971776.259 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 37.361320 min 
2018-07-30T17:29:36.260Z,1532971776.260 [Default:CheckIn:E] Stopped
2018-07-30T17:29:36.260Z,1532971776.260 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-07-30T17:29:36.260Z,1532971776.260 [Default:CheckIn] Stopped
2018-07-30T17:29:36.260Z,1532971776.260 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-07-30T17:29:36.260Z,1532971776.260 [Default:CheckIn](INFO): Running loop #7
2018-07-30T17:29:36.260Z,1532971776.260 [Default:CheckIn] Running Loop=7
2018-07-30T17:29:36.260Z,1532971776.260 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-07-30T17:29:36.261Z,1532971776.261 [Default:CheckIn:Read_GPS] Running Loop=1
2018-07-30T17:29:39.573Z,1532971779.573 [NAL9602](INFO): Powering up
2018-07-30T17:29:50.713Z,1532971790.713 [NAL9602](INFO): NAL9602 initialized
2018-07-30T17:30:03.906Z,1532971803.906 [NAL9602](INFO): SBD MO Status=0, MOMSN=518, MT Status=0, MTMSN=0
2018-07-30T17:30:03.907Z,1532971803.907 [NAL9602](INFO): No messages in MT queue
2018-07-30T17:30:55.817Z,1532971855.817 [NAL9602](INFO): GPS fix at 20180730T173054: (36.802206, -121.787029)
2018-07-30T17:30:55.889Z,1532971855.889 [Default:CheckIn:Read_GPS] Stopped
2018-07-30T17:30:55.889Z,1532971855.889 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-07-30T17:31:00.736Z,1532971860.736 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20180730T164932/Courier0022.lzma
2018-07-30T17:31:01.520Z,1532971861.520 [DataOverHttps](INFO): Moved sent file to Logs/20180730T164932/Courier0022.lzma.bak
2018-07-30T17:31:01.520Z,1532971861.520 [DataOverHttps](INFO): SBD MOMSN=8385867
2018-07-30T17:31:10.591Z,1532971870.591 [DataOverHttps](INFO): Sending 122 bytes from file Logs/20180730T164932/Express0023.lzma
2018-07-30T17:31:11.368Z,1532971871.368 [DataOverHttps](INFO): Moved sent file to Logs/20180730T164932/Express0023.lzma.bak
2018-07-30T17:31:11.369Z,1532971871.369 [DataOverHttps](INFO): SBD MOMSN=8385870
2018-07-30T17:31:11.882Z,1532971871.882 [Default:CheckIn:Read_Iridium] Stopped
2018-07-30T17:31:11.882Z,1532971871.882 [Default:CheckIn:C.Wait] Running Loop=1
2018-07-30T17:31:11.882Z,1532971871.882 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-07-30T17:31:30.445Z,1532971890.445 [NAL9602](INFO): Powering down
2018-07-30T17:36:12.593Z,1532972172.593 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-07-30T17:36:12.593Z,1532972172.593 [Default:CheckIn:C.Wait] Stopped
2018-07-30T17:36:12.593Z,1532972172.593 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-07-30T17:36:12.593Z,1532972172.593 [Default:CheckIn:D] Running Loop=1
2018-07-30T17:36:12.990Z,1532972172.990 [Default:CheckIn:D] Stopped
2018-07-30T17:36:12.991Z,1532972172.991 [Default:CheckIn:E] Running Loop=1
2018-07-30T17:36:16.188Z,1532972176.188 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.980037 min 
2018-07-30T17:36:16.188Z,1532972176.188 [Default:CheckIn:E] Stopped
2018-07-30T17:36:16.188Z,1532972176.188 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-07-30T17:36:16.188Z,1532972176.188 [Default:CheckIn] Stopped
2018-07-30T17:36:16.188Z,1532972176.188 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-07-30T17:36:16.188Z,1532972176.188 [Default:CheckIn](INFO): Running loop #8
2018-07-30T17:36:16.189Z,1532972176.189 [Default:CheckIn] Running Loop=8
2018-07-30T17:36:16.189Z,1532972176.189 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-07-30T17:36:16.189Z,1532972176.189 [Default:CheckIn:Read_GPS] Running Loop=1
2018-07-30T17:36:16.625Z,1532972176.625 [NAL9602](INFO): Powering up
2018-07-30T17:36:27.432Z,1532972187.432 [NAL9602](INFO): NAL9602 initialized
2018-07-30T17:37:01.446Z,1532972221.446 [NAL9602](INFO): SBD MO Status=2, MOMSN=519, MT Status=2, MTMSN=0
2018-07-30T17:37:01.446Z,1532972221.446 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-07-30T17:37:17.736Z,1532972237.736 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-32768,-32768,-32768,-32768,V
2018-07-30T17:38:35.870Z,1532972315.870 [NAL9602](INFO): SBD MO Status=2, MOMSN=519, MT Status=2, MTMSN=0
2018-07-30T17:38:35.871Z,1532972315.871 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-07-30T17:38:46.258Z,1532972326.258 [NAL9602](INFO): SBD MO Status=0, MOMSN=519, MT Status=0, MTMSN=0
2018-07-30T17:38:46.259Z,1532972326.259 [NAL9602](INFO): No messages in MT queue
2018-07-30T17:38:47.469Z,1532972327.469 [NAL9602](INFO): GPS fix at 20180730T173845: (36.802216, -121.787064)
2018-07-30T17:38:47.568Z,1532972327.568 [Default:CheckIn:Read_GPS] Stopped
2018-07-30T17:38:47.568Z,1532972327.568 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-07-30T17:38:52.114Z,1532972332.114 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20180730T164932/Courier0025.lzma
2018-07-30T17:38:52.887Z,1532972332.887 [DataOverHttps](INFO): Moved sent file to Logs/20180730T164932/Courier0025.lzma.bak
2018-07-30T17:38:52.887Z,1532972332.887 [DataOverHttps](INFO): SBD MOMSN=8385895
2018-07-30T17:39:02.696Z,1532972342.696 [DataOverHttps](INFO): Sending 122 bytes from file Logs/20180730T164932/Express0026.lzma
2018-07-30T17:39:03.488Z,1532972343.488 [DataOverHttps](INFO): Moved sent file to Logs/20180730T164932/Express0026.lzma.bak
2018-07-30T17:39:03.488Z,1532972343.488 [DataOverHttps](INFO): SBD MOMSN=8385898
2018-07-30T17:39:03.990Z,1532972343.990 [Default:CheckIn:Read_Iridium] Stopped
2018-07-30T17:39:03.990Z,1532972343.990 [Default:CheckIn:C.Wait] Running Loop=1
2018-07-30T17:39:03.990Z,1532972343.990 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-07-30T17:39:22.297Z,1532972362.297 [NAL9602](INFO): Powering down
2018-07-30T17:44:04.579Z,1532972644.579 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-07-30T17:44:04.611Z,1532972644.611 [Default:CheckIn:C.Wait] Stopped
2018-07-30T17:44:04.611Z,1532972644.611 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-07-30T17:44:04.611Z,1532972644.611 [Default:CheckIn:D] Running Loop=1
2018-07-30T17:44:04.996Z,1532972644.996 [Default:CheckIn:D] Stopped
2018-07-30T17:44:04.996Z,1532972644.996 [Default:CheckIn:E] Running Loop=1
2018-07-30T17:44:05.384Z,1532972645.384 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.846794 min 
2018-07-30T17:44:05.384Z,1532972645.384 [Default:CheckIn:E] Stopped
2018-07-30T17:44:05.384Z,1532972645.384 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-07-30T17:44:05.385Z,1532972645.385 [Default:CheckIn] Stopped
2018-07-30T17:44:05.385Z,1532972645.385 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-07-30T17:44:05.385Z,1532972645.385 [Default:CheckIn](INFO): Running loop #9
2018-07-30T17:44:05.385Z,1532972645.385 [Default:CheckIn] Running Loop=9
2018-07-30T17:44:05.385Z,1532972645.385 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-07-30T17:44:05.385Z,1532972645.385 [Default:CheckIn:Read_GPS] Running Loop=1
2018-07-30T17:44:08.694Z,1532972648.694 [NAL9602](INFO): Powering up
2018-07-30T17:44:19.881Z,1532972659.881 [NAL9602](INFO): NAL9602 initialized
2018-07-30T17:44:35.486Z,1532972675.486 [NAL9602](INFO): SBD MO Status=0, MOMSN=520, MT Status=0, MTMSN=0
2018-07-30T17:44:35.487Z,1532972675.487 [NAL9602](INFO): No messages in MT queue
2018-07-30T17:45:38.941Z,1532972738.941 [NAL9602](INFO): GPS fix at 20180730T174537: (36.802159, -121.787007)
2018-07-30T17:45:39.021Z,1532972739.021 [Default:CheckIn:Read_GPS] Stopped
2018-07-30T17:45:39.021Z,1532972739.021 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-07-30T17:45:43.666Z,1532972743.666 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20180730T164932/Courier0028.lzma
2018-07-30T17:45:44.443Z,1532972744.443 [DataOverHttps](INFO): Moved sent file to Logs/20180730T164932/Courier0028.lzma.bak
2018-07-30T17:45:44.443Z,1532972744.443 [DataOverHttps](INFO): SBD MOMSN=8385910
2018-07-30T17:45:44.921Z,1532972744.921 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-32768,-32768,-32768,-32768,V
2018-07-30T17:45:53.470Z,1532972753.470 [DataOverHttps](INFO): Sending 122 bytes from file Logs/20180730T164932/Express0029.lzma
2018-07-30T17:45:54.232Z,1532972754.232 [DataOverHttps](INFO): Moved sent file to Logs/20180730T164932/Express0029.lzma.bak
2018-07-30T17:45:54.232Z,1532972754.232 [DataOverHttps](INFO): SBD MOMSN=8385913
2018-07-30T17:45:54.761Z,1532972754.761 [Default:CheckIn:Read_Iridium] Stopped
2018-07-30T17:45:54.761Z,1532972754.761 [Default:CheckIn:C.Wait] Running Loop=1
2018-07-30T17:45:54.762Z,1532972754.762 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-07-30T17:46:13.765Z,1532972773.765 [NAL9602](INFO): Powering down
2018-07-30T17:49:00.696Z,1532972940.696 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-32768,-32768,-32768,-32768,V
2018-07-30T17:50:55.260Z,1532973055.260 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-07-30T17:50:55.260Z,1532973055.260 [Default:CheckIn:C.Wait] Stopped
2018-07-30T17:50:55.260Z,1532973055.260 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-07-30T17:50:55.260Z,1532973055.260 [Default:CheckIn:D] Running Loop=1
2018-07-30T17:50:55.657Z,1532973055.657 [Default:CheckIn:D] Stopped
2018-07-30T17:50:55.657Z,1532973055.657 [Default:CheckIn:E] Running Loop=1
2018-07-30T17:50:56.076Z,1532973056.076 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 58.691146 min 
2018-07-30T17:50:56.077Z,1532973056.077 [Default:CheckIn:E] Stopped
2018-07-30T17:50:56.077Z,1532973056.077 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-07-30T17:50:56.077Z,1532973056.077 [Default:CheckIn] Stopped
2018-07-30T17:50:56.077Z,1532973056.077 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-07-30T17:50:56.077Z,1532973056.077 [Default:CheckIn](INFO): Running loop #10
2018-07-30T17:50:56.077Z,1532973056.077 [Default:CheckIn] Running Loop=10
2018-07-30T17:50:56.077Z,1532973056.077 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-07-30T17:50:56.078Z,1532973056.078 [Default:CheckIn:Read_GPS] Running Loop=1
2018-07-30T17:50:59.610Z,1532973059.610 [NAL9602](INFO): Powering up
2018-07-30T17:51:10.588Z,1532973070.588 [NAL9602](INFO): NAL9602 initialized
2018-07-30T17:51:19.783Z,1532973079.783 [RDI_Pathfinder](ERROR): only read 3 of 5 data items
2018-07-30T17:51:19.783Z,1532973079.783 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-32768,-3768,-32768,V
2018-07-30T17:51:45.349Z,1532973105.349 [NAL9602](INFO): SBD MO Status=2, MOMSN=521, MT Status=2, MTMSN=0
2018-07-30T17:51:45.350Z,1532973105.350 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-07-30T17:51:59.929Z,1532973119.929 [NAL9602](INFO): SBD MO Status=0, MOMSN=521, MT Status=0, MTMSN=0
2018-07-30T17:51:59.929Z,1532973119.929 [NAL9602](INFO): No messages in MT queue
2018-07-30T17:52:51.681Z,1532973171.681 [NAL9602](INFO): GPS fix at 20180730T175250: (36.802239, -121.787038)
2018-07-30T17:52:51.759Z,1532973171.759 [Default:CheckIn:Read_GPS] Stopped
2018-07-30T17:52:51.759Z,1532973171.759 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-07-30T17:52:56.314Z,1532973176.314 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20180730T164932/Courier0031.lzma
2018-07-30T17:52:57.097Z,1532973177.097 [DataOverHttps](INFO): Moved sent file to Logs/20180730T164932/Courier0031.lzma.bak
2018-07-30T17:52:57.097Z,1532973177.097 [DataOverHttps](INFO): SBD MOMSN=8385918
2018-07-30T17:53:06.128Z,1532973186.128 [DataOverHttps](INFO): Sending 122 bytes from file Logs/20180730T164932/Express0032.lzma
2018-07-30T17:53:06.900Z,1532973186.900 [DataOverHttps](INFO): Moved sent file to Logs/20180730T164932/Express0032.lzma.bak
2018-07-30T17:53:06.900Z,1532973186.900 [DataOverHttps](INFO): SBD MOMSN=8385921
2018-07-30T17:53:07.413Z,1532973187.413 [Default:CheckIn:Read_Iridium] Stopped
2018-07-30T17:53:07.413Z,1532973187.413 [Default:CheckIn:C.Wait] Running Loop=1
2018-07-30T17:53:07.413Z,1532973187.413 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-07-30T17:53:26.396Z,1532973206.396 [NAL9602](INFO): Powering down
2018-07-30T17:58:08.142Z,1532973488.142 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-07-30T17:58:08.142Z,1532973488.142 [Default:CheckIn:C.Wait] Stopped
2018-07-30T17:58:08.142Z,1532973488.142 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-07-30T17:58:08.143Z,1532973488.143 [Default:CheckIn:D] Running Loop=1
2018-07-30T17:58:08.559Z,1532973488.559 [Default:CheckIn:D] Stopped
2018-07-30T17:58:08.559Z,1532973488.559 [Default:CheckIn:E] Running Loop=1
2018-07-30T17:58:11.760Z,1532973491.760 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 65.906177 min 
2018-07-30T17:58:11.760Z,1532973491.760 [Default:CheckIn:E] Stopped
2018-07-30T17:58:11.761Z,1532973491.761 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-07-30T17:58:11.761Z,1532973491.761 [Default:CheckIn] Stopped
2018-07-30T17:58:11.761Z,1532973491.761 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-07-30T17:58:11.761Z,1532973491.761 [Default:CheckIn](INFO): Running loop #11
2018-07-30T17:58:11.761Z,1532973491.761 [Default:CheckIn] Running Loop=11
2018-07-30T17:58:11.761Z,1532973491.761 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-07-30T17:58:11.761Z,1532973491.761 [Default:CheckIn:Read_GPS] Running Loop=1
2018-07-30T17:58:12.208Z,1532973492.208 [NAL9602](INFO): Powering up
2018-07-30T17:58:23.393Z,1532973503.393 [NAL9602](INFO): NAL9602 initialized
2018-07-30T17:58:50.207Z,1532973530.207 [NAL9602](INFO): SBD MO Status=2, MOMSN=522, MT Status=2, MTMSN=0
2018-07-30T17:58:50.207Z,1532973530.207 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-07-30T18:00:15.086Z,1532973615.086 [NAL9602](INFO): SBD MO Status=2, MOMSN=522, MT Status=2, MTMSN=0
2018-07-30T18:00:15.087Z,1532973615.087 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-07-30T18:00:26.282Z,1532973626.282 [NAL9602](INFO): SBD MO Status=0, MOMSN=522, MT Status=0, MTMSN=0
2018-07-30T18:00:26.282Z,1532973626.282 [NAL9602](INFO): No messages in MT queue
2018-07-30T18:00:27.481Z,1532973627.481 [NAL9602](INFO): GPS fix at 20180730T180025: (36.802170, -121.787074)
2018-07-30T18:00:27.568Z,1532973627.568 [Default:CheckIn:Read_GPS] Stopped
2018-07-30T18:00:27.568Z,1532973627.568 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-07-30T18:00:32.289Z,1532973632.289 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20180730T164932/Courier0034.lzma
2018-07-30T18:00:33.060Z,1532973633.060 [DataOverHttps](INFO): Moved sent file to Logs/20180730T164932/Courier0034.lzma.bak
2018-07-30T18:00:33.060Z,1532973633.060 [DataOverHttps](INFO): SBD MOMSN=8385949
2018-07-30T18:00:42.556Z,1532973642.556 [DataOverHttps](INFO): Sending 122 bytes from file Logs/20180730T164932/Express0035.lzma
2018-07-30T18:00:43.325Z,1532973643.325 [DataOverHttps](INFO): Moved sent file to Logs/20180730T164932/Express0035.lzma.bak
2018-07-30T18:00:43.325Z,1532973643.325 [DataOverHttps](INFO): SBD MOMSN=8385952
2018-07-30T18:00:43.805Z,1532973643.805 [RDI_Pathfinder](ERROR): Failed to parse:
:BE,-32768,-32768,-32768,V
2018-07-30T18:00:43.819Z,1532973643.819 [Default:CheckIn:Read_Iridium] Stopped
2018-07-30T18:00:43.819Z,1532973643.819 [Default:CheckIn:C.Wait] Running Loop=1
2018-07-30T18:00:43.819Z,1532973643.819 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-07-30T18:01:02.415Z,1532973662.415 [NAL9602](INFO): Powering down
2018-07-30T18:02:07.763Z,1532973727.763 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2018-07-30T18:02:07.763Z,1532973727.763 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,18073018031635,35.0, -0.1,   0.I,-32768,-32768,-32768,-32768,V
2018-07-30T18:05:44.415Z,1532973944.415 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-07-30T18:05:44.415Z,1532973944.415 [Default:CheckIn:C.Wait] Stopped
2018-07-30T18:05:44.419Z,1532973944.419 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-07-30T18:05:44.419Z,1532973944.419 [Default:CheckIn:D] Running Loop=1
2018-07-30T18:05:44.817Z,1532973944.817 [Default:CheckIn:D] Stopped
2018-07-30T18:05:44.817Z,1532973944.817 [Default:CheckIn:E] Running Loop=1
2018-07-30T18:05:45.184Z,1532973945.184 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 73.510482 min 
2018-07-30T18:05:45.185Z,1532973945.185 [Default:CheckIn:E] Stopped
2018-07-30T18:05:45.185Z,1532973945.185 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-07-30T18:05:45.185Z,1532973945.185 [Default:CheckIn] Stopped
2018-07-30T18:05:45.185Z,1532973945.185 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-07-30T18:05:45.185Z,1532973945.185 [Default:CheckIn](INFO): Running loop #12
2018-07-30T18:05:45.185Z,1532973945.185 [Default:CheckIn] Running Loop=12
2018-07-30T18:05:45.186Z,1532973945.186 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-07-30T18:05:45.186Z,1532973945.186 [Default:CheckIn:Read_GPS] Running Loop=1
2018-07-30T18:05:48.499Z,1532973948.499 [NAL9602](INFO): Powering up
2018-07-30T18:05:59.685Z,1532973959.685 [NAL9602](INFO): NAL9602 initialized
2018-07-30T18:06:12.478Z,1532973972.478 [NAL9602](INFO): SBD MO Status=0, MOMSN=523, MT Status=0, MTMSN=0
2018-07-30T18:06:12.479Z,1532973972.479 [NAL9602](INFO): No messages in MT queue
2018-07-30T18:06:32.089Z,1532973992.089 [NAL9602](INFO): GPS fix at 20180730T180630: (36.802257, -121.787053)
2018-07-30T18:06:32.168Z,1532973992.168 [Default:CheckIn:Read_GPS] Stopped
2018-07-30T18:06:32.168Z,1532973992.168 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-07-30T18:06:37.048Z,1532973997.048 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20180730T164932/Courier0037.lzma
2018-07-30T18:06:37.844Z,1532973997.844 [DataOverHttps](INFO): Moved sent file to Logs/20180730T164932/Courier0037.lzma.bak
2018-07-30T18:06:37.844Z,1532973997.844 [DataOverHttps](INFO): SBD MOMSN=8385964
2018-07-30T18:06:46.877Z,1532974006.877 [DataOverHttps](INFO): Sending 122 bytes from file Logs/20180730T164932/Express0038.lzma
2018-07-30T18:06:47.656Z,1532974007.656 [DataOverHttps](INFO): Moved sent file to Logs/20180730T164932/Express0038.lzma.bak
2018-07-30T18:06:47.656Z,1532974007.656 [DataOverHttps](INFO): SBD MOMSN=8385967
2018-07-30T18:06:48.157Z,1532974008.157 [Default:CheckIn:Read_Iridium] Stopped
2018-07-30T18:06:48.157Z,1532974008.157 [Default:CheckIn:C.Wait] Running Loop=1
2018-07-30T18:06:48.157Z,1532974008.157 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-07-30T18:07:06.773Z,1532974026.773 [NAL9602](INFO): Powering down
2018-07-30T18:11:04.751Z,1532974264.751 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2018-07-30T18:11:04.751Z,1532974264.751 [RDI_Pathfinder](ERROR): Failed to parse:
:BD,        +0.00,        +0.00,     ,   0.00,4856.96
2018-07-30T18:11:19.085Z,1532974279.085 [CommandLine](IMPORTANT): got command restart system
2018-07-30T18:11:21.272Z,1532974281.272 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2018-07-30T18:11:21.273Z,1532974281.273 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-07-30T18:11:21.274Z,1532974281.274 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-07-30T18:11:21.359Z,1532974281.359 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2018-07-30T18:11:21.359Z,1532974281.359 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-07-30T18:11:21.360Z,1532974281.360 [CommandLine](INFO): Join timeout helper Thread ID is 1176
2018-07-30T18:11:21.361Z,1532974281.361 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-07-30T18:11:21.361Z,1532974281.361 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-07-30T18:11:21.361Z,1532974281.361 [NavChartDb](INFO): Join timeout helper Thread ID is 1177
2018-07-30T18:11:21.528Z,1532974281.528 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-07-30T18:11:21.528Z,1532974281.528 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-07-30T18:11:21.531Z,1532974281.531 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-07-30T18:11:21.531Z,1532974281.531 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-07-30T18:11:21.532Z,1532974281.532 [Radio_Surface](INFO): Join timeout helper Thread ID is 1178
2018-07-30T18:11:21.788Z,1532974281.788 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-07-30T18:11:21.788Z,1532974281.788 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-07-30T18:11:21.807Z,1532974281.807 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2018-07-30T18:11:21.807Z,1532974281.807 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-07-30T18:11:21.808Z,1532974281.808 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1179
2018-07-30T18:11:22.052Z,1532974282.052 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2018-07-30T18:11:22.052Z,1532974282.052 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-07-30T18:11:22.071Z,1532974282.071 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-07-30T18:11:22.072Z,1532974282.072 [logger ThreadHandler](INFO): Thread cancelled.
2018-07-30T18:11:22.074Z,1532974282.074 [logger](INFO): Join timeout helper Thread ID is 1180
2018-07-30T18:11:22.095Z,1532974282.095 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-07-30T18:11:22.096Z,1532974282.096 [logger ThreadHandler](INFO): Thread cancelled.
2018-07-30T18:11:22.112Z,1532974282.112 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-07-30T18:11:22.112Z,1532974282.112 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-07-30T18:11:22.112Z,1532974282.112 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-07-30T18:11:22.113Z,1532974282.113 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-07-30T18:11:22.113Z,1532974282.113 [controlThread](INFO): Join timeout helper Thread ID is 1181
2018-07-30T18:11:22.272Z,1532974282.272 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-07-30T18:11:22.272Z,1532974282.272 [controlThread](DEBUG): Uninitializing ControlThread
2018-07-30T18:11:22.272Z,1532974282.272 [Aanderaa_O2](INFO): Powering down
2018-07-30T18:11:22.273Z,1532974282.273 [AHRS_M2](INFO): Powering down
2018-07-30T18:11:22.344Z,1532974282.344 [NAL9602](INFO): Powering down
2018-07-30T18:11:22.415Z,1532974282.415 [RDI_Pathfinder](INFO): Powering down
2018-07-30T18:11:22.417Z,1532974282.417 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-07-30T18:11:22.418Z,1532974282.418 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2018-07-30T18:11:22.419Z,1532974282.419 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-07-30T18:11:22.420Z,1532974282.420 [MissionManager](INFO): Uninitializing Mission Default
2018-07-30T18:11:22.420Z,1532974282.420 [Default] Stopped
2018-07-30T18:11:22.420Z,1532974282.420 [Default](DEBUG): Aggregate::uninitialize Default
2018-07-30T18:11:22.420Z,1532974282.420 [Default:B.GoToSurface] Stopped
2018-07-30T18:11:22.420Z,1532974282.420 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-07-30T18:11:22.421Z,1532974282.421 [Default:CheckIn] Stopped
2018-07-30T18:11:22.421Z,1532974282.421 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-07-30T18:11:22.421Z,1532974282.421 [Default:CheckIn:C.Wait] Stopped
2018-07-30T18:11:22.421Z,1532974282.421 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-07-30T18:11:22.425Z,1532974282.425 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-07-30T18:11:22.425Z,1532974282.425 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-07-30T18:11:22.426Z,1532974282.426 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-07-30T18:11:22.426Z,1532974282.426 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-07-30T18:11:22.426Z,1532974282.426 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-07-30T18:11:22.426Z,1532974282.426 [BuoyancyServo](INFO): Powering down
2018-07-30T18:11:22.439Z,1532974282.439 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-07-30T18:11:22.439Z,1532974282.439 [ElevatorServo](INFO): Powering down
2018-07-30T18:11:22.441Z,1532974282.441 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-07-30T18:11:22.441Z,1532974282.441 [MassServo](INFO): Powering down
2018-07-30T18:11:22.442Z,1532974282.442 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-07-30T18:11:22.442Z,1532974282.442 [RudderServo](INFO): Powering down
2018-07-30T18:11:22.443Z,1532974282.443 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-07-30T18:11:22.443Z,1532974282.443 [ThrusterServo](INFO): Powering down
2018-07-30T18:11:22.444Z,1532974282.444 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-07-30T18:11:22.444Z,1532974282.444 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-07-30T18:11:22.445Z,1532974282.445 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-07-30T18:11:22.446Z,1532974282.446 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-07-30T18:11:22.503Z,1532974282.503 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-07-30T18:11:22.565Z,1532974282.565 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-07-30T18:11:22.609Z,1532974282.609 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-07-30T18:11:22.680Z,1532974282.680 [logger ThreadHandler](INFO): Thread cancelled.