2018-09-24T16:59:07.534Z,1537808347.534 [Supervisor](DEBUG): Initializing supervisor.
2018-09-24T16:59:07.537Z,1537808347.537 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-09-24T16:59:07.537Z,1537808347.537 [SyncHandler](INFO): Protected caller Thread ID is 1761
2018-09-24T16:59:07.538Z,1537808347.538 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-09-24T16:59:07.539Z,1537808347.539 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-09-24T16:59:07.539Z,1537808347.539 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1762
2018-09-24T16:59:07.542Z,1537808347.542 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-09-24T16:59:07.554Z,1537808347.554 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-09-24T16:59:07.555Z,1537808347.555 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-09-24T16:59:07.555Z,1537808347.555 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1763
2018-09-24T16:59:07.556Z,1537808347.556 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-09-24T16:59:07.557Z,1537808347.557 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-09-24T16:59:07.557Z,1537808347.557 [logger ThreadHandler](INFO): Protected caller Thread ID is 1764
2018-09-24T16:59:07.560Z,1537808347.560 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-09-24T16:59:07.560Z,1537808347.560 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-09-24T16:59:07.561Z,1537808347.561 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-09-24T16:59:07.750Z,1537808347.750 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-09-24T16:59:07.750Z,1537808347.750 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-09-24T16:59:07.894Z,1537808347.894 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-09-24T16:59:07.894Z,1537808347.894 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-09-24T16:59:08.240Z,1537808348.240 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-09-24T16:59:08.241Z,1537808348.241 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-09-24T16:59:08.379Z,1537808348.379 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-09-24T16:59:08.380Z,1537808348.380 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-09-24T16:59:08.460Z,1537808348.460 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-09-24T16:59:08.663Z,1537808348.663 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-09-24T16:59:08.664Z,1537808348.664 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-09-24T16:59:08.762Z,1537808348.762 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-09-24T16:59:08.763Z,1537808348.763 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-09-24T16:59:09.110Z,1537808349.110 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-09-24T16:59:09.111Z,1537808349.111 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-09-24T16:59:09.578Z,1537808349.578 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-09-24T16:59:09.579Z,1537808349.579 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-09-24T16:59:10.006Z,1537808350.006 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-09-24T16:59:10.006Z,1537808350.006 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-09-24T16:59:10.508Z,1537808350.508 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-09-24T16:59:10.509Z,1537808350.509 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-09-24T16:59:10.770Z,1537808350.770 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-09-24T16:59:10.770Z,1537808350.770 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-09-24T16:59:10.973Z,1537808350.973 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-09-24T16:59:10.974Z,1537808350.974 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-09-24T16:59:11.465Z,1537808351.465 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-09-24T16:59:11.465Z,1537808351.465 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-09-24T16:59:11.572Z,1537808351.572 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-09-24T16:59:11.574Z,1537808351.574 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2018-09-24T16:59:11.575Z,1537808351.575 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2018-09-24T16:59:11.804Z,1537808351.804 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-09-24T16:59:11.805Z,1537808351.805 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2018-09-24T16:59:11.903Z,1537808351.903 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2018-09-24T16:59:11.996Z,1537808351.996 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2018-09-24T16:59:12.099Z,1537808352.099 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2018-09-24T16:59:12.185Z,1537808352.185 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2018-09-24T16:59:12.363Z,1537808352.363 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2018-09-24T16:59:12.532Z,1537808352.532 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2018-09-24T16:59:12.643Z,1537808352.643 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2018-09-24T16:59:12.728Z,1537808352.728 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2018-09-24T16:59:12.811Z,1537808352.811 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2018-09-24T16:59:13.002Z,1537808353.002 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-09-24T16:59:13.016Z,1537808353.016 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-09-24T16:59:13.146Z,1537808353.146 [SBIT](DEBUG): Construct Startup Built In Test.
2018-09-24T16:59:13.176Z,1537808353.176 [SBIT] Loaded
2018-09-24T16:59:13.177Z,1537808353.177 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-09-24T16:59:13.177Z,1537808353.177 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-09-24T16:59:13.205Z,1537808353.205 [IBIT] Loaded
2018-09-24T16:59:13.205Z,1537808353.205 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-09-24T16:59:13.208Z,1537808353.208 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-09-24T16:59:13.366Z,1537808353.366 [CBIT] Loaded
2018-09-24T16:59:13.366Z,1537808353.366 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-09-24T16:59:13.367Z,1537808353.367 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-09-24T16:59:13.367Z,1537808353.367 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-09-24T16:59:13.435Z,1537808353.435 [VerticalControl](DEBUG): Construct VerticalControl.
2018-09-24T16:59:13.538Z,1537808353.538 [VerticalControl] Loaded
2018-09-24T16:59:13.538Z,1537808353.538 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-09-24T16:59:13.539Z,1537808353.539 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-09-24T16:59:13.600Z,1537808353.600 [HorizontalControl] Loaded
2018-09-24T16:59:13.601Z,1537808353.601 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-09-24T16:59:13.601Z,1537808353.601 [SpeedControl](DEBUG): Construct SpeedControl.
2018-09-24T16:59:13.607Z,1537808353.607 [SpeedControl] Loaded
2018-09-24T16:59:13.607Z,1537808353.607 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-09-24T16:59:13.608Z,1537808353.608 [LoopControl](DEBUG): Construct LoopControl.
2018-09-24T16:59:13.608Z,1537808353.608 [LoopControl] Loaded
2018-09-24T16:59:13.609Z,1537808353.609 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-09-24T16:59:13.609Z,1537808353.609 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-09-24T16:59:13.610Z,1537808353.610 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-09-24T16:59:13.652Z,1537808353.652 [DepthRateCalculator] Loaded
2018-09-24T16:59:13.652Z,1537808353.652 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-09-24T16:59:13.658Z,1537808353.658 [PitchRateCalculator] Loaded
2018-09-24T16:59:13.658Z,1537808353.658 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-09-24T16:59:13.674Z,1537808353.674 [SpeedCalculator] Loaded
2018-09-24T16:59:13.674Z,1537808353.674 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-09-24T16:59:13.696Z,1537808353.696 [TempGradientCalculator] Loaded
2018-09-24T16:59:13.696Z,1537808353.696 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-09-24T16:59:13.702Z,1537808353.702 [YawRateCalculator] Loaded
2018-09-24T16:59:13.702Z,1537808353.702 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-09-24T16:59:13.732Z,1537808353.732 [ElevatorOffsetCalculator] Loaded
2018-09-24T16:59:13.732Z,1537808353.732 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-09-24T16:59:13.733Z,1537808353.733 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-09-24T16:59:13.733Z,1537808353.733 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-09-24T16:59:13.798Z,1537808353.798 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-09-24T16:59:13.798Z,1537808353.798 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-09-24T16:59:14.044Z,1537808354.044 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-09-24T16:59:14.044Z,1537808354.044 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-09-24T16:59:14.142Z,1537808354.142 [DeadReckonUsingMultipleVelocitySources] Loaded
2018-09-24T16:59:14.142Z,1537808354.142 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2018-09-24T16:59:14.197Z,1537808354.197 [DeadReckonUsingSpeedCalculator] Loaded
2018-09-24T16:59:14.197Z,1537808354.197 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-09-24T16:59:14.214Z,1537808354.214 [NavChart] Loaded
2018-09-24T16:59:14.214Z,1537808354.214 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-09-24T16:59:14.219Z,1537808354.219 [UniversalFixResidualReporter] Loaded
2018-09-24T16:59:14.219Z,1537808354.219 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-09-24T16:59:14.219Z,1537808354.219 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-09-24T16:59:14.220Z,1537808354.220 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-09-24T16:59:14.273Z,1537808354.273 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-09-24T16:59:14.273Z,1537808354.273 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-09-24T16:59:14.485Z,1537808354.485 [WetLabsSeaOWL_UV_A] Loaded
2018-09-24T16:59:14.485Z,1537808354.485 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2018-09-24T16:59:14.486Z,1537808354.486 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 406DB4E0
2018-09-24T16:59:14.486Z,1537808354.486 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 1843
2018-09-24T16:59:14.487Z,1537808354.487 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-09-24T16:59:14.488Z,1537808354.488 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-09-24T16:59:14.794Z,1537808354.794 [AHRS_M2] Loaded
2018-09-24T16:59:14.794Z,1537808354.794 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2018-09-24T16:59:14.862Z,1537808354.862 [DataOverHttps] Loaded
2018-09-24T16:59:14.862Z,1537808354.862 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-09-24T16:59:14.876Z,1537808354.876 [Depth_Keller] Loaded
2018-09-24T16:59:14.876Z,1537808354.876 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-09-24T16:59:14.881Z,1537808354.881 [DropWeight] Loaded
2018-09-24T16:59:14.881Z,1537808354.881 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-09-24T16:59:14.972Z,1537808354.972 [NAL9602] Loaded
2018-09-24T16:59:14.972Z,1537808354.972 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-09-24T16:59:14.978Z,1537808354.978 [Onboard] Loaded
2018-09-24T16:59:14.978Z,1537808354.978 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-09-24T16:59:14.985Z,1537808354.985 [Radio_Surface] Loaded
2018-09-24T16:59:14.985Z,1537808354.985 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-09-24T16:59:14.986Z,1537808354.986 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4093C4E0
2018-09-24T16:59:14.987Z,1537808354.987 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1844
2018-09-24T16:59:15.016Z,1537808355.016 [RDI_Pathfinder] Loaded
2018-09-24T16:59:15.016Z,1537808355.016 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2018-09-24T16:59:15.023Z,1537808355.023 [SCPI] Loaded
2018-09-24T16:59:15.023Z,1537808355.023 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread.
2018-09-24T16:59:17.247Z,1537808357.247 [BPC1] Loaded
2018-09-24T16:59:17.247Z,1537808357.247 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-09-24T16:59:17.248Z,1537808357.248 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-09-24T16:59:17.248Z,1537808357.248 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-09-24T16:59:17.350Z,1537808357.350 [BuoyancyServo] Loaded
2018-09-24T16:59:17.350Z,1537808357.350 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-09-24T16:59:17.362Z,1537808357.362 [ElevatorServo] Loaded
2018-09-24T16:59:17.363Z,1537808357.363 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-09-24T16:59:17.374Z,1537808357.374 [MassServo] Loaded
2018-09-24T16:59:17.374Z,1537808357.374 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-09-24T16:59:17.386Z,1537808357.386 [RudderServo] Loaded
2018-09-24T16:59:17.386Z,1537808357.386 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-09-24T16:59:17.397Z,1537808357.397 [ThrusterServo] Loaded
2018-09-24T16:59:17.398Z,1537808357.398 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-09-24T16:59:17.398Z,1537808357.398 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-09-24T16:59:17.399Z,1537808357.399 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-09-24T16:59:17.501Z,1537808357.501 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-09-24T16:59:17.502Z,1537808357.502 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-09-24T16:59:17.526Z,1537808357.526 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-09-24T16:59:17.530Z,1537808357.530 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-09-24T16:59:17.531Z,1537808357.531 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-09-24T16:59:17.538Z,1537808357.538 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-09-24T16:59:17.539Z,1537808357.539 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 409E54E0
2018-09-24T16:59:17.539Z,1537808357.539 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1845
2018-09-24T16:59:17.544Z,1537808357.544 [Supervisor](INFO): Main Thread ID is 795
2018-09-24T16:59:17.544Z,1537808357.544 [Supervisor](DEBUG): Running supervisor.
2018-09-24T16:59:17.544Z,1537808357.544 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1846
2018-09-24T16:59:17.547Z,1537808357.547 [controlThread ThreadHandler](INFO): Handler Thread ID is 1847
2018-09-24T16:59:17.547Z,1537808357.547 [controlThread](DEBUG): Initializing ControlThread
2018-09-24T16:59:17.548Z,1537808357.548 [SBIT](INFO): Initialize SBIT Component.
2018-09-24T16:59:17.548Z,1537808357.548 [SBIT](IMPORTANT): git: 2018-09-20
2018-09-24T16:59:17.549Z,1537808357.549 [SBIT](INFO): git hash: cc82e4f04ca47b19cdcc10b5d3e1760510b3ba6f
2018-09-24T16:59:17.549Z,1537808357.549 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-09-24T16:59:17.549Z,1537808357.549 [SBIT](IMPORTANT): Kernel Version:#2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-09-24T16:59:17.551Z,1537808357.551 [SBIT](INFO): Beginning SBIT in 20.000000 seconds.
2018-09-24T16:59:17.551Z,1537808357.551 [IBIT](INFO): Initialize IBIT Component.
2018-09-24T16:59:17.552Z,1537808357.552 [CBIT](DEBUG): Initialize CBIT Component.
2018-09-24T16:59:17.552Z,1537808357.552 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-09-24T16:59:17.553Z,1537808357.553 [logger ThreadHandler](INFO): Handler Thread ID is 1848
2018-09-24T16:59:17.581Z,1537808357.581 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 1849
2018-09-24T16:59:17.583Z,1537808357.583 [WetLabsSeaOWL_UV_A](INFO): Powering down
2018-09-24T16:59:17.621Z,1537808357.621 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1850
2018-09-24T16:59:17.627Z,1537808357.627 [Radio_Surface](INFO): Powering up
2018-09-24T16:59:17.633Z,1537808357.633 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1851
2018-09-24T16:59:17.637Z,1537808357.637 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-09-24T16:59:17.637Z,1537808357.637 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-09-24T16:59:17.637Z,1537808357.637 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-09-24T16:59:17.637Z,1537808357.637 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-09-24T16:59:17.637Z,1537808357.637 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-09-24T16:59:17.638Z,1537808357.638 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-09-24T16:59:17.638Z,1537808357.638 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-09-24T16:59:17.638Z,1537808357.638 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-09-24T16:59:17.638Z,1537808357.638 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-09-24T16:59:17.638Z,1537808357.638 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-09-24T16:59:17.639Z,1537808357.639 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-09-24T16:59:17.639Z,1537808357.639 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-09-24T16:59:17.639Z,1537808357.639 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-09-24T16:59:17.639Z,1537808357.639 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-09-24T16:59:17.639Z,1537808357.639 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-09-24T16:59:17.640Z,1537808357.640 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-09-24T16:59:17.657Z,1537808357.657 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-09-24T16:59:17.659Z,1537808357.659 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-09-24T16:59:17.659Z,1537808357.659 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-09-24T16:59:17.660Z,1537808357.660 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-09-24T16:59:17.660Z,1537808357.660 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-09-24T16:59:17.660Z,1537808357.660 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-09-24T16:59:17.661Z,1537808357.661 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-09-24T16:59:17.661Z,1537808357.661 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-09-24T16:59:17.662Z,1537808357.662 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-09-24T16:59:17.662Z,1537808357.662 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-09-24T16:59:17.663Z,1537808357.663 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2018-09-24T16:59:17.664Z,1537808357.664 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2018-09-24T16:59:17.664Z,1537808357.664 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2018-09-24T16:59:17.664Z,1537808357.664 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-09-24T16:59:17.665Z,1537808357.665 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-09-24T16:59:17.665Z,1537808357.665 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-09-24T16:59:17.666Z,1537808357.666 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-09-24T16:59:17.666Z,1537808357.666 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-09-24T16:59:17.674Z,1537808357.674 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-09-24T16:59:17.710Z,1537808357.710 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-09-24T16:59:17.745Z,1537808357.745 [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-09-24T16:59:17.746Z,1537808357.746 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-09-24T16:59:17.822Z,1537808357.822 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-09-24T16:59:17.823Z,1537808357.823 [Default:A.Wait](DEBUG): Construct Wait.
2018-09-24T16:59:17.824Z,1537808357.824 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-09-24T16:59:17.872Z,1537808357.872 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-09-24T16:59:17.874Z,1537808357.874 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-09-24T16:59:17.913Z,1537808357.913 [Default:E.Execute](DEBUG): Construct Execute.
2018-09-24T16:59:17.933Z,1537808357.933 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2018-09-24T16:59:17.938Z,1537808357.938 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,RDI_Pathfinder,SCPI,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-09-24T16:59:17.967Z,1537808357.967 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2018-09-24T16:59:18.041Z,1537808358.041 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-09-24T16:59:18.058Z,1537808358.058 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2018-09-24T16:59:18.211Z,1537808358.211 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-09-24T16:59:18.281Z,1537808358.281 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T16:59:18.309Z,1537808358.309 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T16:59:18.404Z,1537808358.404 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-09-24T16:59:18.409Z,1537808358.409 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-09-24T16:59:18.436Z,1537808358.436 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-09-24T16:59:18.441Z,1537808358.441 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-09-24T16:59:18.449Z,1537808358.449 [MassServo](DEBUG): Initializing EZServoServo.
2018-09-24T16:59:18.457Z,1537808358.457 [MassServo](DEBUG): Initializing MassServo.
2018-09-24T16:59:18.479Z,1537808358.479 [RudderServo](DEBUG): Initializing EZServoServo.
2018-09-24T16:59:18.485Z,1537808358.485 [RudderServo](DEBUG): Initializing RudderServo.
2018-09-24T16:59:18.499Z,1537808358.499 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-09-24T16:59:18.501Z,1537808358.501 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-09-24T16:59:18.705Z,1537808358.705 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-09-24T16:59:18.708Z,1537808358.708 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T16:59:18.709Z,1537808358.709 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T16:59:19.028Z,1537808359.028 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T16:59:19.037Z,1537808359.037 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T16:59:19.377Z,1537808359.377 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2018-09-24T16:59:19.377Z,1537808359.377 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2018-09-24T16:59:19.377Z,1537808359.377 [BuoyancyServo] Communications Fault, FailCount= 1
2018-09-24T16:59:19.377Z,1537808359.377 [BuoyancyServo](ERROR): Communications Fault
2018-09-24T16:59:19.589Z,1537808359.589 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2018-09-24T16:59:19.634Z,1537808359.634 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T16:59:19.635Z,1537808359.635 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T16:59:19.647Z,1537808359.647 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-09-24T16:59:19.648Z,1537808359.648 [BuoyancyServo](INFO): Powering down
2018-09-24T16:59:20.024Z,1537808360.024 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T16:59:20.025Z,1537808360.025 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T16:59:20.424Z,1537808360.424 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T16:59:20.425Z,1537808360.425 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T16:59:20.824Z,1537808360.824 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T16:59:20.825Z,1537808360.825 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T16:59:21.256Z,1537808361.256 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T16:59:21.269Z,1537808361.269 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T16:59:21.762Z,1537808361.762 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2018-09-24T16:59:21.763Z,1537808361.763 [BuoyancyServo] No Fault, FailCount= 1
2018-09-24T16:59:22.073Z,1537808362.073 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-09-24T16:59:22.194Z,1537808362.194 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-09-24T16:59:31.734Z,1537808371.734 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2018-09-24T16:59:38.176Z,1537808378.176 [SBIT](IMPORTANT): Beginning Startup BIT
2018-09-24T16:59:38.181Z,1537808378.181 [CBIT](IMPORTANT): Beginning ground fault scan
2018-09-24T16:59:45.051Z,1537808385.051 [NAL9602](INFO): Powering up NAL9602
2018-09-24T16:59:49.155Z,1537808389.155 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.025406
CHAN A1 (24V): -0.028376
CHAN A2 (12V): -0.007136
CHAN A3 (5V): -0.002308
CHAN B0 (3.3V): 0.000399
CHAN B1 (3.15aV): -0.000067
CHAN B2 (3.15bV): 0.000483
CHAN B3 (GND): 0.001994
OPEN: 0.005376
Full Scale Calc: 4.765 mA, -1.589 mA
2018-09-24T16:59:56.109Z,1537808396.109 [NAL9602](INFO): NAL9602 initialized
2018-09-24T17:00:03.353Z,1537808403.353 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2018-09-24T17:00:03.353Z,1537808403.353 [RDI_Pathfinder](ERROR): Failed to parse:
:BD,        +0.00,        +0.00,       32.00
2018-09-24T17:00:15.330Z,1537808415.330 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=1533, MT Status=1, MTMSN=76
2018-09-24T17:00:15.330Z,1537808415.330 [NAL9602](INFO): Data available in MT queue
2018-09-24T17:00:15.870Z,1537808415.870 [NAL9602](INFO): Received command:stop;configSet Express linearApprox RDI_Pathfinder.height_above_sea_floor 5 meter persist
2018-09-24T17:00:18.109Z,1537808418.109 [CommandLine](IMPORTANT): got command stop
2018-09-24T17:00:18.109Z,1537808418.109 [CommandLine](IMPORTANT): Scheduling is paused
2018-09-24T17:00:18.110Z,1537808418.110 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2018-09-24T17:00:18.110Z,1537808418.110 [CommandLine](IMPORTANT): got command configSet Express linearApproximation RDI_Pathfinder.height_above_sea_floor 5.000000 meter persist
2018-09-24T17:00:32.156Z,1537808432.156 [SBIT](IMPORTANT): SBIT PASSED
2018-09-24T17:00:32.214Z,1537808432.214 [CommandLine](IMPORTANT): got command configSet list
2018-09-24T17:00:32.214Z,1537808432.214 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-09-24T17:00:32.215Z,1537808432.215 [CommandLine](IMPORTANT): Aanderaa_O2.loadAtStartup=0 bool;

2018-09-24T17:00:32.215Z,1537808432.215 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=1 hour;

2018-09-24T17:00:32.215Z,1537808432.215 [CommandLine](IMPORTANT): BuoyancyServo.accel=400 none;

2018-09-24T17:00:32.216Z,1537808432.216 [CommandLine](IMPORTANT): BuoyancyServo.fastPumpCoefficient=1 none;

2018-09-24T17:00:32.216Z,1537808432.216 [CommandLine](IMPORTANT): BuoyancyServo.velocity=300 none;

2018-09-24T17:00:32.216Z,1537808432.216 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.height_above_sea_floor 5.000000 meter;

2018-09-24T17:00:32.216Z,1537808432.216 [CommandLine](IMPORTANT): Express linearApproximation WetLabsSeaOWL_UV_A.mass_concentration_of_chlorophyll_in_sea_water 0.500000 microgram_per_liter;

2018-09-24T17:00:32.216Z,1537808432.216 [CommandLine](IMPORTANT): Express linearApproximation height_above_sea_floor 5.000000 meter;

2018-09-24T17:00:32.216Z,1537808432.216 [CommandLine](IMPORTANT): IBIT.batteryVoltageThreshold=13.7 volt;

2018-09-24T17:00:32.216Z,1537808432.216 [CommandLine](IMPORTANT): RDI_PathfinderUp.loadAtStartup=0 bool;

2018-09-24T17:00:32.216Z,1537808432.217 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=205 cubic_centimeter;

2018-09-24T17:00:32.217Z,1537808432.217 [CommandLine](IMPORTANT): VerticalControl.massDefault=0 millimeter;

2018-09-24T17:00:32.217Z,1537808432.217 [CommandLine](IMPORTANT): WetLabsBB2FL.loadAtStartup=0 bool;

2018-09-24T17:00:32.217Z,1537808432.217 [CommandLine](IMPORTANT): WetLabsBB2FL.simulateHardware=0 bool;

2018-09-24T17:00:32.541Z,1537808432.541 [MissionManager](IMPORTANT): Started mission Startup
2018-09-24T17:00:32.541Z,1537808432.541 [Startup] Running Loop=1
2018-09-24T17:00:32.542Z,1537808432.542 [Startup](DEBUG): Aggregate::initialize Startup
2018-09-24T17:00:32.542Z,1537808432.542 [Startup:A.GoToSurface] Running Loop=1
2018-09-24T17:00:32.542Z,1537808432.542 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-09-24T17:00:32.542Z,1537808432.542 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-09-24T17:00:32.543Z,1537808432.543 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-09-24T17:00:32.543Z,1537808432.543 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-09-24T17:00:32.544Z,1537808432.544 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-09-24T17:00:32.544Z,1537808432.544 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-09-24T17:00:32.559Z,1537808432.559 [Startup:StartupSatComms] Running Loop=1
2018-09-24T17:00:32.559Z,1537808432.559 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-09-24T17:00:32.559Z,1537808432.559 [Startup:StartupSatComms:A] Running Loop=1
2018-09-24T17:00:32.931Z,1537808432.931 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-09-24T17:01:32.933Z,1537808492.933 [Startup:StartupSatComms:A](INFO): Timed out from 2018-09-24T17:00:32.6Z
2018-09-24T17:01:32.933Z,1537808492.933 [Startup:StartupSatComms:A] Stopped
2018-09-24T17:01:32.933Z,1537808492.933 [Startup:StartupSatComms:B] Running Loop=1
2018-09-24T17:01:33.359Z,1537808493.359 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-09-24T17:02:03.416Z,1537808523.416 [NAL9602](INFO): SBD MO Status=1, MOMSN=1534, MT Status=0, MTMSN=0
2018-09-24T17:02:03.485Z,1537808523.485 [NAL9602](INFO): Sent 25 bytes from file Logs/20180924T161144/Courier0019.lzma
2018-09-24T17:02:03.485Z,1537808523.485 [NAL9602](INFO): Packets left to send: 0
2018-09-24T17:02:03.487Z,1537808523.487 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180924T161144/Courier0019.lzma.parts/0000.sbd
2018-09-24T17:02:03.487Z,1537808523.487 [NAL9602](DEBUG): Completed sending Logs/20180924T161144/Courier0019.lzma
2018-09-24T17:02:15.148Z,1537808535.148 [NAL9602](INFO): SBD MO Status=1, MOMSN=1535, MT Status=0, MTMSN=0
2018-09-24T17:02:15.197Z,1537808535.197 [NAL9602](INFO): Sent 332 bytes from file Logs/20180924T161144/Express0020.lzma
2018-09-24T17:02:15.197Z,1537808535.197 [NAL9602](INFO): Packets left to send: 1
2018-09-24T17:02:15.200Z,1537808535.200 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180924T161144/Express0020.lzma.parts/0001.sbd
2018-09-24T17:02:18.007Z,1537808538.007 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-09-24T17:02:18.007Z,1537808538.007 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2018-09-24T17:02:18.007Z,1537808538.007 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2018-09-24T17:02:18.009Z,1537808538.009 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-09-24T17:02:18.009Z,1537808538.009 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2018-09-24T17:02:18.009Z,1537808538.009 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-09-24T17:02:18.022Z,1537808538.022 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2018-09-24T17:02:18.023Z,1537808538.023 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-09-24T17:02:18.143Z,1537808538.143 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2018-09-24T17:02:18.143Z,1537808538.143 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2018-09-24T17:02:18.143Z,1537808538.143 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-09-24T17:02:18.143Z,1537808538.143 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2018-09-24T17:02:18.487Z,1537808538.487 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2018-09-24T17:02:18.488Z,1537808538.488 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2018-09-24T17:02:18.488Z,1537808538.488 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2018-09-24T17:02:18.493Z,1537808538.493 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-09-24T17:02:18.494Z,1537808538.494 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-09-24T17:02:18.495Z,1537808538.495 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-09-24T17:02:28.844Z,1537808548.844 [NAL9602](INFO): SBD MO Status=1, MOMSN=1536, MT Status=0, MTMSN=0
2018-09-24T17:02:28.902Z,1537808548.902 [NAL9602](INFO): Sent 39 bytes from file Logs/20180924T161144/Express0020.lzma
2018-09-24T17:02:28.902Z,1537808548.902 [NAL9602](INFO): Packets left to send: 0
2018-09-24T17:02:28.904Z,1537808548.904 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180924T161144/Express0020.lzma.parts/0000.sbd
2018-09-24T17:02:28.904Z,1537808548.904 [NAL9602](DEBUG): Completed sending Logs/20180924T161144/Express0020.lzma
2018-09-24T17:02:33.013Z,1537808553.013 [Startup:StartupSatComms:B](INFO): Timed out from 2018-09-24T17:01:32.9Z
2018-09-24T17:02:33.013Z,1537808553.013 [Startup:StartupSatComms:B] Stopped
2018-09-24T17:02:33.013Z,1537808553.013 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-09-24T17:02:33.013Z,1537808553.013 [Startup:StartupSatComms] Stopped
2018-09-24T17:02:33.013Z,1537808553.013 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-09-24T17:02:33.014Z,1537808553.014 [Startup](INFO): Completed Startup
2018-09-24T17:02:33.014Z,1537808553.014 [MissionManager](INFO): Startup is completed.
2018-09-24T17:02:33.014Z,1537808553.014 [MissionManager](INFO): Uninitializing Mission Startup
2018-09-24T17:02:33.015Z,1537808553.015 [Startup] Stopped
2018-09-24T17:02:33.015Z,1537808553.015 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-09-24T17:02:33.015Z,1537808553.015 [Startup:A.GoToSurface] Stopped
2018-09-24T17:02:33.015Z,1537808553.015 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-09-24T17:02:33.429Z,1537808553.429 [MissionManager](IMPORTANT): Started mission Default
2018-09-24T17:02:33.429Z,1537808553.429 [Default] Running Loop=1
2018-09-24T17:02:33.429Z,1537808553.429 [Default](DEBUG): Aggregate::initialize Default
2018-09-24T17:02:33.429Z,1537808553.429 [Default:B.GoToSurface] Running Loop=1
2018-09-24T17:02:33.429Z,1537808553.429 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-09-24T17:02:33.430Z,1537808553.430 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-09-24T17:02:33.430Z,1537808553.430 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-09-24T17:02:33.430Z,1537808553.430 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-09-24T17:02:33.431Z,1537808553.431 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-09-24T17:02:33.431Z,1537808553.431 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-09-24T17:02:33.431Z,1537808553.431 [Default:A.Wait] Running Loop=1
2018-09-24T17:02:33.431Z,1537808553.431 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-09-24T17:02:44.693Z,1537808564.693 [DataOverHttps](IMPORTANT): SBD MTMSN=20180924T170236
2018-09-24T17:02:44.697Z,1537808564.697 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.013481
2018-09-24T17:02:48.688Z,1537808568.688 [NAL9602](INFO): SBD MO Status=2, MOMSN=1537, MT Status=2, MTMSN=0
2018-09-24T17:02:48.689Z,1537808568.689 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-24T17:02:48.768Z,1537808568.768 [Default:A.Wait](INFO): Done Waiting.
2018-09-24T17:02:48.769Z,1537808568.769 [Default:A.Wait] Stopped
2018-09-24T17:02:48.769Z,1537808568.769 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-09-24T17:02:48.815Z,1537808568.815 [DataOverHttps](INFO): Received command:load Science/trackPatch_yz.xml;set trackPatch.MissionTimeout 30 min;set trackPatch.YoYoMinDepth 2 m;set trackPatch.YoYoMaxDepth 10 m;set trackPatch.PeakChlShallowBnd 3 m;set trackPatch.PeakChlDeepBnd 8 m;run
2018-09-24T17:02:48.848Z,1537808568.848 [CommandLine](IMPORTANT): got command load ./Missions/Science/trackPatch_yz.xml
2018-09-24T17:02:48.853Z,1537808568.853 [MissionManager](INFO): Loading Mission: ./Missions/Science/trackPatch_yz.xml
2018-09-24T17:02:49.083Z,1537808569.083 [MissionManager](INFO): DefineArg trackPatch.MinAltitude = 5.000000 m
2018-09-24T17:02:49.086Z,1537808569.086 [MissionManager](INFO): DefineArg trackPatch.MaxDepth = 65.000000 m
2018-09-24T17:02:49.089Z,1537808569.089 [MissionManager](INFO): DefineArg trackPatch.MinWaterDepth = 10.000000 m
2018-09-24T17:02:49.092Z,1537808569.092 [MissionManager](INFO): DefineArg trackPatch.MinOffshore = 2000.000000 m
2018-09-24T17:02:49.095Z,1537808569.095 [MissionManager](INFO): DefineArg trackPatch.NeedCommsTime = 180.000000 min
2018-09-24T17:02:49.098Z,1537808569.098 [MissionManager](INFO): DefineArg trackPatch.MissionTimeout = 56.000000 h
2018-09-24T17:02:49.122Z,1537808569.122 [MissionManager](INFO): DefineArg trackPatch.MassDefault = 0.000000 cm
2018-09-24T17:02:49.130Z,1537808569.130 [MissionManager](INFO): DefineArg trackPatch.BuoyancyNeutral = 205.000004 cc
2018-09-24T17:02:49.133Z,1537808569.133 [MissionManager](INFO): DefineArg trackPatch.YoYoMinDepth = 2.000000 m
2018-09-24T17:02:49.136Z,1537808569.136 [MissionManager](INFO): DefineArg trackPatch.YoYoMaxDepth = 10.000000 m
2018-09-24T17:02:49.151Z,1537808569.151 [MissionManager](INFO): DefineArg trackPatch.YoYoUpPitch = 20.000000 arcdeg
2018-09-24T17:02:49.154Z,1537808569.154 [MissionManager](INFO): DefineArg trackPatch.YoYoDownPitch = -20.000000 arcdeg
2018-09-24T17:02:49.157Z,1537808569.157 [MissionManager](INFO): DefineArg trackPatch.Speed = 1.000000 m/s
2018-09-24T17:02:49.160Z,1537808569.160 [MissionManager](INFO): DefineArg trackPatch.WpMaxDistance = 1000.000000 m
2018-09-24T17:02:49.183Z,1537808569.183 [MissionManager](INFO): DefineArg trackPatch.WpTimeout = 8000.000000 s
2018-09-24T17:02:49.186Z,1537808569.186 [MissionManager](INFO): DefineArg trackPatch.WaterFrame = 1 bool
2018-09-24T17:02:49.188Z,1537808569.188 [MissionManager](INFO): DefineArg trackPatch.Repeat = 20.000000 count
2018-09-24T17:02:49.199Z,1537808569.199 [MissionManager](INFO): DefineArg trackPatch.Turn = 90.000000 arcdeg
2018-09-24T17:02:49.222Z,1537808569.222 [MissionManager](INFO): DefineArg trackPatch.Reverse = 180.000000 arcdeg
2018-09-24T17:02:49.229Z,1537808569.229 [MissionManager](INFO): DefineArg trackPatch.TwoPi = 360.000000 arcdeg
2018-09-24T17:02:49.232Z,1537808569.232 [MissionManager](INFO): DefineArg trackPatch.LowPassWindowLen = 20.000000 count
2018-09-24T17:02:49.235Z,1537808569.235 [MissionManager](INFO): DefineArg trackPatch.PeakChlShallowBnd = 3.000000 m
2018-09-24T17:02:49.250Z,1537808569.250 [MissionManager](INFO): DefineArg trackPatch.PeakChlDeepBnd = 8.000000 m
2018-09-24T17:02:49.253Z,1537808569.253 [MissionManager](INFO): DefineArg trackPatch.FilterWidth = 4.000000 count
2018-09-24T17:02:49.256Z,1537808569.256 [MissionManager](INFO): DefineArg trackPatch.BeginThreshold = nan ug/l
2018-09-24T17:02:49.267Z,1537808569.267 [MissionManager](INFO): DefineArg trackPatch.OffPeakFraction = 80.000000 %
2018-09-24T17:02:49.270Z,1537808569.270 [MissionManager](INFO): DefineArg trackPatch.PatchMode = 0 bool
2018-09-24T17:02:49.273Z,1537808569.273 [MissionManager](INFO): DefineArg trackPatch.WpBearing = -90.000000 arcdeg
2018-09-24T17:02:49.276Z,1537808569.276 [MissionManager](INFO): DefineOutput trackPatch.PatchDetectOn = 0 bool
2018-09-24T17:02:49.279Z,1537808569.279 [MissionManager](INFO): DefineOutput trackPatch.WpDone = 0 bool
2018-09-24T17:02:49.301Z,1537808569.301 [MissionManager](INFO): DefineOutput trackPatch.PatchChl = nan ug/l
2018-09-24T17:02:49.304Z,1537808569.304 [MissionManager](INFO): DefineOutput trackPatch.PatchChlDepth = nan m
2018-09-24T17:02:49.308Z,1537808569.308 [MissionManager](INFO): DefineOutput trackPatch.PatchChlLatitude = nan arcdeg
2018-09-24T17:02:49.319Z,1537808569.319 [MissionManager](INFO): DefineOutput trackPatch.PatchChlLongitude = nan arcdeg
2018-09-24T17:02:49.323Z,1537808569.323 [MissionManager](INFO): DefineOutput trackPatch.PatchChlDistance = 0.000000 m
2018-09-24T17:02:49.327Z,1537808569.327 [trackPatch:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2018-09-24T17:02:49.347Z,1537808569.347 [trackPatch:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2018-09-24T17:02:49.367Z,1537808569.367 [MissionManager](INFO): Inserting Stack: Missions/Insert/Surface.xml
2018-09-24T17:02:49.426Z,1537808569.426 [MissionManager](INFO): DefineArg trackPatch:SurfaceCommsSplit.SurfaceDepthRate = nan m/s
2018-09-24T17:02:49.440Z,1537808569.440 [MissionManager](INFO): DefineArg trackPatch:SurfaceCommsSplit.SurfacePitch = 20.000000 arcdeg
2018-09-24T17:02:49.451Z,1537808569.451 [MissionManager](INFO): DefineArg trackPatch:SurfaceCommsSplit.SurfaceSpeed = 1.000000 m/s
2018-09-24T17:02:49.454Z,1537808569.454 [MissionManager](INFO): DefineArg trackPatch:SurfaceCommsSplit.IridiumTimeout = 30.000000 min
2018-09-24T17:02:49.457Z,1537808569.457 [MissionManager](INFO): DefineArg trackPatch:SurfaceCommsSplit.UnpackSplitAtSurface = 0 bool
2018-09-24T17:02:49.458Z,1537808569.458 [trackPatch:SurfaceCommsSplit:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-09-24T17:02:49.495Z,1537808569.495 [MissionManager](INFO): RedefineArg trackPatch:SurfaceCommsSplit.SurfacePitch = value:20.000000 arcdeg
2018-09-24T17:02:49.501Z,1537808569.501 [MissionManager](INFO): RedefineArg trackPatch:SurfaceCommsSplit.SurfaceSpeed = value:1.000000 m/s
2018-09-24T17:02:49.503Z,1537808569.503 [MissionManager](INFO): RedefineArg trackPatch:SurfaceCommsSplit.UnpackSplitAtSurface = value:1 bool
2018-09-24T17:02:49.505Z,1537808569.505 [MissionManager](INFO): Inserting Stack: Missions/Insert/Surface.xml
2018-09-24T17:02:49.556Z,1537808569.556 [MissionManager](INFO): DefineArg trackPatch:SurfaceComms:SurfaceComms.SurfaceDepthRate = nan m/s
2018-09-24T17:02:49.563Z,1537808569.563 [MissionManager](INFO): DefineArg trackPatch:SurfaceComms:SurfaceComms.SurfacePitch = 20.000000 arcdeg
2018-09-24T17:02:49.567Z,1537808569.567 [MissionManager](INFO): DefineArg trackPatch:SurfaceComms:SurfaceComms.SurfaceSpeed = 1.000000 m/s
2018-09-24T17:02:49.582Z,1537808569.582 [MissionManager](INFO): DefineArg trackPatch:SurfaceComms:SurfaceComms.IridiumTimeout = 30.000000 min
2018-09-24T17:02:49.584Z,1537808569.584 [MissionManager](INFO): DefineArg trackPatch:SurfaceComms:SurfaceComms.UnpackSplitAtSurface = 0 bool
2018-09-24T17:02:49.590Z,1537808569.590 [trackPatch:SurfaceComms:SurfaceComms:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-09-24T17:02:49.615Z,1537808569.615 [MissionManager](INFO): RedefineArg trackPatch:SurfaceComms:SurfaceComms.SurfacePitch = value:20.000000 arcdeg
2018-09-24T17:02:49.618Z,1537808569.618 [MissionManager](INFO): RedefineArg trackPatch:SurfaceComms:SurfaceComms.SurfaceSpeed = value:1.000000 m/s
2018-09-24T17:02:49.636Z,1537808569.636 [trackPatch:F.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2018-09-24T17:02:49.656Z,1537808569.656 [trackPatch:G.WaterDepthEnvelope](DEBUG): Construct WaterDepthEnvelope.
2018-09-24T17:02:49.684Z,1537808569.684 [trackPatch:H.Pitch](DEBUG): Construct.
2018-09-24T17:02:49.700Z,1537808569.700 [trackPatch:I.Buoyancy](DEBUG): Construct Buoyancy.
2018-09-24T17:02:49.733Z,1537808569.733 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science_yz.xml
2018-09-24T17:02:49.995Z,1537808569.995 [MissionManager](INFO): DefineArg trackPatch:Science.SampleISUS = 0 bool
2018-09-24T17:02:49.998Z,1537808569.998 [MissionManager](INFO): DefineArg trackPatch:Science.SampleISUSmaxPitch = 60.000000 arcdeg
2018-09-24T17:02:50.000Z,1537808570.000 [MissionManager](INFO): DefineArg trackPatch:Science.SampleISUSminPitch = -60.000000 arcdeg
2018-09-24T17:02:50.012Z,1537808570.012 [MissionManager](INFO): DefineArg trackPatch:Science.PeakDetectChlActive = 0 bool
2018-09-24T17:02:50.018Z,1537808570.018 [MissionManager](INFO): DefineArg trackPatch:Science.HighestChlPeakReportActive = 0 bool
2018-09-24T17:02:50.033Z,1537808570.033 [MissionManager](INFO): DefineArg trackPatch:Science.PatchTracking = 1 bool
2018-09-24T17:02:50.036Z,1537808570.036 [MissionManager](INFO): DefineArg trackPatch:Science.FilterWidthHorizontal = 3.000000 count
2018-09-24T17:02:50.039Z,1537808570.039 [MissionManager](INFO): DefineArg trackPatch:Science.NumProfilesSlidingwindow = 100.000000 count
2018-09-24T17:02:50.050Z,1537808570.050 [MissionManager](INFO): DefineArg trackPatch:Science.OffPeakFractionHorizontal = 80.000000 %
2018-09-24T17:02:50.053Z,1537808570.053 [MissionManager](INFO): DefineArg trackPatch:Science.PeakDetectNO3Active = 0 bool
2018-09-24T17:02:50.056Z,1537808570.056 [MissionManager](INFO): DefineArg trackPatch:Science.PeakDetectOilActive = 0 bool
2018-09-24T17:02:50.058Z,1537808570.058 [MissionManager](INFO): DefineArg trackPatch:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2018-09-24T17:02:50.074Z,1537808570.074 [MissionManager](INFO): DefineArg trackPatch:Science.EnabledAanderaaO2 = 0.000000 bool
2018-09-24T17:02:50.077Z,1537808570.077 [MissionManager](INFO): DefineArg trackPatch:Science.EnabledNeilBrown = 0.000000 bool
2018-09-24T17:02:50.080Z,1537808570.080 [MissionManager](INFO): DefineArg trackPatch:Science.EnabledSeabird = 0.000000 bool
2018-09-24T17:02:50.084Z,1537808570.084 [MissionManager](INFO): DefineArg trackPatch:Science.EnabledTurbulence_NPS = 0.000000 bool
2018-09-24T17:02:50.107Z,1537808570.107 [MissionManager](INFO): DefineArg trackPatch:Science.EnabledWetLabsBB2FL = 0.000000 bool
2018-09-24T17:02:50.111Z,1537808570.111 [MissionManager](INFO): DefineArg trackPatch:Science.EnabledWetLabsSeaOWL_UV_A = 1.000000 bool
2018-09-24T17:02:50.114Z,1537808570.114 [MissionManager](INFO): DefineArg trackPatch:Science.EnabledISUS = 0.000000 bool
2018-09-24T17:02:50.117Z,1537808570.117 [MissionManager](INFO): DefineArg trackPatch:Science.LowPassWindowLength = 20.000000 count
2018-09-24T17:02:50.120Z,1537808570.120 [MissionManager](INFO): DefineArg trackPatch:Science.PeakChlShallowBound = 10.000000 m
2018-09-24T17:02:50.123Z,1537808570.123 [MissionManager](INFO): DefineArg trackPatch:Science.PeakChlDeepBound = 20.000000 m
2018-09-24T17:02:50.147Z,1537808570.147 [MissionManager](INFO): DefineOutput trackPatch:Science.PeakChl = 0.000000 ug/l
2018-09-24T17:02:50.150Z,1537808570.150 [MissionManager](INFO): DefineOutput trackPatch:Science.PeakChlDepth = 0.000000 m
2018-09-24T17:02:50.153Z,1537808570.153 [MissionManager](INFO): DefineOutput trackPatch:Science.PeakChlTemperature = 0.000000 degC
2018-09-24T17:02:50.156Z,1537808570.156 [MissionManager](INFO): DefineOutput trackPatch:Science.PeakChlLatitude = nan arcdeg
2018-09-24T17:02:50.159Z,1537808570.159 [MissionManager](INFO): DefineOutput trackPatch:Science.PeakChlLongitude = nan arcdeg
2018-09-24T17:02:50.162Z,1537808570.162 [MissionManager](INFO): DefineOutput trackPatch:Science.PeakNO3 = 0.000000 umol/l
2018-09-24T17:02:50.177Z,1537808570.177 [MissionManager](INFO): DefineOutput trackPatch:Science.PeakNO3Depth = 0.000000 m
2018-09-24T17:02:50.180Z,1537808570.180 [MissionManager](INFO): DefineOutput trackPatch:Science.PeakNO3Latitude = nan arcdeg
2018-09-24T17:02:50.184Z,1537808570.184 [MissionManager](INFO): DefineOutput trackPatch:Science.PeakNO3Longitude = nan arcdeg
2018-09-24T17:02:50.187Z,1537808570.187 [MissionManager](INFO): DefineOutput trackPatch:Science.PatchChl = 0.000000 m
2018-09-24T17:02:50.210Z,1537808570.210 [MissionManager](INFO): DefineOutput trackPatch:Science.PatchChlDepth = 0.000000 m
2018-09-24T17:02:50.213Z,1537808570.213 [MissionManager](INFO): DefineOutput trackPatch:Science.PatchChlLatitude = nan arcdeg
2018-09-24T17:02:50.216Z,1537808570.216 [MissionManager](INFO): DefineOutput trackPatch:Science.PatchChlLongitude = nan arcdeg
2018-09-24T17:02:50.235Z,1537808570.235 [MissionManager](INFO): DefineOutput trackPatch:Science.PatchChlDistance = nan m
2018-09-24T17:02:50.238Z,1537808570.238 [MissionManager](INFO): DefineOutput trackPatch:Science.PeakOil = 0.000000 kg/m3
2018-09-24T17:02:50.241Z,1537808570.241 [MissionManager](INFO): DefineOutput trackPatch:Science.PeakOilDepth = 0.000000 m
2018-09-24T17:02:50.244Z,1537808570.244 [MissionManager](INFO): DefineOutput trackPatch:Science.PeakOilLatitude = nan arcdeg
2018-09-24T17:02:50.261Z,1537808570.261 [MissionManager](INFO): DefineOutput trackPatch:Science.PeakOilLongitude = nan arcdeg
2018-09-24T17:02:50.298Z,1537808570.298 [trackPatch:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2018-09-24T17:02:50.319Z,1537808570.319 [trackPatch:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2018-09-24T17:02:50.353Z,1537808570.353 [trackPatch:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2018-09-24T17:02:50.373Z,1537808570.373 [trackPatch:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2018-09-24T17:02:50.386Z,1537808570.386 [MissionManager](INFO): RedefineArg trackPatch:Science.PeakDetectChlActive = value:1 bool
2018-09-24T17:02:50.388Z,1537808570.388 [MissionManager](INFO): RedefineArg trackPatch:Science.PatchTracking = value:1 bool
2018-09-24T17:02:50.398Z,1537808570.398 [MissionManager](INFO): RedefineArg trackPatch:Science.LowPassWindowLength = reader:trackPatch.LowPassWindowLen
2018-09-24T17:02:50.400Z,1537808570.400 [MissionManager](INFO): RedefineArg trackPatch:Science.PeakChlShallowBound = reader:trackPatch.PeakChlShallowBnd
2018-09-24T17:02:50.401Z,1537808570.401 [MissionManager](INFO): RedefineArg trackPatch:Science.PeakChlDeepBound = reader:trackPatch.PeakChlDeepBnd
2018-09-24T17:02:50.403Z,1537808570.403 [MissionManager](INFO): RedefineArg trackPatch:Science.OffPeakFractionHorizontal = reader:trackPatch.OffPeakFraction
2018-09-24T17:02:50.404Z,1537808570.404 [trackPatch:K.SetSpeed](DEBUG): Construct.
2018-09-24T17:02:50.407Z,1537808570.407 [trackPatch:L.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2018-09-24T17:02:50.440Z,1537808570.440 [trackPatch:M.YoYo](DEBUG): Construct YoYo.
2018-09-24T17:02:50.463Z,1537808570.463 [trackPatch:PatchDetectHorizontal:PatchDetection:PeakDetectHorizontalTrigger.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2018-09-24T17:02:50.513Z,1537808570.513 [trackPatch:PatchDetectHorizontal:CrossLeg:CrossSurfaceWp.Waypoint](DEBUG): Construct Waypoint.
2018-09-24T17:02:50.532Z,1537808570.532 [trackPatch:PatchDetectHorizontal:CrossLeg:CrossPeakWp.Waypoint](DEBUG): Construct Waypoint.
2018-09-24T17:02:50.568Z,1537808570.568 [trackPatch:PatchDetectHorizontal:InLegWp.Waypoint](DEBUG): Construct Waypoint.
2018-09-24T17:02:50.605Z,1537808570.605 [trackPatch:PatchDetectHorizontal:OutLeg:OutLegWp.Waypoint](DEBUG): Construct Waypoint.
2018-09-24T17:02:50.735Z,1537808570.735 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Trigger="Tethys/Trigger" 
       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/Trigger http://okeanids.mbari.org/tethys/Xml/Trigger.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="trackPatch">

    <Description>
        Vehicle runs yo-yos, with patch detect enabled for cholorphyll
        concentration.
    </Description>

<!-- Vehicle safety parameters -->

    <DefineArg Name="MinAltitude"><Description>
        Minimum altitude for the entire mission.
    </Description><Units:meter/><Value>5</Value></DefineArg>

    <DefineArg Name="MaxDepth"><Description>
        Maximum depth for the entire mission.
    </Description><Units:meter/><Value>65</Value></DefineArg>

    <DefineArg Name="MinWaterDepth"><Description>
        Minimum water depth for the entire mission.
    </Description><Units:meter/><Value>10</Value></DefineArg>

    <DefineArg Name="MinOffshore"><Description>
        Minimum offshore distance for the entire mission.
    </Description><Units:meter/><Value>2000</Value></DefineArg>

    <DefineArg Name="NeedCommsTime"><Description>
        Maximum time between surfacings for communications
    </Description><Units:minute/><Value>180</Value></DefineArg>

    <DefineArg Name="MissionTimeout"><Description>
        Timeout for the entire mission
    </Description><Units:hour/><Value>56</Value></DefineArg>

    <DefineArg Name="MassDefault"><Description>
        Static setting for mass during the mission. Defaults to massDefault
        setting in the Config/Control.cfg file.
    </Description><Control:VerticalControl.massDefault/></DefineArg>

    <DefineArg Name="BuoyancyNeutral"><Description>
        Buoyancy bladder position while performing the YoYo behavior. Defaults
        to buoyancyNeutral setting in the Config/Control.cfg file.
    </Description><Control:VerticalControl.buoyancyNeutral/></DefineArg>

<!-- Basic guidance settings -->

    <DefineArg Name="YoYoMinDepth"><Description>
        Minimum depth during yo-yo's.
    </Description><Units:meter/><Value>2.0</Value></DefineArg>

    <DefineArg Name="YoYoMaxDepth"><Description>
        Maximum depth during yo-yo's.
    </Description><Units:meter/><Value>10.0</Value></DefineArg>

    <DefineArg Name="YoYoUpPitch"><Description>
        Pitch when yo-yo's are ascending.
    </Description><Units:degree/><Value>20.0</Value></DefineArg>

    <DefineArg Name="YoYoDownPitch"><Description>
        Pitch when yo-yo's are descending.
    </Description><Units:degree/><Value>-20.0</Value></DefineArg>

    <DefineArg Name="Speed"><Description>
        Vehicle speed.
    </Description><Units:meter_per_second/><Value>1</Value></DefineArg>

    <DefineArg Name="WpMaxDistance"><Description>
        Maximum length of each tracking leg
<!--debug
    </Description><Units:meter/><Value>7500</Value></DefineArg>
-->
    </Description><Units:meter/><Value>1000</Value></DefineArg>

    <DefineArg Name="WpTimeout"><Description>
        Maximum duration of each tracking leg
    </Description><Units:second/><Value>8000</Value></DefineArg>

    <DefineArg Name="WaterFrame"><Description>
        Set WaterFrame true to drive towards waypoints in the water frame of
        reference
    </Description><True/></DefineArg>

    <DefineArg Name="Repeat"><Description>
        Maximum number of tracking legs
    </Description><Units:count/><Value>20</Value></DefineArg>

<!-- Constant settings for each tracking leg -->

    <DefineArg Name="Turn"><Description>
        Amount to turn at each leg
    </Description><Units:degree/><Value>90</Value></DefineArg>

    <DefineArg Name="Reverse"><Description>
        Change in bearing which reverses vehicle direction
    </Description><Units:degree/><Value>180</Value></DefineArg>

    <DefineArg Name="TwoPi"><Description>
        Applied to stop run-up of angles
    </Description><Units:degree/><Value>360</Value></DefineArg>

    <DefineArg Name="LowPassWindowLen"><Description>
        Low-pass window length (based on depth sensor sampling interval 0.4
        second) for low-pass filtering.
    </Description><Units:count/><Value>20</Value></DefineArg>

    <DefineArg Name="PeakChlShallowBnd"><Description>
        Shallow depth bound for detecting chl peak on each descent or ascent
        profile.
<!--debug
    </Description><Units:meter/><Value>NaN</Value></DefineArg>
-->
    </Description><Units:meter/><Value>3</Value></DefineArg>

    <DefineArg Name="PeakChlDeepBnd"><Description>
        Deep depth bound for detecting chl peak on each descent or ascent
        profile.
<!--debug
    </Description><Units:meter/><Value>NaN</Value></DefineArg>
-->
    </Description><Units:meter/><Value>8</Value></DefineArg>

    <DefineArg Name="FilterWidth"><Description>
        Width of boxcar filter used in horizontal patch detection
    </Description><Units:count/><Value>4</Value></DefineArg>

    <DefineArg Name="BeginThreshold"><Description>
        If non-NaN, sets threshold for starting horizontal patch detection
    </Description><Units:microgram_per_liter/><Value>NaN</Value></DefineArg>

    <DefineArg Name="OffPeakFraction"><Description>
        When filtered horizontal value is this fraction of the peak, consider it
        outside the patch.
    </Description><Units:percent/><Value>80</Value></DefineArg>

    <DefineArg Name="PatchMode"><Description>
        If true, use center of "in peak" range as the turn-around point. If
        false use maximum horizontal peak location as the turn-around point.
    </Description><False/></DefineArg>

<!-- Variable Settings for each tracking leg -->

    <DefineArg Name="WpBearing"><Description>
        Bearing being followed in the current leg. Set this to initialize start
        direction of patch tracking.
    </Description><Units:degree/><Value>-90</Value></DefineArg>

    <DefineOutput Name="PatchDetectOn"><Description>
        Mission sets this to true when the patch has been crossed.
    </Description><False/></DefineOutput>

    <DefineOutput Name="WpDone"><Description>
        Mission sets this to true when the cross-patch waypoint has been
        reached.
    </Description><False/></DefineOutput>

    <DefineOutput Name="PatchChl"><Units:microgram_per_liter/><Value>NaN</Value></DefineOutput>

    <DefineOutput Name="PatchChlDepth"><Units:meter/><Value>NaN</Value></DefineOutput>

    <DefineOutput Name="PatchChlLatitude"><Units:degree/><Value>NaN</Value></DefineOutput>

    <DefineOutput Name="PatchChlLongitude"><Units:degree/><Value>NaN</Value></DefineOutput>

    <DefineOutput Name="PatchChlDistance"><Units:meter/><Value>0</Value></DefineOutput>

<!-- The timeout -->

    <Timeout Duration="MissionTimeout"/>

<!-- And now the mission -->

    <Guidance:AltitudeEnvelope>
        <Parallel/>
        <Setting><Guidance:AltitudeEnvelope.minAltitude/><Arg Name="MinAltitude"/></Setting>
    </Guidance:AltitudeEnvelope>

    <Guidance:DepthEnvelope>
        <Parallel/>
        <Setting><Guidance:DepthEnvelope.maxDepth/><Arg Name="MaxDepth"/></Setting>
    </Guidance:DepthEnvelope>

    <Insert Filename="Insert/Surface.xml" Id="SurfaceCommsSplit">
        <RedefineArg Name="SurfacePitch"><Units:degree/><Value>20</Value></RedefineArg>
        <RedefineArg Name="SurfaceSpeed"><Units:meter_per_second/><Value>1</Value></RedefineArg>
        <RedefineArg Name="UnpackSplitAtSurface"><True/></RedefineArg>
    </Insert>

    <Aggregate Id="SurfaceComms">

        <When>
            <Called/>
        </When>

        <Insert Filename="Insert/Surface.xml">
            <RedefineArg Name="SurfacePitch"><Units:degree/><Value>20</Value></RedefineArg>
            <RedefineArg Name="SurfaceSpeed"><Units:meter_per_second/><Value>1</Value></RedefineArg>
        </Insert>

    </Aggregate>

<!-- GPS Update.  Don't go too long w/o a GPS fix. -->

    <Aggregate Id="NeedComms">

        <When>
            <Universal:platform_pitch_angle/>
            <Gt><Units:degree/><Value>0</Value></Gt>
            <And><Elapsed><Universal:time_fix/></Elapsed><Gt><Arg Name="NeedCommsTime"/></Gt></And>
            <Or><Elapsed><Universal:time_fix/></Elapsed><Gt><Arg Name="NeedCommsTime"/><Add><Units:minute/><Value>10</Value></Add></Gt></Or>
        </When>

        <Syslog Severity="Important">NeedComms Timeout Surfacing</Syslog>

        <Call RefId="SurfaceComms"/>

    </Aggregate>

    <Guidance:OffshoreEnvelope>
        <Parallel/>
        <Setting><Guidance:OffshoreEnvelope.minOffshore/><Arg Name="MinOffshore"/></Setting>
    </Guidance:OffshoreEnvelope>

    <Guidance:WaterDepthEnvelope>
        <Parallel/>
        <Setting><Guidance:WaterDepthEnvelope.minWaterDepth/><Arg Name="MinWaterDepth"/></Setting>
    </Guidance:WaterDepthEnvelope>

    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Arg Name="MassDefault"/></Setting>
    </Guidance:Pitch>

    <Guidance:Buoyancy>
        <Parallel/>
        <Setting><Guidance:Buoyancy.position /><Arg Name="BuoyancyNeutral"/></Setting>
    </Guidance:Buoyancy>

<!-- If we're executing here or below, lets' get science data! -->

    <Insert Filename="Insert/Science_yz.xml">
        <RedefineArg Name="PeakDetectChlActive"><True/></RedefineArg>
        <RedefineArg Name="PatchTracking"><True/></RedefineArg>
        <RedefineArg Name="LowPassWindowLength"><Arg Name="LowPassWindowLen"/></RedefineArg>
        <RedefineArg Name="PeakChlShallowBound"><Arg Name="PeakChlShallowBnd"/></RedefineArg>
        <RedefineArg Name="PeakChlDeepBound"><Arg Name="PeakChlDeepBnd"/></RedefineArg>
        <RedefineArg Name="OffPeakFractionHorizontal"><Arg Name="OffPeakFraction"/></RedefineArg>
    </Insert>

    <Guidance:SetSpeed>
        <Parallel/>
        <Setting><Guidance:SetSpeed.speed/><Arg Name="Speed"/></Setting>
    </Guidance:SetSpeed>

    <Guidance:DepthEnvelope>
        <Parallel/>
        <Setting><Guidance:DepthEnvelope.minDepth/><Arg Name="YoYoMinDepth"/></Setting>
        <Setting><Guidance:DepthEnvelope.maxDepth/><Arg Name="YoYoMaxDepth"/></Setting>
        <Setting><Guidance:DepthEnvelope.downPitch/><Arg Name="YoYoDownPitch"/></Setting>
        <Setting><Guidance:DepthEnvelope.upPitch/><Arg Name="YoYoUpPitch"/></Setting>
    </Guidance:DepthEnvelope>

    <Guidance:YoYo>
        <Parallel/>
        <Setting><Guidance:YoYo.downPitch/><Arg Name="YoYoDownPitch"/></Setting>
        <Setting><Guidance:YoYo.upPitch/><Arg Name="YoYoUpPitch"/></Setting>
    </Guidance:YoYo>

    <Aggregate Id="PatchDetectHorizontal">

        <Sequence Repeat="Repeat"/>

        <Aggregate Id="PatchDetection">

            <When>
                <Arg Name="PatchDetectOn"/>
            </When>

            <Trigger:PeakDetectHorizontal Id="PeakDetectHorizontalTrigger">
                <Sequence/>
<!--debug
                <Break><Arg Name="WpDone"/>
                </Break>
-->
                <Setting><Trigger:PeakDetectHorizontal.patchTracking/><Units:bool/><Value>1</Value></Setting>
                <Setting><Trigger:PeakDetectHorizontal.detectFrom/><Arg Name="Science:PeakChl"/></Setting>
                <Setting><Trigger:PeakDetectHorizontal.depthFrom/><Arg Name="Science:PeakChlDepth"/></Setting>
                <Setting><Trigger:PeakDetectHorizontal.latitudeFrom/><Arg Name="Science:PeakChlLatitude"/></Setting>
                <Setting><Trigger:PeakDetectHorizontal.longitudeFrom/><Arg Name="Science:PeakChlLongitude"/></Setting>
                <Setting><Trigger:PeakDetectHorizontal.beginThreshold/><Arg Name="BeginThreshold"/></Setting>
                <Setting><Trigger:PeakDetectHorizontal.offPeakFraction/><Arg Name="OffPeakFraction"/></Setting>
                <Setting><Trigger:PeakDetectHorizontal.filterWidth/><Arg Name="FilterWidth"/></Setting>
                <Setting><Trigger:PeakDetectHorizontal.centerPeak/><Arg Name="PatchMode"/></Setting>
                <OutputArg Name="PatchChl"><Trigger:PeakDetectHorizontal.peakDetect/></OutputArg>
                <OutputArg Name="PatchChlDepth"><Trigger:PeakDetectHorizontal.peakDepth/></OutputArg>
                <OutputArg Name="PatchChlLatitude"><Trigger:PeakDetectHorizontal.peakLatitude/></OutputArg>
                <OutputArg Name="PatchChlLongitude"><Trigger:PeakDetectHorizontal.peakLongitude/></OutputArg>
                <OutputArg Name="PatchChlDistance"><Trigger:PeakDetectHorizontal.peakDistance/></OutputArg>
            </Trigger:PeakDetectHorizontal>

            <Syslog Severity="Important">Fell below OffPeakFraction. Patch value is <Arg Name="PatchChl"/><Units:microgram_per_liter/> at lat = <Arg Name="PatchChlLatitude"/><Units:degree/>, lon = <Arg Name="PatchChlLongitude"/><Units:degree/>, dep = <Arg Name="PatchChlDepth"/><Units:meter/>, distance = <Arg Name="PatchChlDistance"/><Units:meter/></Syslog>

            <SendData Service="Express"><Arg Name="PatchChl"/><Arg Name="PatchChlDepth"/><Arg Name="PatchChlLatitude"/><Arg Name="PatchChlLongitude"/>
            </SendData>

            <Assign Id="AssignPatchDetectOff"><Sequence/><Arg Name="PatchDetectOn"/><False/></Assign>

        </Aggregate>

        <Assign Id="AssignPatchDetectOn"><Sequence/><Arg Name="PatchDetectOn"/><True/></Assign>

        <Syslog Severity="Important">Next: bearing for CrossLeg: <Arg Name="WpBearing"/><Units:degree/>. WpMaxDistance = <Arg Name="WpMaxDistance"/><Units:meter/>. Current lat, lon = <Universal:latitude/><Units:degree/>, <Universal:longitude/><Units:degree/>.</Syslog>

        <Aggregate Id="CrossLeg">

            <Description>
                This is a long leg across the width of the patch. Also the first
                leg in a mission run. Two waypoints run in parallel: a short run
                to the surfacing point, and a longer run to the edge of the
                patch.
            </Description>

            <Sequence/>

            <Break><Arg Name="WpDone"/>
                <Or><Arg Name="PatchDetectOn"/><Eq><False/></Eq></Or>
            </Break>

            <Guidance:Waypoint Id="CrossSurfaceWp">
                <Sequence/>
                <Timeout Duration="WpTimeout"/>
                <Setting><Guidance:Waypoint.distanceDelta/><Arg Name="PatchChlDistance"/></Setting>
                <Setting><Guidance:Waypoint.distanceDeltaBearing/><Arg Name="WpBearing"/></Setting>
                <Setting><Guidance:Waypoint.waterFrame/><Arg Name="WaterFrame"/></Setting>
            </Guidance:Waypoint>

            <Call RefId="SurfaceComms"/>

            <Guidance:Waypoint Id="CrossPeakWp">
                <Sequence/>
                <Timeout Duration="WpTimeout"/>
                <Setting><Guidance:Waypoint.distanceDelta/><Arg Name="WpMaxDistance"/></Setting>
                <Setting><Guidance:Waypoint.distanceDeltaBearing/><Arg Name="WpBearing"/></Setting>
                <Setting><Guidance:Waypoint.waterFrame/><Arg Name="WaterFrame"/></Setting>
            </Guidance:Waypoint>

<!--debug-->
            <Syslog Severity="Important">CrossPeakWp done. Lat, lon = <Universal:latitude/><Units:degree/>, <Universal:longitude/><Units:degree/>. Patch value is <Arg Name="PatchChl"/><Units:microgram_per_liter/> at lat = <Arg Name="PatchChlLatitude"/><Units:degree/>, lon = <Arg Name="PatchChlLongitude"/><Units:degree/>, dep = <Arg Name="PatchChlDepth"/><Units:meter/>, distance = <Arg Name="PatchChlDistance"/><Units:meter/></Syslog> 

            <Assign Id="AssignPatchDetectOffInCrossLeg"><Sequence/><Arg Name="PatchDetectOn"/><False/></Assign>

            <Assign Id="AssignWpDoneInCrossLeg"><Sequence/><Arg Name="WpDone"/><True/></Assign>

        </Aggregate>

        <Assign Id="AssignWpBearingForInLeg"><Sequence/><Arg Name="WpBearing"/><Arg Name="WpBearing"/><Add><Arg Name="Reverse"/></Add><Mod><Arg Name="TwoPi"/>
        </Mod></Assign>

        <Syslog Severity="Important">Next: bearing for InLeg: <Arg Name="WpBearing"/><Units:degree/>. Current lat, lon = <Universal:latitude/><Units:degree/>, <Universal:longitude/><Units:degree/>. Patch value is <Arg Name="PatchChl"/><Units:microgram_per_liter/> at lat = <Arg Name="PatchChlLatitude"/><Units:degree/>, lon = <Arg Name="PatchChlLongitude"/><Units:degree/>, dep = <Arg Name="PatchChlDepth"/><Units:meter/>, distance = <Arg Name="PatchChlDistance"/><Units:meter/></Syslog> 

        <Guidance:Waypoint Id="InLegWp">
            <Description>
                Simply drive back towards the patch center
            </Description>
            <Sequence/>
            <Timeout Duration="WpTimeout"/>
            <Setting><Guidance:Waypoint.distanceDelta/><Arg Name="PatchChlDistance"/></Setting>
            <Setting><Guidance:Waypoint.distanceDeltaBearing/><Arg Name="WpBearing"/></Setting>
            <Setting><Guidance:Waypoint.waterFrame/><Arg Name="WaterFrame"/></Setting>
        </Guidance:Waypoint>

        <Assign Id="AssignWpBearingForOutLeg"><Sequence/><Arg Name="WpBearing"/><Arg Name="WpBearing"/><Sub><Arg Name="Turn"/></Sub><Mod><Arg Name="TwoPi"/>
        </Mod></Assign>

        <Syslog Severity="Important">Next: bearing for OutLeg: <Arg Name="WpBearing"/><Units:degree/>. WpMaxDistance = <Arg Name="WpMaxDistance"/><Units:meter/>. Current lat, lon = <Universal:latitude/><Units:degree/>, <Universal:longitude/><Units:degree/>. Patch value is <Arg Name="PatchChl"/><Units:microgram_per_liter/> at lat = <Arg Name="PatchChlLatitude"/><Units:degree/>, lon = <Arg Name="PatchChlLongitude"/><Units:degree/>, dep = <Arg Name="PatchChlDepth"/><Units:meter/>, distance = <Arg Name="PatchChlDistance"/><Units:meter/></Syslog>

        <Call RefId="SurfaceCommsSplit"/>

        <Assign Id="AssignPatchDetectOnForOutLeg"><Sequence/><Arg Name="PatchDetectOn"/><True/></Assign>

        <Aggregate Id="OutLeg">

            <Description>
                Drive outward until edge of patch is detected.
            </Description>

            <Sequence/>

            <Break><Arg Name="WpDone"/>
                <Or><Arg Name="PatchDetectOn"/><Eq><False/></Eq></Or>
            </Break>

            <Guidance:Waypoint Id="OutLegWp">
                <Sequence/>
                <Timeout Duration="WpTimeout"/>
                <Setting><Guidance:Waypoint.distanceDelta/><Arg Name="WpMaxDistance"/></Setting>
                <Setting><Guidance:Waypoint.distanceDeltaBearing/><Arg Name="WpBearing"/></Setting>
                <Setting><Guidance:Waypoint.waterFrame/><Arg Name="WaterFrame"/></Setting>
            </Guidance:Waypoint>

            <Assign Id="AssignPatchDetectOffInOutLeg"><Sequence/><Arg Name="PatchDetectOn"/><False/></Assign>

            <Assign Id="AssignWpDoneInOutLeg"><Sequence/><Arg Name="WpDone"/><True/></Assign>

        </Aggregate>

        <Assign Id="AssignWpBearingForCrossLeg"><Sequence/><Arg Name="WpBearing"/><Arg Name="WpBearing"/><Add><Arg Name="Reverse"/></Add><Mod><Arg Name="TwoPi"/>
        </Mod></Assign>

    </Aggregate>

</Mission>


2018-09-24T17:02:50.736Z,1537808570.736 [CommandLine](IMPORTANT): Loaded ./Missions/Science/trackPatch_yz.xml
2018-09-24T17:03:00.351Z,1537808580.351 [CommandLine](IMPORTANT): got command set trackPatch.MissionTimeout 30.000000 minute
2018-09-24T17:03:00.352Z,1537808580.352 [CommandLine](IMPORTANT): got command set trackPatch.YoYoMinDepth 2.000000 meter
2018-09-24T17:03:00.352Z,1537808580.352 [CommandLine](IMPORTANT): got command set trackPatch.YoYoMaxDepth 10.000000 meter
2018-09-24T17:03:00.366Z,1537808580.366 [CommandLine](IMPORTANT): got command set trackPatch.PeakChlShallowBnd 3.000000 meter
2018-09-24T17:03:00.367Z,1537808580.367 [CommandLine](IMPORTANT): got command set trackPatch.PeakChlDeepBnd 8.000000 meter
2018-09-24T17:03:00.367Z,1537808580.367 [CommandLine](IMPORTANT): got command run
2018-09-24T17:03:00.372Z,1537808580.372 [CommandLine](IMPORTANT): Running 
2018-09-24T17:03:00.394Z,1537808580.394 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2018-09-24T17:03:00.394Z,1537808580.394 [RDI_Pathfinder] Communications Fault, FailCount= 1
2018-09-24T17:03:00.394Z,1537808580.394 [RDI_Pathfinder](ERROR): Communications Fault
2018-09-24T17:03:00.572Z,1537808580.572 [Default] Stopped
2018-09-24T17:03:00.572Z,1537808580.572 [Default](DEBUG): Aggregate::uninitialize Default
2018-09-24T17:03:00.572Z,1537808580.572 [Default:B.GoToSurface] Stopped
2018-09-24T17:03:00.572Z,1537808580.572 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-09-24T17:03:00.572Z,1537808580.572 [MissionManager](IMPORTANT): Started mission trackPatch
2018-09-24T17:03:00.572Z,1537808580.572 [trackPatch] Running Loop=1
2018-09-24T17:03:00.573Z,1537808580.573 [trackPatch](DEBUG): Aggregate::initialize trackPatch
2018-09-24T17:03:00.573Z,1537808580.573 [trackPatch:A.AltitudeEnvelope] Running Loop=1
2018-09-24T17:03:00.573Z,1537808580.573 [trackPatch:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2018-09-24T17:03:00.573Z,1537808580.573 [trackPatch:B.DepthEnvelope] Running Loop=1
2018-09-24T17:03:00.574Z,1537808580.574 [trackPatch:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2018-09-24T17:03:00.574Z,1537808580.574 [trackPatch:F.OffshoreEnvelope] Running Loop=1
2018-09-24T17:03:00.574Z,1537808580.574 [trackPatch:F.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2018-09-24T17:03:00.574Z,1537808580.574 [trackPatch:G.WaterDepthEnvelope] Running Loop=1
2018-09-24T17:03:00.574Z,1537808580.574 [trackPatch:G.WaterDepthEnvelope](DEBUG): Initialize WaterDepthEnvelopeComponent.
2018-09-24T17:03:00.574Z,1537808580.574 [trackPatch:H.Pitch] Running Loop=1
2018-09-24T17:03:00.574Z,1537808580.574 [trackPatch:H.Pitch](DEBUG): Initialize.
2018-09-24T17:03:00.574Z,1537808580.574 [trackPatch:I.Buoyancy] Running Loop=1
2018-09-24T17:03:00.575Z,1537808580.575 [trackPatch:I.Buoyancy](DEBUG): Initialize Buoyancy Component.
2018-09-24T17:03:00.575Z,1537808580.575 [trackPatch:Science] Running Loop=1
2018-09-24T17:03:00.575Z,1537808580.575 [trackPatch:Science](DEBUG): Aggregate::initialize trackPatch:Science
2018-09-24T17:03:00.575Z,1537808580.575 [trackPatch:Science:A] Running Loop=1
2018-09-24T17:03:00.575Z,1537808580.575 [trackPatch:Science:B] Running Loop=1
2018-09-24T17:03:00.575Z,1537808580.575 [trackPatch:Science:C] Running Loop=1
2018-09-24T17:03:00.575Z,1537808580.575 [trackPatch:Science:D] Running Loop=1
2018-09-24T17:03:00.575Z,1537808580.575 [trackPatch:Science:E] Running Loop=1
2018-09-24T17:03:00.575Z,1537808580.575 [trackPatch:Science:F] Running Loop=1
2018-09-24T17:03:00.575Z,1537808580.575 [trackPatch:Science:G] Running Loop=1
2018-09-24T17:03:00.575Z,1537808580.575 [trackPatch:Science:Read_Oil] Running Loop=1
2018-09-24T17:03:00.576Z,1537808580.576 [trackPatch:Science:HighestChlPeakReport] Running Loop=1
2018-09-24T17:03:00.576Z,1537808580.576 [trackPatch:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize trackPatch:Science:HighestChlPeakReport
2018-09-24T17:03:00.576Z,1537808580.576 [trackPatch:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2018-09-24T17:03:00.576Z,1537808580.576 [trackPatch:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2018-09-24T17:03:00.577Z,1537808580.577 [trackPatch:Science:PeakDetectNO3] Running Loop=1
2018-09-24T17:03:00.577Z,1537808580.577 [trackPatch:Science:PeakDetectNO3](DEBUG): Aggregate::initialize trackPatch:Science:PeakDetectNO3
2018-09-24T17:03:00.577Z,1537808580.577 [trackPatch:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2018-09-24T17:03:00.577Z,1537808580.577 [trackPatch:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2018-09-24T17:03:00.579Z,1537808580.579 [trackPatch:Science:PeakDetectOil] Running Loop=1
2018-09-24T17:03:00.579Z,1537808580.579 [trackPatch:Science:PeakDetectOil](DEBUG): Aggregate::initialize trackPatch:Science:PeakDetectOil
2018-09-24T17:03:00.580Z,1537808580.580 [trackPatch:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2018-09-24T17:03:00.580Z,1537808580.580 [trackPatch:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2018-09-24T17:03:00.581Z,1537808580.581 [trackPatch:Science:PeakDetectChl] Running Loop=1
2018-09-24T17:03:00.582Z,1537808580.582 [trackPatch:Science:PeakDetectChl](DEBUG): Aggregate::initialize trackPatch:Science:PeakDetectChl
2018-09-24T17:03:00.582Z,1537808580.582 [trackPatch:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2018-09-24T17:03:00.582Z,1537808580.582 [trackPatch:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2018-09-24T17:03:00.583Z,1537808580.583 [trackPatch:K.SetSpeed] Running Loop=1
2018-09-24T17:03:00.583Z,1537808580.583 [trackPatch:K.SetSpeed](DEBUG): Initialize.
2018-09-24T17:03:00.583Z,1537808580.583 [trackPatch:L.DepthEnvelope] Running Loop=1
2018-09-24T17:03:00.584Z,1537808580.584 [trackPatch:L.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2018-09-24T17:03:00.584Z,1537808580.584 [trackPatch:M.YoYo] Running Loop=1
2018-09-24T17:03:00.584Z,1537808580.584 [trackPatch:M.YoYo](DEBUG): Initialize YoYoComponent.
2018-09-24T17:03:00.584Z,1537808580.584 [trackPatch:SurfaceCommsSplit] Running Loop=1
2018-09-24T17:03:00.584Z,1537808580.584 [trackPatch:SurfaceCommsSplit](DEBUG): Aggregate::initialize trackPatch:SurfaceCommsSplit
2018-09-24T17:03:00.585Z,1537808580.585 [trackPatch:SurfaceCommsSplit:A.GoToSurface] Running Loop=1
2018-09-24T17:03:00.585Z,1537808580.585 [trackPatch:SurfaceCommsSplit:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-09-24T17:03:00.585Z,1537808580.585 [trackPatch:SurfaceCommsSplit:A.GoToSurface](INFO): Received depth rate setting nan m/s.
2018-09-24T17:03:00.586Z,1537808580.586 [trackPatch:SurfaceCommsSplit:A.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2018-09-24T17:03:00.586Z,1537808580.586 [trackPatch:SurfaceCommsSplit:A.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2018-09-24T17:03:00.586Z,1537808580.586 [trackPatch:SurfaceCommsSplit:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-09-24T17:03:00.587Z,1537808580.587 [trackPatch:SurfaceCommsSplit:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-09-24T17:03:00.588Z,1537808580.588 [trackPatch:M.YoYo] Running Loop=1
2018-09-24T17:03:00.593Z,1537808580.593 [trackPatch:L.DepthEnvelope] Running Loop=1
2018-09-24T17:03:00.599Z,1537808580.599 [trackPatch:K.SetSpeed] Running Loop=1
2018-09-24T17:03:00.604Z,1537808580.604 [trackPatch:Science] Running Loop=1
2018-09-24T17:03:00.640Z,1537808580.640 [trackPatch:Science:PeakDetectOil] Stopped
2018-09-24T17:03:00.641Z,1537808580.641 [trackPatch:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize trackPatch:Science:PeakDetectOil
2018-09-24T17:03:00.649Z,1537808580.649 [trackPatch:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2018-09-24T17:03:00.649Z,1537808580.649 [trackPatch:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2018-09-24T17:03:00.649Z,1537808580.649 [trackPatch:Science:PeakDetectNO3] Stopped
2018-09-24T17:03:00.650Z,1537808580.650 [trackPatch:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize trackPatch:Science:PeakDetectNO3
2018-09-24T17:03:00.650Z,1537808580.650 [trackPatch:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2018-09-24T17:03:00.650Z,1537808580.650 [trackPatch:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2018-09-24T17:03:00.650Z,1537808580.650 [trackPatch:Science:HighestChlPeakReport] Stopped
2018-09-24T17:03:00.651Z,1537808580.651 [trackPatch:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize trackPatch:Science:HighestChlPeakReport
2018-09-24T17:03:00.651Z,1537808580.651 [trackPatch:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2018-09-24T17:03:00.651Z,1537808580.651 [trackPatch:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2018-09-24T17:03:00.668Z,1537808580.668 [trackPatch:Science:Read_Oil] Running Loop=1
2018-09-24T17:03:00.672Z,1537808580.672 [trackPatch:Science:Read_Oil](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2018-09-24T17:03:00.686Z,1537808580.686 [trackPatch:Science:G] Running Loop=1
2018-09-24T17:03:00.687Z,1537808580.687 [trackPatch:Science:G](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2018-09-24T17:03:00.688Z,1537808580.688 [trackPatch:Science:F] Stopped
2018-09-24T17:03:00.689Z,1537808580.689 [trackPatch:Science:E] Stopped
2018-09-24T17:03:00.689Z,1537808580.689 [trackPatch:Science:D] Stopped
2018-09-24T17:03:00.689Z,1537808580.689 [trackPatch:Science:C] Stopped
2018-09-24T17:03:00.689Z,1537808580.689 [trackPatch:Science:B] Stopped
2018-09-24T17:03:00.689Z,1537808580.689 [trackPatch:Science:A] Stopped
2018-09-24T17:03:00.689Z,1537808580.689 [trackPatch:I.Buoyancy] Running Loop=1
2018-09-24T17:03:00.696Z,1537808580.696 [trackPatch:H.Pitch] Running Loop=1
2018-09-24T17:03:00.709Z,1537808580.709 [trackPatch:G.WaterDepthEnvelope] Running Loop=1
2018-09-24T17:03:00.710Z,1537808580.710 [trackPatch:G.WaterDepthEnvelope](ERROR): Location Measurement is not Active.
2018-09-24T17:03:00.724Z,1537808580.724 [trackPatch:F.OffshoreEnvelope] Running Loop=1
2018-09-24T17:03:00.724Z,1537808580.724 [trackPatch:F.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2018-09-24T17:03:00.725Z,1537808580.725 [WetLabsSeaOWL_UV_A](INFO): Opening uart, block timeout 10ths=4
2018-09-24T17:03:00.726Z,1537808580.726 [WetLabsSeaOWL_UV_A](INFO): Powering up
2018-09-24T17:03:00.741Z,1537808580.741 [trackPatch:NeedComms] Running Loop=1
2018-09-24T17:03:00.741Z,1537808580.741 [trackPatch:NeedComms](DEBUG): Aggregate::initialize trackPatch:NeedComms
2018-09-24T17:03:00.741Z,1537808580.741 [trackPatch:NeedComms:A] Running Loop=1
2018-09-24T17:03:00.741Z,1537808580.741 [trackPatch:NeedComms:A](IMPORTANT): NeedComms Timeout Surfacing
2018-09-24T17:03:00.743Z,1537808580.743 [trackPatch:NeedComms:A] Stopped
2018-09-24T17:03:00.744Z,1537808580.744 [trackPatch:NeedComms:B] Running Loop=1
2018-09-24T17:03:00.744Z,1537808580.744 [trackPatch:NeedComms:B](DEBUG): Aggregate::initialize trackPatch:NeedComms:B
2018-09-24T17:03:00.768Z,1537808580.768 [trackPatch:SurfaceCommsSplit:B] Running Loop=1
2018-09-24T17:03:00.768Z,1537808580.768 [trackPatch:SurfaceCommsSplit:B](DEBUG): Aggregate::initialize trackPatch:SurfaceCommsSplit:B
2018-09-24T17:03:00.768Z,1537808580.768 [trackPatch:SurfaceCommsSplit:B:A] Running Loop=1
2018-09-24T17:03:00.770Z,1537808580.770 [trackPatch:B.DepthEnvelope] Running Loop=1
2018-09-24T17:03:00.784Z,1537808580.784 [trackPatch:A.AltitudeEnvelope] Running Loop=1
2018-09-24T17:03:00.817Z,1537808580.817 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2018-09-24T17:03:00.957Z,1537808580.957 [RDI_Pathfinder](INFO): Powering down
2018-09-24T17:03:01.002Z,1537808581.002 [trackPatch:G.WaterDepthEnvelope](ERROR): Location Measurement is not Active.
2018-09-24T17:03:01.002Z,1537808581.002 [trackPatch:F.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2018-09-24T17:03:01.003Z,1537808581.003 [trackPatch:SurfaceComms] Running Loop=1
2018-09-24T17:03:01.003Z,1537808581.003 [trackPatch:SurfaceComms](DEBUG): Aggregate::initialize trackPatch:SurfaceComms
2018-09-24T17:03:01.003Z,1537808581.003 [trackPatch:SurfaceComms:SurfaceComms] Running Loop=1
2018-09-24T17:03:01.003Z,1537808581.003 [trackPatch:SurfaceComms:SurfaceComms](DEBUG): Aggregate::initialize trackPatch:SurfaceComms:SurfaceComms
2018-09-24T17:03:01.003Z,1537808581.003 [trackPatch:SurfaceComms:SurfaceComms:A.GoToSurface] Running Loop=1
2018-09-24T17:03:01.003Z,1537808581.003 [trackPatch:SurfaceComms:SurfaceComms:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-09-24T17:03:01.004Z,1537808581.004 [trackPatch:SurfaceComms:SurfaceComms:A.GoToSurface](INFO): Received depth rate setting nan m/s.
2018-09-24T17:03:01.004Z,1537808581.004 [trackPatch:SurfaceComms:SurfaceComms:A.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2018-09-24T17:03:01.005Z,1537808581.005 [trackPatch:SurfaceComms:SurfaceComms:A.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2018-09-24T17:03:01.005Z,1537808581.005 [trackPatch:SurfaceComms:SurfaceComms:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-09-24T17:03:01.005Z,1537808581.005 [trackPatch:SurfaceComms:SurfaceComms:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-09-24T17:03:01.027Z,1537808581.027 [trackPatch:SurfaceComms:SurfaceComms:B] Running Loop=1
2018-09-24T17:03:01.027Z,1537808581.027 [trackPatch:SurfaceComms:SurfaceComms:B](DEBUG): Aggregate::initialize trackPatch:SurfaceComms:SurfaceComms:B
2018-09-24T17:03:01.027Z,1537808581.027 [trackPatch:SurfaceComms:SurfaceComms:B:A] Running Loop=1
2018-09-24T17:03:01.028Z,1537808581.028 [trackPatch:SurfaceCommsSplit:B:A](INFO): ##UnpackSplit##
2018-09-24T17:03:01.029Z,1537808581.029 [trackPatch:SurfaceCommsSplit:B:A] Stopped
2018-09-24T17:03:01.029Z,1537808581.029 [trackPatch:SurfaceCommsSplit:B](INFO): Completed trackPatch:SurfaceCommsSplit:B
2018-09-24T17:03:01.030Z,1537808581.030 [trackPatch:SurfaceCommsSplit:B] Stopped
2018-09-24T17:03:01.030Z,1537808581.030 [trackPatch:SurfaceCommsSplit:B](DEBUG): Aggregate::uninitialize trackPatch:SurfaceCommsSplit:B
2018-09-24T17:03:01.030Z,1537808581.030 [trackPatch:SurfaceCommsSplit:C] Running Loop=1
2018-09-24T17:03:01.030Z,1537808581.030 [trackPatch:SurfaceCommsSplit:C](DEBUG): Aggregate::initialize trackPatch:SurfaceCommsSplit:C
2018-09-24T17:03:01.030Z,1537808581.030 [trackPatch:SurfaceCommsSplit:C:A] Running Loop=1
2018-09-24T17:03:01.317Z,1537808581.317 [trackPatch:M.YoYo] Preempted
2018-09-24T17:03:01.317Z,1537808581.317 [trackPatch:L.DepthEnvelope] Preempted
2018-09-24T17:03:01.317Z,1537808581.317 [trackPatch:K.SetSpeed] Preempted
2018-09-24T17:03:01.317Z,1537808581.317 [trackPatch:Science] Preempted
2018-09-24T17:03:01.317Z,1537808581.317 [trackPatch:Science:G] Preempted
2018-09-24T17:03:01.317Z,1537808581.317 [trackPatch:Science:Read_Oil] Preempted
2018-09-24T17:03:01.317Z,1537808581.317 [trackPatch:I.Buoyancy] Preempted
2018-09-24T17:03:01.317Z,1537808581.317 [trackPatch:H.Pitch] Preempted
2018-09-24T17:03:01.317Z,1537808581.317 [trackPatch:G.WaterDepthEnvelope] Preempted
2018-09-24T17:03:01.317Z,1537808581.317 [trackPatch:F.OffshoreEnvelope] Preempted
2018-09-24T17:03:01.319Z,1537808581.319 [trackPatch:SurfaceCommsSplit:C:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-09-24T17:03:01.757Z,1537808581.757 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2018-09-24T17:03:01.757Z,1537808581.757 [RDI_Pathfinder] No Fault, FailCount= 1
2018-09-24T17:03:02.897Z,1537808582.897 [WetLabsSeaOWL_UV_A](INFO): Powering down
2018-09-24T17:03:09.648Z,1537808589.648 [NAL9602](INFO): GPS fix at 20180924T170300: (36.845625, -121.916728)
2018-09-24T17:03:09.711Z,1537808589.711 [trackPatch:SurfaceCommsSplit:C:A] Stopped
2018-09-24T17:03:09.711Z,1537808589.711 [trackPatch:SurfaceCommsSplit:C:B] Running Loop=1
2018-09-24T17:03:10.088Z,1537808590.088 [trackPatch:SurfaceCommsSplit:C:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-09-24T17:03:14.608Z,1537808594.608 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20180924T165907/Courier0004.lzma
2018-09-24T17:03:14.998Z,1537808594.998 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2018-09-24T17:03:15.337Z,1537808595.337 [DataOverHttps](INFO): Moved sent file to Logs/20180924T165907/Courier0004.lzma.bak
2018-09-24T17:03:15.337Z,1537808595.337 [DataOverHttps](INFO): SBD MOMSN=8574112
2018-09-24T17:03:25.498Z,1537808605.498 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180924T165907/Courier0007.lzma
2018-09-24T17:03:26.271Z,1537808606.271 [DataOverHttps](INFO): Moved sent file to Logs/20180924T165907/Courier0007.lzma.bak
2018-09-24T17:03:26.271Z,1537808606.271 [DataOverHttps](INFO): SBD MOMSN=8574118
2018-09-24T17:03:36.981Z,1537808616.981 [DataOverHttps](INFO): Sending 1176 bytes from file Logs/20180924T165907/Express0001.lzma
2018-09-24T17:03:37.726Z,1537808617.726 [DataOverHttps](INFO): Moved sent file to Logs/20180924T165907/Express0001.lzma.bak
2018-09-24T17:03:37.726Z,1537808617.726 [DataOverHttps](INFO): SBD MOMSN=8574120
2018-09-24T17:03:46.743Z,1537808626.743 [NAL9602](INFO): Powering down
2018-09-24T17:03:47.026Z,1537808627.026 [DataOverHttps](INFO): Sending 523 bytes from file Logs/20180924T165907/Express0005.lzma
2018-09-24T17:03:47.805Z,1537808627.805 [DataOverHttps](INFO): Moved sent file to Logs/20180924T165907/Express0005.lzma.bak
2018-09-24T17:03:47.805Z,1537808627.805 [DataOverHttps](INFO): SBD MOMSN=8574152
2018-09-24T17:03:56.880Z,1537808636.880 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180924T165907/Express0008.lzma
2018-09-24T17:03:57.661Z,1537808637.661 [DataOverHttps](INFO): Moved sent file to Logs/20180924T165907/Express0008.lzma.bak
2018-09-24T17:03:57.661Z,1537808637.661 [DataOverHttps](INFO): SBD MOMSN=8574175
2018-09-24T17:03:58.222Z,1537808638.222 [trackPatch:SurfaceCommsSplit:C:B] Stopped
2018-09-24T17:03:58.222Z,1537808638.222 [trackPatch:SurfaceCommsSplit:C:C] Running Loop=1
2018-09-24T17:03:58.518Z,1537808638.518 [trackPatch:SurfaceCommsSplit:C:C](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-09-24T17:04:01.688Z,1537808641.688 [NAL9602](INFO): Powering up
2018-09-24T17:04:12.746Z,1537808652.746 [NAL9602](INFO): NAL9602 initialized
2018-09-24T17:04:33.140Z,1537808673.140 [NAL9602](INFO): SBD MO Status=0, MOMSN=1537, MT Status=0, MTMSN=0
2018-09-24T17:04:33.140Z,1537808673.140 [NAL9602](INFO): No messages in MT queue
2018-09-24T17:06:20.397Z,1537808780.397 [RDI_Pathfinder](ERROR): only read 3 of 5 data items
2018-09-24T17:06:20.397Z,1537808780.397 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-3268,-32768,-32768,V
2018-09-24T17:06:40.005Z,1537808800.005 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2018-09-24T17:06:40.005Z,1537808800.005 [RDI_Pathfinder](ERROR): Failed to parse:
:BD,        +0.00,        +0.   +0.00,   0.00,205.00
2018-09-24T17:06:49.216Z,1537808809.216 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2018-09-24T17:07:34.532Z,1537808854.532 [NAL9602](INFO): GPS fix at 20180924T170725: (36.845794, -121.916783)
2018-09-24T17:07:34.605Z,1537808854.605 [trackPatch:SurfaceCommsSplit:C:C] Stopped
2018-09-24T17:07:34.606Z,1537808854.606 [trackPatch:SurfaceCommsSplit:C](INFO): Completed trackPatch:SurfaceCommsSplit:C
2018-09-24T17:07:34.606Z,1537808854.606 [trackPatch:SurfaceCommsSplit:C] Stopped
2018-09-24T17:07:34.606Z,1537808854.606 [trackPatch:SurfaceCommsSplit:C](DEBUG): Aggregate::uninitialize trackPatch:SurfaceCommsSplit:C
2018-09-24T17:07:34.607Z,1537808854.607 [trackPatch:SurfaceCommsSplit](INFO): Completed trackPatch:SurfaceCommsSplit
2018-09-24T17:07:34.607Z,1537808854.607 [trackPatch:SurfaceCommsSplit] Stopped
2018-09-24T17:07:34.607Z,1537808854.607 [trackPatch:SurfaceCommsSplit](DEBUG): Aggregate::uninitialize trackPatch:SurfaceCommsSplit
2018-09-24T17:07:34.607Z,1537808854.607 [trackPatch:SurfaceCommsSplit:A.GoToSurface] Stopped
2018-09-24T17:07:34.607Z,1537808854.607 [trackPatch:SurfaceCommsSplit:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-09-24T17:07:34.608Z,1537808854.608 [trackPatch:PatchDetectHorizontal] Running Loop=1
2018-09-24T17:07:34.608Z,1537808854.608 [trackPatch:PatchDetectHorizontal](DEBUG): Aggregate::initialize trackPatch:PatchDetectHorizontal
2018-09-24T17:07:34.608Z,1537808854.608 [trackPatch:PatchDetectHorizontal:AssignPatchDetectOn] Running Loop=1
2018-09-24T17:07:35.007Z,1537808855.007 [trackPatch:PatchDetectHorizontal:AssignPatchDetectOn] Stopped
2018-09-24T17:07:35.007Z,1537808855.007 [trackPatch:PatchDetectHorizontal:C] Running Loop=1
2018-09-24T17:07:35.007Z,1537808855.007 [trackPatch:M.YoYo] Running Loop=1
2018-09-24T17:07:35.007Z,1537808855.007 [trackPatch:L.DepthEnvelope] Running Loop=1
2018-09-24T17:07:35.008Z,1537808855.008 [trackPatch:K.SetSpeed] Running Loop=1
2018-09-24T17:07:35.013Z,1537808855.013 [trackPatch:Science] Running Loop=1
2018-09-24T17:07:35.015Z,1537808855.015 [trackPatch:Science:Read_Oil] Running Loop=1
2018-09-24T17:07:35.015Z,1537808855.015 [trackPatch:Science:G] Running Loop=1
2018-09-24T17:07:35.015Z,1537808855.015 [trackPatch:I.Buoyancy] Running Loop=1
2018-09-24T17:07:35.016Z,1537808855.016 [trackPatch:H.Pitch] Running Loop=1
2018-09-24T17:07:35.016Z,1537808855.016 [trackPatch:G.WaterDepthEnvelope] Running Loop=1
2018-09-24T17:07:35.018Z,1537808855.018 [trackPatch:F.OffshoreEnvelope] Running Loop=1
2018-09-24T17:07:35.019Z,1537808855.019 [trackPatch:SurfaceComms:SurfaceComms:B] Stopped
2018-09-24T17:07:35.019Z,1537808855.019 [trackPatch:SurfaceComms:SurfaceComms:B](DEBUG): Aggregate::uninitialize trackPatch:SurfaceComms:SurfaceComms:B
2018-09-24T17:07:35.019Z,1537808855.019 [trackPatch:SurfaceComms:SurfaceComms:B:A] Stopped
2018-09-24T17:07:35.019Z,1537808855.019 [trackPatch:SurfaceComms:SurfaceComms:C] Running Loop=1
2018-09-24T17:07:35.019Z,1537808855.019 [trackPatch:SurfaceComms:SurfaceComms:C](DEBUG): Aggregate::initialize trackPatch:SurfaceComms:SurfaceComms:C
2018-09-24T17:07:35.020Z,1537808855.020 [trackPatch:SurfaceComms:SurfaceComms:C:A] Running Loop=1
2018-09-24T17:07:35.338Z,1537808855.338 [WetLabsSeaOWL_UV_A](INFO): Opening uart, block timeout 10ths=4
2018-09-24T17:07:35.338Z,1537808855.338 [WetLabsSeaOWL_UV_A](INFO): Powering up
2018-09-24T17:07:35.386Z,1537808855.386 [trackPatch:M.YoYo] Preempted
2018-09-24T17:07:35.386Z,1537808855.386 [trackPatch:L.DepthEnvelope] Preempted
2018-09-24T17:07:35.386Z,1537808855.386 [trackPatch:K.SetSpeed] Preempted
2018-09-24T17:07:35.386Z,1537808855.386 [trackPatch:Science] Preempted
2018-09-24T17:07:35.387Z,1537808855.387 [trackPatch:Science:G] Preempted
2018-09-24T17:07:35.387Z,1537808855.387 [trackPatch:Science:Read_Oil] Preempted
2018-09-24T17:07:35.387Z,1537808855.387 [trackPatch:I.Buoyancy] Preempted
2018-09-24T17:07:35.387Z,1537808855.387 [trackPatch:H.Pitch] Preempted
2018-09-24T17:07:35.387Z,1537808855.387 [trackPatch:G.WaterDepthEnvelope] Preempted
2018-09-24T17:07:35.387Z,1537808855.387 [trackPatch:F.OffshoreEnvelope] Preempted
2018-09-24T17:07:35.388Z,1537808855.388 [trackPatch:SurfaceComms:SurfaceComms:C:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-09-24T17:07:37.501Z,1537808857.501 [WetLabsSeaOWL_UV_A](INFO): Powering down
2018-09-24T17:07:37.731Z,1537808857.731 [NAL9602](INFO): GPS fix at 20180924T170728: (36.845817, -121.916793)
2018-09-24T17:07:37.801Z,1537808857.801 [trackPatch:SurfaceComms:SurfaceComms:C:A] Stopped
2018-09-24T17:07:37.802Z,1537808857.802 [trackPatch:SurfaceComms:SurfaceComms:C:B] Running Loop=1
2018-09-24T17:07:38.196Z,1537808858.196 [trackPatch:SurfaceComms:SurfaceComms:C:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-09-24T17:07:42.348Z,1537808862.348 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20180924T165907/Courier0010.lzma
2018-09-24T17:07:43.100Z,1537808863.100 [DataOverHttps](INFO): Moved sent file to Logs/20180924T165907/Courier0010.lzma.bak
2018-09-24T17:07:43.100Z,1537808863.100 [DataOverHttps](INFO): SBD MOMSN=8574217
2018-09-24T17:07:52.227Z,1537808872.227 [DataOverHttps](INFO): Sending 90 bytes from file Logs/20180924T165907/Express0011.lzma
2018-09-24T17:07:52.000Z,1537808873.000 [DataOverHttps](INFO): Moved sent file to Logs/20180924T165907/Express0011.lzma.bak
2018-09-24T17:07:53.000Z,1537808873.000 [DataOverHttps](INFO): SBD MOMSN=8574220
2018-09-24T17:07:53.528Z,1537808873.528 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-32768,-32768,-32768,V
2018-09-24T17:07:53.542Z,1537808873.542 [trackPatch:SurfaceComms:SurfaceComms:C:B] Stopped
2018-09-24T17:07:53.542Z,1537808873.542 [trackPatch:SurfaceComms:SurfaceComms:C:C] Running Loop=1
2018-09-24T17:07:53.850Z,1537808873.850 [trackPatch:SurfaceComms:SurfaceComms:C:C](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-09-24T17:07:57.993Z,1537808877.993 [NAL9602](INFO): GPS fix at 20180924T170748: (36.845816, -121.916826)
2018-09-24T17:07:58.103Z,1537808878.103 [trackPatch:SurfaceComms:SurfaceComms:C:C] Stopped
2018-09-24T17:07:58.103Z,1537808878.103 [trackPatch:SurfaceComms:SurfaceComms:C](INFO): Completed trackPatch:SurfaceComms:SurfaceComms:C
2018-09-24T17:07:58.104Z,1537808878.104 [trackPatch:SurfaceComms:SurfaceComms:C] Stopped
2018-09-24T17:07:58.104Z,1537808878.104 [trackPatch:SurfaceComms:SurfaceComms:C](DEBUG): Aggregate::uninitialize trackPatch:SurfaceComms:SurfaceComms:C
2018-09-24T17:07:58.121Z,1537808878.121 [trackPatch:SurfaceComms:SurfaceComms](INFO): Completed trackPatch:SurfaceComms:SurfaceComms
2018-09-24T17:07:58.121Z,1537808878.121 [trackPatch:SurfaceComms:SurfaceComms] Stopped
2018-09-24T17:07:58.121Z,1537808878.121 [trackPatch:SurfaceComms:SurfaceComms](DEBUG): Aggregate::uninitialize trackPatch:SurfaceComms:SurfaceComms
2018-09-24T17:07:58.121Z,1537808878.121 [trackPatch:SurfaceComms:SurfaceComms:A.GoToSurface] Stopped
2018-09-24T17:07:58.121Z,1537808878.121 [trackPatch:SurfaceComms:SurfaceComms:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-09-24T17:07:58.121Z,1537808878.121 [trackPatch:SurfaceComms](INFO): Completed trackPatch:SurfaceComms
2018-09-24T17:07:58.121Z,1537808878.121 [trackPatch:SurfaceComms] Stopped
2018-09-24T17:07:58.122Z,1537808878.122 [trackPatch:SurfaceComms](DEBUG): Aggregate::uninitialize trackPatch:SurfaceComms
2018-09-24T17:07:58.447Z,1537808878.447 [trackPatch:PatchDetectHorizontal:C](IMPORTANT): Next: bearing for CrossLeg: -90.000000 arcdeg . WpMaxDistance = 1000.000000 m . Current lat, lon = 36.845816 arcdeg , -121.916826 arcdeg .
2018-09-24T17:07:58.448Z,1537808878.448 [trackPatch:PatchDetectHorizontal:C] Stopped
2018-09-24T17:07:58.448Z,1537808878.448 [trackPatch:PatchDetectHorizontal:CrossLeg] Running Loop=1
2018-09-24T17:07:58.448Z,1537808878.448 [trackPatch:PatchDetectHorizontal:CrossLeg](DEBUG): Aggregate::initialize trackPatch:PatchDetectHorizontal:CrossLeg
2018-09-24T17:07:58.448Z,1537808878.448 [trackPatch:PatchDetectHorizontal:CrossLeg:CrossSurfaceWp.Waypoint] Running Loop=1
2018-09-24T17:07:58.449Z,1537808878.449 [trackPatch:PatchDetectHorizontal:CrossLeg:CrossSurfaceWp.Waypoint](DEBUG): Initialize WaypointComponent.
2018-09-24T17:07:58.454Z,1537808878.454 [trackPatch:PatchDetectHorizontal:PatchDetection] Running Loop=1
2018-09-24T17:07:58.454Z,1537808878.454 [trackPatch:PatchDetectHorizontal:PatchDetection](DEBUG): Aggregate::initialize trackPatch:PatchDetectHorizontal:PatchDetection
2018-09-24T17:07:58.454Z,1537808878.454 [trackPatch:PatchDetectHorizontal:PatchDetection:PeakDetectHorizontalTrigger.PeakDetectHorizontal] Running Loop=1
2018-09-24T17:07:58.454Z,1537808878.454 [trackPatch:PatchDetectHorizontal:PatchDetection:PeakDetectHorizontalTrigger.PeakDetectHorizontal](INFO): Initialize.
2018-09-24T17:07:58.464Z,1537808878.464 [trackPatch:M.YoYo] Running Loop=1
2018-09-24T17:07:58.469Z,1537808878.469 [trackPatch:L.DepthEnvelope] Running Loop=1
2018-09-24T17:07:58.472Z,1537808878.472 [trackPatch:K.SetSpeed] Running Loop=1
2018-09-24T17:07:58.475Z,1537808878.475 [trackPatch:Science] Running Loop=1
2018-09-24T17:07:58.486Z,1537808878.486 [trackPatch:Science:Read_Oil] Running Loop=1
2018-09-24T17:07:58.486Z,1537808878.486 [trackPatch:Science:G] Running Loop=1
2018-09-24T17:07:58.486Z,1537808878.486 [trackPatch:I.Buoyancy] Running Loop=1
2018-09-24T17:07:58.487Z,1537808878.487 [trackPatch:H.Pitch] Running Loop=1
2018-09-24T17:07:58.487Z,1537808878.487 [trackPatch:G.WaterDepthEnvelope] Running Loop=1
2018-09-24T17:07:58.487Z,1537808878.487 [trackPatch:F.OffshoreEnvelope] Running Loop=1
2018-09-24T17:07:58.488Z,1537808878.488 [trackPatch:NeedComms:B](INFO): Completed trackPatch:NeedComms:B
2018-09-24T17:07:58.488Z,1537808878.488 [trackPatch:NeedComms:B] Stopped
2018-09-24T17:07:58.488Z,1537808878.488 [trackPatch:NeedComms:B](DEBUG): Aggregate::uninitialize trackPatch:NeedComms:B
2018-09-24T17:07:58.488Z,1537808878.488 [trackPatch:NeedComms](INFO): Completed trackPatch:NeedComms
2018-09-24T17:07:58.488Z,1537808878.488 [trackPatch:NeedComms] Stopped
2018-09-24T17:07:58.497Z,1537808878.497 [trackPatch:NeedComms](DEBUG): Aggregate::uninitialize trackPatch:NeedComms
2018-09-24T17:07:58.515Z,1537808878.515 [WetLabsSeaOWL_UV_A](INFO): Opening uart, block timeout 10ths=4
2018-09-24T17:07:58.515Z,1537808878.515 [WetLabsSeaOWL_UV_A](INFO): Powering up
2018-09-24T17:07:58.854Z,1537808878.854 [trackPatch:PatchDetectHorizontal:CrossLeg:CrossSurfaceWp.Waypoint] Stopped
2018-09-24T17:07:58.854Z,1537808878.854 [trackPatch:PatchDetectHorizontal:CrossLeg:CrossSurfaceWp.Waypoint](DEBUG): Uninitialize WaypointComponent.
2018-09-24T17:07:58.854Z,1537808878.854 [trackPatch:PatchDetectHorizontal:CrossLeg:B] Running Loop=1
2018-09-24T17:07:58.854Z,1537808878.854 [trackPatch:PatchDetectHorizontal:CrossLeg:B](DEBUG): Aggregate::initialize trackPatch:PatchDetectHorizontal:CrossLeg:B
2018-09-24T17:07:59.287Z,1537808879.287 [trackPatch:SurfaceComms] Running Loop=1
2018-09-24T17:07:59.287Z,1537808879.287 [trackPatch:SurfaceComms](DEBUG): Aggregate::initialize trackPatch:SurfaceComms
2018-09-24T17:07:59.287Z,1537808879.287 [trackPatch:SurfaceComms:SurfaceComms] Running Loop=1
2018-09-24T17:07:59.287Z,1537808879.287 [trackPatch:SurfaceComms:SurfaceComms](DEBUG): Aggregate::initialize trackPatch:SurfaceComms:SurfaceComms
2018-09-24T17:07:59.287Z,1537808879.287 [trackPatch:SurfaceComms:SurfaceComms:A.GoToSurface] Running Loop=1
2018-09-24T17:07:59.287Z,1537808879.287 [trackPatch:SurfaceComms:SurfaceComms:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-09-24T17:07:59.288Z,1537808879.288 [trackPatch:SurfaceComms:SurfaceComms:A.GoToSurface](INFO): Received depth rate setting nan m/s.
2018-09-24T17:07:59.288Z,1537808879.288 [trackPatch:SurfaceComms:SurfaceComms:A.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2018-09-24T17:07:59.288Z,1537808879.288 [trackPatch:SurfaceComms:SurfaceComms:A.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2018-09-24T17:07:59.293Z,1537808879.293 [trackPatch:SurfaceComms:SurfaceComms:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-09-24T17:07:59.293Z,1537808879.293 [trackPatch:SurfaceComms:SurfaceComms:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-09-24T17:07:59.295Z,1537808879.295 [trackPatch:SurfaceComms:SurfaceComms:B] Running Loop=1
2018-09-24T17:07:59.295Z,1537808879.295 [trackPatch:SurfaceComms:SurfaceComms:B](DEBUG): Aggregate::initialize trackPatch:SurfaceComms:SurfaceComms:B
2018-09-24T17:07:59.295Z,1537808879.295 [trackPatch:SurfaceComms:SurfaceComms:B:A] Running Loop=1
2018-09-24T17:07:59.658Z,1537808879.658 [trackPatch:SurfaceComms:SurfaceComms:B] Stopped
2018-09-24T17:07:59.658Z,1537808879.658 [trackPatch:SurfaceComms:SurfaceComms:B](DEBUG): Aggregate::uninitialize trackPatch:SurfaceComms:SurfaceComms:B
2018-09-24T17:07:59.658Z,1537808879.658 [trackPatch:SurfaceComms:SurfaceComms:B:A] Stopped
2018-09-24T17:07:59.658Z,1537808879.658 [trackPatch:SurfaceComms:SurfaceComms:C] Running Loop=1
2018-09-24T17:07:59.658Z,1537808879.658 [trackPatch:SurfaceComms:SurfaceComms:C](DEBUG): Aggregate::initialize trackPatch:SurfaceComms:SurfaceComms:C
2018-09-24T17:07:59.659Z,1537808879.659 [trackPatch:SurfaceComms:SurfaceComms:C:A] Running Loop=1
2018-09-24T17:08:00.058Z,1537808880.058 [trackPatch:M.YoYo] Preempted
2018-09-24T17:08:00.058Z,1537808880.058 [trackPatch:L.DepthEnvelope] Preempted
2018-09-24T17:08:00.058Z,1537808880.058 [trackPatch:K.SetSpeed] Preempted
2018-09-24T17:08:00.058Z,1537808880.058 [trackPatch:Science] Preempted
2018-09-24T17:08:00.058Z,1537808880.058 [trackPatch:Science:G] Preempted
2018-09-24T17:08:00.058Z,1537808880.058 [trackPatch:Science:Read_Oil] Preempted
2018-09-24T17:08:00.058Z,1537808880.058 [trackPatch:I.Buoyancy] Preempted
2018-09-24T17:08:00.059Z,1537808880.059 [trackPatch:H.Pitch] Preempted
2018-09-24T17:08:00.059Z,1537808880.059 [trackPatch:G.WaterDepthEnvelope] Preempted
2018-09-24T17:08:00.059Z,1537808880.059 [trackPatch:F.OffshoreEnvelope] Preempted
2018-09-24T17:08:00.677Z,1537808880.677 [WetLabsSeaOWL_UV_A](INFO): Powering down
2018-09-24T17:08:01.987Z,1537808881.987 [NAL9602](INFO): GPS fix at 20180924T170752: (36.845799, -121.916799)
2018-09-24T17:08:02.065Z,1537808882.065 [trackPatch:SurfaceComms:SurfaceComms:C:A] Stopped
2018-09-24T17:08:02.065Z,1537808882.065 [trackPatch:SurfaceComms:SurfaceComms:C:B] Running Loop=1
2018-09-24T17:08:06.584Z,1537808886.584 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20180924T165907/Courier0013.lzma
2018-09-24T17:08:07.357Z,1537808887.357 [DataOverHttps](INFO): Moved sent file to Logs/20180924T165907/Courier0013.lzma.bak
2018-09-24T17:08:07.357Z,1537808887.357 [DataOverHttps](INFO): SBD MOMSN=8574222
2018-09-24T17:08:16.463Z,1537808896.463 [DataOverHttps](INFO): Sending 256 bytes from file Logs/20180924T165907/Express0014.lzma
2018-09-24T17:08:17.205Z,1537808897.205 [DataOverHttps](INFO): Moved sent file to Logs/20180924T165907/Express0014.lzma.bak
2018-09-24T17:08:17.205Z,1537808897.205 [DataOverHttps](INFO): SBD MOMSN=8574225
2018-09-24T17:08:17.761Z,1537808897.761 [trackPatch:SurfaceComms:SurfaceComms:C:B] Stopped
2018-09-24T17:08:17.761Z,1537808897.761 [trackPatch:SurfaceComms:SurfaceComms:C:C] Running Loop=1
2018-09-24T17:08:22.168Z,1537808902.168 [NAL9602](INFO): GPS fix at 20180924T170812: (36.845863, -121.916804)
2018-09-24T17:08:22.239Z,1537808902.239 [trackPatch:SurfaceComms:SurfaceComms:C:C] Stopped
2018-09-24T17:08:22.239Z,1537808902.239 [trackPatch:SurfaceComms:SurfaceComms:C](INFO): Completed trackPatch:SurfaceComms:SurfaceComms:C
2018-09-24T17:08:22.239Z,1537808902.239 [trackPatch:SurfaceComms:SurfaceComms:C] Stopped
2018-09-24T17:08:22.240Z,1537808902.240 [trackPatch:SurfaceComms:SurfaceComms:C](DEBUG): Aggregate::uninitialize trackPatch:SurfaceComms:SurfaceComms:C
2018-09-24T17:08:22.240Z,1537808902.240 [trackPatch:SurfaceComms:SurfaceComms](INFO): Completed trackPatch:SurfaceComms:SurfaceComms
2018-09-24T17:08:22.241Z,1537808902.241 [trackPatch:SurfaceComms:SurfaceComms] Stopped
2018-09-24T17:08:22.241Z,1537808902.241 [trackPatch:SurfaceComms:SurfaceComms](DEBUG): Aggregate::uninitialize trackPatch:SurfaceComms:SurfaceComms
2018-09-24T17:08:22.241Z,1537808902.241 [trackPatch:SurfaceComms:SurfaceComms:A.GoToSurface] Stopped
2018-09-24T17:08:22.241Z,1537808902.241 [trackPatch:SurfaceComms:SurfaceComms:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-09-24T17:08:22.241Z,1537808902.241 [trackPatch:SurfaceComms](INFO): Completed trackPatch:SurfaceComms
2018-09-24T17:08:22.241Z,1537808902.241 [trackPatch:SurfaceComms] Stopped
2018-09-24T17:08:22.242Z,1537808902.242 [trackPatch:SurfaceComms](DEBUG): Aggregate::uninitialize trackPatch:SurfaceComms
2018-09-24T17:08:22.605Z,1537808902.605 [trackPatch:PatchDetectHorizontal:CrossLeg:B](INFO): Completed trackPatch:PatchDetectHorizontal:CrossLeg:B
2018-09-24T17:08:22.605Z,1537808902.605 [trackPatch:PatchDetectHorizontal:CrossLeg:B] Stopped
2018-09-24T17:08:22.606Z,1537808902.606 [trackPatch:PatchDetectHorizontal:CrossLeg:B](DEBUG): Aggregate::uninitialize trackPatch:PatchDetectHorizontal:CrossLeg:B
2018-09-24T17:08:22.606Z,1537808902.606 [trackPatch:PatchDetectHorizontal:CrossLeg:CrossPeakWp.Waypoint] Running Loop=1
2018-09-24T17:08:22.606Z,1537808902.606 [trackPatch:PatchDetectHorizontal:CrossLeg:CrossPeakWp.Waypoint](DEBUG): Initialize WaypointComponent.
2018-09-24T17:08:22.607Z,1537808902.607 [trackPatch:M.YoYo] Running Loop=1
2018-09-24T17:08:22.608Z,1537808902.608 [trackPatch:L.DepthEnvelope] Running Loop=1
2018-09-24T17:08:22.609Z,1537808902.609 [trackPatch:K.SetSpeed] Running Loop=1
2018-09-24T17:08:22.609Z,1537808902.609 [trackPatch:Science] Running Loop=1
2018-09-24T17:08:22.611Z,1537808902.611 [trackPatch:Science:Read_Oil] Running Loop=1
2018-09-24T17:08:22.611Z,1537808902.611 [trackPatch:Science:G] Running Loop=1
2018-09-24T17:08:22.612Z,1537808902.612 [trackPatch:I.Buoyancy] Running Loop=1
2018-09-24T17:08:22.612Z,1537808902.612 [trackPatch:H.Pitch] Running Loop=1
2018-09-24T17:08:22.613Z,1537808902.613 [trackPatch:G.WaterDepthEnvelope] Running Loop=1
2018-09-24T17:08:22.621Z,1537808902.621 [trackPatch:F.OffshoreEnvelope] Running Loop=1
2018-09-24T17:08:22.906Z,1537808902.906 [WetLabsSeaOWL_UV_A](INFO): Opening uart, block timeout 10ths=4
2018-09-24T17:08:22.906Z,1537808902.906 [WetLabsSeaOWL_UV_A](INFO): Powering up
2018-09-24T17:08:41.372Z,1537808921.372 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2018-09-24T17:08:41.372Z,1537808921.372 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,1809241014181-0.1,   0.0,1448.9,  0
2018-09-24T17:08:51.286Z,1537808931.286 [Radio_Surface](INFO): Powering down
2018-09-24T17:08:53.779Z,1537808933.779 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch -20.00 deg, mass-position 0.00 mm (1 active estimators).
2018-09-24T17:08:54.153Z,1537808934.153 [NAL9602](INFO): Powering down
2018-09-24T17:09:17.781Z,1537808957.781 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 20.00 deg, mass-position 0.00 mm (2 active estimators).
2018-09-24T17:09:47.752Z,1537808987.752 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:10:48.216Z,1537809048.216 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:11:22.213Z,1537809082.213 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.061920
2018-09-24T17:12:48.612Z,1537809168.612 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:13:48.620Z,1537809228.620 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:14:49.012Z,1537809289.012 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:15:49.027Z,1537809349.027 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:16:49.426Z,1537809409.426 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:17:44.332Z,1537809464.332 [RDI_Pathfinder](ERROR): Failed to parse:
:         +0.00,        +0.00,   0.00,868.97
2018-09-24T17:17:49.060Z,1537809469.060 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:18:49.460Z,1537809529.460 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:19:49.460Z,1537809589.460 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:20:49.460Z,1537809649.460 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:21:49.468Z,1537809709.468 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:22:49.862Z,1537809769.862 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:23:49.860Z,1537809829.860 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:24:49.863Z,1537809889.863 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:25:04.708Z,1537809904.708 [trackPatch:PatchDetectHorizontal:CrossLeg:CrossPeakWp.Waypoint] Stopped
2018-09-24T17:25:04.708Z,1537809904.708 [trackPatch:PatchDetectHorizontal:CrossLeg:CrossPeakWp.Waypoint](DEBUG): Uninitialize WaypointComponent.
2018-09-24T17:25:04.708Z,1537809904.708 [trackPatch:PatchDetectHorizontal:CrossLeg:D] Running Loop=1
2018-09-24T17:25:05.131Z,1537809905.131 [trackPatch:PatchDetectHorizontal:CrossLeg:D](IMPORTANT): CrossPeakWp done. Lat, lon = 36.846033 arcdeg , -121.927512 arcdeg . Patch value is nan ug/l at lat = nan arcdeg , lon = nan arcdeg , dep = nan m , distance = 0.000000 m 
2018-09-24T17:25:05.132Z,1537809905.132 [trackPatch:PatchDetectHorizontal:CrossLeg:D] Stopped
2018-09-24T17:25:05.133Z,1537809905.133 [trackPatch:PatchDetectHorizontal:CrossLeg:AssignPatchDetectOffInCrossLeg] Running Loop=1
2018-09-24T17:25:05.505Z,1537809905.505 [trackPatch:PatchDetectHorizontal:CrossLeg:AssignPatchDetectOffInCrossLeg] Stopped
2018-09-24T17:25:05.505Z,1537809905.505 [trackPatch:PatchDetectHorizontal:CrossLeg:AssignWpDoneInCrossLeg] Running Loop=1
2018-09-24T17:25:05.954Z,1537809905.954 [trackPatch:PatchDetectHorizontal:CrossLeg] Stopped
2018-09-24T17:25:05.954Z,1537809905.954 [trackPatch:PatchDetectHorizontal:CrossLeg](DEBUG): Aggregate::uninitialize trackPatch:PatchDetectHorizontal:CrossLeg
2018-09-24T17:25:05.955Z,1537809905.955 [trackPatch:PatchDetectHorizontal:CrossLeg:AssignWpDoneInCrossLeg] Stopped
2018-09-24T17:25:05.955Z,1537809905.955 [trackPatch:PatchDetectHorizontal:AssignWpBearingForInLeg] Running Loop=1
2018-09-24T17:25:06.320Z,1537809906.320 [trackPatch:PatchDetectHorizontal:AssignWpBearingForInLeg] Stopped
2018-09-24T17:25:06.320Z,1537809906.320 [trackPatch:PatchDetectHorizontal:F] Running Loop=1
2018-09-24T17:25:06.712Z,1537809906.712 [trackPatch:PatchDetectHorizontal:F](IMPORTANT): Next: bearing for InLeg: 90.000000 arcdeg . Current lat, lon = 36.846033 arcdeg , -121.927529 arcdeg . Patch value is nan ug/l at lat = nan arcdeg , lon = nan arcdeg , dep = nan m , distance = 0.000000 m 
2018-09-24T17:25:06.718Z,1537809906.718 [trackPatch:PatchDetectHorizontal:F] Stopped
2018-09-24T17:25:06.718Z,1537809906.718 [trackPatch:PatchDetectHorizontal:InLegWp.Waypoint] Running Loop=1
2018-09-24T17:25:06.718Z,1537809906.718 [trackPatch:PatchDetectHorizontal:InLegWp.Waypoint](DEBUG): Initialize WaypointComponent.
2018-09-24T17:25:07.129Z,1537809907.129 [trackPatch:PatchDetectHorizontal:InLegWp.Waypoint] Stopped
2018-09-24T17:25:07.129Z,1537809907.129 [trackPatch:PatchDetectHorizontal:InLegWp.Waypoint](DEBUG): Uninitialize WaypointComponent.
2018-09-24T17:25:07.130Z,1537809907.130 [trackPatch:PatchDetectHorizontal:AssignWpBearingForOutLeg] Running Loop=1
2018-09-24T17:25:07.523Z,1537809907.523 [trackPatch:PatchDetectHorizontal:AssignWpBearingForOutLeg] Stopped
2018-09-24T17:25:07.523Z,1537809907.523 [trackPatch:PatchDetectHorizontal:I] Running Loop=1
2018-09-24T17:25:07.962Z,1537809907.962 [trackPatch:PatchDetectHorizontal:I](IMPORTANT): Next: bearing for OutLeg: 0.000000 arcdeg . WpMaxDistance = 1000.000000 m . Current lat, lon = 36.846034 arcdeg , -121.927542 arcdeg . Patch value is nan ug/l at lat = nan arcdeg , lon = nan arcdeg , dep = nan m , distance = 0.000000 m 
2018-09-24T17:25:07.964Z,1537809907.964 [trackPatch:PatchDetectHorizontal:I] Stopped
2018-09-24T17:25:07.964Z,1537809907.964 [trackPatch:PatchDetectHorizontal:J] Running Loop=1
2018-09-24T17:25:07.964Z,1537809907.964 [trackPatch:PatchDetectHorizontal:J](DEBUG): Aggregate::initialize trackPatch:PatchDetectHorizontal:J
2018-09-24T17:25:08.330Z,1537809908.330 [trackPatch:SurfaceCommsSplit] Running Loop=1
2018-09-24T17:25:08.330Z,1537809908.330 [trackPatch:SurfaceCommsSplit](DEBUG): Aggregate::initialize trackPatch:SurfaceCommsSplit
2018-09-24T17:25:08.330Z,1537809908.330 [trackPatch:SurfaceCommsSplit:A.GoToSurface] Running Loop=1
2018-09-24T17:25:08.330Z,1537809908.330 [trackPatch:SurfaceCommsSplit:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-09-24T17:25:08.330Z,1537809908.330 [trackPatch:SurfaceCommsSplit:A.GoToSurface](INFO): Received depth rate setting nan m/s.
2018-09-24T17:25:08.331Z,1537809908.331 [trackPatch:SurfaceCommsSplit:A.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2018-09-24T17:25:08.331Z,1537809908.331 [trackPatch:SurfaceCommsSplit:A.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2018-09-24T17:25:08.332Z,1537809908.332 [trackPatch:SurfaceCommsSplit:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-09-24T17:25:08.332Z,1537809908.332 [trackPatch:SurfaceCommsSplit:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-09-24T17:25:20.076Z,1537809920.076 [trackPatch:SurfaceCommsSplit:B] Running Loop=1
2018-09-24T17:25:20.076Z,1537809920.076 [trackPatch:SurfaceCommsSplit:B](DEBUG): Aggregate::initialize trackPatch:SurfaceCommsSplit:B
2018-09-24T17:25:20.076Z,1537809920.076 [trackPatch:SurfaceCommsSplit:B:A] Running Loop=1
2018-09-24T17:25:20.094Z,1537809920.094 [Radio_Surface](INFO): Powering up
2018-09-24T17:25:20.451Z,1537809920.451 [trackPatch:SurfaceCommsSplit:B:A](INFO): ##UnpackSplit##
2018-09-24T17:25:20.451Z,1537809920.451 [trackPatch:SurfaceCommsSplit:B:A] Stopped
2018-09-24T17:25:20.451Z,1537809920.451 [trackPatch:SurfaceCommsSplit:B](INFO): Completed trackPatch:SurfaceCommsSplit:B
2018-09-24T17:25:20.451Z,1537809920.451 [trackPatch:SurfaceCommsSplit:B] Stopped
2018-09-24T17:25:20.451Z,1537809920.451 [trackPatch:SurfaceCommsSplit:B](DEBUG): Aggregate::uninitialize trackPatch:SurfaceCommsSplit:B
2018-09-24T17:25:20.451Z,1537809920.451 [trackPatch:SurfaceCommsSplit:C] Running Loop=1
2018-09-24T17:25:20.452Z,1537809920.452 [trackPatch:SurfaceCommsSplit:C](DEBUG): Aggregate::initialize trackPatch:SurfaceCommsSplit:C
2018-09-24T17:25:20.452Z,1537809920.452 [trackPatch:SurfaceCommsSplit:C:A] Running Loop=1
2018-09-24T17:25:20.840Z,1537809920.840 [trackPatch:M.YoYo] Preempted
2018-09-24T17:25:20.840Z,1537809920.840 [trackPatch:L.DepthEnvelope] Preempted
2018-09-24T17:25:20.840Z,1537809920.840 [trackPatch:K.SetSpeed] Preempted
2018-09-24T17:25:20.840Z,1537809920.840 [trackPatch:Science] Preempted
2018-09-24T17:25:20.840Z,1537809920.840 [trackPatch:Science:G] Preempted
2018-09-24T17:25:20.840Z,1537809920.840 [trackPatch:Science:Read_Oil] Preempted
2018-09-24T17:25:20.840Z,1537809920.840 [trackPatch:I.Buoyancy] Preempted
2018-09-24T17:25:20.840Z,1537809920.840 [trackPatch:H.Pitch] Preempted
2018-09-24T17:25:20.841Z,1537809920.841 [trackPatch:G.WaterDepthEnvelope] Preempted
2018-09-24T17:25:20.845Z,1537809920.845 [trackPatch:F.OffshoreEnvelope] Preempted
2018-09-24T17:25:21.182Z,1537809921.182 [NAL9602](INFO): Powering up
2018-09-24T17:25:21.241Z,1537809921.241 [WetLabsSeaOWL_UV_A](INFO): Powering down
2018-09-24T17:25:32.081Z,1537809932.081 [NAL9602](INFO): NAL9602 initialized
2018-09-24T17:25:33.266Z,1537809933.266 [BuoyancyServo](ERROR): getPosition uart error serial timeout
2018-09-24T17:25:33.266Z,1537809933.266 [BuoyancyServo](FAULT): Buoyancy getPosition uart error.serial timeout
2018-09-24T17:25:33.266Z,1537809933.266 [BuoyancyServo] Communications Fault, FailCount= 1
2018-09-24T17:25:33.267Z,1537809933.267 [BuoyancyServo](ERROR): Communications Fault
2018-09-24T17:25:33.281Z,1537809933.281 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2018-09-24T17:25:33.399Z,1537809933.399 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-09-24T17:25:33.400Z,1537809933.400 [BuoyancyServo](INFO): Powering down
2018-09-24T17:25:34.999Z,1537809934.999 [BuoyancyServo](FAULT): LCB fault:  Current Limiter Activated.
2018-09-24T17:25:34.999Z,1537809934.999 [BuoyancyServo] Hardware Fault, FailCount= 1
2018-09-24T17:25:34.999Z,1537809934.999 [BuoyancyServo](ERROR): Hardware Fault
2018-09-24T17:25:35.402Z,1537809935.402 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2018-09-24T17:25:35.402Z,1537809935.402 [BuoyancyServo] No Fault, FailCount= 1
2018-09-24T17:25:35.790Z,1537809935.790 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-09-24T17:25:35.911Z,1537809935.911 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-09-24T17:25:46.931Z,1537809946.931 [NAL9602](INFO): SBD MO Status=0, MOMSN=1538, MT Status=0, MTMSN=0
2018-09-24T17:25:46.931Z,1537809946.931 [NAL9602](INFO): No messages in MT queue
2018-09-24T17:25:50.104Z,1537809950.104 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:26:29.722Z,1537809989.722 [NAL9602](INFO): GPS fix at 20180924T172620: (36.846578, -121.927219)
2018-09-24T17:26:29.757Z,1537809989.757 [UniversalFixResidualReporter](INFO): Fix residual: 7.4 %DT, over the last 969.1 m. Residual distance 72.0 m at bearing -145.3 degrees. Fix at (36.8466, -121.9272) with 930.1 m made good.
2018-09-24T17:26:29.759Z,1537809989.759 [trackPatch:SurfaceCommsSplit:C:A] Stopped
2018-09-24T17:26:29.759Z,1537809989.759 [trackPatch:SurfaceCommsSplit:C:B] Running Loop=1
2018-09-24T17:26:45.894Z,1537810005.894 [NAL9602](INFO): SBD MO Status=2, MOMSN=1539, MT Status=2, MTMSN=0
2018-09-24T17:26:45.895Z,1537810005.895 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-24T17:26:50.284Z,1537810010.284 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:27:07.628Z,1537810027.628 [NAL9602](INFO): SBD MO Status=1, MOMSN=1539, MT Status=0, MTMSN=0
2018-09-24T17:27:07.674Z,1537810027.674 [NAL9602](INFO): Sent 194 bytes from file Logs/20180924T165907/Courier0016.lzma
2018-09-24T17:27:07.674Z,1537810027.674 [NAL9602](INFO): Packets left to send: 0
2018-09-24T17:27:07.675Z,1537810027.675 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180924T165907/Courier0016.lzma.parts/0000.sbd
2018-09-24T17:27:07.676Z,1537810027.676 [NAL9602](DEBUG): Completed sending Logs/20180924T165907/Courier0016.lzma
2018-09-24T17:27:24.573Z,1537810044.573 [NAL9602](INFO): SBD MO Status=2, MOMSN=1540, MT Status=2, MTMSN=0
2018-09-24T17:27:24.573Z,1537810044.573 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-24T17:27:47.953Z,1537810067.953 [NAL9602](INFO): SBD MO Status=2, MOMSN=1540, MT Status=2, MTMSN=0
2018-09-24T17:27:47.953Z,1537810067.953 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-24T17:27:50.316Z,1537810070.316 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:28:14.120Z,1537810094.120 [NAL9602](INFO): SBD MO Status=2, MOMSN=1540, MT Status=2, MTMSN=0
2018-09-24T17:28:14.120Z,1537810094.120 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-24T17:28:39.889Z,1537810119.889 [NAL9602](INFO): SBD MO Status=2, MOMSN=1540, MT Status=2, MTMSN=0
2018-09-24T17:28:39.889Z,1537810119.889 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-24T17:28:52.035Z,1537810132.035 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:29:05.646Z,1537810145.646 [NAL9602](INFO): SBD MO Status=2, MOMSN=1540, MT Status=2, MTMSN=0
2018-09-24T17:29:05.646Z,1537810145.646 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-24T17:29:39.824Z,1537810179.824 [NAL9602](INFO): SBD MO Status=2, MOMSN=1540, MT Status=2, MTMSN=0
2018-09-24T17:29:39.824Z,1537810179.824 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-24T17:29:52.392Z,1537810192.392 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:29:59.200Z,1537810199.200 [NAL9602](INFO): SBD MO Status=2, MOMSN=1540, MT Status=2, MTMSN=0
2018-09-24T17:29:59.200Z,1537810199.200 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-24T17:30:17.394Z,1537810217.394 [NAL9602](INFO): SBD MO Status=2, MOMSN=1540, MT Status=2, MTMSN=0
2018-09-24T17:30:17.394Z,1537810217.394 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-24T17:30:43.952Z,1537810243.952 [NAL9602](INFO): SBD MO Status=2, MOMSN=1540, MT Status=2, MTMSN=0
2018-09-24T17:30:43.952Z,1537810243.952 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-24T17:30:52.484Z,1537810252.484 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:31:09.688Z,1537810269.688 [NAL9602](INFO): SBD MO Status=2, MOMSN=1540, MT Status=2, MTMSN=0
2018-09-24T17:31:09.688Z,1537810269.688 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-24T17:31:29.856Z,1537810289.856 [NAL9602](INFO): SBD MO Status=1, MOMSN=1540, MT Status=0, MTMSN=0
2018-09-24T17:31:29.903Z,1537810289.903 [NAL9602](INFO): Sent 332 bytes from file Logs/20180924T165907/Express0017.lzma
2018-09-24T17:31:29.903Z,1537810289.903 [NAL9602](INFO): Packets left to send: 6
2018-09-24T17:31:29.905Z,1537810289.905 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180924T165907/Express0017.lzma.parts/0006.sbd
2018-09-24T17:31:42.392Z,1537810302.392 [NAL9602](INFO): SBD MO Status=1, MOMSN=1541, MT Status=0, MTMSN=0
2018-09-24T17:31:42.449Z,1537810302.449 [NAL9602](INFO): Sent 332 bytes from file Logs/20180924T165907/Express0017.lzma
2018-09-24T17:31:42.449Z,1537810302.449 [NAL9602](INFO): Packets left to send: 5
2018-09-24T17:31:42.451Z,1537810302.451 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180924T165907/Express0017.lzma.parts/0005.sbd
2018-09-24T17:31:52.544Z,1537810312.544 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:31:52.948Z,1537810312.948 [NAL9602](INFO): SBD MO Status=1, MOMSN=1542, MT Status=0, MTMSN=0
2018-09-24T17:31:53.002Z,1537810313.002 [NAL9602](INFO): Sent 332 bytes from file Logs/20180924T165907/Express0017.lzma
2018-09-24T17:31:53.003Z,1537810313.003 [NAL9602](INFO): Packets left to send: 4
2018-09-24T17:31:53.004Z,1537810313.004 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180924T165907/Express0017.lzma.parts/0004.sbd
2018-09-24T17:32:03.916Z,1537810323.916 [NAL9602](INFO): SBD MO Status=1, MOMSN=1543, MT Status=0, MTMSN=0
2018-09-24T17:32:03.962Z,1537810323.962 [NAL9602](INFO): Sent 332 bytes from file Logs/20180924T165907/Express0017.lzma
2018-09-24T17:32:03.962Z,1537810323.962 [NAL9602](INFO): Packets left to send: 3
2018-09-24T17:32:03.963Z,1537810323.963 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180924T165907/Express0017.lzma.parts/0003.sbd
2018-09-24T17:32:13.662Z,1537810333.662 [NAL9602](INFO): SBD MO Status=1, MOMSN=1544, MT Status=0, MTMSN=0
2018-09-24T17:32:13.713Z,1537810333.713 [NAL9602](INFO): Sent 332 bytes from file Logs/20180924T165907/Express0017.lzma
2018-09-24T17:32:13.714Z,1537810333.714 [NAL9602](INFO): Packets left to send: 2
2018-09-24T17:32:13.715Z,1537810333.715 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180924T165907/Express0017.lzma.parts/0002.sbd
2018-09-24T17:32:25.448Z,1537810345.448 [NAL9602](INFO): SBD MO Status=1, MOMSN=1545, MT Status=0, MTMSN=0
2018-09-24T17:32:25.497Z,1537810345.497 [NAL9602](INFO): Sent 332 bytes from file Logs/20180924T165907/Express0017.lzma
2018-09-24T17:32:25.497Z,1537810345.497 [NAL9602](INFO): Packets left to send: 1
2018-09-24T17:32:25.498Z,1537810345.498 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180924T165907/Express0017.lzma.parts/0001.sbd
2018-09-24T17:32:35.200Z,1537810355.200 [NAL9602](INFO): SBD MO Status=1, MOMSN=1546, MT Status=0, MTMSN=0
2018-09-24T17:32:35.253Z,1537810355.253 [NAL9602](INFO): Sent 39 bytes from file Logs/20180924T165907/Express0017.lzma
2018-09-24T17:32:35.253Z,1537810355.253 [NAL9602](INFO): Packets left to send: 0
2018-09-24T17:32:35.255Z,1537810355.255 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180924T165907/Express0017.lzma.parts/0000.sbd
2018-09-24T17:32:35.255Z,1537810355.255 [NAL9602](DEBUG): Completed sending Logs/20180924T165907/Express0017.lzma
2018-09-24T17:32:44.012Z,1537810364.012 [NAL9602](INFO): SBD MO Status=0, MOMSN=1547, MT Status=0, MTMSN=0
2018-09-24T17:32:44.113Z,1537810364.113 [trackPatch:SurfaceCommsSplit:C:B] Stopped
2018-09-24T17:32:44.113Z,1537810364.113 [trackPatch:SurfaceCommsSplit:C:C] Running Loop=1
2018-09-24T17:32:46.406Z,1537810366.406 [NAL9602](INFO): GPS fix at 20180924T173237: (36.846888, -121.927289)
2018-09-24T17:32:46.475Z,1537810366.475 [trackPatch:SurfaceCommsSplit:C:C] Stopped
2018-09-24T17:32:46.475Z,1537810366.475 [trackPatch:SurfaceCommsSplit:C](INFO): Completed trackPatch:SurfaceCommsSplit:C
2018-09-24T17:32:46.476Z,1537810366.476 [trackPatch:SurfaceCommsSplit:C] Stopped
2018-09-24T17:32:46.476Z,1537810366.476 [trackPatch:SurfaceCommsSplit:C](DEBUG): Aggregate::uninitialize trackPatch:SurfaceCommsSplit:C
2018-09-24T17:32:46.481Z,1537810366.481 [trackPatch:SurfaceCommsSplit](INFO): Completed trackPatch:SurfaceCommsSplit
2018-09-24T17:32:46.481Z,1537810366.481 [trackPatch:SurfaceCommsSplit] Stopped
2018-09-24T17:32:46.481Z,1537810366.481 [trackPatch:SurfaceCommsSplit](DEBUG): Aggregate::uninitialize trackPatch:SurfaceCommsSplit
2018-09-24T17:32:46.481Z,1537810366.481 [trackPatch:SurfaceCommsSplit:A.GoToSurface] Stopped
2018-09-24T17:32:46.481Z,1537810366.481 [trackPatch:SurfaceCommsSplit:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-09-24T17:32:46.861Z,1537810366.861 [trackPatch:PatchDetectHorizontal:J](INFO): Completed trackPatch:PatchDetectHorizontal:J
2018-09-24T17:32:46.861Z,1537810366.861 [trackPatch:PatchDetectHorizontal:J] Stopped
2018-09-24T17:32:46.861Z,1537810366.861 [trackPatch:PatchDetectHorizontal:J](DEBUG): Aggregate::uninitialize trackPatch:PatchDetectHorizontal:J
2018-09-24T17:32:46.862Z,1537810366.862 [trackPatch:PatchDetectHorizontal:AssignPatchDetectOnForOutLeg] Running Loop=1
2018-09-24T17:32:46.862Z,1537810366.862 [trackPatch:M.YoYo] Running Loop=1
2018-09-24T17:32:46.862Z,1537810366.862 [trackPatch:L.DepthEnvelope] Running Loop=1
2018-09-24T17:32:46.863Z,1537810366.863 [trackPatch:K.SetSpeed] Running Loop=1
2018-09-24T17:32:46.864Z,1537810366.864 [trackPatch:Science] Running Loop=1
2018-09-24T17:32:46.866Z,1537810366.866 [trackPatch:Science:Read_Oil] Running Loop=1
2018-09-24T17:32:46.866Z,1537810366.866 [trackPatch:Science:G] Running Loop=1
2018-09-24T17:32:46.866Z,1537810366.866 [trackPatch:I.Buoyancy] Running Loop=1
2018-09-24T17:32:46.867Z,1537810366.867 [trackPatch:H.Pitch] Running Loop=1
2018-09-24T17:32:46.867Z,1537810366.867 [trackPatch:G.WaterDepthEnvelope] Running Loop=1
2018-09-24T17:32:46.868Z,1537810366.868 [trackPatch:F.OffshoreEnvelope] Running Loop=1
2018-09-24T17:32:47.062Z,1537810367.062 [WetLabsSeaOWL_UV_A](INFO): Opening uart, block timeout 10ths=4
2018-09-24T17:32:47.062Z,1537810367.062 [WetLabsSeaOWL_UV_A](INFO): Powering up
2018-09-24T17:32:47.281Z,1537810367.281 [trackPatch:PatchDetectHorizontal:AssignPatchDetectOnForOutLeg] Stopped
2018-09-24T17:32:47.281Z,1537810367.281 [trackPatch:PatchDetectHorizontal:OutLeg] Running Loop=1
2018-09-24T17:32:47.281Z,1537810367.281 [trackPatch:PatchDetectHorizontal:OutLeg](DEBUG): Aggregate::initialize trackPatch:PatchDetectHorizontal:OutLeg
2018-09-24T17:32:47.281Z,1537810367.281 [trackPatch:PatchDetectHorizontal:OutLeg:OutLegWp.Waypoint] Running Loop=1
2018-09-24T17:32:47.281Z,1537810367.281 [trackPatch:PatchDetectHorizontal:OutLeg:OutLegWp.Waypoint](DEBUG): Initialize WaypointComponent.
2018-09-24T17:32:52.798Z,1537810372.798 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:33:00.865Z,1537810380.865 [trackPatch](INFO): Timed out from 2018-09-24T17:03:00.6Z
2018-09-24T17:33:00.865Z,1537810380.865 [MissionManager](INFO): trackPatch is completed.
2018-09-24T17:33:00.866Z,1537810380.866 [MissionManager](INFO): Uninitializing Mission trackPatch
2018-09-24T17:33:00.866Z,1537810380.866 [trackPatch] Stopped
2018-09-24T17:33:00.866Z,1537810380.866 [trackPatch](DEBUG): Aggregate::uninitialize trackPatch
2018-09-24T17:33:00.866Z,1537810380.866 [trackPatch:A.AltitudeEnvelope] Stopped
2018-09-24T17:33:00.866Z,1537810380.866 [trackPatch:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2018-09-24T17:33:00.866Z,1537810380.866 [trackPatch:B.DepthEnvelope] Stopped
2018-09-24T17:33:00.866Z,1537810380.866 [trackPatch:B.DepthEnvelope](DEBUG): Uninitialize.
2018-09-24T17:33:00.866Z,1537810380.866 [trackPatch:F.OffshoreEnvelope] Stopped
2018-09-24T17:33:00.866Z,1537810380.866 [trackPatch:F.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2018-09-24T17:33:00.866Z,1537810380.866 [trackPatch:G.WaterDepthEnvelope] Stopped
2018-09-24T17:33:00.867Z,1537810380.867 [trackPatch:G.WaterDepthEnvelope](DEBUG): Uninitialize WaterDepthEnvelopeComponent.
2018-09-24T17:33:00.867Z,1537810380.867 [trackPatch:H.Pitch] Stopped
2018-09-24T17:33:00.867Z,1537810380.867 [trackPatch:I.Buoyancy] Stopped
2018-09-24T17:33:00.867Z,1537810380.867 [trackPatch:I.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2018-09-24T17:33:00.867Z,1537810380.867 [trackPatch:Science] Stopped
2018-09-24T17:33:00.867Z,1537810380.867 [trackPatch:Science](DEBUG): Aggregate::uninitialize trackPatch:Science
2018-09-24T17:33:00.867Z,1537810380.867 [trackPatch:Science:G] Stopped
2018-09-24T17:33:00.867Z,1537810380.867 [trackPatch:Science:Read_Oil] Stopped
2018-09-24T17:33:00.867Z,1537810380.867 [trackPatch:Science:PeakDetectChl] Stopped
2018-09-24T17:33:00.867Z,1537810380.867 [trackPatch:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize trackPatch:Science:PeakDetectChl
2018-09-24T17:33:00.867Z,1537810380.867 [trackPatch:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2018-09-24T17:33:00.867Z,1537810380.867 [trackPatch:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2018-09-24T17:33:00.868Z,1537810380.868 [trackPatch:K.SetSpeed] Stopped
2018-09-24T17:33:00.868Z,1537810380.868 [trackPatch:K.SetSpeed](DEBUG): Uninitialize.
2018-09-24T17:33:00.868Z,1537810380.868 [trackPatch:L.DepthEnvelope] Stopped
2018-09-24T17:33:00.868Z,1537810380.868 [trackPatch:L.DepthEnvelope](DEBUG): Uninitialize.
2018-09-24T17:33:00.868Z,1537810380.868 [trackPatch:M.YoYo] Stopped
2018-09-24T17:33:00.868Z,1537810380.868 [trackPatch:M.YoYo](DEBUG): Uninitialize YoYoComponent.
2018-09-24T17:33:00.868Z,1537810380.868 [trackPatch:PatchDetectHorizontal] Stopped
2018-09-24T17:33:00.868Z,1537810380.868 [trackPatch:PatchDetectHorizontal](DEBUG): Aggregate::uninitialize trackPatch:PatchDetectHorizontal
2018-09-24T17:33:00.868Z,1537810380.868 [trackPatch:PatchDetectHorizontal:PatchDetection] Stopped
2018-09-24T17:33:00.868Z,1537810380.868 [trackPatch:PatchDetectHorizontal:PatchDetection](DEBUG): Aggregate::uninitialize trackPatch:PatchDetectHorizontal:PatchDetection
2018-09-24T17:33:00.869Z,1537810380.869 [trackPatch:PatchDetectHorizontal:PatchDetection:PeakDetectHorizontalTrigger.PeakDetectHorizontal] Stopped
2018-09-24T17:33:00.873Z,1537810380.873 [trackPatch:PatchDetectHorizontal:PatchDetection:PeakDetectHorizontalTrigger.PeakDetectHorizontal](DEBUG): Uninitialize.
2018-09-24T17:33:00.874Z,1537810380.874 [trackPatch:PatchDetectHorizontal:OutLeg] Stopped
2018-09-24T17:33:00.874Z,1537810380.874 [trackPatch:PatchDetectHorizontal:OutLeg](DEBUG): Aggregate::uninitialize trackPatch:PatchDetectHorizontal:OutLeg
2018-09-24T17:33:00.874Z,1537810380.874 [trackPatch:PatchDetectHorizontal:OutLeg:OutLegWp.Waypoint] Stopped
2018-09-24T17:33:00.874Z,1537810380.874 [trackPatch:PatchDetectHorizontal:OutLeg:OutLegWp.Waypoint](DEBUG): Uninitialize WaypointComponent.
2018-09-24T17:33:00.970Z,1537810380.970 [WetLabsSeaOWL_UV_A](INFO): Powering down
2018-09-24T17:33:01.256Z,1537810381.256 [MissionManager](IMPORTANT): Started mission Default
2018-09-24T17:33:01.256Z,1537810381.256 [Default] Running Loop=1
2018-09-24T17:33:01.256Z,1537810381.256 [Default](DEBUG): Aggregate::initialize Default
2018-09-24T17:33:01.256Z,1537810381.256 [Default:B.GoToSurface] Running Loop=1
2018-09-24T17:33:01.256Z,1537810381.256 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-09-24T17:33:01.256Z,1537810381.256 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-09-24T17:33:01.257Z,1537810381.257 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-09-24T17:33:01.257Z,1537810381.257 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-09-24T17:33:01.258Z,1537810381.258 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-09-24T17:33:01.258Z,1537810381.258 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-09-24T17:33:01.259Z,1537810381.259 [Default:A.Wait] Running Loop=1
2018-09-24T17:33:01.259Z,1537810381.259 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-09-24T17:33:14.466Z,1537810394.466 [Default:A.Wait](INFO): Done Waiting.
2018-09-24T17:33:14.466Z,1537810394.466 [Default:A.Wait] Stopped
2018-09-24T17:33:14.466Z,1537810394.466 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-09-24T17:33:14.840Z,1537810394.840 [Default:CheckIn] Running Loop=1
2018-09-24T17:33:14.840Z,1537810394.840 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-09-24T17:33:14.840Z,1537810394.840 [Default:CheckIn:Read_GPS] Running Loop=1
2018-09-24T17:33:15.270Z,1537810395.270 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-09-24T17:33:16.807Z,1537810396.807 [NAL9602](INFO): GPS fix at 20180924T173307: (36.846889, -121.927383)
2018-09-24T17:33:16.867Z,1537810396.867 [Default:CheckIn:Read_GPS] Stopped
2018-09-24T17:33:16.867Z,1537810396.867 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-09-24T17:33:17.284Z,1537810397.284 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-09-24T17:33:40.152Z,1537810420.152 [NAL9602](INFO): SBD MO Status=1, MOMSN=1548, MT Status=0, MTMSN=0
2018-09-24T17:33:40.209Z,1537810420.209 [NAL9602](INFO): Sent 63 bytes from file Logs/20180924T165907/Courier0019.lzma
2018-09-24T17:33:40.209Z,1537810420.209 [NAL9602](INFO): Packets left to send: 0
2018-09-24T17:33:40.211Z,1537810420.211 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180924T165907/Courier0019.lzma.parts/0000.sbd
2018-09-24T17:33:40.211Z,1537810420.211 [NAL9602](DEBUG): Completed sending Logs/20180924T165907/Courier0019.lzma
2018-09-24T17:33:53.104Z,1537810433.104 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:33:55.112Z,1537810435.112 [NAL9602](INFO): SBD MO Status=1, MOMSN=1549, MT Status=0, MTMSN=0
2018-09-24T17:33:55.169Z,1537810435.169 [NAL9602](INFO): Sent 161 bytes from file Logs/20180924T165907/Express0020.lzma
2018-09-24T17:33:55.169Z,1537810435.169 [NAL9602](INFO): Packets left to send: 0
2018-09-24T17:33:55.180Z,1537810435.180 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180924T165907/Express0020.lzma.parts/0000.sbd
2018-09-24T17:33:55.180Z,1537810435.180 [NAL9602](DEBUG): Completed sending Logs/20180924T165907/Express0020.lzma
2018-09-24T17:34:06.712Z,1537810446.712 [NAL9602](INFO): SBD MO Status=0, MOMSN=1550, MT Status=0, MTMSN=0
2018-09-24T17:34:06.812Z,1537810446.812 [Default:CheckIn:Read_Iridium] Stopped
2018-09-24T17:34:06.813Z,1537810446.813 [Default:CheckIn:C.Wait] Running Loop=1
2018-09-24T17:34:06.829Z,1537810446.829 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-09-24T17:34:37.506Z,1537810477.506 [NAL9602](INFO): Powering down
2018-09-24T17:34:53.104Z,1537810493.104 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:35:53.504Z,1537810553.504 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:36:53.904Z,1537810613.904 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:37:54.704Z,1537810674.704 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:38:54.704Z,1537810734.704 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:39:07.551Z,1537810747.551 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-09-24T17:39:07.552Z,1537810747.552 [Default:CheckIn:C.Wait] Stopped
2018-09-24T17:39:07.552Z,1537810747.552 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-09-24T17:39:07.553Z,1537810747.553 [Default:CheckIn:D] Running Loop=1
2018-09-24T17:39:07.992Z,1537810747.992 [Default:CheckIn:D] Stopped
2018-09-24T17:39:07.992Z,1537810747.992 [Default:CheckIn:E] Running Loop=1
2018-09-24T17:39:08.355Z,1537810748.355 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.112232 min 
2018-09-24T17:39:08.357Z,1537810748.357 [Default:CheckIn:E] Stopped
2018-09-24T17:39:08.357Z,1537810748.357 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-09-24T17:39:08.357Z,1537810748.357 [Default:CheckIn] Stopped
2018-09-24T17:39:08.357Z,1537810748.357 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-09-24T17:39:08.358Z,1537810748.358 [Default:CheckIn](INFO): Running loop #2
2018-09-24T17:39:08.358Z,1537810748.358 [Default:CheckIn] Running Loop=2
2018-09-24T17:39:08.358Z,1537810748.358 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-09-24T17:39:08.358Z,1537810748.358 [Default:CheckIn:Read_GPS] Running Loop=1
2018-09-24T17:39:09.110Z,1537810749.110 [NAL9602](INFO): Powering up
2018-09-24T17:39:20.306Z,1537810760.306 [NAL9602](INFO): NAL9602 initialized
2018-09-24T17:39:51.924Z,1537810791.924 [NAL9602](INFO): SBD MO Status=2, MOMSN=1551, MT Status=2, MTMSN=0
2018-09-24T17:39:51.924Z,1537810791.924 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-24T17:39:54.704Z,1537810794.704 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:40:35.116Z,1537810835.116 [NAL9602](INFO): SBD MO Status=2, MOMSN=1551, MT Status=2, MTMSN=0
2018-09-24T17:40:35.116Z,1537810835.116 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-24T17:40:55.504Z,1537810855.504 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T17:40:56.712Z,1537810856.712 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=1551, MT Status=1, MTMSN=77
2018-09-24T17:40:56.712Z,1537810856.712 [NAL9602](INFO): Data available in MT queue
2018-09-24T17:40:57.193Z,1537810857.193 [NAL9602](INFO): Received command:restart logs