2020-12-10T18:03:18.849Z,1607623398.849 [Supervisor](DEBUG): Initializing supervisor.
2020-12-10T18:03:18.853Z,1607623398.853 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-12-10T18:03:18.854Z,1607623398.854 [SyncHandler](INFO): Protected caller Thread ID is 704
2020-12-10T18:03:18.854Z,1607623398.854 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-12-10T18:03:18.855Z,1607623398.855 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-12-10T18:03:18.856Z,1607623398.856 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 705
2020-12-10T18:03:18.859Z,1607623398.859 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-12-10T18:03:18.879Z,1607623398.879 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-12-10T18:03:18.880Z,1607623398.880 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-12-10T18:03:18.880Z,1607623398.880 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 706
2020-12-10T18:03:18.882Z,1607623398.882 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-12-10T18:03:18.883Z,1607623398.883 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-12-10T18:03:18.884Z,1607623398.884 [logger ThreadHandler](INFO): Protected caller Thread ID is 707
2020-12-10T18:03:18.887Z,1607623398.887 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-12-10T18:03:18.888Z,1607623398.888 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-12-10T18:03:18.892Z,1607623398.892 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-12-10T18:03:19.342Z,1607623399.342 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-12-10T18:03:19.342Z,1607623399.342 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-12-10T18:03:19.422Z,1607623399.422 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-12-10T18:03:19.802Z,1607623399.802 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-12-10T18:03:19.802Z,1607623399.802 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-12-10T18:03:20.303Z,1607623400.303 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-12-10T18:03:20.304Z,1607623400.304 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-12-10T18:03:20.499Z,1607623400.499 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-12-10T18:03:20.500Z,1607623400.500 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-12-10T18:03:21.010Z,1607623401.010 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-12-10T18:03:21.011Z,1607623401.011 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-12-10T18:03:21.247Z,1607623401.247 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-12-10T18:03:21.247Z,1607623401.247 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-12-10T18:03:21.396Z,1607623401.396 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-12-10T18:03:21.396Z,1607623401.396 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-12-10T18:03:21.588Z,1607623401.588 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-12-10T18:03:21.588Z,1607623401.588 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-12-10T18:03:21.686Z,1607623401.686 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-12-10T18:03:21.687Z,1607623401.687 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2020-12-10T18:03:21.904Z,1607623401.904 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2020-12-10T18:03:21.905Z,1607623401.905 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-12-10T18:03:22.221Z,1607623402.221 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-12-10T18:03:22.221Z,1607623402.221 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-12-10T18:03:22.303Z,1607623402.303 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-12-10T18:03:22.429Z,1607623402.429 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-12-10T18:03:22.430Z,1607623402.430 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-12-10T18:03:23.089Z,1607623403.089 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-12-10T18:03:23.089Z,1607623403.089 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-12-10T18:03:23.455Z,1607623403.455 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-12-10T18:03:23.457Z,1607623403.457 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2020-12-10T18:03:23.460Z,1607623403.460 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2020-12-10T18:03:23.657Z,1607623403.657 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2020-12-10T18:03:23.759Z,1607623403.759 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2020-12-10T18:03:23.859Z,1607623403.859 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2020-12-10T18:03:24.115Z,1607623404.115 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-12-10T18:03:24.115Z,1607623404.115 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2020-12-10T18:03:24.201Z,1607623404.201 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2020-12-10T18:03:24.297Z,1607623404.297 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2020-12-10T18:03:24.410Z,1607623404.410 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2020-12-10T18:03:24.496Z,1607623404.496 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Dock.cfg
2020-12-10T18:03:24.582Z,1607623404.582 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2020-12-10T18:03:24.692Z,1607623404.692 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/workSite.cfg
2020-12-10T18:03:24.810Z,1607623404.810 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2020-12-10T18:03:25.584Z,1607623405.584 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2020-12-10T18:03:25.722Z,1607623405.722 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-12-10T18:03:25.729Z,1607623405.729 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-12-10T18:03:26.079Z,1607623406.079 [AHRS_M2] Loaded
2020-12-10T18:03:26.080Z,1607623406.080 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-12-10T18:03:26.807Z,1607623406.807 [BPC1] Loaded
2020-12-10T18:03:26.807Z,1607623406.807 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-12-10T18:03:26.879Z,1607623406.879 [DataOverHttps] Loaded
2020-12-10T18:03:26.879Z,1607623406.879 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-12-10T18:03:26.881Z,1607623406.881 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407974E0
2020-12-10T18:03:26.881Z,1607623406.881 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 802
2020-12-10T18:03:26.902Z,1607623406.902 [DDM] Loaded
2020-12-10T18:03:26.902Z,1607623406.902 [ComponentRegistry](DEBUG): SyncComponent "DDM" handled in the control thread.
2020-12-10T18:03:26.920Z,1607623406.920 [Depth_Keller] Loaded
2020-12-10T18:03:26.920Z,1607623406.920 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-12-10T18:03:26.924Z,1607623406.924 [DropWeight] Loaded
2020-12-10T18:03:26.925Z,1607623406.925 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-12-10T18:03:26.966Z,1607623406.966 [DUSBL_Hydroid] Loaded
2020-12-10T18:03:26.966Z,1607623406.966 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2020-12-10T18:03:27.010Z,1607623407.010 [Micromodem] Loaded
2020-12-10T18:03:27.011Z,1607623407.011 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2020-12-10T18:03:27.066Z,1607623407.066 [NAL9602] Loaded
2020-12-10T18:03:27.067Z,1607623407.067 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-12-10T18:03:27.093Z,1607623407.093 [Onboard] Loaded
2020-12-10T18:03:27.094Z,1607623407.094 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2020-12-10T18:03:27.095Z,1607623407.095 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 407C74E0
2020-12-10T18:03:27.095Z,1607623407.095 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 803
2020-12-10T18:03:27.108Z,1607623407.108 [Radio_Surface] Loaded
2020-12-10T18:03:27.108Z,1607623407.108 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-12-10T18:03:27.109Z,1607623407.109 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407F74E0
2020-12-10T18:03:27.110Z,1607623407.110 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 804
2020-12-10T18:03:27.139Z,1607623407.139 [RDI_Pathfinder] Loaded
2020-12-10T18:03:27.139Z,1607623407.139 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2020-12-10T18:03:27.163Z,1607623407.163 [RDI_PathfinderUp] Loaded
2020-12-10T18:03:27.163Z,1607623407.163 [ComponentRegistry](DEBUG): SyncComponent "RDI_PathfinderUp" handled in the control thread.
2020-12-10T18:03:27.164Z,1607623407.164 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-12-10T18:03:27.165Z,1607623407.165 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-12-10T18:03:27.175Z,1607623407.175 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-12-10T18:03:27.176Z,1607623407.176 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-12-10T18:03:27.279Z,1607623407.279 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-12-10T18:03:27.279Z,1607623407.279 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-12-10T18:03:27.292Z,1607623407.292 [NavChart] Loaded
2020-12-10T18:03:27.292Z,1607623407.292 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-12-10T18:03:27.298Z,1607623407.298 [UniversalFixResidualReporter] Loaded
2020-12-10T18:03:27.298Z,1607623407.298 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-12-10T18:03:27.308Z,1607623407.308 [WorkSite] Loaded
2020-12-10T18:03:27.308Z,1607623407.308 [ComponentRegistry](DEBUG): SyncComponent "WorkSite" handled in the control thread.
2020-12-10T18:03:27.309Z,1607623407.309 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-12-10T18:03:27.309Z,1607623407.309 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2020-12-10T18:03:27.395Z,1607623407.395 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2020-12-10T18:03:27.396Z,1607623407.396 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-12-10T18:03:27.507Z,1607623407.507 [BuoyancyServo] Loaded
2020-12-10T18:03:27.508Z,1607623407.508 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-12-10T18:03:27.528Z,1607623407.528 [ElevatorServo] Loaded
2020-12-10T18:03:27.528Z,1607623407.528 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-12-10T18:03:27.548Z,1607623407.548 [MassServo] Loaded
2020-12-10T18:03:27.548Z,1607623407.548 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-12-10T18:03:27.567Z,1607623407.567 [RudderServo] Loaded
2020-12-10T18:03:27.567Z,1607623407.567 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-12-10T18:03:27.585Z,1607623407.585 [ThrusterServo] Loaded
2020-12-10T18:03:27.585Z,1607623407.585 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-12-10T18:03:27.586Z,1607623407.586 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-12-10T18:03:27.586Z,1607623407.586 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-12-10T18:03:27.752Z,1607623407.752 [CTD_Seabird] Loaded
2020-12-10T18:03:27.752Z,1607623407.752 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2020-12-10T18:03:27.753Z,1607623407.753 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409274E0
2020-12-10T18:03:27.754Z,1607623407.754 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 805
2020-12-10T18:03:27.773Z,1607623407.773 [PAR_Licor] Loaded
2020-12-10T18:03:27.773Z,1607623407.773 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-12-10T18:03:27.804Z,1607623407.804 [WetLabsSeaOWL_UV_A] Loaded
2020-12-10T18:03:27.804Z,1607623407.804 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2020-12-10T18:03:27.805Z,1607623407.805 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409574E0
2020-12-10T18:03:27.806Z,1607623407.806 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 806
2020-12-10T18:03:27.806Z,1607623407.806 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-12-10T18:03:27.807Z,1607623407.807 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-12-10T18:03:28.105Z,1607623408.105 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-12-10T18:03:28.106Z,1607623408.106 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-12-10T18:03:28.146Z,1607623408.146 [DepthRateCalculator] Loaded
2020-12-10T18:03:28.146Z,1607623408.146 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-12-10T18:03:28.151Z,1607623408.151 [PitchRateCalculator] Loaded
2020-12-10T18:03:28.151Z,1607623408.151 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-12-10T18:03:28.161Z,1607623408.161 [SpeedCalculator] Loaded
2020-12-10T18:03:28.161Z,1607623408.161 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-12-10T18:03:28.174Z,1607623408.174 [TempGradientCalculator] Loaded
2020-12-10T18:03:28.174Z,1607623408.174 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-12-10T18:03:28.179Z,1607623408.179 [YawRateCalculator] Loaded
2020-12-10T18:03:28.179Z,1607623408.179 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-12-10T18:03:28.200Z,1607623408.200 [ElevatorOffsetCalculator] Loaded
2020-12-10T18:03:28.200Z,1607623408.200 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-12-10T18:03:28.201Z,1607623408.201 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-12-10T18:03:28.201Z,1607623408.201 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-12-10T18:03:28.335Z,1607623408.335 [SBIT](DEBUG): Construct Startup Built In Test.
2020-12-10T18:03:28.347Z,1607623408.347 [SBIT] Loaded
2020-12-10T18:03:28.347Z,1607623408.347 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-12-10T18:03:28.350Z,1607623408.350 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-12-10T18:03:28.362Z,1607623408.362 [IBIT] Loaded
2020-12-10T18:03:28.363Z,1607623408.363 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-12-10T18:03:28.369Z,1607623408.369 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-12-10T18:03:28.467Z,1607623408.467 [CBIT] Loaded
2020-12-10T18:03:28.468Z,1607623408.468 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-12-10T18:03:28.468Z,1607623408.468 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-12-10T18:03:28.469Z,1607623408.469 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-12-10T18:03:28.522Z,1607623408.522 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-12-10T18:03:28.523Z,1607623408.523 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-12-10T18:03:28.619Z,1607623408.619 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-12-10T18:03:28.619Z,1607623408.619 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-12-10T18:03:28.668Z,1607623408.668 [VerticalControl](DEBUG): Construct VerticalControl.
2020-12-10T18:03:28.719Z,1607623408.719 [VerticalControl] Loaded
2020-12-10T18:03:28.719Z,1607623408.719 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-12-10T18:03:28.722Z,1607623408.722 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-12-10T18:03:28.757Z,1607623408.757 [HorizontalControl] Loaded
2020-12-10T18:03:28.758Z,1607623408.758 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-12-10T18:03:28.760Z,1607623408.760 [SpeedControl](DEBUG): Construct SpeedControl.
2020-12-10T18:03:28.762Z,1607623408.762 [SpeedControl] Loaded
2020-12-10T18:03:28.762Z,1607623408.762 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-12-10T18:03:28.765Z,1607623408.765 [LoopControl](DEBUG): Construct LoopControl.
2020-12-10T18:03:28.765Z,1607623408.765 [LoopControl] Loaded
2020-12-10T18:03:28.765Z,1607623408.765 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-12-10T18:03:28.766Z,1607623408.766 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-12-10T18:03:28.766Z,1607623408.766 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-12-10T18:03:28.793Z,1607623408.793 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-12-10T18:03:28.799Z,1607623408.799 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-12-10T18:03:28.801Z,1607623408.801 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-12-10T18:03:28.812Z,1607623408.812 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-12-10T18:03:28.813Z,1607623408.813 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AFF4E0
2020-12-10T18:03:28.813Z,1607623408.813 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 807
2020-12-10T18:03:28.818Z,1607623408.818 [Supervisor](INFO): Main Thread ID is 821
2020-12-10T18:03:28.818Z,1607623408.818 [Supervisor](DEBUG): Running supervisor.
2020-12-10T18:03:28.819Z,1607623408.819 [CommandLine ThreadHandler](INFO): Handler Thread ID is 808
2020-12-10T18:03:28.821Z,1607623408.821 [controlThread ThreadHandler](INFO): Handler Thread ID is 809
2020-12-10T18:03:28.821Z,1607623408.821 [controlThread](DEBUG): Initializing ControlThread
2020-12-10T18:03:28.830Z,1607623408.830 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-12-10T18:03:28.830Z,1607623408.830 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-12-10T18:03:28.831Z,1607623408.831 [WorkSite](DEBUG): Initializing WorkSite component.
2020-12-10T18:03:28.836Z,1607623408.836 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-12-10T18:03:28.836Z,1607623408.836 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-12-10T18:03:28.836Z,1607623408.836 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-12-10T18:03:28.837Z,1607623408.837 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-12-10T18:03:28.837Z,1607623408.837 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-12-10T18:03:28.838Z,1607623408.838 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-12-10T18:03:28.838Z,1607623408.838 [SBIT](INFO): Initialize SBIT Component.
2020-12-10T18:03:28.839Z,1607623408.839 [SBIT](IMPORTANT): git: 2020-12-09_polaris
2020-12-10T18:03:28.839Z,1607623408.839 [SBIT](INFO): git hash: af9a0cd533cadbfdab8ca7c32aa0f39f5c9a4f8c
2020-12-10T18:03:28.840Z,1607623408.840 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-12-10T18:03:28.841Z,1607623408.841 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Thu Aug 6 12:04:53 PDT 2020
2020-12-10T18:03:28.842Z,1607623408.842 [SBIT](INFO): Beginning SBIT in 21.000000 seconds.
2020-12-10T18:03:28.842Z,1607623408.842 [IBIT](INFO): Initialize IBIT Component.
2020-12-10T18:03:28.844Z,1607623408.844 [CBIT](DEBUG): Initialize CBIT Component.
2020-12-10T18:03:28.844Z,1607623408.844 [logger ThreadHandler](INFO): Handler Thread ID is 810
2020-12-10T18:03:28.855Z,1607623408.855 [CBIT](DEBUG): Initialized mux pins.
2020-12-10T18:03:28.855Z,1607623408.855 [CBIT](DEBUG): Initializing the watchdog timer.
2020-12-10T18:03:28.864Z,1607623408.864 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 811
2020-12-10T18:03:28.865Z,1607623408.865 [DataOverHttps](DEBUG): dashIP=128.128.181.155 starts with a digit so assuming it is a numeric IP
2020-12-10T18:03:28.876Z,1607623408.876 [Onboard ThreadHandler](INFO): Handler Thread ID is 812
2020-12-10T18:03:28.880Z,1607623408.880 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-12-10T18:03:28.880Z,1607623408.880 [CBIT](DEBUG): Initializing heartbeat.
2020-12-10T18:03:28.911Z,1607623408.911 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 814
2020-12-10T18:03:28.920Z,1607623408.920 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 815
2020-12-10T18:03:28.920Z,1607623408.920 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2020-12-10T18:03:28.925Z,1607623408.925 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 817
2020-12-10T18:03:28.925Z,1607623408.925 [WetLabsSeaOWL_UV_A](INFO): Powering down
2020-12-10T18:03:28.936Z,1607623408.936 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 818
2020-12-10T18:03:28.943Z,1607623408.943 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-12-10T18:03:28.943Z,1607623408.943 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-12-10T18:03:28.943Z,1607623408.943 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-12-10T18:03:28.944Z,1607623408.944 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-12-10T18:03:28.944Z,1607623408.944 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-12-10T18:03:28.944Z,1607623408.944 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-12-10T18:03:28.944Z,1607623408.944 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-12-10T18:03:28.944Z,1607623408.944 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-12-10T18:03:28.944Z,1607623408.944 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-12-10T18:03:28.945Z,1607623408.945 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-12-10T18:03:28.945Z,1607623408.945 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-12-10T18:03:28.945Z,1607623408.945 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-12-10T18:03:28.945Z,1607623408.945 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-12-10T18:03:28.945Z,1607623408.945 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-12-10T18:03:28.945Z,1607623408.945 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-12-10T18:03:28.946Z,1607623408.946 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-12-10T18:03:28.951Z,1607623408.951 [CBIT](DEBUG): Deactivating GF circuits.
2020-12-10T18:03:28.951Z,1607623408.951 [CBIT](DEBUG): Deactivating emergency mode.
2020-12-10T18:03:28.987Z,1607623408.987 [CBIT](DEBUG): Backplane powered.
2020-12-10T18:03:28.988Z,1607623408.988 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-12-10T18:03:28.989Z,1607623408.989 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-12-10T18:03:28.990Z,1607623408.990 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-12-10T18:03:28.991Z,1607623408.991 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-12-10T18:03:28.991Z,1607623408.991 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-12-10T18:03:29.006Z,1607623409.006 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-12-10T18:03:29.026Z,1607623409.026 [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>


2020-12-10T18:03:29.051Z,1607623409.051 [MissionManager](INFO): Loading Mission: Missions/underIce/DefaultWithUndock.xml
2020-12-10T18:03:29.204Z,1607623409.204 [MissionManager](INFO): DefineArg DefaultWithUndock.ElapsedSinceDefaultStarted = 0.000000 min
2020-12-10T18:03:29.207Z,1607623409.207 [MissionManager](INFO): DefineArg DefaultWithUndock.DetachTimeout = 30.000000 min
2020-12-10T18:03:29.227Z,1607623409.227 [MissionManager](INFO): DefineArg DefaultWithUndock.TransponderCode = 2 count
2020-12-10T18:03:29.231Z,1607623409.231 [MissionManager](INFO): DefineArg DefaultWithUndock.TrackingUpdatePeriod = 2.500000 s
2020-12-10T18:03:29.234Z,1607623409.234 [MissionManager](INFO): DefineArg DefaultWithUndock.NumberOfPings = 1.000000 count
2020-12-10T18:03:29.247Z,1607623409.247 [MissionManager](INFO): DefineArg DefaultWithUndock.DetachModeDDM = 2.000000 count
2020-12-10T18:03:29.248Z,1607623409.248 [DefaultWithUndock:A.Wait](DEBUG): Construct Wait.
2020-12-10T18:03:29.315Z,1607623409.315 [Radio_Surface](INFO): Powering up
2020-12-10T18:03:29.367Z,1607623409.367 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Construct.
2020-12-10T18:03:29.368Z,1607623409.368 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values.
2020-12-10T18:03:29.437Z,1607623409.437 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-12-10T18:03:29.481Z,1607623409.481 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-12-10T18:03:29.484Z,1607623409.484 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-12-10T18:03:29.499Z,1607623409.499 [DefaultWithUndock:E.Execute](DEBUG): Construct Execute.
2020-12-10T18:03:29.537Z,1607623409.537 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Dock="Tethys/Dock"
         xmlns:Estimation="Tethys/Estimation"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Sensor="Tethys/Sensor"
         xmlns:Units="Tethys/Units"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Dock http://okeanids.mbari.org/tethys/Xml/Dock.xsd
                             Tethys/Estimation http://okeanids.mbari.org/tethys/Xml/Estimation.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Sensor http://okeanids.mbari.org/tethys/Xml/Sensor.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="DefaultWithUndock">

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

    <DefineArg Name="DetachTimeout"><Description>
        Maximum time duration for the vehicle to detach form the dock.
    </Description><Units:minute/><Value>30</Value></DefineArg>

    <DefineArg Name="TransponderCode"><Description>
        Dock transponder address.
    </Description><Dock:Dock.transponderCode/></DefineArg>

    <DefineArg Name="TrackingUpdatePeriod"><Description>
        Time duration between acoustic range queries while the
        mission is detaching from the dock.
    </Description><Units:second/><Value>2.5</Value></DefineArg>

    <DefineArg Name="NumberOfPings"><Description>
        Number of pings requested each time.
    </Description><Units:count/><Value>1</Value></DefineArg>

    <DefineArg Name="DetachModeDDM"><Description>
        DDM DETACH mode enumeration (whiskers retracted, latch open).
    </Description><Units:count/><Value>2</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>30</Value></Setting>
    </Guidance:Wait>

    <Aggregate Id="LeaveDock">
        <Sequence/>

        <Timeout Duration="DetachTimeout">
            <Syslog Severity="Important">Timed out while trying to detach from dock at current depth of <Universal:depth/><Units:meter/>.</Syslog>
        </Timeout>

        <!-- Acoustic tracking directives -->
        <Estimation:TrackAcousticContact>
            <Parallel/>
            <Setting><Estimation:TrackAcousticContact.contactLabelSetting/><Arg Name="TransponderCode"/></Setting>
            <Setting><Estimation:TrackAcousticContact.numberOfSamplesSetting/><Arg Name="NumberOfPings"/></Setting>
            <Setting><Estimation:TrackAcousticContact.updatePeriodSetting/><Arg Name="TrackingUpdatePeriod"/></Setting>
        </Estimation:TrackAcousticContact>

        <!-- Leave the dock -->
        <Dock:Undock>
            <Sequence/>
        </Dock:Undock>

    </Aggregate>


    <Aggregate Id="SurfaceDefault">

        <Sequence/>

        <Aggregate Id="HoldLatchOpen">

            <While>
                <Universal:depth/>
                <Gt><Control:VerticalControl.surfaceThreshold/></Gt>
            </While>

            <!-- Power the DDM -->
            <ReadData>
                <Sensor:DDM.DDMMode/>
            </ReadData>

            <!-- Hold the DDM in DETACH mode (whiskers retracted, latch open) -->
            <Assign><Parallel/><Sensor:DDM.DDMModeCmd/><Arg Name="DetachModeDDM"/></Assign>

        </Aggregate>

        <!-- This mission assumes open water so from here on it's the same old default that's always used -->
        <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>

    </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>


2020-12-10T18:03:29.542Z,1607623409.542 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,DDM,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,RDI_Pathfinder,RDI_PathfinderUp,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,WorkSite,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2020-12-10T18:03:29.546Z,1607623409.546 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-12-10T18:03:29.616Z,1607623409.616 [DDM](INFO): Powering up
2020-12-10T18:03:29.616Z,1607623409.616 [DDM](DEBUG): Initializing DDM.
2020-12-10T18:03:29.636Z,1607623409.636 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2020-12-10T18:03:29.637Z,1607623409.637 [DUSBL_Hydroid](INFO): Powering up
2020-12-10T18:03:29.637Z,1607623409.637 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2020-12-10T18:03:29.703Z,1607623409.703 [DepthRateCalculator](ERROR): Depth measurement is not active
2020-12-10T18:03:29.733Z,1607623409.733 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-12-10T18:03:29.739Z,1607623409.739 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-12-10T18:03:29.741Z,1607623409.741 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-12-10T18:03:29.747Z,1607623409.747 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-12-10T18:03:29.748Z,1607623409.748 [MassServo](DEBUG): Initializing EZServoServo.
2020-12-10T18:03:29.756Z,1607623409.756 [MassServo](DEBUG): Initializing MassServo.
2020-12-10T18:03:29.756Z,1607623409.756 [RudderServo](DEBUG): Initializing EZServoServo.
2020-12-10T18:03:29.763Z,1607623409.763 [RudderServo](DEBUG): Initializing RudderServo.
2020-12-10T18:03:29.764Z,1607623409.764 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-12-10T18:03:29.771Z,1607623409.771 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-12-10T18:03:29.973Z,1607623409.973 [Micromodem](INFO): Powering up
2020-12-10T18:03:29.973Z,1607623409.973 [Micromodem](DEBUG): Initializing Micromodem.
2020-12-10T18:03:30.683Z,1607623410.683 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2020-12-10T18:03:30.683Z,1607623410.683 [RudderServo](FAULT): Rudder failed to initialize
2020-12-10T18:03:30.683Z,1607623410.683 [RudderServo] Communications Fault, FailCount= 1
2020-12-10T18:03:30.683Z,1607623410.683 [RudderServo](ERROR): Communications Fault
2020-12-10T18:03:30.784Z,1607623410.784 [CBIT](ERROR): Communications Fault in component: RudderServo
2020-12-10T18:03:30.984Z,1607623410.984 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-12-10T18:03:30.984Z,1607623410.984 [RudderServo](INFO): Powering down
2020-12-10T18:03:31.628Z,1607623411.628 [RudderServo](DEBUG): Initializing EZServoServo.
2020-12-10T18:03:31.748Z,1607623411.748 [RudderServo](DEBUG): Initializing RudderServo.
2020-12-10T18:03:31.752Z,1607623411.752 [CBIT](INFO): Clearing failed state for component RudderServo
2020-12-10T18:03:31.752Z,1607623411.752 [RudderServo] No Fault, FailCount= 1
2020-12-10T18:03:35.278Z,1607623415.278 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2020-12-10T18:03:34.479089Z,RTC,RTC*54

2020-12-10T18:03:35.952Z,1607623415.952 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2020-12-10T18:03:45.335Z,1607623425.335 [DDM](INFO): Dynamic Docking Module:
2020-12-10T18:03:47.772Z,1607623427.772 [DUSBL_Hydroid](INFO): DUSBL Version:O
2020-12-10T18:03:50.638Z,1607623430.638 [SBIT](IMPORTANT): Beginning Startup BIT
2020-12-10T18:03:50.642Z,1607623430.642 [CBIT](IMPORTANT): Beginning ground fault scan
2020-12-10T18:03:57.458Z,1607623437.458 [NAL9602](INFO): Powering up NAL9602
2020-12-10T18:04:01.572Z,1607623441.572 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.066068
CHAN A1 (24V): 0.087381
CHAN A2 (12V): 0.041870
CHAN A3 (5V): 0.009150
CHAN B0 (3.3V): 0.003610
CHAN B1 (3.15aV): 0.002930
CHAN B2 (3.15bV): 0.003918
CHAN B3 (GND): -0.011498
OPEN: 0.006600
Full Scale Calc: 4.765 mA, -1.589 mA
2020-12-10T18:04:08.366Z,1607623448.366 [NAL9602](INFO): NAL9602 initialized
2020-12-10T18:04:14.071Z,1607623454.071 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items
2020-12-10T18:04:28.180Z,1607623468.180 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2020-12-10T18:04:37.065Z,1607623477.065 [NAL9602](INFO): SBD MO Status=0, MOMSN=12198, MT Status=0, MTMSN=0
2020-12-10T18:04:37.065Z,1607623477.065 [NAL9602](INFO): No messages in MT queue
2020-12-10T18:04:44.764Z,1607623484.764 [SBIT](IMPORTANT): SBIT PASSED
2020-12-10T18:04:44.764Z,1607623484.764 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-12-10T18:04:44.765Z,1607623484.765 [SBIT](IMPORTANT): Micromodem.destinationAddress=9 enum;

2020-12-10T18:04:44.765Z,1607623484.765 [SBIT](IMPORTANT): PowerOnly.loadAtStartup=0 bool;

2020-12-10T18:04:44.765Z,1607623484.765 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=114.655585 cubic_centimeter;

2020-12-10T18:04:44.765Z,1607623484.765 [SBIT](IMPORTANT): VerticalControl.massDefault=-0.364238 millimeter;

2020-12-10T18:04:45.157Z,1607623485.157 [WorkSite](IMPORTANT): Reading workSite position from Data/workSite.cfg
2020-12-10T18:04:45.160Z,1607623485.160 [WorkSite](IMPORTANT): WorkSite fix at 20201210T180243: (41.555574, -70.715091)
2020-12-10T18:04:45.162Z,1607623485.162 [MissionManager](IMPORTANT): Started mission Startup
2020-12-10T18:04:45.162Z,1607623485.162 [Startup] Running Loop=1
2020-12-10T18:04:45.162Z,1607623485.162 [Startup](DEBUG): Aggregate::initialize Startup
2020-12-10T18:04:45.162Z,1607623485.162 [Startup:A.GoToSurface] Running Loop=1
2020-12-10T18:04:45.162Z,1607623485.162 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-12-10T18:04:45.180Z,1607623485.180 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-12-10T18:04:45.180Z,1607623485.180 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-12-10T18:04:45.181Z,1607623485.181 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-12-10T18:04:45.181Z,1607623485.181 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-12-10T18:04:45.181Z,1607623485.181 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-12-10T18:04:45.183Z,1607623485.183 [Startup:StartupSatComms] Running Loop=1
2020-12-10T18:04:45.183Z,1607623485.183 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-12-10T18:04:45.183Z,1607623485.183 [Startup:StartupSatComms:A] Running Loop=1
2020-12-10T18:04:45.569Z,1607623485.569 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-12-10T18:04:59.286Z,1607623499.286 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2020-12-10T18:05:45.389Z,1607623545.389 [Startup:StartupSatComms:A](INFO): Timed out from 2020-12-10T18:04:45.2Z
2020-12-10T18:05:45.391Z,1607623545.391 [Startup:StartupSatComms:A] Stopped
2020-12-10T18:05:45.391Z,1607623545.391 [Startup:StartupSatComms:B] Running Loop=1
2020-12-10T18:05:45.811Z,1607623545.811 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-12-10T18:05:59.204Z,1607623559.204 [NAL9602](INFO): SBD MO Status=2, MOMSN=12199, MT Status=2, MTMSN=0
2020-12-10T18:05:59.204Z,1607623559.204 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-12-10T18:06:27.933Z,1607623587.933 [NAL9602](INFO): SBD MO Status=1, MOMSN=12199, MT Status=0, MTMSN=0
2020-12-10T18:06:27.991Z,1607623587.991 [NAL9602](INFO): Sent 53 bytes from file Logs/20201209T223704/Courier0222.lzma
2020-12-10T18:06:27.992Z,1607623587.992 [NAL9602](INFO): Packets left to send: 0
2020-12-10T18:06:45.428Z,1607623605.428 [Startup:StartupSatComms:B](INFO): Timed out from 2020-12-10T18:05:45.4Z
2020-12-10T18:06:45.428Z,1607623605.428 [Startup:StartupSatComms:B] Stopped
2020-12-10T18:06:45.428Z,1607623605.428 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-12-10T18:06:45.428Z,1607623605.428 [Startup:StartupSatComms] Stopped
2020-12-10T18:06:45.428Z,1607623605.428 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-12-10T18:06:45.429Z,1607623605.429 [Startup](INFO): Completed Startup
2020-12-10T18:06:45.429Z,1607623605.429 [MissionManager](INFO): Startup is completed.
2020-12-10T18:06:45.429Z,1607623605.429 [MissionManager](INFO): Uninitializing Mission Startup
2020-12-10T18:06:45.429Z,1607623605.429 [Startup] Stopped
2020-12-10T18:06:45.429Z,1607623605.429 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-12-10T18:06:45.430Z,1607623605.430 [Startup:A.GoToSurface] Stopped
2020-12-10T18:06:45.430Z,1607623605.430 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-12-10T18:06:45.795Z,1607623605.795 [MissionManager](IMPORTANT): Started mission DefaultWithUndock
2020-12-10T18:06:45.795Z,1607623605.795 [DefaultWithUndock] Running Loop=1
2020-12-10T18:06:45.795Z,1607623605.795 [DefaultWithUndock](DEBUG): Aggregate::initialize DefaultWithUndock
2020-12-10T18:06:45.795Z,1607623605.795 [DefaultWithUndock:A.Wait] Running Loop=1
2020-12-10T18:06:45.795Z,1607623605.795 [DefaultWithUndock:A.Wait](DEBUG): Initialize Wait Component.
2020-12-10T18:06:51.834Z,1607623611.834 [NAL9602](INFO): SBD MO Status=1, MOMSN=12200, MT Status=0, MTMSN=0
2020-12-10T18:06:51.889Z,1607623611.889 [NAL9602](INFO): Sent 53 bytes from file Logs/20201209T223704/Courier0225.lzma
2020-12-10T18:06:51.889Z,1607623611.889 [NAL9602](INFO): Packets left to send: 0
2020-12-10T18:07:03.753Z,1607623623.753 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004555
2020-12-10T18:07:15.286Z,1607623635.286 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2020-12-10T18:07:16.093Z,1607623636.093 [RDI_PathfinderUp](ERROR): only read 1 of 4 data items
2020-12-10T18:07:16.103Z,1607623636.103 [DefaultWithUndock:A.Wait](INFO): Done Waiting.
2020-12-10T18:07:16.103Z,1607623636.103 [DefaultWithUndock:A.Wait] Stopped
2020-12-10T18:07:16.103Z,1607623636.103 [DefaultWithUndock:A.Wait](DEBUG): Uninitialize Wait Component.
2020-12-10T18:07:16.103Z,1607623636.103 [DefaultWithUndock:LeaveDock] Running Loop=1
2020-12-10T18:07:16.103Z,1607623636.103 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::initialize DefaultWithUndock:LeaveDock
2020-12-10T18:07:16.104Z,1607623636.104 [DefaultWithUndock:LeaveDock:A.] Running Loop=1
2020-12-10T18:07:16.104Z,1607623636.104 [DefaultWithUndock:LeaveDock:A.](INFO): Initializing TrackAcousticContact.
2020-12-10T18:07:16.104Z,1607623636.104 [DefaultWithUndock:LeaveDock:B.Undock] Running Loop=1
2020-12-10T18:07:16.104Z,1607623636.104 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize.
2020-12-10T18:07:16.104Z,1607623636.104 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values.
2020-12-10T18:07:16.502Z,1607623636.502 [DefaultWithUndock:LeaveDock:A.] Running Loop=1
2020-12-10T18:07:19.012Z,1607623639.012 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-10T18:07:19.910Z,1607623639.910 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detaching from dock.
2020-12-10T18:07:20.205Z,1607623640.205 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detected possible detachment. Starting timer.
2020-12-10T18:07:21.769Z,1607623641.769 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-10T18:07:22.566Z,1607623642.566 [NAL9602](INFO): Not Powering down - fast GPS
2020-12-10T18:07:23.369Z,1607623643.369 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-12-10T18:07:24.596Z,1607623644.596 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-10T18:07:27.429Z,1607623647.429 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-10T18:07:29.024Z,1607623649.024 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-12-10T18:07:30.262Z,1607623650.262 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-10T18:07:33.313Z,1607623653.313 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-10T18:07:34.680Z,1607623654.680 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-12-10T18:07:35.000Z,1607623656.000 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-10T18:07:38.728Z,1607623658.728 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-10T18:07:40.336Z,1607623660.336 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-12-10T18:07:40.377Z,1607623660.377 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached at range: nan m. Transitioning DDM to standby.
2020-12-10T18:07:41.577Z,1607623661.577 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-10T18:07:43.239Z,1607623663.239 [DefaultWithUndock:LeaveDock:B.Undock](INFO): DDM at standby.
2020-12-10T18:07:43.601Z,1607623663.601 [DefaultWithUndock:LeaveDock:B.Undock](IMPORTANT): Undocking sequence complete.
2020-12-10T18:07:43.601Z,1607623663.601 [DefaultWithUndock:LeaveDock:B.Undock] Stopped
2020-12-10T18:07:43.601Z,1607623663.601 [DefaultWithUndock:LeaveDock](INFO): Completed DefaultWithUndock:LeaveDock
2020-12-10T18:07:43.601Z,1607623663.601 [DefaultWithUndock:LeaveDock] Stopped
2020-12-10T18:07:43.601Z,1607623663.601 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::uninitialize DefaultWithUndock:LeaveDock
2020-12-10T18:07:43.601Z,1607623663.601 [DefaultWithUndock:LeaveDock:A.] Stopped
2020-12-10T18:07:43.602Z,1607623663.602 [DefaultWithUndock:SurfaceDefault] Running Loop=1
2020-12-10T18:07:43.602Z,1607623663.602 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault
2020-12-10T18:07:43.602Z,1607623663.602 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen] Running Loop=1
2020-12-10T18:07:43.602Z,1607623663.602 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:HoldLatchOpen
2020-12-10T18:07:43.602Z,1607623663.602 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:A] Running Loop=1
2020-12-10T18:07:43.602Z,1607623663.602 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:B] Running Loop=1
2020-12-10T18:07:43.602Z,1607623663.602 [DefaultWithUndock:SurfaceDefault:B.GoToSurface] Running Loop=1
2020-12-10T18:07:43.602Z,1607623663.602 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-12-10T18:07:43.602Z,1607623663.602 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-12-10T18:07:43.603Z,1607623663.603 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-12-10T18:07:43.603Z,1607623663.603 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-12-10T18:07:43.604Z,1607623663.604 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-12-10T18:07:43.604Z,1607623663.604 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-12-10T18:07:44.007Z,1607623664.007 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=1
2020-12-10T18:07:44.007Z,1607623664.007 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-12-10T18:07:44.007Z,1607623664.007 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-12-10T18:07:44.007Z,1607623664.007 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen] Stopped
2020-12-10T18:07:44.019Z,1607623664.019 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:HoldLatchOpen
2020-12-10T18:07:44.019Z,1607623664.019 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:A] Stopped
2020-12-10T18:07:44.019Z,1607623664.019 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:B] Stopped
2020-12-10T18:07:44.396Z,1607623664.396 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-12-10T18:07:56.579Z,1607623676.579 [BuoyancyServo](FAULT): Overload Error
2020-12-10T18:07:56.579Z,1607623676.579 [BuoyancyServo] Hardware Fault, FailCount= 1
2020-12-10T18:07:56.579Z,1607623676.579 [BuoyancyServo](ERROR): Hardware Fault
2020-12-10T18:07:56.584Z,1607623676.584 [CBIT](ERROR): Hardware Fault in component: BuoyancyServo
2020-12-10T18:07:58.523Z,1607623678.523 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2020-12-10T18:07:58.523Z,1607623678.523 [BuoyancyServo](INFO): Powering down
2020-12-10T18:07:59.324Z,1607623679.324 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2020-12-10T18:07:59.324Z,1607623679.324 [BuoyancyServo] No Fault, FailCount= 1
2020-12-10T18:07:59.733Z,1607623679.733 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-12-10T18:07:59.734Z,1607623679.734 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-12-10T18:08:12.635Z,1607623692.635 [NAL9602](INFO): SBD MO Status=2, MOMSN=12201, MT Status=2, MTMSN=0
2020-12-10T18:08:12.635Z,1607623692.635 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-12-10T18:08:29.880Z,1607623709.880 [CommandLine](IMPORTANT): got command gfscan
2020-12-10T18:08:30.054Z,1607623710.054 [CBIT](IMPORTANT): Beginning ground fault scan
2020-12-10T18:08:40.947Z,1607623720.947 [NAL9602](INFO): SBD MO Status=2, MOMSN=12201, MT Status=2, MTMSN=0
2020-12-10T18:08:40.947Z,1607623720.947 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-12-10T18:08:41.034Z,1607623721.034 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.065779
CHAN A1 (24V): 0.087160
CHAN A2 (12V): 0.041185
CHAN A3 (5V): 0.008757
CHAN B0 (3.3V): 0.004042
CHAN B1 (3.15aV): 0.003189
CHAN B2 (3.15bV): 0.002470
CHAN B3 (GND): -0.011656
OPEN: 0.006528
Full Scale Calc: 4.765 mA, -1.589 mA
2020-12-10T18:08:53.496Z,1607623733.496 [BPC1](ERROR): BPC1B: No match for serial number FFFF in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2020-12-10T18:09:03.968Z,1607623743.968 [CommandLine](IMPORTANT): got command configSet Micromodem.surfaceThreshold 0.000000 meter
2020-12-10T18:09:06.845Z,1607623746.845 [NAL9602](INFO): SBD MO Status=2, MOMSN=12201, MT Status=2, MTMSN=0
2020-12-10T18:09:06.845Z,1607623746.845 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-12-10T18:09:24.349Z,1607623764.349 [DataOverHttps](IMPORTANT): SBD MTMSN=20201210T180924
2020-12-10T18:09:28.367Z,1607623768.367 [DataOverHttps](INFO): Received command:get depth
2020-12-10T18:09:28.492Z,1607623768.492 [CommandLine](IMPORTANT): got command get depth
2020-12-10T18:09:28.492Z,1607623768.492 [CommandLine](IMPORTANT): depth 0.453522 m
2020-12-10T18:09:28.594Z,1607623768.594 [NAL9602](INFO): SBD MO Status=0, MOMSN=12201, MT Status=0, MTMSN=0
2020-12-10T18:09:28.594Z,1607623768.594 [NAL9602](INFO): No messages in MT queue
2020-12-10T18:10:53.043Z,1607623853.043 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-12-10T18:10:53.045Z,1607623853.045 [BPC1](INFO): Received data from all battery sticks.
2020-12-10T18:11:24.158Z,1607623884.158 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181123.00,A,4133.32471,N,07042.84346,W,0.797,100.25,101220,,,A*71
2020-12-10T18:11:24.161Z,1607623884.161 [NAL9602](INFO): GPS fix at 20201210T181123: (41.555412, -70.714058)
2020-12-10T18:11:24.182Z,1607623884.182 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-12-10T18:11:24.182Z,1607623884.182 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-12-10T18:11:24.584Z,1607623884.584 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-12-10T18:11:27.851Z,1607623887.851 [DataOverHttps](INFO): Sending 53 bytes from file Logs/20201209T223704/Courier0228.lzma
2020-12-10T18:11:28.853Z,1607623888.853 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Courier0228.lzma.bak
2020-12-10T18:11:28.853Z,1607623888.853 [DataOverHttps](INFO): SBD MOMSN=59637
2020-12-10T18:11:39.116Z,1607623899.116 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2020-12-10T18:11:56.473Z,1607623916.473 [NAL9602](INFO): Not Powering down - fast GPS
2020-12-10T18:12:53.211Z,1607623973.211 [DataOverHttps](INFO): Sending 264 bytes from file Logs/20201210T180318/Courier0000.lzma
2020-12-10T18:12:54.213Z,1607623974.213 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Courier0000.lzma.bak
2020-12-10T18:12:54.213Z,1607623974.213 [DataOverHttps](INFO): SBD MOMSN=59639
2020-12-10T18:12:59.927Z,1607623979.927 [CommandLine](IMPORTANT): got command configSet Micromodem.surfaceThreshold 1.500000 meter
2020-12-10T18:13:03.251Z,1607623983.251 [DataOverHttps](INFO): Sending 201 bytes from file Logs/20201210T180318/Courier0004.lzma
2020-12-10T18:13:04.253Z,1607623984.253 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Courier0004.lzma.bak
2020-12-10T18:13:04.253Z,1607623984.253 [DataOverHttps](INFO): SBD MOMSN=59643
2020-12-10T18:13:13.291Z,1607623993.291 [DataOverHttps](INFO): Sending 53 bytes from file Logs/20201210T180318/Courier0007.lzma
2020-12-10T18:13:14.293Z,1607623994.293 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Courier0007.lzma.bak
2020-12-10T18:13:14.293Z,1607623994.293 [DataOverHttps](INFO): SBD MOMSN=59646
2020-12-10T18:13:23.336Z,1607624003.336 [DataOverHttps](INFO): Sending 810 bytes from file Logs/20201209T223704/Express0103.lzma
2020-12-10T18:13:24.333Z,1607624004.333 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0103.lzma.bak
2020-12-10T18:13:24.333Z,1607624004.333 [DataOverHttps](INFO): SBD MOMSN=59648
2020-12-10T18:14:53.716Z,1607624093.716 [DataOverHttps](INFO): Sending 819 bytes from file Logs/20201209T223704/Express0106.lzma
2020-12-10T18:14:54.717Z,1607624094.717 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0106.lzma.bak
2020-12-10T18:14:54.717Z,1607624094.717 [DataOverHttps](INFO): SBD MOMSN=59650
2020-12-10T18:15:24.838Z,1607624124.838 [DataOverHttps](IMPORTANT): SBD MTMSN=20201210T181524
2020-12-10T18:15:28.855Z,1607624128.855 [DataOverHttps](INFO): Received command:sched asap "load underIce/profile_stationUnder.xml;set profile_stationUnder.MissionTimeout 20 minute;set profile_stationUnder.Lat 41.557417 degree;set profile_stationUnder.Lon -70.714644 degree;set profile_stationUnder.Radius 100 meter" cipn 1 3
2020-12-10T18:15:28.906Z,1607624128.906 [CommandLine](IMPORTANT): got command schedule asap "load underIce/profile_stationUnder.xml;set profile_stationUnder.MissionTimeout 20 minute;set profile_stationUnder.Lat 41.557417 degree;set profile_stationUnder.Lon -70.714644 degree;set profile_stationUnder.Radius 100 meter" cipn 1 3.000000
2020-12-10T18:15:28.908Z,1607624128.908 [CommandLine](IMPORTANT): Scheduling command #1 of 3 with id=cipn
2020-12-10T18:15:28.910Z,1607624128.910 [CommandLine](IMPORTANT): Scheduled #1 (#1 of 3 with id='cipn'): "load underIce/profile_stationUnder.xml;set profile_stationUnder.MissionTimeout 20 minute;set profile_stationUnder.Lat 41.557417 degree;set profile_stationUnder.Lon -70.714644 degree;set profile_stationUnder.Radius 100 meter" ASAP
2020-12-10T18:15:30.104Z,1607624130.104 [DataOverHttps](IMPORTANT): SBD MTMSN=20201210T181529
2020-12-10T18:15:33.942Z,1607624133.942 [DataOverHttps](INFO): Received command:sched asap "set profile_stationUnder.YoYoMinDepth 3 meter;set profile_stationUnder.YoYoMaxDepth 8 meter;set profile_stationUnder.YoYoMinAltitude 3 meter;set profile_stationUnder.CircleMaxError 20 meter" cipn 2 3
2020-12-10T18:15:33.954Z,1607624133.954 [CommandLine](IMPORTANT): got command schedule asap "set profile_stationUnder.YoYoMinDepth 3 meter;set profile_stationUnder.YoYoMaxDepth 8 meter;set profile_stationUnder.YoYoMinAltitude 3 meter;set profile_stationUnder.CircleMaxError 20 meter" cipn 2 3.000000
2020-12-10T18:15:33.954Z,1607624133.954 [CommandLine](IMPORTANT): Scheduling command #2 of 3 with id=cipn
2020-12-10T18:15:33.955Z,1607624133.955 [CommandLine](IMPORTANT): Scheduled #2 (#2 of 3 with id='cipn'): "set profile_stationUnder.YoYoMinDepth 3 meter;set profile_stationUnder.YoYoMaxDepth 8 meter;set profile_stationUnder.YoYoMinAltitude 3 meter;set profile_stationUnder.CircleMaxError 20 meter" ASAP
2020-12-10T18:15:35.358Z,1607624135.358 [DataOverHttps](IMPORTANT): SBD MTMSN=20201210T181534
2020-12-10T18:15:38.955Z,1607624138.955 [DataOverHttps](INFO): Received command:sched asap "set profile_stationUnder.MinAltitude 3 meter;set profile_stationUnder.MaxDepth 9 meter;set profile_stationUnder.MinOffshore 100 meter;run" cipn 3 3
2020-12-10T18:15:39.000Z,1607624139.000 [CommandLine](IMPORTANT): got command schedule asap "set profile_stationUnder.MinAltitude 3 meter;set profile_stationUnder.MaxDepth 9 meter;set profile_stationUnder.MinOffshore 100 meter;run" cipn 3 3.000000
2020-12-10T18:15:39.001Z,1607624139.001 [CommandLine](IMPORTANT): Scheduling command #3 of 3 with id=cipn
2020-12-10T18:15:39.002Z,1607624139.002 [CommandLine](IMPORTANT): Scheduled #3 (#3 of 3 with id='cipn'): "set profile_stationUnder.MinAltitude 3 meter;set profile_stationUnder.MaxDepth 9 meter;set profile_stationUnder.MinOffshore 100 meter;run" ASAP
2020-12-10T18:15:39.147Z,1607624139.147 [CommandLine](IMPORTANT): got command load ./Missions/underIce/profile_stationUnder.xml
2020-12-10T18:15:39.155Z,1607624139.155 [MissionManager](INFO): Loading Mission: ./Missions/underIce/profile_stationUnder.xml
2020-12-10T18:15:39.381Z,1607624139.381 [MissionManager](INFO): DefineArg profile_stationUnder.MissionTimeout = 2.000000 h
2020-12-10T18:15:39.384Z,1607624139.384 [MissionManager](INFO): DefineArg profile_stationUnder.DetachTimeout = 20.000000 min
2020-12-10T18:15:39.392Z,1607624139.392 [MissionManager](INFO): DefineArg profile_stationUnder.Lat = 44.847000 deg
2020-12-10T18:15:39.394Z,1607624139.394 [MissionManager](INFO): DefineArg profile_stationUnder.Lon = -67.577538 deg
2020-12-10T18:15:39.397Z,1607624139.397 [MissionManager](INFO): DefineArg profile_stationUnder.Radius = 50.000000 m
2020-12-10T18:15:39.440Z,1607624139.440 [MissionManager](INFO): DefineArg profile_stationUnder.YoYoMinDepth = 2.500000 m
2020-12-10T18:15:39.443Z,1607624139.443 [MissionManager](INFO): DefineArg profile_stationUnder.YoYoMaxDepth = 5.000000 m
2020-12-10T18:15:39.446Z,1607624139.446 [MissionManager](INFO): DefineArg profile_stationUnder.YoYoMinAltitude = 4.000000 m
2020-12-10T18:15:39.457Z,1607624139.457 [MissionManager](INFO): DefineArg profile_stationUnder.YoYoPitch = 15.000000 deg
2020-12-10T18:15:39.468Z,1607624139.468 [MissionManager](INFO): DefineArg profile_stationUnder.Speed = 1.000000 m/s
2020-12-10T18:15:39.479Z,1607624139.479 [MissionManager](INFO): DefineArg profile_stationUnder.CircleMaxError = 1.000000 m
2020-12-10T18:15:39.482Z,1607624139.482 [MissionManager](INFO): DefineArg profile_stationUnder.CircleTurnToPort = 0 bool
2020-12-10T18:15:39.491Z,1607624139.491 [MissionManager](INFO): DefineArg profile_stationUnder.KwpHeading = 0.010000 rad/m
2020-12-10T18:15:39.551Z,1607624139.551 [MissionManager](INFO): DefineArg profile_stationUnder.MinAltitude = 2.000000 m
2020-12-10T18:15:39.574Z,1607624139.574 [MissionManager](INFO): DefineArg profile_stationUnder.MaxDepth = 8.000000 m
2020-12-10T18:15:39.585Z,1607624139.585 [MissionManager](INFO): DefineArg profile_stationUnder.MinOffshore = 10.000000 m
2020-12-10T18:15:39.609Z,1607624139.609 [MissionManager](INFO): DefineArg profile_stationUnder.MicromodemCommsInterval = 5.000000 min
2020-12-10T18:15:39.632Z,1607624139.632 [MissionManager](INFO): DefineArg profile_stationUnder.DetachDepth = 4.500000 m
2020-12-10T18:15:39.635Z,1607624139.635 [MissionManager](INFO): DefineArg profile_stationUnder.DetachBounceTimeout = 20.000000 s
2020-12-10T18:15:39.650Z,1607624139.650 [MissionManager](INFO): DefineArg profile_stationUnder.TransponderCode = 2.000000 count
2020-12-10T18:15:39.658Z,1607624139.658 [MissionManager](INFO): DefineArg profile_stationUnder.TrackingUpdatePeriod = 2.500000 s
2020-12-10T18:15:39.682Z,1607624139.682 [MissionManager](INFO): DefineArg profile_stationUnder.NumberOfPings = 1.000000 count
2020-12-10T18:15:39.683Z,1607624139.683 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml
2020-12-10T18:15:40.437Z,1607624140.437 [MissionManager](INFO): DefineArg profile_stationUnder:Science.PeakDetectChlActive = 0 bool
2020-12-10T18:15:40.460Z,1607624140.460 [MissionManager](INFO): DefineArg profile_stationUnder:Science.TimeWindowPeakReport = nan min
2020-12-10T18:15:40.462Z,1607624140.462 [MissionManager](INFO): DefineArg profile_stationUnder:Science.HighestChlPeakReportActive = 0 bool
2020-12-10T18:15:40.478Z,1607624140.478 [MissionManager](INFO): DefineArg profile_stationUnder:Science.PatchTracking = 0 bool
2020-12-10T18:15:40.501Z,1607624140.501 [MissionManager](INFO): DefineArg profile_stationUnder:Science.FilterWidthHorizontal = 3.000000 count
2020-12-10T18:15:40.520Z,1607624140.520 [MissionManager](INFO): DefineArg profile_stationUnder:Science.NumProfilesSlidingwindow = 100.000000 count
2020-12-10T18:15:40.543Z,1607624140.543 [MissionManager](INFO): DefineArg profile_stationUnder:Science.OffPeakFractionHorizontal = 80.000000 %
2020-12-10T18:15:40.546Z,1607624140.546 [MissionManager](INFO): DefineArg profile_stationUnder:Science.PeakDetectNO3Active = 0 bool
2020-12-10T18:15:40.557Z,1607624140.557 [MissionManager](INFO): DefineArg profile_stationUnder:Science.PeakDetectOilActive = 0 bool
2020-12-10T18:15:40.581Z,1607624140.581 [MissionManager](INFO): DefineArg profile_stationUnder:Science.PeakDetectFDOMActive = 0 bool
2020-12-10T18:15:40.608Z,1607624140.608 [MissionManager](INFO): DefineArg profile_stationUnder:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2020-12-10T18:15:40.628Z,1607624140.628 [MissionManager](INFO): DefineArg profile_stationUnder:Science.EnabledAanderaaO2 = 0 bool
2020-12-10T18:15:40.643Z,1607624140.643 [MissionManager](INFO): DefineArg profile_stationUnder:Science.EnabledNeilBrown = 0 bool
2020-12-10T18:15:40.647Z,1607624140.647 [MissionManager](INFO): DefineArg profile_stationUnder:Science.EnabledSeabird = 1 bool
2020-12-10T18:15:40.666Z,1607624140.666 [MissionManager](INFO): DefineArg profile_stationUnder:Science.EnabledWetLabsBB2FL = 0 bool
2020-12-10T18:15:40.682Z,1607624140.682 [MissionManager](INFO): DefineArg profile_stationUnder:Science.EnabledWetLabsSeaOWL_UV_A = 1 bool
2020-12-10T18:15:40.761Z,1607624140.761 [MissionManager](INFO): DefineArg profile_stationUnder:Science.EnabledWetLabsUBAT = 0 bool
2020-12-10T18:15:40.784Z,1607624140.784 [MissionManager](INFO): DefineArg profile_stationUnder:Science.LowPassWindowLength = 20.000000 count
2020-12-10T18:15:40.787Z,1607624140.787 [MissionManager](INFO): DefineArg profile_stationUnder:Science.MedianFilterLen = 5.000000 count
2020-12-10T18:15:40.826Z,1607624140.826 [MissionManager](INFO): DefineArg profile_stationUnder:Science.PeakShallowBound = nan m
2020-12-10T18:15:40.845Z,1607624140.845 [MissionManager](INFO): DefineArg profile_stationUnder:Science.PeakDeepBound = nan m
2020-12-10T18:15:40.869Z,1607624140.869 [MissionManager](INFO): DefineOutput profile_stationUnder:Science.PeakChl = 0.000000 ug/l
2020-12-10T18:15:40.898Z,1607624140.898 [MissionManager](INFO): DefineOutput profile_stationUnder:Science.PeakChlDepth = 0.000000 m
2020-12-10T18:15:40.931Z,1607624140.931 [MissionManager](INFO): DefineOutput profile_stationUnder:Science.PeakChlTemperature = 0.000000 degC
2020-12-10T18:15:40.945Z,1607624140.945 [MissionManager](INFO): DefineOutput profile_stationUnder:Science.PeakChlLatitude = nan deg
2020-12-10T18:15:40.953Z,1607624140.953 [MissionManager](INFO): DefineOutput profile_stationUnder:Science.PeakChlLongitude = nan deg
2020-12-10T18:15:40.965Z,1607624140.965 [MissionManager](INFO): DefineOutput profile_stationUnder:Science.PeakNO3 = 0.000000 umol/l
2020-12-10T18:15:40.969Z,1607624140.969 [MissionManager](INFO): DefineOutput profile_stationUnder:Science.PeakNO3Depth = 0.000000 m
2020-12-10T18:15:40.988Z,1607624140.988 [MissionManager](INFO): DefineOutput profile_stationUnder:Science.PeakNO3Latitude = nan deg
2020-12-10T18:15:40.991Z,1607624140.991 [MissionManager](INFO): DefineOutput profile_stationUnder:Science.PeakNO3Longitude = nan deg
2020-12-10T18:15:41.003Z,1607624141.003 [MissionManager](INFO): DefineOutput profile_stationUnder:Science.PatchChl = 0.000000 m
2020-12-10T18:15:41.014Z,1607624141.014 [MissionManager](INFO): DefineOutput profile_stationUnder:Science.PatchChlDepth = 0.000000 m
2020-12-10T18:15:41.025Z,1607624141.025 [MissionManager](INFO): DefineOutput profile_stationUnder:Science.PatchChlLatitude = nan deg
2020-12-10T18:15:41.029Z,1607624141.029 [MissionManager](INFO): DefineOutput profile_stationUnder:Science.PatchChlLongitude = nan deg
2020-12-10T18:15:41.048Z,1607624141.048 [MissionManager](INFO): DefineOutput profile_stationUnder:Science.PatchChlDistance = nan m
2020-12-10T18:15:41.051Z,1607624141.051 [MissionManager](INFO): DefineOutput profile_stationUnder:Science.PeakOil = 0.000000 kg/m3
2020-12-10T18:15:41.065Z,1607624141.065 [MissionManager](INFO): DefineOutput profile_stationUnder:Science.PeakOilDepth = 0.000000 m
2020-12-10T18:15:41.072Z,1607624141.072 [MissionManager](INFO): DefineOutput profile_stationUnder:Science.PeakOilLatitude = nan deg
2020-12-10T18:15:41.075Z,1607624141.075 [MissionManager](INFO): DefineOutput profile_stationUnder:Science.PeakOilLongitude = nan deg
2020-12-10T18:15:41.086Z,1607624141.086 [MissionManager](INFO): DefineOutput profile_stationUnder:Science.PeakFDOM = 0.000000 ppb
2020-12-10T18:15:41.097Z,1607624141.097 [MissionManager](INFO): DefineOutput profile_stationUnder:Science.PeakFDOMDepth = 0.000000 m
2020-12-10T18:15:41.101Z,1607624141.101 [MissionManager](INFO): DefineOutput profile_stationUnder:Science.PeakFDOMLatitude = nan deg
2020-12-10T18:15:41.120Z,1607624141.120 [MissionManager](INFO): DefineOutput profile_stationUnder:Science.PeakFDOMLongitude = nan deg
2020-12-10T18:15:41.123Z,1607624141.123 [MissionManager](INFO): DefineOutput profile_stationUnder:Science.PatchFDOMDistance = nan m
2020-12-10T18:15:41.293Z,1607624141.293 [profile_stationUnder:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2020-12-10T18:15:41.360Z,1607624141.360 [profile_stationUnder:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2020-12-10T18:15:41.408Z,1607624141.408 [profile_stationUnder:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2020-12-10T18:15:41.435Z,1607624141.435 [profile_stationUnder:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2020-12-10T18:15:41.474Z,1607624141.474 [profile_stationUnder:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2020-12-10T18:15:41.509Z,1607624141.509 [MissionManager](INFO): RedefineArg profile_stationUnder:Science.PeakDetectChlActive = value:1 bool
2020-12-10T18:15:41.509Z,1607624141.509 [MissionManager](INFO): Inserting Stack: Missions/Insert/MicromodemComms.xml
2020-12-10T18:15:41.583Z,1607624141.583 [MissionManager](INFO): DefineArg profile_stationUnder:MicromodemComms.Timeout = 10.000000 min
2020-12-10T18:15:41.602Z,1607624141.602 [MissionManager](INFO): DefineArg profile_stationUnder:MicromodemComms.CommsInterval = 5.000000 min
2020-12-10T18:15:41.619Z,1607624141.619 [MissionManager](INFO): RedefineArg profile_stationUnder:MicromodemComms.CommsInterval = reader:profile_stationUnder.MicromodemCommsInterval
2020-12-10T18:15:41.639Z,1607624141.639 [MissionManager](INFO): Inserting Stack: Missions/Insert/StandardEnvelopes.xml
2020-12-10T18:15:41.687Z,1607624141.687 [MissionManager](INFO): DefineArg profile_stationUnder:StandardEnvelopes.MinAltitude = 5.000000 m
2020-12-10T18:15:41.690Z,1607624141.690 [MissionManager](INFO): DefineArg profile_stationUnder:StandardEnvelopes.MaxDepth = 200.000000 m
2020-12-10T18:15:41.702Z,1607624141.702 [MissionManager](INFO): DefineArg profile_stationUnder:StandardEnvelopes.MinOffshore = 2000.000000 m
2020-12-10T18:15:41.703Z,1607624141.703 [profile_stationUnder:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2020-12-10T18:15:41.735Z,1607624141.735 [profile_stationUnder:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2020-12-10T18:15:41.761Z,1607624141.761 [profile_stationUnder:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2020-12-10T18:15:41.827Z,1607624141.827 [profile_stationUnder:Detach:A_Timeout:B.Execute](DEBUG): Construct Execute.
2020-12-10T18:15:41.942Z,1607624141.942 [profile_stationUnder:Detach:C.Undock](DEBUG): Construct.
2020-12-10T18:15:41.942Z,1607624141.942 [profile_stationUnder:Detach:C.Undock](DEBUG): Initializing internal variables to default values.
2020-12-10T18:15:42.033Z,1607624142.033 [profile_stationUnder:ProfileStation:A.Pitch](DEBUG): Construct.
2020-12-10T18:15:42.079Z,1607624142.079 [profile_stationUnder:ProfileStation:B.Buoyancy](DEBUG): Construct Buoyancy.
2020-12-10T18:15:42.091Z,1607624142.091 [profile_stationUnder:ProfileStation:C.SetSpeed](DEBUG): Construct.
2020-12-10T18:15:42.098Z,1607624142.098 [profile_stationUnder:ProfileStation:D.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2020-12-10T18:15:42.141Z,1607624142.141 [profile_stationUnder:ProfileStation:E.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2020-12-10T18:15:42.181Z,1607624142.181 [profile_stationUnder:ProfileStation:F.YoYo](DEBUG): Construct YoYo.
2020-12-10T18:15:42.215Z,1607624142.215 [profile_stationUnder:ProfileStation:CircleWrapper:B.Circle](DEBUG): Construct.
2020-12-10T18:15:42.298Z,1607624142.298 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Derivation="Tethys/Derivation"
       xmlns:Dock="Tethys/Dock"
       xmlns:Estimation="Tethys/Estimation"
       xmlns:Guidance="Tethys/Guidance"
       xmlns:Sensor="Tethys/Sensor"
       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/Derivation http://okeanids.mbari.org/tethys/Xml/Derivation.xsd
                           Tethys/Dock http://okeanids.mbari.org/tethys/Xml/Dock.xsd
                           Tethys/Estimation http://okeanids.mbari.org/tethys/Xml/Estimation.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Sensor http://okeanids.mbari.org/tethys/Xml/Sensor.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="profile_stationUnder">

    <Description>
        This mission yoyos in a circle around a specified location. Designed for under ice. 
    </Description>

    <!-- Mission-wide settings -->

    <DefineArg Name="MissionTimeout"><Description>
        Maximum duration of mission
    </Description><Units:hour/><Value>2</Value></DefineArg>

    <DefineArg Name="DetachTimeout"><Description>
        Maximum time to spend getting off the dock
    </Description><Units:minute/><Value>20</Value></DefineArg>
    
    <!-- You probably need to change these. -->

    <DefineArg Name="Lat"><Description>
        The latitude of the center of the circle.
    </Description><Units:degree/><Value>44.847</Value></DefineArg>

    <DefineArg Name="Lon"><Description>
        The longitude of the center of the circle.
    </Description><Units:degree/><Value>-67.577535</Value></DefineArg>

    <DefineArg Name="Radius"><Description>
        Radius to circle at
    </Description><Units:meter/><Value>50</Value></DefineArg>

    <!-- You probably do not need to change these. -->

    <DefineArg Name="YoYoMinDepth"><Description>
        Minimum depth while performing the YoYo behavior.
    </Description><Units:meter/><Value>2.5</Value></DefineArg>

    <DefineArg Name="YoYoMaxDepth"><Description>
        Maximum depth while performing the YoYo behavior.
    </Description><Units:meter/><Value>5</Value></DefineArg>

    <DefineArg Name="YoYoMinAltitude"><Description>
        Minimum altitude while performing the YoYo behavior (for
        bottom-terminated YoYos).
    </Description><Units:meter/><Value>4</Value></DefineArg>

    <DefineArg Name="YoYoPitch"><Description>
        Pitch (plus and minus) for yo-yo behavior.
    </Description><Units:degree/><Value>15</Value></DefineArg>

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

    <!-- You are even less likely to need to change these. -->

    <DefineArg Name="CircleMaxError"><Description>
        If this distance away from the circle, drive straight towards (or away
        from the center). Otherwise, try to reduce distance from the ideal
        circle.
    </Description><Units:meter/><Value>1</Value></DefineArg>

    <DefineArg Name="CircleTurnToPort"><Description>
        If true, vehicle turns to the left around the center point. If false,
        vehicle turns to the right.
    </Description><False/></DefineArg>

    <DefineArg Name="KwpHeading"><Description>
        Used to relax waypoint cross-track error constant that is adjusted for
        docking. (You can override this setting by passing an argument.)
    </Description><Units:radian_per_meter/><Value>0.010</Value></DefineArg>

    <DefineArg Name="MinAltitude"><Description>
        Minimum height above the sea floor for the entire mission.
    </Description><Units:meter/><Value>2</Value></DefineArg>

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

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

    <DefineArg Name="MicromodemCommsInterval"><Description>
        How often to trigger Umodem communications
    </Description><Units:minute/><Value>5</Value></DefineArg>

    <DefineArg Name="DetachDepth"><Description>
        Desired vehicle depth when leaving the dock.
    </Description><Units:meter/><Value>4.5</Value></DefineArg>

    <DefineArg Name="DetachBounceTimeout"><Description>
        Time duration to keep the thruster engaged to bounce/slingshot off the dock.
    </Description><Units:second/><Value>20</Value></DefineArg>

    <DefineArg Name="TransponderCode"><Description>
        Transponder Address.
    </Description><Units:count/><Value>2</Value></DefineArg>

    <DefineArg Name="TrackingUpdatePeriod"><Description>
        How long to wait between acoustic queries.
    </Description><Units:second/><Value>2.5</Value></DefineArg>

    <DefineArg Name="NumberOfPings"><Description>
        Number of pings requested each time.
    </Description><Units:count/><Value>1</Value></DefineArg>
    
    <!-- Missions should almost always start with a timeout -->

    <Timeout Duration="MissionTimeout"/>

    <Insert Filename="Insert/Science.xml">
        <Description>
            Most missions will run the science sensors. 
        </Description>
        <RedefineArg Name="PeakDetectChlActive"><True/></RedefineArg>
    </Insert>


    <Insert Filename="Insert/MicromodemComms.xml" Id="MicromodemComms">
            <RedefineArg Name="CommsInterval"><Arg Name="MicromodemCommsInterval"/></RedefineArg>
    </Insert>    

    <!-- Missions should almost always start with standard safety envelopes; most missions should not expose the parameters of these envelopes. -->

    <Insert Filename="Insert/StandardEnvelopes.xml"/>

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MinAltitude"/><Arg Name="MinAltitude"/></Assign>

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MaxDepth"/><Arg Name="MaxDepth"/></Assign>

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MinOffshore"/><Arg Name="MinOffshore"/></Assign>


    <!-- Many missions will keep mass position and buoyancy volume fixed at defaults. -->

    <Aggregate Id="Detach">
        <Sequence/>

        <Timeout Duration="DetachTimeout">
            <Syslog Severity="Important">Timed out trying to detach from dock. Stopping mission.</Syslog>
            <Guidance:Execute>
                <Sequence/>
                <Setting><Guidance:Execute.command/><String>stop</String></Setting>
            </Guidance:Execute>
        </Timeout>

        <Syslog Severity="Important">Detaching from dock.</Syslog>

        <!-- Turn on tracking so we get some ranges to see how far we are from the dock -->
        <Estimation:TrackAcousticContact>
            <Parallel/>
            <Setting><Estimation:TrackAcousticContact.contactLabelSetting/><Arg Name="TransponderCode"/></Setting>
            <Setting><Estimation:TrackAcousticContact.numberOfSamplesSetting/><Arg Name="NumberOfPings"/></Setting>
            <Setting><Estimation:TrackAcousticContact.updatePeriodSetting/><Arg Name="TrackingUpdatePeriod"/></Setting>
        </Estimation:TrackAcousticContact>

        <!-- Time to leave the dock! -->
        <Dock:Undock>
            <Sequence/>
        </Dock:Undock>

    </Aggregate>


    <Aggregate Id="ProfileStation">
        <Sequence/>

        <Guidance:Pitch>
            <Parallel/>
            <Setting><Guidance:Pitch.massPosition/><Control:VerticalControl.massDefault/></Setting>
        </Guidance:Pitch>

        <Guidance:Buoyancy>
            <Parallel/>
            <Setting><Guidance:Buoyancy.position/><Control:VerticalControl.buoyancyNeutral/></Setting>
        </Guidance:Buoyancy>

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

        <Guidance:DepthEnvelope>
            <Description>
                Another depth envelope for the YoYo behavior. This envelope should
                fall within the limits of the standard safety envelopes in
                Insert/StandardEnvelopes.xml in order to avoid commanding high pitch
                angles for depth-terminated YoYos.
            </Description>
            <Parallel/>
            <Setting><Guidance:DepthEnvelope.minDepth/><Arg Name="YoYoMinDepth"/></Setting>
            <Setting><Guidance:DepthEnvelope.maxDepth/><Arg Name="YoYoMaxDepth"/></Setting>
            <Setting><Guidance:DepthEnvelope.pitch/><Arg Name="YoYoPitch"/></Setting>
        </Guidance:DepthEnvelope>

        <Guidance:AltitudeEnvelope>
            <Description>
                Another altitude envelope for the YoYo behavior. This envelope
                should fall within the limits of the standard safety envelopes in
                Insert/StandardEnvelopes.xml in order to avoid commanding high pitch
                angles for bottom-terminated YoYos.
            </Description>
            <Parallel/>
            <Setting><Guidance:AltitudeEnvelope.minAltitude/><Arg Name="YoYoMinAltitude"/></Setting>
            <Setting><Guidance:AltitudeEnvelope.pitch/><Arg Name="YoYoPitch"/></Setting>
        </Guidance:AltitudeEnvelope>

        <Guidance:YoYo>
            <Parallel/>
            <Setting><Guidance:YoYo.pitch/><Arg Name="YoYoPitch"/></Setting>
        </Guidance:YoYo>

        <Aggregate Id="CircleWrapper">

            <Sequence Repeat="4096"/>

            <Assign><Parallel/><Control:HorizontalControl.kwpHeading/><Arg Name="KwpHeading"/></Assign>

            <Guidance:Circle>
                <Sequence/>
                <Setting><Guidance:Circle.latitude/><Arg Name="Lat"/></Setting>
                <Setting><Guidance:Circle.longitude/><Arg Name="Lon"/></Setting>
                <Setting><Guidance:Circle.radius/><Arg Name="Radius"/></Setting>
                <Setting><Guidance:Circle.maxError/><Arg Name="CircleMaxError"/></Setting>
                <Setting><Guidance:Circle.turnToPort/><Arg Name="CircleTurnToPort"/></Setting>
            </Guidance:Circle>

        </Aggregate>

    </Aggregate>

</Mission>


2020-12-10T18:15:42.298Z,1607624142.298 [CommandLine](IMPORTANT): Loaded ./Missions/underIce/profile_stationUnder.xml
2020-12-10T18:16:01.674Z,1607624161.674 [CommandLine](IMPORTANT): got command set profile_stationUnder.MissionTimeout 20 minute
2020-12-10T18:16:01.675Z,1607624161.675 [CommandLine](IMPORTANT): got command set profile_stationUnder.Lat 41.557417 degree
2020-12-10T18:16:01.676Z,1607624161.676 [CommandLine](IMPORTANT): got command set profile_stationUnder.Lon -70.714644 degree
2020-12-10T18:16:01.676Z,1607624161.676 [CommandLine](IMPORTANT): got command set profile_stationUnder.Radius 100 meter
2020-12-10T18:16:12.616Z,1607624172.616 [CommandLine](IMPORTANT): got command set profile_stationUnder.YoYoMinDepth 3 meter
2020-12-10T18:16:12.616Z,1607624172.616 [CommandLine](IMPORTANT): got command set profile_stationUnder.YoYoMaxDepth 8 meter
2020-12-10T18:16:12.617Z,1607624172.617 [CommandLine](IMPORTANT): got command set profile_stationUnder.YoYoMinAltitude 3 meter
2020-12-10T18:16:12.618Z,1607624172.618 [CommandLine](IMPORTANT): got command set profile_stationUnder.CircleMaxError 20 meter
2020-12-10T18:16:20.275Z,1607624180.275 [CommandLine](IMPORTANT): got command set profile_stationUnder.MinAltitude 3 meter
2020-12-10T18:16:20.276Z,1607624180.276 [CommandLine](IMPORTANT): got command set profile_stationUnder.MaxDepth 9 meter
2020-12-10T18:16:20.276Z,1607624180.276 [CommandLine](IMPORTANT): got command set profile_stationUnder.MinOffshore 100 meter
2020-12-10T18:16:20.277Z,1607624180.277 [CommandLine](IMPORTANT): got command run
2020-12-10T18:16:20.280Z,1607624180.280 [CommandLine](IMPORTANT): Running 
2020-12-10T18:16:20.538Z,1607624180.538 [DefaultWithUndock] Stopped
2020-12-10T18:16:20.538Z,1607624180.538 [DefaultWithUndock](DEBUG): Aggregate::uninitialize DefaultWithUndock
2020-12-10T18:16:20.538Z,1607624180.538 [DefaultWithUndock:SurfaceDefault] Stopped
2020-12-10T18:16:20.538Z,1607624180.538 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault
2020-12-10T18:16:20.538Z,1607624180.538 [DefaultWithUndock:SurfaceDefault:B.GoToSurface] Stopped
2020-12-10T18:16:20.538Z,1607624180.538 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-12-10T18:16:20.539Z,1607624180.539 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-12-10T18:16:20.539Z,1607624180.539 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-12-10T18:16:20.539Z,1607624180.539 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-12-10T18:16:20.539Z,1607624180.539 [MissionManager](IMPORTANT): Started mission profile_stationUnder
2020-12-10T18:16:20.539Z,1607624180.539 [profile_stationUnder] Running Loop=1
2020-12-10T18:16:20.539Z,1607624180.539 [profile_stationUnder](DEBUG): Aggregate::initialize profile_stationUnder
2020-12-10T18:16:20.540Z,1607624180.540 [profile_stationUnder:Science] Running Loop=1
2020-12-10T18:16:20.540Z,1607624180.540 [profile_stationUnder:Science](DEBUG): Aggregate::initialize profile_stationUnder:Science
2020-12-10T18:16:20.540Z,1607624180.540 [profile_stationUnder:Science:A] Running Loop=1
2020-12-10T18:16:20.540Z,1607624180.540 [profile_stationUnder:Science:B] Running Loop=1
2020-12-10T18:16:20.540Z,1607624180.540 [profile_stationUnder:Science:C] Running Loop=1
2020-12-10T18:16:20.540Z,1607624180.540 [profile_stationUnder:Science:D] Running Loop=1
2020-12-10T18:16:20.540Z,1607624180.540 [profile_stationUnder:Science:E] Running Loop=1
2020-12-10T18:16:20.540Z,1607624180.540 [profile_stationUnder:Science:F] Running Loop=1
2020-12-10T18:16:20.540Z,1607624180.540 [profile_stationUnder:Science:Read_Oil] Running Loop=1
2020-12-10T18:16:20.540Z,1607624180.540 [profile_stationUnder:Science:PeakDetectChl] Running Loop=1
2020-12-10T18:16:20.540Z,1607624180.540 [profile_stationUnder:Science:PeakDetectChl](DEBUG): Aggregate::initialize profile_stationUnder:Science:PeakDetectChl
2020-12-10T18:16:20.541Z,1607624180.541 [profile_stationUnder:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2020-12-10T18:16:20.541Z,1607624180.541 [profile_stationUnder:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2020-12-10T18:16:20.543Z,1607624180.543 [profile_stationUnder:Science:HighestChlPeakReport] Running Loop=1
2020-12-10T18:16:20.543Z,1607624180.543 [profile_stationUnder:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize profile_stationUnder:Science:HighestChlPeakReport
2020-12-10T18:16:20.544Z,1607624180.544 [profile_stationUnder:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2020-12-10T18:16:20.544Z,1607624180.544 [profile_stationUnder:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2020-12-10T18:16:20.544Z,1607624180.544 [profile_stationUnder:Science:PeakDetectNO3] Running Loop=1
2020-12-10T18:16:20.544Z,1607624180.544 [profile_stationUnder:Science:PeakDetectNO3](DEBUG): Aggregate::initialize profile_stationUnder:Science:PeakDetectNO3
2020-12-10T18:16:20.544Z,1607624180.544 [profile_stationUnder:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2020-12-10T18:16:20.544Z,1607624180.544 [profile_stationUnder:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2020-12-10T18:16:20.546Z,1607624180.546 [profile_stationUnder:Science:PeakDetectOil] Running Loop=1
2020-12-10T18:16:20.546Z,1607624180.546 [profile_stationUnder:Science:PeakDetectOil](DEBUG): Aggregate::initialize profile_stationUnder:Science:PeakDetectOil
2020-12-10T18:16:20.546Z,1607624180.546 [profile_stationUnder:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2020-12-10T18:16:20.547Z,1607624180.547 [profile_stationUnder:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2020-12-10T18:16:20.548Z,1607624180.548 [profile_stationUnder:Science:PeakDetectFDOM] Running Loop=1
2020-12-10T18:16:20.548Z,1607624180.548 [profile_stationUnder:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize profile_stationUnder:Science:PeakDetectFDOM
2020-12-10T18:16:20.549Z,1607624180.549 [profile_stationUnder:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1
2020-12-10T18:16:20.549Z,1607624180.549 [profile_stationUnder:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize.
2020-12-10T18:16:20.551Z,1607624180.551 [profile_stationUnder:Science:OceanCurrent] Running Loop=1
2020-12-10T18:16:20.551Z,1607624180.551 [profile_stationUnder:Science:OceanCurrent](DEBUG): Aggregate::initialize profile_stationUnder:Science:OceanCurrent
2020-12-10T18:16:20.551Z,1607624180.551 [profile_stationUnder:Science:OceanCurrent:A.] Running Loop=1
2020-12-10T18:16:20.551Z,1607624180.551 [profile_stationUnder:Science:OceanCurrent:A.](INFO): Initializing CurrentEstimator.
2020-12-10T18:16:20.551Z,1607624180.551 [profile_stationUnder:MicromodemComms] Running Loop=1
2020-12-10T18:16:20.552Z,1607624180.552 [profile_stationUnder:MicromodemComms](DEBUG): Aggregate::initialize profile_stationUnder:MicromodemComms
2020-12-10T18:16:20.552Z,1607624180.552 [profile_stationUnder:MicromodemComms:CheckIn] Running Loop=1
2020-12-10T18:16:20.552Z,1607624180.552 [profile_stationUnder:MicromodemComms:CheckIn](DEBUG): Aggregate::initialize profile_stationUnder:MicromodemComms:CheckIn
2020-12-10T18:16:20.552Z,1607624180.552 [profile_stationUnder:MicromodemComms:CheckIn:A] Running Loop=1
2020-12-10T18:16:20.552Z,1607624180.552 [profile_stationUnder:StandardEnvelopes] Running Loop=1
2020-12-10T18:16:20.552Z,1607624180.552 [profile_stationUnder:StandardEnvelopes](DEBUG): Aggregate::initialize profile_stationUnder:StandardEnvelopes
2020-12-10T18:16:20.552Z,1607624180.552 [profile_stationUnder:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2020-12-10T18:16:20.552Z,1607624180.552 [profile_stationUnder:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2020-12-10T18:16:20.553Z,1607624180.553 [profile_stationUnder:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2020-12-10T18:16:20.553Z,1607624180.553 [profile_stationUnder:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2020-12-10T18:16:20.553Z,1607624180.553 [profile_stationUnder:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2020-12-10T18:16:20.553Z,1607624180.553 [profile_stationUnder:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2020-12-10T18:16:20.553Z,1607624180.553 [profile_stationUnder:D] Running Loop=1
2020-12-10T18:16:20.554Z,1607624180.554 [profile_stationUnder:D] Stopped
2020-12-10T18:16:20.554Z,1607624180.554 [profile_stationUnder:E] Running Loop=1
2020-12-10T18:16:20.554Z,1607624180.554 [profile_stationUnder:StandardEnvelopes] Running Loop=1
2020-12-10T18:16:20.554Z,1607624180.554 [profile_stationUnder:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2020-12-10T18:16:20.554Z,1607624180.554 [profile_stationUnder:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2020-12-10T18:16:20.556Z,1607624180.556 [profile_stationUnder:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2020-12-10T18:16:20.556Z,1607624180.556 [profile_stationUnder:MicromodemComms] Running Loop=1
2020-12-10T18:16:20.557Z,1607624180.557 [profile_stationUnder:MicromodemComms:CheckIn:A](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-12-10T18:16:20.557Z,1607624180.557 [profile_stationUnder:Science] Running Loop=1
2020-12-10T18:16:20.558Z,1607624180.558 [profile_stationUnder:Science:PeakDetectFDOM] Stopped
2020-12-10T18:16:20.558Z,1607624180.558 [profile_stationUnder:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize profile_stationUnder:Science:PeakDetectFDOM
2020-12-10T18:16:20.558Z,1607624180.558 [profile_stationUnder:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped
2020-12-10T18:16:20.559Z,1607624180.559 [profile_stationUnder:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2020-12-10T18:16:20.559Z,1607624180.559 [profile_stationUnder:Science:PeakDetectOil] Stopped
2020-12-10T18:16:20.559Z,1607624180.559 [profile_stationUnder:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize profile_stationUnder:Science:PeakDetectOil
2020-12-10T18:16:20.559Z,1607624180.559 [profile_stationUnder:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2020-12-10T18:16:20.559Z,1607624180.559 [profile_stationUnder:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2020-12-10T18:16:20.559Z,1607624180.559 [profile_stationUnder:Science:PeakDetectNO3] Stopped
2020-12-10T18:16:20.559Z,1607624180.559 [profile_stationUnder:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize profile_stationUnder:Science:PeakDetectNO3
2020-12-10T18:16:20.559Z,1607624180.559 [profile_stationUnder:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2020-12-10T18:16:20.559Z,1607624180.559 [profile_stationUnder:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2020-12-10T18:16:20.560Z,1607624180.560 [profile_stationUnder:Science:HighestChlPeakReport] Stopped
2020-12-10T18:16:20.560Z,1607624180.560 [profile_stationUnder:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize profile_stationUnder:Science:HighestChlPeakReport
2020-12-10T18:16:20.560Z,1607624180.560 [profile_stationUnder:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2020-12-10T18:16:20.560Z,1607624180.560 [profile_stationUnder:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2020-12-10T18:16:20.560Z,1607624180.560 [profile_stationUnder:Science:PeakDetectChl] Running Loop=1
2020-12-10T18:16:20.560Z,1607624180.560 [profile_stationUnder:Science:OceanCurrent:A.] Running Loop=1
2020-12-10T18:16:20.562Z,1607624180.562 [profile_stationUnder:Science:Read_Oil] Running Loop=1
2020-12-10T18:16:20.563Z,1607624180.563 [profile_stationUnder:Science:Read_Oil](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2020-12-10T18:16:20.563Z,1607624180.563 [profile_stationUnder:Science:F] Stopped
2020-12-10T18:16:20.563Z,1607624180.563 [profile_stationUnder:Science:E] Running Loop=1
2020-12-10T18:16:20.564Z,1607624180.564 [profile_stationUnder:Science:E](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2020-12-10T18:16:20.564Z,1607624180.564 [profile_stationUnder:Science:D] Stopped
2020-12-10T18:16:20.564Z,1607624180.564 [profile_stationUnder:Science:C] Running Loop=1
2020-12-10T18:16:20.565Z,1607624180.565 [profile_stationUnder:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature
2020-12-10T18:16:20.565Z,1607624180.565 [profile_stationUnder:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity
2020-12-10T18:16:20.565Z,1607624180.565 [profile_stationUnder:Science:B] Running Loop=1
2020-12-10T18:16:20.566Z,1607624180.566 [profile_stationUnder:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2020-12-10T18:16:20.567Z,1607624180.567 [profile_stationUnder:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2020-12-10T18:16:20.567Z,1607624180.567 [profile_stationUnder:Science:A] Stopped
2020-12-10T18:16:20.801Z,1607624180.801 [WetLabsSeaOWL_UV_A](INFO): Powering up
2020-12-10T18:16:20.996Z,1607624180.996 [profile_stationUnder:E] Stopped
2020-12-10T18:16:20.996Z,1607624180.996 [profile_stationUnder:F] Running Loop=1
2020-12-10T18:16:21.370Z,1607624181.370 [profile_stationUnder:F] Stopped
2020-12-10T18:16:21.370Z,1607624181.370 [profile_stationUnder:Detach] Running Loop=1
2020-12-10T18:16:21.370Z,1607624181.370 [profile_stationUnder:Detach](DEBUG): Aggregate::initialize profile_stationUnder:Detach
2020-12-10T18:16:21.370Z,1607624181.370 [profile_stationUnder:Detach:B.] Running Loop=1
2020-12-10T18:16:21.370Z,1607624181.370 [profile_stationUnder:Detach:B.](INFO): Initializing TrackAcousticContact.
2020-12-10T18:16:21.370Z,1607624181.370 [profile_stationUnder:Detach:A] Running Loop=1
2020-12-10T18:16:21.748Z,1607624181.748 [profile_stationUnder:Detach:B.] Running Loop=1
2020-12-10T18:16:21.748Z,1607624181.748 [profile_stationUnder:Detach:A](IMPORTANT): Detaching from dock.
2020-12-10T18:16:21.748Z,1607624181.748 [profile_stationUnder:Detach:A] Stopped
2020-12-10T18:16:21.748Z,1607624181.748 [profile_stationUnder:Detach:C.Undock] Running Loop=1
2020-12-10T18:16:21.749Z,1607624181.749 [profile_stationUnder:Detach:C.Undock](DEBUG): Initialize.
2020-12-10T18:16:21.749Z,1607624181.749 [profile_stationUnder:Detach:C.Undock](DEBUG): Initializing internal variables to default values.
2020-12-10T18:16:24.208Z,1607624184.208 [DataOverHttps](INFO): Sending 728 bytes from file Logs/20201209T223704/Express0109.lzma
2020-12-10T18:16:24.216Z,1607624184.216 [CTD_Seabird](ERROR): Failed to parse device response: <!--startlogging-->
2020-12-10T18:16:24.272Z,1607624184.272 [profile_stationUnder:Detach:B.](INFO): *** querying acoustic contact ***
2020-12-10T18:16:25.209Z,1607624185.209 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0109.lzma.bak
2020-12-10T18:16:25.209Z,1607624185.209 [DataOverHttps](INFO): SBD MOMSN=59656
2020-12-10T18:16:25.460Z,1607624185.460 [profile_stationUnder:Detach:C.Undock](INFO): Detaching from dock.
2020-12-10T18:16:25.816Z,1607624185.816 [profile_stationUnder:Detach:C.Undock](INFO): Detected possible detachment. Starting timer.
2020-12-10T18:16:27.064Z,1607624187.064 [profile_stationUnder:Detach:B.](INFO): *** querying acoustic contact ***
2020-12-10T18:16:28.289Z,1607624188.289 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-12-10T18:16:29.903Z,1607624189.903 [profile_stationUnder:Detach:B.](INFO): *** querying acoustic contact ***
2020-12-10T18:16:32.689Z,1607624192.689 [profile_stationUnder:Detach:B.](INFO): *** querying acoustic contact ***
2020-12-10T18:16:34.284Z,1607624194.284 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-12-10T18:16:35.516Z,1607624195.516 [profile_stationUnder:Detach:B.](INFO): *** querying acoustic contact ***
2020-12-10T18:16:38.017Z,1607624198.017 [profile_stationUnder:Detach:B.](INFO): *** querying acoustic contact ***
2020-12-10T18:16:39.943Z,1607624199.943 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-12-10T18:16:40.765Z,1607624200.765 [profile_stationUnder:Detach:B.](INFO): *** querying acoustic contact ***
2020-12-10T18:16:43.602Z,1607624203.602 [profile_stationUnder:Detach:B.](INFO): *** querying acoustic contact ***
2020-12-10T18:16:45.189Z,1607624205.189 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-12-10T18:16:46.038Z,1607624206.038 [profile_stationUnder:Detach:C.Undock](INFO): Detached at range: nan m. Transitioning DDM to standby.
2020-12-10T18:16:46.438Z,1607624206.438 [profile_stationUnder:Detach:B.](INFO): *** querying acoustic contact ***
2020-12-10T18:16:48.904Z,1607624208.904 [profile_stationUnder:Detach:C.Undock](INFO): DDM at standby.
2020-12-10T18:16:49.280Z,1607624209.280 [profile_stationUnder:Detach:C.Undock](IMPORTANT): Undocking sequence complete.
2020-12-10T18:16:49.280Z,1607624209.280 [profile_stationUnder:Detach:C.Undock] Stopped
2020-12-10T18:16:49.280Z,1607624209.280 [profile_stationUnder:Detach:B.](INFO): *** querying acoustic contact ***
2020-12-10T18:16:49.281Z,1607624209.281 [profile_stationUnder:Detach](INFO): Completed profile_stationUnder:Detach
2020-12-10T18:16:49.281Z,1607624209.281 [profile_stationUnder:Detach] Stopped
2020-12-10T18:16:49.281Z,1607624209.281 [profile_stationUnder:Detach](DEBUG): Aggregate::uninitialize profile_stationUnder:Detach
2020-12-10T18:16:49.281Z,1607624209.281 [profile_stationUnder:Detach:B.] Stopped
2020-12-10T18:16:49.281Z,1607624209.281 [profile_stationUnder:ProfileStation] Running Loop=1
2020-12-10T18:16:49.281Z,1607624209.281 [profile_stationUnder:ProfileStation](DEBUG): Aggregate::initialize profile_stationUnder:ProfileStation
2020-12-10T18:16:49.281Z,1607624209.281 [profile_stationUnder:ProfileStation:A.Pitch] Running Loop=1
2020-12-10T18:16:49.281Z,1607624209.281 [profile_stationUnder:ProfileStation:A.Pitch](DEBUG): Initialize.
2020-12-10T18:16:49.281Z,1607624209.281 [profile_stationUnder:ProfileStation:B.Buoyancy] Running Loop=1
2020-12-10T18:16:49.282Z,1607624209.282 [profile_stationUnder:ProfileStation:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2020-12-10T18:16:49.282Z,1607624209.282 [profile_stationUnder:ProfileStation:C.SetSpeed] Running Loop=1
2020-12-10T18:16:49.282Z,1607624209.282 [profile_stationUnder:ProfileStation:C.SetSpeed](DEBUG): Initialize.
2020-12-10T18:16:49.282Z,1607624209.282 [profile_stationUnder:ProfileStation:D.DepthEnvelope] Running Loop=1
2020-12-10T18:16:49.282Z,1607624209.282 [profile_stationUnder:ProfileStation:D.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2020-12-10T18:16:49.282Z,1607624209.282 [profile_stationUnder:ProfileStation:E.AltitudeEnvelope] Running Loop=1
2020-12-10T18:16:49.282Z,1607624209.282 [profile_stationUnder:ProfileStation:E.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2020-12-10T18:16:49.282Z,1607624209.282 [profile_stationUnder:ProfileStation:F.YoYo] Running Loop=1
2020-12-10T18:16:49.282Z,1607624209.282 [profile_stationUnder:ProfileStation:F.YoYo](DEBUG): Initialize YoYoComponent.
2020-12-10T18:16:49.283Z,1607624209.283 [profile_stationUnder:ProfileStation:CircleWrapper] Running Loop=1
2020-12-10T18:16:49.283Z,1607624209.283 [profile_stationUnder:ProfileStation:CircleWrapper](DEBUG): Aggregate::initialize profile_stationUnder:ProfileStation:CircleWrapper
2020-12-10T18:16:49.283Z,1607624209.283 [profile_stationUnder:ProfileStation:CircleWrapper:A] Running Loop=1
2020-12-10T18:16:49.283Z,1607624209.283 [profile_stationUnder:ProfileStation:CircleWrapper:B.Circle] Running Loop=1
2020-12-10T18:16:49.283Z,1607624209.283 [profile_stationUnder:ProfileStation:CircleWrapper:B.Circle](DEBUG): Initialize CircleComponent.
2020-12-10T18:16:49.652Z,1607624209.652 [profile_stationUnder:ProfileStation:CircleWrapper:A] Running Loop=1
2020-12-10T18:16:49.652Z,1607624209.652 [profile_stationUnder:ProfileStation:F.YoYo] Running Loop=1
2020-12-10T18:16:49.653Z,1607624209.653 [profile_stationUnder:ProfileStation:E.AltitudeEnvelope] Running Loop=1
2020-12-10T18:16:49.653Z,1607624209.653 [profile_stationUnder:ProfileStation:D.DepthEnvelope] Running Loop=1
2020-12-10T18:16:49.654Z,1607624209.654 [profile_stationUnder:ProfileStation:C.SetSpeed] Running Loop=1
2020-12-10T18:16:49.654Z,1607624209.654 [profile_stationUnder:ProfileStation:B.Buoyancy] Running Loop=1
2020-12-10T18:16:49.654Z,1607624209.654 [profile_stationUnder:ProfileStation:A.Pitch] Running Loop=1
2020-12-10T18:16:54.919Z,1607624214.919 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2020-12-10T18:17:51.996Z,1607624271.996 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-12-10T18:17:54.623Z,1607624274.623 [DataOverHttps](INFO): Sending 55 bytes from file Logs/20201210T180318/Courier0009.lzma
2020-12-10T18:17:55.625Z,1607624275.625 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Courier0009.lzma.bak
2020-12-10T18:17:55.625Z,1607624275.625 [DataOverHttps](INFO): SBD MOMSN=59658
2020-12-10T18:18:05.668Z,1607624285.668 [DataOverHttps](INFO): Sending 53 bytes from file Logs/20201210T180318/Courier0013.lzma
2020-12-10T18:18:06.669Z,1607624286.669 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Courier0013.lzma.bak
2020-12-10T18:18:06.669Z,1607624286.669 [DataOverHttps](INFO): SBD MOMSN=59660
2020-12-10T18:18:10.551Z,1607624290.551 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch -15.00 deg, mass-position -0.36 mm (1 active estimators).
2020-12-10T18:18:21.452Z,1607624301.452 [Micromodem](INFO): Sent 53 bytes from file Logs/20201210T180318/Courier0016.lzma.parts
2020-12-10T18:18:21.452Z,1607624301.452 [Micromodem](INFO): Packets left to send: 0
2020-12-10T18:18:21.947Z,1607624301.947 [profile_stationUnder:MicromodemComms] Stopped
2020-12-10T18:18:21.947Z,1607624301.947 [profile_stationUnder:MicromodemComms](DEBUG): Aggregate::uninitialize profile_stationUnder:MicromodemComms
2020-12-10T18:18:21.947Z,1607624301.947 [profile_stationUnder:MicromodemComms:CheckIn] Stopped
2020-12-10T18:18:21.947Z,1607624301.947 [profile_stationUnder:MicromodemComms:CheckIn](DEBUG): Aggregate::uninitialize profile_stationUnder:MicromodemComms:CheckIn
2020-12-10T18:18:21.947Z,1607624301.947 [profile_stationUnder:MicromodemComms:CheckIn:A] Stopped
2020-12-10T18:18:38.893Z,1607624318.893 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 15.00 deg, mass-position -0.36 mm (2 active estimators).
2020-12-10T18:18:52.985Z,1607624332.985 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2020-12-10T18:19:06.916Z,1607624346.916 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.247440
2020-12-10T18:19:10.895Z,1607624350.895 [Radio_Surface](INFO): Powering down
2020-12-10T18:19:10.932Z,1607624350.932 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2020-12-10T18:20:04.917Z,1607624404.917 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2020-12-10T18:20:10.146Z,1607624410.146 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2020-12-10T18:20:25.107Z,1607624425.107 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2020-12-10T18:20:29.939Z,1607624429.939 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2020-12-10T18:20:34.879Z,1607624434.879 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2020-12-10T18:20:38.869Z,1607624438.869 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2020-12-10T18:20:39.265Z,1607624439.265 [CTD_Seabird](ERROR): Failed to parse device response: .92
2020-12-10T18:20:40.037Z,1607624440.037 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-12-10T18:20:40.041Z,1607624440.041 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2020-12-10T18:20:46.107Z,1607624446.107 [RDI_PathfinderUp](ERROR): only read 1 of 4 data items
2020-12-10T18:20:54.993Z,1607624454.993 [RDI_PathfinderUp](ERROR): only read 0 of 4 data items
2020-12-10T18:21:01.918Z,1607624461.918 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2020-12-10T18:21:05.093Z,1607624465.093 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude
2020-12-10T18:21:35.003Z,1607624495.003 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-12-10T18:21:55.185Z,1607624515.185 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-12-10T18:22:00.040Z,1607624520.040 [RDI_Pathfinder](ERROR): only read 1 of 4 data items
2020-12-10T18:22:04.898Z,1607624524.898 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-12-10T18:22:10.138Z,1607624530.138 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2020-12-10T18:22:21.054Z,1607624541.054 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2020-12-10T18:22:35.180Z,1607624555.180 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2020-12-10T18:23:22.076Z,1607624602.076 [profile_stationUnder:MicromodemComms] Running Loop=1
2020-12-10T18:23:22.076Z,1607624602.076 [profile_stationUnder:MicromodemComms](DEBUG): Aggregate::initialize profile_stationUnder:MicromodemComms
2020-12-10T18:23:22.076Z,1607624602.076 [profile_stationUnder:MicromodemComms:CheckIn] Running Loop=1
2020-12-10T18:23:22.076Z,1607624602.076 [profile_stationUnder:MicromodemComms:CheckIn](DEBUG): Aggregate::initialize profile_stationUnder:MicromodemComms:CheckIn
2020-12-10T18:23:22.077Z,1607624602.077 [profile_stationUnder:MicromodemComms:CheckIn:A] Running Loop=1
2020-12-10T18:23:30.126Z,1607624610.126 [Micromodem](INFO): Sent 53 bytes from file Logs/20201210T180318/Courier0019.lzma.parts
2020-12-10T18:23:30.126Z,1607624610.126 [Micromodem](INFO): Packets left to send: 0
2020-12-10T18:23:30.666Z,1607624610.666 [profile_stationUnder:MicromodemComms] Stopped
2020-12-10T18:23:30.666Z,1607624610.666 [profile_stationUnder:MicromodemComms](DEBUG): Aggregate::uninitialize profile_stationUnder:MicromodemComms
2020-12-10T18:23:30.666Z,1607624610.666 [profile_stationUnder:MicromodemComms:CheckIn] Stopped
2020-12-10T18:23:30.666Z,1607624610.666 [profile_stationUnder:MicromodemComms:CheckIn](DEBUG): Aggregate::uninitialize profile_stationUnder:MicromodemComms:CheckIn
2020-12-10T18:23:30.666Z,1607624610.666 [profile_stationUnder:MicromodemComms:CheckIn:A] Stopped
2020-12-10T18:24:01.249Z,1607624641.249 [NAL9602](INFO): Not Powering down - fast GPS
2020-12-10T18:26:40.422Z,1607624800.422 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2020-12-10T18:28:30.733Z,1607624910.733 [profile_stationUnder:MicromodemComms] Running Loop=1
2020-12-10T18:28:30.733Z,1607624910.733 [profile_stationUnder:MicromodemComms](DEBUG): Aggregate::initialize profile_stationUnder:MicromodemComms
2020-12-10T18:28:30.733Z,1607624910.733 [profile_stationUnder:MicromodemComms:CheckIn] Running Loop=1
2020-12-10T18:28:30.733Z,1607624910.733 [profile_stationUnder:MicromodemComms:CheckIn](DEBUG): Aggregate::initialize profile_stationUnder:MicromodemComms:CheckIn
2020-12-10T18:28:30.733Z,1607624910.733 [profile_stationUnder:MicromodemComms:CheckIn:A] Running Loop=1
2020-12-10T18:29:36.170Z,1607624976.170 [Micromodem](ERROR): Buffer fill timout failure.
2020-12-10T18:30:41.629Z,1607625041.629 [Micromodem](ERROR): Buffer fill timout failure.
2020-12-10T18:30:49.304Z,1607625049.304 [Micromodem](INFO): Sent 53 bytes from file Logs/20201210T180318/Courier0022.lzma.parts
2020-12-10T18:30:49.304Z,1607625049.304 [Micromodem](INFO): Packets left to send: 0
2020-12-10T18:30:49.873Z,1607625049.873 [profile_stationUnder:MicromodemComms] Stopped
2020-12-10T18:30:49.873Z,1607625049.873 [profile_stationUnder:MicromodemComms](DEBUG): Aggregate::uninitialize profile_stationUnder:MicromodemComms
2020-12-10T18:30:49.874Z,1607625049.874 [profile_stationUnder:MicromodemComms:CheckIn] Stopped
2020-12-10T18:30:49.874Z,1607625049.874 [profile_stationUnder:MicromodemComms:CheckIn](DEBUG): Aggregate::uninitialize profile_stationUnder:MicromodemComms:CheckIn
2020-12-10T18:30:49.874Z,1607625049.874 [profile_stationUnder:MicromodemComms:CheckIn:A] Stopped
2020-12-10T18:31:23.643Z,1607625083.643 [NAL9602](INFO): Not Powering down - fast GPS
2020-12-10T18:35:49.925Z,1607625349.925 [profile_stationUnder:MicromodemComms] Running Loop=1
2020-12-10T18:35:49.925Z,1607625349.925 [profile_stationUnder:MicromodemComms](DEBUG): Aggregate::initialize profile_stationUnder:MicromodemComms
2020-12-10T18:35:49.925Z,1607625349.925 [profile_stationUnder:MicromodemComms:CheckIn] Running Loop=1
2020-12-10T18:35:49.926Z,1607625349.926 [profile_stationUnder:MicromodemComms:CheckIn](DEBUG): Aggregate::initialize profile_stationUnder:MicromodemComms:CheckIn
2020-12-10T18:35:49.926Z,1607625349.926 [profile_stationUnder:MicromodemComms:CheckIn:A] Running Loop=1
2020-12-10T18:36:20.692Z,1607625380.692 [profile_stationUnder](INFO): Timed out from 2020-12-10T18:16:20.5Z
2020-12-10T18:36:20.692Z,1607625380.692 [MissionManager](INFO): profile_stationUnder is completed.
2020-12-10T18:36:20.692Z,1607625380.692 [MissionManager](INFO): Uninitializing Mission profile_stationUnder
2020-12-10T18:36:20.692Z,1607625380.692 [profile_stationUnder] Stopped
2020-12-10T18:36:20.692Z,1607625380.692 [profile_stationUnder](DEBUG): Aggregate::uninitialize profile_stationUnder
2020-12-10T18:36:20.692Z,1607625380.692 [profile_stationUnder:Science] Stopped
2020-12-10T18:36:20.692Z,1607625380.692 [profile_stationUnder:Science](DEBUG): Aggregate::uninitialize profile_stationUnder:Science
2020-12-10T18:36:20.692Z,1607625380.692 [profile_stationUnder:Science:B] Stopped
2020-12-10T18:36:20.692Z,1607625380.692 [profile_stationUnder:Science:C] Stopped
2020-12-10T18:36:20.693Z,1607625380.693 [profile_stationUnder:Science:E] Stopped
2020-12-10T18:36:20.693Z,1607625380.693 [profile_stationUnder:Science:Read_Oil] Stopped
2020-12-10T18:36:20.693Z,1607625380.693 [profile_stationUnder:Science:OceanCurrent] Stopped
2020-12-10T18:36:20.693Z,1607625380.693 [profile_stationUnder:Science:OceanCurrent](DEBUG): Aggregate::uninitialize profile_stationUnder:Science:OceanCurrent
2020-12-10T18:36:20.693Z,1607625380.693 [profile_stationUnder:Science:OceanCurrent:A.] Stopped
2020-12-10T18:36:20.693Z,1607625380.693 [profile_stationUnder:Science:PeakDetectChl] Stopped
2020-12-10T18:36:20.693Z,1607625380.693 [profile_stationUnder:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize profile_stationUnder:Science:PeakDetectChl
2020-12-10T18:36:20.693Z,1607625380.693 [profile_stationUnder:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2020-12-10T18:36:20.693Z,1607625380.693 [profile_stationUnder:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2020-12-10T18:36:20.693Z,1607625380.693 [profile_stationUnder:MicromodemComms] Stopped
2020-12-10T18:36:20.693Z,1607625380.693 [profile_stationUnder:MicromodemComms](DEBUG): Aggregate::uninitialize profile_stationUnder:MicromodemComms
2020-12-10T18:36:20.693Z,1607625380.693 [profile_stationUnder:MicromodemComms:CheckIn] Stopped
2020-12-10T18:36:20.693Z,1607625380.693 [profile_stationUnder:MicromodemComms:CheckIn](DEBUG): Aggregate::uninitialize profile_stationUnder:MicromodemComms:CheckIn
2020-12-10T18:36:20.694Z,1607625380.694 [profile_stationUnder:MicromodemComms:CheckIn:A] Stopped
2020-12-10T18:36:20.694Z,1607625380.694 [profile_stationUnder:StandardEnvelopes] Stopped
2020-12-10T18:36:20.694Z,1607625380.694 [profile_stationUnder:StandardEnvelopes](DEBUG): Aggregate::uninitialize profile_stationUnder:StandardEnvelopes
2020-12-10T18:36:20.694Z,1607625380.694 [profile_stationUnder:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2020-12-10T18:36:20.694Z,1607625380.694 [profile_stationUnder:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2020-12-10T18:36:20.694Z,1607625380.694 [profile_stationUnder:StandardEnvelopes:B.DepthEnvelope] Stopped
2020-12-10T18:36:20.694Z,1607625380.694 [profile_stationUnder:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2020-12-10T18:36:20.694Z,1607625380.694 [profile_stationUnder:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2020-12-10T18:36:20.694Z,1607625380.694 [profile_stationUnder:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2020-12-10T18:36:20.694Z,1607625380.694 [profile_stationUnder:ProfileStation] Stopped
2020-12-10T18:36:20.694Z,1607625380.694 [profile_stationUnder:ProfileStation](DEBUG): Aggregate::uninitialize profile_stationUnder:ProfileStation
2020-12-10T18:36:20.694Z,1607625380.694 [profile_stationUnder:ProfileStation:A.Pitch] Stopped
2020-12-10T18:36:20.694Z,1607625380.694 [profile_stationUnder:ProfileStation:B.Buoyancy] Stopped
2020-12-10T18:36:20.695Z,1607625380.694 [profile_stationUnder:ProfileStation:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2020-12-10T18:36:20.695Z,1607625380.695 [profile_stationUnder:ProfileStation:C.SetSpeed] Stopped
2020-12-10T18:36:20.695Z,1607625380.695 [profile_stationUnder:ProfileStation:C.SetSpeed](DEBUG): Uninitialize.
2020-12-10T18:36:20.695Z,1607625380.695 [profile_stationUnder:ProfileStation:D.DepthEnvelope] Stopped
2020-12-10T18:36:20.695Z,1607625380.695 [profile_stationUnder:ProfileStation:D.DepthEnvelope](DEBUG): Uninitialize.
2020-12-10T18:36:20.695Z,1607625380.695 [profile_stationUnder:ProfileStation:E.AltitudeEnvelope] Stopped
2020-12-10T18:36:20.695Z,1607625380.695 [profile_stationUnder:ProfileStation:E.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2020-12-10T18:36:20.695Z,1607625380.695 [profile_stationUnder:ProfileStation:F.YoYo] Stopped
2020-12-10T18:36:20.695Z,1607625380.695 [profile_stationUnder:ProfileStation:F.YoYo](DEBUG): Uninitialize YoYoComponent.
2020-12-10T18:36:20.695Z,1607625380.695 [profile_stationUnder:ProfileStation:CircleWrapper] Stopped
2020-12-10T18:36:20.696Z,1607625380.696 [profile_stationUnder:ProfileStation:CircleWrapper](DEBUG): Aggregate::uninitialize profile_stationUnder:ProfileStation:CircleWrapper
2020-12-10T18:36:20.696Z,1607625380.696 [profile_stationUnder:ProfileStation:CircleWrapper:A] Stopped
2020-12-10T18:36:20.696Z,1607625380.696 [profile_stationUnder:ProfileStation:CircleWrapper:B.Circle] Stopped
2020-12-10T18:36:20.696Z,1607625380.696 [profile_stationUnder:ProfileStation:CircleWrapper:B.Circle](DEBUG): Uninitialize.
2020-12-10T18:36:20.912Z,1607625380.912 [WetLabsSeaOWL_UV_A](INFO): Powering down
2020-12-10T18:36:21.111Z,1607625381.111 [MissionManager](IMPORTANT): Started mission DefaultWithUndock
2020-12-10T18:36:21.115Z,1607625381.115 [DefaultWithUndock] Running Loop=1
2020-12-10T18:36:21.115Z,1607625381.115 [DefaultWithUndock](DEBUG): Aggregate::initialize DefaultWithUndock
2020-12-10T18:36:21.116Z,1607625381.116 [DefaultWithUndock:A.Wait] Running Loop=1
2020-12-10T18:36:21.116Z,1607625381.116 [DefaultWithUndock:A.Wait](DEBUG): Initialize Wait Component.
2020-12-10T18:36:51.375Z,1607625411.375 [DefaultWithUndock:A.Wait](INFO): Done Waiting.
2020-12-10T18:36:51.376Z,1607625411.376 [DefaultWithUndock:A.Wait] Stopped
2020-12-10T18:36:51.376Z,1607625411.376 [DefaultWithUndock:A.Wait](DEBUG): Uninitialize Wait Component.
2020-12-10T18:36:51.376Z,1607625411.376 [DefaultWithUndock:LeaveDock] Running Loop=1
2020-12-10T18:36:51.376Z,1607625411.376 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::initialize DefaultWithUndock:LeaveDock
2020-12-10T18:36:51.376Z,1607625411.376 [DefaultWithUndock:LeaveDock:A.] Running Loop=1
2020-12-10T18:36:51.376Z,1607625411.376 [DefaultWithUndock:LeaveDock:A.](INFO): Initializing TrackAcousticContact.
2020-12-10T18:36:51.377Z,1607625411.377 [DefaultWithUndock:LeaveDock:B.Undock] Running Loop=1
2020-12-10T18:36:51.377Z,1607625411.377 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize.
2020-12-10T18:36:51.377Z,1607625411.377 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values.
2020-12-10T18:36:53.023Z,1607625413.023 [NAL9602](INFO): Not Powering down - fast GPS
2020-12-10T18:36:53.912Z,1607625413.912 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-10T18:36:55.120Z,1607625415.120 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detaching from dock.
2020-12-10T18:36:55.440Z,1607625415.440 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Engaging thruster for 10.0 seconds (max) to disengage.
2020-12-10T18:36:56.679Z,1607625416.679 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Thruster off.
2020-12-10T18:36:57.101Z,1607625417.101 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detected possible detachment. Starting timer.
2020-12-10T18:36:59.103Z,1607625419.103 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-10T18:37:04.341Z,1607625424.341 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-10T18:37:09.584Z,1607625429.584 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-10T18:37:14.893Z,1607625434.893 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-10T18:37:17.280Z,1607625437.280 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached at range: 673.92 m. Transitioning DDM to standby.
2020-12-10T18:37:20.141Z,1607625440.141 [DefaultWithUndock:LeaveDock:B.Undock](INFO): DDM at standby.
2020-12-10T18:37:20.141Z,1607625440.141 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-10T18:37:20.505Z,1607625440.505 [DefaultWithUndock:LeaveDock:B.Undock](IMPORTANT): Undocking sequence complete.
2020-12-10T18:37:20.505Z,1607625440.505 [DefaultWithUndock:LeaveDock:B.Undock] Stopped
2020-12-10T18:37:20.506Z,1607625440.506 [DefaultWithUndock:LeaveDock](INFO): Completed DefaultWithUndock:LeaveDock
2020-12-10T18:37:20.506Z,1607625440.506 [DefaultWithUndock:LeaveDock] Stopped
2020-12-10T18:37:20.506Z,1607625440.506 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::uninitialize DefaultWithUndock:LeaveDock
2020-12-10T18:37:20.506Z,1607625440.506 [DefaultWithUndock:LeaveDock:A.] Stopped
2020-12-10T18:37:20.506Z,1607625440.506 [DefaultWithUndock:SurfaceDefault] Running Loop=1
2020-12-10T18:37:20.506Z,1607625440.506 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault
2020-12-10T18:37:20.506Z,1607625440.506 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen] Running Loop=1
2020-12-10T18:37:20.506Z,1607625440.506 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:HoldLatchOpen
2020-12-10T18:37:20.506Z,1607625440.506 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:A] Running Loop=1
2020-12-10T18:37:20.506Z,1607625440.506 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:B] Running Loop=1
2020-12-10T18:37:20.506Z,1607625440.506 [DefaultWithUndock:SurfaceDefault:B.GoToSurface] Running Loop=1
2020-12-10T18:37:20.506Z,1607625440.506 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-12-10T18:37:20.507Z,1607625440.507 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-12-10T18:37:20.507Z,1607625440.507 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-12-10T18:37:20.508Z,1607625440.508 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-12-10T18:37:20.508Z,1607625440.508 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-12-10T18:37:20.508Z,1607625440.508 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-12-10T18:37:20.922Z,1607625440.922 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen] Running Loop=1
2020-12-10T18:37:20.923Z,1607625440.923 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:B] Running Loop=1
2020-12-10T18:37:20.923Z,1607625440.923 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:A] Running Loop=1
2020-12-10T18:37:20.924Z,1607625440.924 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:A](DEBUG): Initialize ReadDataComponent to sense DDM.DDMMode
2020-12-10T18:37:21.296Z,1607625441.296 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 30.00 deg, mass-position -24.00 mm (3 active estimators).
2020-12-10T18:37:21.387Z,1607625441.387 [Radio_Surface](INFO): Powering up
2020-12-10T18:37:27.432Z,1607625447.432 [DataOverHttps](INFO): Radio surface powered ON.
2020-12-10T18:37:49.192Z,1607625469.192 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=1
2020-12-10T18:37:49.192Z,1607625469.192 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-12-10T18:37:49.192Z,1607625469.192 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-12-10T18:37:49.192Z,1607625469.192 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen] Stopped
2020-12-10T18:37:49.192Z,1607625469.192 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:HoldLatchOpen
2020-12-10T18:37:49.192Z,1607625469.192 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:A] Stopped
2020-12-10T18:37:49.192Z,1607625469.192 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:B] Stopped
2020-12-10T18:37:51.208Z,1607625471.208 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-12-10T18:37:57.575Z,1607625477.575 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-12-10T18:38:18.627Z,1607625498.627 [NAL9602](INFO): SBD MO Status=0, MOMSN=12202, MT Status=0, MTMSN=0
2020-12-10T18:38:18.627Z,1607625498.627 [NAL9602](INFO): No messages in MT queue
2020-12-10T18:38:19.841Z,1607625499.841 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183818.00,A,4133.38231,N,07042.86547,W,0.350,313.32,101220,,,A*76
2020-12-10T18:38:19.843Z,1607625499.843 [NAL9602](INFO): GPS fix at 20201210T183818: (41.556372, -70.714425)
2020-12-10T18:38:19.914Z,1607625499.914 [UniversalFixResidualReporter](INFO): Fix residual: 2.1 %DT, over the last 931.5 m. Residual distance 19.5 m at bearing -1.7 degrees. Fix at (41.5564, -70.7144) with 111.0 m made good.
2020-12-10T18:38:19.919Z,1607625499.919 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-12-10T18:38:19.919Z,1607625499.919 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-12-10T18:38:20.642Z,1607625500.642 [Micromodem](ERROR): Buffer fill timout failure.
2020-12-10T18:38:32.715Z,1607625512.715 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-12-10T18:38:44.620Z,1607625524.620 [NAL9602](INFO): SBD MO Status=1, MOMSN=12203, MT Status=0, MTMSN=0
2020-12-10T18:38:44.671Z,1607625524.671 [NAL9602](INFO): Sent 53 bytes from file Logs/20201210T180318/Courier0025.lzma
2020-12-10T18:38:44.672Z,1607625524.672 [NAL9602](INFO): Packets left to send: 0
2020-12-10T18:39:02.109Z,1607625542.109 [NAL9602](INFO): SBD MO Status=2, MOMSN=12204, MT Status=2, MTMSN=0
2020-12-10T18:39:02.109Z,1607625542.109 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-12-10T18:39:07.857Z,1607625547.857 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-12-10T18:39:22.813Z,1607625562.813 [NAL9602](INFO): SBD MO Status=1, MOMSN=12204, MT Status=0, MTMSN=0
2020-12-10T18:39:22.857Z,1607625562.857 [NAL9602](INFO): Sent 184 bytes from file Logs/20201210T180318/Courier0028.lzma
2020-12-10T18:39:22.858Z,1607625562.858 [NAL9602](INFO): Packets left to send: 1
2020-12-10T18:39:42.996Z,1607625582.996 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-12-10T18:39:45.187Z,1607625585.187 [NAL9602](INFO): SBD MO Status=1, MOMSN=12205, MT Status=0, MTMSN=0
2020-12-10T18:39:45.235Z,1607625585.235 [NAL9602](INFO): Sent 29 bytes from file Logs/20201210T180318/Courier0028.lzma
2020-12-10T18:39:45.236Z,1607625585.236 [NAL9602](INFO): Packets left to send: 0
2020-12-10T18:39:56.231Z,1607625596.231 [NAL9602](INFO): SBD MO Status=1, MOMSN=12206, MT Status=0, MTMSN=0
2020-12-10T18:39:56.279Z,1607625596.279 [NAL9602](INFO): Sent 184 bytes from file Logs/20201209T223704/Express0112.lzma
2020-12-10T18:39:56.280Z,1607625596.280 [NAL9602](INFO): Packets left to send: 4
2020-12-10T18:40:09.305Z,1607625609.305 [NAL9602](INFO): SBD MO Status=1, MOMSN=12207, MT Status=0, MTMSN=0
2020-12-10T18:40:09.359Z,1607625609.359 [NAL9602](INFO): Sent 184 bytes from file Logs/20201209T223704/Express0112.lzma
2020-12-10T18:40:09.360Z,1607625609.360 [NAL9602](INFO): Packets left to send: 3
2020-12-10T18:40:18.139Z,1607625618.139 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-12-10T18:40:21.136Z,1607625621.136 [NAL9602](INFO): SBD MO Status=1, MOMSN=12208, MT Status=0, MTMSN=0
2020-12-10T18:40:21.187Z,1607625621.187 [NAL9602](INFO): Sent 184 bytes from file Logs/20201209T223704/Express0112.lzma
2020-12-10T18:40:21.188Z,1607625621.188 [NAL9602](INFO): Packets left to send: 2
2020-12-10T18:40:30.152Z,1607625630.152 [NAL9602](INFO): SBD MO Status=1, MOMSN=12209, MT Status=0, MTMSN=0
2020-12-10T18:40:30.201Z,1607625630.201 [NAL9602](INFO): Sent 184 bytes from file Logs/20201209T223704/Express0112.lzma
2020-12-10T18:40:30.201Z,1607625630.201 [NAL9602](INFO): Packets left to send: 1
2020-12-10T18:40:42.001Z,1607625642.001 [NAL9602](INFO): SBD MO Status=1, MOMSN=12210, MT Status=0, MTMSN=0
2020-12-10T18:40:42.047Z,1607625642.047 [NAL9602](INFO): Sent 6 bytes from file Logs/20201209T223704/Express0112.lzma
2020-12-10T18:40:42.048Z,1607625642.048 [NAL9602](INFO): Packets left to send: 0
2020-12-10T18:40:47.272Z,1607625647.272 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003172
2020-12-10T18:40:50.254Z,1607625650.254 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2020-12-10T18:40:51.289Z,1607625651.289 [DataOverHttps](INFO): Sending 880 bytes from file Logs/20201209T223704/Express0115.lzma
2020-12-10T18:40:52.289Z,1607625652.289 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0115.lzma.bak
2020-12-10T18:40:52.289Z,1607625652.289 [DataOverHttps](INFO): SBD MOMSN=59679
2020-12-10T18:40:53.075Z,1607625653.075 [NAL9602](INFO): SBD MO Status=1, MOMSN=12211, MT Status=0, MTMSN=0
2020-12-10T18:40:53.122Z,1607625653.122 [NAL9602](INFO): Sent 184 bytes from file Logs/20201209T223704/Express0115.lzma
2020-12-10T18:40:53.122Z,1607625653.122 [NAL9602](INFO): Packets left to send: 4
2020-12-10T18:41:23.778Z,1607625683.778 [NAL9602](INFO): Not Powering down - fast GPS
2020-12-10T18:41:37.957Z,1607625697.957 [RDI_Pathfinder](ERROR): only read 1 of 4 data items
2020-12-10T18:41:56.134Z,1607625716.134 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-12-10T18:42:11.069Z,1607625731.069 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-12-10T18:42:11.076Z,1607625731.076 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items
2020-12-10T18:42:21.649Z,1607625741.649 [DataOverHttps](INFO): Sending 1126 bytes from file Logs/20201209T223704/Express0118.lzma
2020-12-10T18:42:22.649Z,1607625742.649 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0118.lzma.bak
2020-12-10T18:42:22.649Z,1607625742.649 [DataOverHttps](INFO): SBD MOMSN=59685
2020-12-10T18:42:26.022Z,1607625746.022 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2020-12-10T18:42:36.118Z,1607625756.118 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2020-12-10T18:42:40.987Z,1607625760.987 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout
2020-12-10T18:42:40.987Z,1607625760.987 [RDI_Pathfinder] Communications Fault, FailCount= 1
2020-12-10T18:42:40.987Z,1607625760.987 [RDI_Pathfinder](ERROR): Communications Fault
2020-12-10T18:42:41.013Z,1607625761.013 [RDI_PathfinderUp](ERROR): only read 0 of 4 data items
2020-12-10T18:42:41.059Z,1607625761.059 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2020-12-10T18:42:41.451Z,1607625761.451 [RDI_Pathfinder](INFO): Powering down
2020-12-10T18:42:42.233Z,1607625762.233 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2020-12-10T18:42:42.233Z,1607625762.233 [RDI_Pathfinder] No Fault, FailCount= 1
2020-12-10T18:45:07.343Z,1607625907.343 [DataOverHttps](INFO): Sending 1312 bytes from file Logs/20201209T223704/Express0121.lzma
2020-12-10T18:45:08.341Z,1607625908.341 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0121.lzma.bak
2020-12-10T18:45:08.341Z,1607625908.341 [DataOverHttps](INFO): SBD MOMSN=59688
2020-12-10T18:46:37.735Z,1607625997.735 [DataOverHttps](INFO): Sending 1529 bytes from file Logs/20201209T223704/Express0124.lzma
2020-12-10T18:46:38.733Z,1607625998.733 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0124.lzma.bak
2020-12-10T18:46:38.733Z,1607625998.733 [DataOverHttps](INFO): SBD MOMSN=59690
2020-12-10T18:48:09.148Z,1607626089.148 [DataOverHttps](INFO): Sending 1028 bytes from file Logs/20201209T223704/Express0127.lzma
2020-12-10T18:48:10.149Z,1607626090.149 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0127.lzma.bak
2020-12-10T18:48:10.149Z,1607626090.149 [DataOverHttps](INFO): SBD MOMSN=59692
2020-12-10T18:49:39.525Z,1607626179.525 [DataOverHttps](INFO): Sending 1116 bytes from file Logs/20201209T223704/Express0130.lzma
2020-12-10T18:49:40.526Z,1607626180.526 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0130.lzma.bak
2020-12-10T18:49:40.526Z,1607626180.526 [DataOverHttps](INFO): SBD MOMSN=59694
2020-12-10T18:51:09.885Z,1607626269.885 [DataOverHttps](INFO): Sending 1341 bytes from file Logs/20201209T223704/Express0133.lzma
2020-12-10T18:51:10.885Z,1607626270.885 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0133.lzma.bak
2020-12-10T18:51:10.886Z,1607626270.886 [DataOverHttps](INFO): SBD MOMSN=59696
2020-12-10T18:52:40.256Z,1607626360.256 [DataOverHttps](INFO): Sending 882 bytes from file Logs/20201209T223704/Express0136.lzma
2020-12-10T18:52:41.257Z,1607626361.257 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0136.lzma.bak
2020-12-10T18:52:41.257Z,1607626361.257 [DataOverHttps](INFO): SBD MOMSN=59698
2020-12-10T18:53:56.521Z,1607626436.521 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-12-10T18:54:10.619Z,1607626450.619 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20201209T223704/Express0139.lzma
2020-12-10T18:54:11.621Z,1607626451.621 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0139.lzma.bak
2020-12-10T18:54:11.621Z,1607626451.621 [DataOverHttps](INFO): SBD MOMSN=59704
2020-12-10T18:55:41.035Z,1607626541.035 [DataOverHttps](INFO): Sending 172 bytes from file Logs/20201209T223704/Express0142.lzma
2020-12-10T18:55:42.041Z,1607626542.041 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0142.lzma.bak
2020-12-10T18:55:42.041Z,1607626542.041 [DataOverHttps](INFO): SBD MOMSN=59706
2020-12-10T18:57:16.423Z,1607626636.423 [DataOverHttps](INFO): Sending 301 bytes from file Logs/20201209T223704/Express0145.lzma
2020-12-10T18:57:17.422Z,1607626637.422 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0145.lzma.bak
2020-12-10T18:57:17.422Z,1607626637.422 [DataOverHttps](INFO): SBD MOMSN=59713
2020-12-10T18:58:46.779Z,1607626726.779 [DataOverHttps](INFO): Sending 283 bytes from file Logs/20201209T223704/Express0148.lzma
2020-12-10T18:58:47.781Z,1607626727.781 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0148.lzma.bak
2020-12-10T18:58:47.781Z,1607626727.781 [DataOverHttps](INFO): SBD MOMSN=59719
2020-12-10T18:59:42.049Z,1607626782.049 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2020-12-10T19:00:01.891Z,1607626801.891 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items
2020-12-10T19:00:17.167Z,1607626817.167 [DataOverHttps](INFO): Sending 274 bytes from file Logs/20201209T223704/Express0151.lzma
2020-12-10T19:00:18.169Z,1607626818.169 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0151.lzma.bak
2020-12-10T19:00:18.169Z,1607626818.169 [DataOverHttps](INFO): SBD MOMSN=59725
2020-12-10T19:01:52.556Z,1607626912.556 [DataOverHttps](INFO): Sending 2852 bytes from file Logs/20201209T223704/Express0154.lzma
2020-12-10T19:01:53.549Z,1607626913.549 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0154.lzma.bak
2020-12-10T19:01:53.549Z,1607626913.549 [DataOverHttps](INFO): SBD MOMSN=59732
2020-12-10T19:03:22.920Z,1607627002.920 [DataOverHttps](INFO): Sending 1065 bytes from file Logs/20201209T223704/Express0157.lzma
2020-12-10T19:03:23.925Z,1607627003.925 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0157.lzma.bak
2020-12-10T19:03:23.925Z,1607627003.925 [DataOverHttps](INFO): SBD MOMSN=59751
2020-12-10T19:04:59.313Z,1607627099.313 [DataOverHttps](INFO): Sending 1260 bytes from file Logs/20201209T223704/Express0160.lzma
2020-12-10T19:05:00.313Z,1607627100.313 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0160.lzma.bak
2020-12-10T19:05:00.313Z,1607627100.313 [DataOverHttps](INFO): SBD MOMSN=59753
2020-12-10T19:06:34.725Z,1607627194.725 [DataOverHttps](INFO): Sending 1402 bytes from file Logs/20201209T223704/Express0163.lzma
2020-12-10T19:06:35.726Z,1607627195.726 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0163.lzma.bak
2020-12-10T19:06:35.726Z,1607627195.726 [DataOverHttps](INFO): SBD MOMSN=59757
2020-12-10T19:08:10.122Z,1607627290.122 [DataOverHttps](INFO): Sending 1396 bytes from file Logs/20201209T223704/Express0166.lzma
2020-12-10T19:08:11.121Z,1607627291.121 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0166.lzma.bak
2020-12-10T19:08:11.121Z,1607627291.121 [DataOverHttps](INFO): SBD MOMSN=59759
2020-12-10T19:09:46.528Z,1607627386.528 [DataOverHttps](INFO): Sending 1116 bytes from file Logs/20201209T223704/Express0169.lzma
2020-12-10T19:09:47.529Z,1607627387.529 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0169.lzma.bak
2020-12-10T19:09:47.530Z,1607627387.530 [DataOverHttps](INFO): SBD MOMSN=59761
2020-12-10T19:11:21.946Z,1607627481.946 [DataOverHttps](INFO): Sending 1195 bytes from file Logs/20201209T223704/Express0172.lzma
2020-12-10T19:11:22.945Z,1607627482.945 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0172.lzma.bak
2020-12-10T19:11:22.945Z,1607627482.945 [DataOverHttps](INFO): SBD MOMSN=59763
2020-12-10T19:12:02.631Z,1607627522.631 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2020-12-10T19:12:57.338Z,1607627577.338 [DataOverHttps](INFO): Sending 1079 bytes from file Logs/20201209T223704/Express0175.lzma
2020-12-10T19:12:58.337Z,1607627578.337 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0175.lzma.bak
2020-12-10T19:12:58.337Z,1607627578.337 [DataOverHttps](INFO): SBD MOMSN=59767
2020-12-10T19:13:07.698Z,1607627587.698 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-12-10T19:14:07.513Z,1607627647.513 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2020-12-10T19:14:32.744Z,1607627672.744 [DataOverHttps](INFO): Sending 894 bytes from file Logs/20201209T223704/Express0178.lzma
2020-12-10T19:14:33.745Z,1607627673.745 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0178.lzma.bak
2020-12-10T19:14:33.745Z,1607627673.745 [DataOverHttps](INFO): SBD MOMSN=59769
2020-12-10T19:16:08.144Z,1607627768.144 [DataOverHttps](INFO): Sending 1046 bytes from file Logs/20201209T223704/Express0181.lzma
2020-12-10T19:16:09.145Z,1607627769.145 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0181.lzma.bak
2020-12-10T19:16:09.146Z,1607627769.146 [DataOverHttps](INFO): SBD MOMSN=59771
2020-12-10T19:17:24.613Z,1607627844.613 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file).
2020-12-10T19:17:43.549Z,1607627863.549 [DataOverHttps](INFO): Sending 967 bytes from file Logs/20201209T223704/Express0184.lzma
2020-12-10T19:17:44.550Z,1607627864.550 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0184.lzma.bak
2020-12-10T19:17:44.550Z,1607627864.550 [DataOverHttps](INFO): SBD MOMSN=59773
2020-12-10T19:18:17.947Z,1607627897.947 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-12-10T19:18:17.949Z,1607627897.949 [BPC1](INFO): Received data from all battery sticks.
2020-12-10T19:18:25.713Z,1607627905.713 [DataOverHttps](IMPORTANT): SBD MTMSN=20201210T191825
2020-12-10T19:18:29.734Z,1607627909.734 [DataOverHttps](INFO): Received command:sched asap "configSet logExpress none CurrentEstimator.current_speed_navigation_frame persist;configSet logExpress none CurrentEstimator.current_direction_navigation_frame persist" clml 1 2
2020-12-10T19:18:29.757Z,1607627909.757 [CommandLine](IMPORTANT): got command schedule asap "configSet logExpress none CurrentEstimator.current_speed_navigation_frame persist;configSet logExpress none CurrentEstimator.current_direction_navigation_frame persist" clml 1 2.000000
2020-12-10T19:18:29.758Z,1607627909.758 [CommandLine](IMPORTANT): Scheduling command #1 of 2 with id=clml
2020-12-10T19:18:29.761Z,1607627909.761 [CommandLine](IMPORTANT): Scheduled #4 (#1 of 2 with id='clml'): "configSet logExpress none CurrentEstimator.current_speed_navigation_frame persist;configSet logExpress none CurrentEstimator.current_direction_navigation_frame persist" ASAP
2020-12-10T19:18:31.041Z,1607627911.041 [DataOverHttps](IMPORTANT): SBD MTMSN=20201210T191830
2020-12-10T19:18:34.753Z,1607627914.753 [DataOverHttps](INFO): Received command:sched asap "configSet logExpress none CTD_Seabird.bin_median_sea_water_salinity persist;" clml 2 2
2020-12-10T19:18:34.800Z,1607627914.800 [CommandLine](IMPORTANT): got command schedule asap "configSet logExpress none CTD_Seabird.bin_median_sea_water_salinity persist;" clml 2 2.000000
2020-12-10T19:18:34.801Z,1607627914.801 [CommandLine](IMPORTANT): Scheduling command #2 of 2 with id=clml
2020-12-10T19:18:34.801Z,1607627914.801 [CommandLine](IMPORTANT): Scheduled #5 (#2 of 2 with id='clml'): "configSet logExpress none CTD_Seabird.bin_median_sea_water_salinity persist;" ASAP
2020-12-10T19:18:38.884Z,1607627918.884 [CommandLine](IMPORTANT): got command configSet Express none CurrentEstimator.current_speed_navigation_frame persist
2020-12-10T19:18:38.886Z,1607627918.886 [CommandLine](IMPORTANT): got command configSet Express none CurrentEstimator.current_direction_navigation_frame persist
2020-12-10T19:18:40.711Z,1607627920.711 [CommandLine](IMPORTANT): got command configSet Express none CTD_Seabird.bin_median_sea_water_salinity persist
2020-12-10T19:19:19.952Z,1607627959.952 [DataOverHttps](INFO): Sending 1041 bytes from file Logs/20201209T223704/Express0187.lzma
2020-12-10T19:19:20.953Z,1607627960.953 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0187.lzma.bak
2020-12-10T19:19:20.953Z,1607627960.953 [DataOverHttps](INFO): SBD MOMSN=59778
2020-12-10T19:20:57.391Z,1607628057.391 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20201210T180318/Courier0031.lzma
2020-12-10T19:20:58.393Z,1607628058.393 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Courier0031.lzma.bak
2020-12-10T19:20:58.393Z,1607628058.393 [DataOverHttps](INFO): SBD MOMSN=59780
2020-12-10T19:21:03.201Z,1607628063.201 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2020-12-10T19:21:07.441Z,1607628067.441 [DataOverHttps](INFO): Sending 53 bytes from file Logs/20201210T180318/Courier0034.lzma
2020-12-10T19:21:08.437Z,1607628068.437 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Courier0034.lzma.bak
2020-12-10T19:21:08.437Z,1607628068.437 [DataOverHttps](INFO): SBD MOMSN=59782
2020-12-10T19:21:17.473Z,1607628077.473 [DataOverHttps](INFO): Sending 1102 bytes from file Logs/20201209T223704/Express0190.lzma
2020-12-10T19:21:18.473Z,1607628078.473 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0190.lzma.bak
2020-12-10T19:21:18.473Z,1607628078.473 [DataOverHttps](INFO): SBD MOMSN=59784
2020-12-10T19:22:57.873Z,1607628177.873 [DataOverHttps](INFO): Sending 1231 bytes from file Logs/20201209T223704/Express0193.lzma
2020-12-10T19:22:58.874Z,1607628178.874 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0193.lzma.bak
2020-12-10T19:22:58.874Z,1607628178.874 [DataOverHttps](IMPORTANT): SBD MOMSN=59787, MTMSN=20201210T192258
2020-12-10T19:23:02.892Z,1607628182.892 [DataOverHttps](INFO): Received command:configSet logExpress none CTD_Seabird.bin_median_sea_water_temperature persist;configSet logExpress none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water persist
2020-12-10T19:23:10.160Z,1607628190.160 [CommandLine](IMPORTANT): got command configSet Express none CTD_Seabird.bin_median_sea_water_temperature persist
2020-12-10T19:23:10.163Z,1607628190.163 [CommandLine](IMPORTANT): got command configSet Express none 
2020-12-10T19:23:10.163Z,1607628190.163 [CommandLine](FAULT): Incomplete syntax. Try: help configSet
2020-12-10T19:24:35.521Z,1607628275.521 [DataOverHttps](INFO): Sending 1235 bytes from file Logs/20201209T223704/Express0196.lzma
2020-12-10T19:24:36.521Z,1607628276.521 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0196.lzma.bak
2020-12-10T19:24:36.521Z,1607628276.521 [DataOverHttps](INFO): SBD MOMSN=59790
2020-12-10T19:26:16.947Z,1607628376.947 [DataOverHttps](INFO): Sending 53 bytes from file Logs/20201210T180318/Courier0037.lzma
2020-12-10T19:26:17.949Z,1607628377.949 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Courier0037.lzma.bak
2020-12-10T19:26:17.949Z,1607628377.949 [DataOverHttps](INFO): SBD MOMSN=59792
2020-12-10T19:26:26.988Z,1607628386.988 [DataOverHttps](INFO): Sending 936 bytes from file Logs/20201209T223704/Express0199.lzma
2020-12-10T19:26:27.990Z,1607628387.990 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0199.lzma.bak
2020-12-10T19:26:27.990Z,1607628387.990 [DataOverHttps](INFO): SBD MOMSN=59794
2020-12-10T19:28:08.457Z,1607628488.457 [DataOverHttps](INFO): Sending 1416 bytes from file Logs/20201209T223704/Express0202.lzma
2020-12-10T19:28:09.450Z,1607628489.450 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0202.lzma.bak
2020-12-10T19:28:09.451Z,1607628489.451 [DataOverHttps](INFO): SBD MOMSN=59796
2020-12-10T19:29:20.031Z,1607628560.031 [CommandLine](IMPORTANT): got command configSet Express none CurrentEstimator.current_speed_navigation_frame persist
2020-12-10T19:29:50.885Z,1607628590.885 [DataOverHttps](INFO): Sending 1196 bytes from file Logs/20201209T223704/Express0205.lzma
2020-12-10T19:29:51.886Z,1607628591.886 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0205.lzma.bak
2020-12-10T19:29:51.886Z,1607628591.886 [DataOverHttps](INFO): SBD MOMSN=59798
2020-12-10T19:29:57.218Z,1607628597.218 [CommandLine](IMPORTANT): got command configSet Express none CurrentEstimator.current_direction_navigation_frame persist
2020-12-10T19:30:13.786Z,1607628613.786 [CommandLine](IMPORTANT): got command configSet Express none CurrentEstimator.current_direction_vehicle_frame persist
2020-12-10T19:31:36.319Z,1607628696.319 [DataOverHttps](INFO): Sending 965 bytes from file Logs/20201209T223704/Express0208.lzma
2020-12-10T19:31:37.318Z,1607628697.318 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0208.lzma.bak
2020-12-10T19:31:37.318Z,1607628697.318 [DataOverHttps](INFO): SBD MOMSN=59800
2020-12-10T19:32:19.242Z,1607628739.242 [CommandLine](IMPORTANT): got command configSet Express none CurrentEstimator.current_speed_vehicle_frame persist
2020-12-10T19:32:53.542Z,1607628773.542 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-12-10T19:32:58.807Z,1607628778.807 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-12-10T19:33:13.733Z,1607628793.733 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-12-10T19:33:17.725Z,1607628797.725 [DataOverHttps](INFO): Sending 1508 bytes from file Logs/20201209T223704/Express0211.lzma
2020-12-10T19:33:18.726Z,1607628798.726 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0211.lzma.bak
2020-12-10T19:33:18.726Z,1607628798.726 [DataOverHttps](INFO): SBD MOMSN=59802
2020-12-10T19:35:05.161Z,1607628905.161 [DataOverHttps](INFO): Sending 1231 bytes from file Logs/20201209T223704/Express0214.lzma
2020-12-10T19:35:06.161Z,1607628906.161 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0214.lzma.bak
2020-12-10T19:35:06.161Z,1607628906.161 [DataOverHttps](INFO): SBD MOMSN=59804
2020-12-10T19:36:50.600Z,1607629010.600 [DataOverHttps](INFO): Sending 1064 bytes from file Logs/20201209T223704/Express0217.lzma
2020-12-10T19:36:51.601Z,1607629011.601 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0217.lzma.bak
2020-12-10T19:36:51.602Z,1607629011.602 [DataOverHttps](INFO): SBD MOMSN=59806
2020-12-10T19:38:32.021Z,1607629112.021 [DataOverHttps](INFO): Sending 1204 bytes from file Logs/20201209T223704/Express0220.lzma
2020-12-10T19:38:33.021Z,1607629113.021 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0220.lzma.bak
2020-12-10T19:38:33.022Z,1607629113.022 [DataOverHttps](INFO): SBD MOMSN=59808
2020-12-10T19:39:18.970Z,1607629158.970 [RDI_PathfinderUp](ERROR): only read 1 of 4 data items
2020-12-10T19:40:07.464Z,1607629207.464 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-12-10T19:40:12.454Z,1607629212.454 [DataOverHttps](INFO): Sending 167 bytes from file Logs/20201209T223704/Express0223.lzma
2020-12-10T19:40:13.453Z,1607629213.453 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0223.lzma.bak
2020-12-10T19:40:13.454Z,1607629213.454 [DataOverHttps](INFO): SBD MOMSN=59812
2020-12-10T19:42:02.919Z,1607629322.919 [DataOverHttps](INFO): Sending 134 bytes from file Logs/20201209T223704/Express0226.lzma
2020-12-10T19:42:03.924Z,1607629323.924 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0226.lzma.bak
2020-12-10T19:42:03.925Z,1607629323.925 [DataOverHttps](INFO): SBD MOMSN=59816
2020-12-10T19:42:13.979Z,1607629333.979 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2020-12-10T19:42:54.313Z,1607629374.313 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude
2020-12-10T19:43:04.006Z,1607629384.006 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2020-12-10T19:43:14.106Z,1607629394.106 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude
2020-12-10T19:43:48.351Z,1607629428.351 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20201209T223704/Express0229.lzma
2020-12-10T19:43:49.353Z,1607629429.353 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223704/Express0229.lzma.bak
2020-12-10T19:43:49.354Z,1607629429.354 [DataOverHttps](INFO): SBD MOMSN=59820
2020-12-10T19:45:30.789Z,1607629530.789 [DataOverHttps](INFO): Sending 873 bytes from file Logs/20201210T180318/Express0001.lzma
2020-12-10T19:45:31.781Z,1607629531.781 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Express0001.lzma.bak
2020-12-10T19:45:31.781Z,1607629531.781 [DataOverHttps](INFO): SBD MOMSN=59822
2020-12-10T19:45:40.828Z,1607629540.828 [DataOverHttps](INFO): Sending 536 bytes from file Logs/20201210T180318/Express0005.lzma
2020-12-10T19:45:41.833Z,1607629541.833 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Express0005.lzma.bak
2020-12-10T19:45:41.833Z,1607629541.833 [DataOverHttps](INFO): SBD MOMSN=59840
2020-12-10T19:45:50.879Z,1607629550.879 [DataOverHttps](INFO): Sending 53 bytes from file Logs/20201210T180318/Express0006.lzma
2020-12-10T19:45:51.881Z,1607629551.881 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Express0006.lzma.bak
2020-12-10T19:45:51.881Z,1607629551.881 [DataOverHttps](INFO): SBD MOMSN=59852
2020-12-10T19:46:00.919Z,1607629560.919 [DataOverHttps](INFO): Sending 359 bytes from file Logs/20201210T180318/Express0011.lzma
2020-12-10T19:46:01.921Z,1607629561.921 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Express0011.lzma.bak
2020-12-10T19:46:01.921Z,1607629561.921 [DataOverHttps](INFO): SBD MOMSN=59854
2020-12-10T19:46:10.959Z,1607629570.959 [DataOverHttps](INFO): Sending 278 bytes from file Logs/20201210T180318/Express0014.lzma
2020-12-10T19:46:11.961Z,1607629571.961 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Express0014.lzma.bak
2020-12-10T19:46:11.961Z,1607629571.961 [DataOverHttps](INFO): SBD MOMSN=59861
2020-12-10T19:46:14.298Z,1607629574.298 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2020-12-10T19:46:20.999Z,1607629580.999 [DataOverHttps](INFO): Sending 304 bytes from file Logs/20201210T180318/Express0017.lzma
2020-12-10T19:46:22.001Z,1607629582.001 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Express0017.lzma.bak
2020-12-10T19:46:22.001Z,1607629582.001 [DataOverHttps](INFO): SBD MOMSN=59867
2020-12-10T19:46:31.044Z,1607629591.044 [DataOverHttps](INFO): Sending 2794 bytes from file Logs/20201210T180318/Express0020.lzma
2020-12-10T19:46:32.041Z,1607629592.041 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Express0020.lzma.bak
2020-12-10T19:46:32.042Z,1607629592.042 [DataOverHttps](INFO): SBD MOMSN=59874
2020-12-10T19:46:41.081Z,1607629601.081 [DataOverHttps](INFO): Sending 1252 bytes from file Logs/20201210T180318/Express0023.lzma
2020-12-10T19:46:42.081Z,1607629602.081 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Express0023.lzma.bak
2020-12-10T19:46:42.081Z,1607629602.081 [DataOverHttps](INFO): SBD MOMSN=59893
2020-12-10T19:46:51.129Z,1607629611.129 [DataOverHttps](INFO): Sending 1656 bytes from file Logs/20201210T180318/Express0026.lzma
2020-12-10T19:46:52.132Z,1607629612.132 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Express0026.lzma.bak
2020-12-10T19:46:52.133Z,1607629612.133 [DataOverHttps](INFO): SBD MOMSN=59895
2020-12-10T19:47:01.168Z,1607629621.168 [DataOverHttps](INFO): Sending 488 bytes from file Logs/20201210T180318/Express0029.lzma
2020-12-10T19:47:02.169Z,1607629622.169 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Express0029.lzma.bak
2020-12-10T19:47:02.170Z,1607629622.170 [DataOverHttps](INFO): SBD MOMSN=59897
2020-12-10T19:47:11.207Z,1607629631.207 [DataOverHttps](INFO): Sending 279 bytes from file Logs/20201210T180318/Express0032.lzma
2020-12-10T19:47:12.209Z,1607629632.209 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Express0032.lzma.bak
2020-12-10T19:47:12.209Z,1607629632.209 [DataOverHttps](INFO): SBD MOMSN=59901
2020-12-10T19:47:21.247Z,1607629641.247 [DataOverHttps](INFO): Sending 265 bytes from file Logs/20201210T180318/Express0035.lzma
2020-12-10T19:47:22.249Z,1607629642.249 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Express0035.lzma.bak
2020-12-10T19:47:22.249Z,1607629642.249 [DataOverHttps](INFO): SBD MOMSN=59907
2020-12-10T19:47:31.303Z,1607629651.303 [DataOverHttps](INFO): Sending 302 bytes from file Logs/20201210T180318/Express0038.lzma
2020-12-10T19:47:32.305Z,1607629652.305 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Express0038.lzma.bak
2020-12-10T19:47:32.305Z,1607629652.305 [DataOverHttps](INFO): SBD MOMSN=59913
2020-12-10T19:47:33.506Z,1607629653.506 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-12-10T19:47:33.506Z,1607629653.506 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-12-10T19:47:33.506Z,1607629653.506 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-12-10T19:52:34.094Z,1607629954.094 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2020-12-10T19:52:34.094Z,1607629954.094 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-12-10T19:52:34.094Z,1607629954.094 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-12-10T19:52:34.095Z,1607629954.095 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2020-12-10T19:52:34.512Z,1607629954.512 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2020-12-10T19:52:34.512Z,1607629954.512 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2020-12-10T19:52:34.880Z,1607629954.880 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 76.223356 min 
2020-12-10T19:52:34.880Z,1607629954.880 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2020-12-10T19:52:34.880Z,1607629954.880 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2020-12-10T19:52:34.881Z,1607629954.881 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-12-10T19:52:34.881Z,1607629954.881 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-12-10T19:52:34.881Z,1607629954.881 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #2
2020-12-10T19:52:34.881Z,1607629954.881 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=2
2020-12-10T19:52:34.881Z,1607629954.881 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-12-10T19:52:34.881Z,1607629954.881 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-12-10T19:52:36.892Z,1607629956.892 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195237.00,A,4133.22136,N,07042.43148,W,0.486,166.20,101220,,,A*74
2020-12-10T19:52:36.894Z,1607629956.894 [NAL9602](INFO): GPS fix at 20201210T195237: (41.553689, -70.707191)
2020-12-10T19:52:36.915Z,1607629956.915 [UniversalFixResidualReporter](INFO): Fix residual: 8.5 %DT, over the last 1319.8 m. Residual distance 112.3 m at bearing -66.8 degrees. Fix at (41.5537, -70.7072) with 671.7 m made good.
2020-12-10T19:52:36.916Z,1607629956.916 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-12-10T19:52:36.916Z,1607629956.916 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-12-10T19:52:40.555Z,1607629960.555 [DataOverHttps](INFO): Sending 82 bytes from file Logs/20201210T180318/Courier0040.lzma
2020-12-10T19:52:41.557Z,1607629961.557 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Courier0040.lzma.bak
2020-12-10T19:52:41.557Z,1607629961.557 [DataOverHttps](INFO): SBD MOMSN=59922
2020-12-10T19:52:51.458Z,1607629971.458 [NAL9602](INFO): SBD MO Status=2, MOMSN=12212, MT Status=2, MTMSN=0
2020-12-10T19:52:51.458Z,1607629971.458 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-12-10T19:52:51.599Z,1607629971.599 [DataOverHttps](INFO): Sending 293 bytes from file Logs/20201210T180318/Express0041.lzma
2020-12-10T19:52:52.601Z,1607629972.601 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Express0041.lzma.bak
2020-12-10T19:52:52.601Z,1607629972.601 [DataOverHttps](INFO): SBD MOMSN=59925
2020-12-10T19:52:53.876Z,1607629973.876 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-12-10T19:52:53.876Z,1607629973.876 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-12-10T19:52:53.876Z,1607629973.876 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-12-10T19:53:08.815Z,1607629988.815 [NAL9602](INFO): SBD MO Status=2, MOMSN=12212, MT Status=2, MTMSN=0
2020-12-10T19:53:08.815Z,1607629988.815 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-12-10T19:53:20.927Z,1607630000.927 [NAL9602](INFO): SBD MO Status=0, MOMSN=12212, MT Status=0, MTMSN=0
2020-12-10T19:53:20.927Z,1607630000.927 [NAL9602](INFO): No messages in MT queue
2020-12-10T19:53:29.837Z,1607630009.837 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2020-12-10T19:53:51.627Z,1607630031.627 [NAL9602](INFO): Not Powering down - fast GPS
2020-12-10T19:57:54.496Z,1607630274.496 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2020-12-10T19:57:54.496Z,1607630274.496 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-12-10T19:57:54.496Z,1607630274.496 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-12-10T19:57:54.496Z,1607630274.496 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2020-12-10T19:57:54.860Z,1607630274.860 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2020-12-10T19:57:54.860Z,1607630274.860 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2020-12-10T19:57:55.273Z,1607630275.273 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 81.562484 min 
2020-12-10T19:57:55.273Z,1607630275.273 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2020-12-10T19:57:55.274Z,1607630275.274 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2020-12-10T19:57:55.274Z,1607630275.274 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-12-10T19:57:55.274Z,1607630275.274 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-12-10T19:57:55.274Z,1607630275.274 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #3
2020-12-10T19:57:55.274Z,1607630275.274 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=3
2020-12-10T19:57:55.274Z,1607630275.274 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-12-10T19:57:55.274Z,1607630275.274 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-12-10T19:57:57.282Z,1607630277.282 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195757.00,A,4133.20671,N,07042.40592,W,0.214,160.83,101220,,,A*73
2020-12-10T19:57:57.284Z,1607630277.284 [NAL9602](INFO): GPS fix at 20201210T195757: (41.553445, -70.706765)
2020-12-10T19:57:57.295Z,1607630277.295 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-12-10T19:57:57.295Z,1607630277.295 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-12-10T19:58:00.872Z,1607630280.872 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20201210T180318/Courier0043.lzma
2020-12-10T19:58:01.873Z,1607630281.873 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Courier0043.lzma.bak
2020-12-10T19:58:01.873Z,1607630281.873 [DataOverHttps](INFO): SBD MOMSN=59933
2020-12-10T19:58:10.911Z,1607630290.911 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20201210T180318/Express0044.lzma
2020-12-10T19:58:11.913Z,1607630291.913 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Express0044.lzma.bak
2020-12-10T19:58:11.913Z,1607630291.913 [DataOverHttps](INFO): SBD MOMSN=59937
2020-12-10T19:58:13.088Z,1607630293.088 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-12-10T19:58:13.088Z,1607630293.088 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-12-10T19:58:13.088Z,1607630293.088 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-12-10T19:58:20.739Z,1607630300.739 [NAL9602](INFO): SBD MO Status=0, MOMSN=12213, MT Status=0, MTMSN=0
2020-12-10T19:58:20.739Z,1607630300.739 [NAL9602](INFO): No messages in MT queue
2020-12-10T19:58:51.460Z,1607630331.460 [NAL9602](INFO): Not Powering down - fast GPS
2020-12-10T19:59:10.035Z,1607630350.035 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2020-12-10T19:59:19.794Z,1607630359.794 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2020-12-10T19:59:39.933Z,1607630379.933 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items
2020-12-10T20:03:13.795Z,1607630593.795 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2020-12-10T20:03:13.795Z,1607630593.795 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-12-10T20:03:13.796Z,1607630593.796 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-12-10T20:03:13.796Z,1607630593.796 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2020-12-10T20:03:14.216Z,1607630594.216 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2020-12-10T20:03:14.216Z,1607630594.216 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2020-12-10T20:03:14.613Z,1607630594.613 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 86.885075 min 
2020-12-10T20:03:14.613Z,1607630594.613 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2020-12-10T20:03:14.613Z,1607630594.613 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2020-12-10T20:03:14.613Z,1607630594.613 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-12-10T20:03:14.613Z,1607630594.613 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-12-10T20:03:14.613Z,1607630594.614 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #4
2020-12-10T20:03:14.614Z,1607630594.614 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=4
2020-12-10T20:03:14.614Z,1607630594.614 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-12-10T20:03:14.614Z,1607630594.614 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-12-10T20:03:16.603Z,1607630596.603 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200316.00,A,4133.18848,N,07042.38659,W,0.350,177.10,101220,,,A*74
2020-12-10T20:03:16.605Z,1607630596.605 [NAL9602](INFO): GPS fix at 20201210T200316: (41.553141, -70.706443)
2020-12-10T20:03:16.626Z,1607630596.626 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-12-10T20:03:16.626Z,1607630596.626 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-12-10T20:03:20.255Z,1607630600.255 [DataOverHttps](INFO): Sending 79 bytes from file Logs/20201210T180318/Courier0046.lzma
2020-12-10T20:03:21.257Z,1607630601.257 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Courier0046.lzma.bak
2020-12-10T20:03:21.257Z,1607630601.257 [DataOverHttps](INFO): SBD MOMSN=59941
2020-12-10T20:03:30.295Z,1607630610.295 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20201210T180318/Express0047.lzma
2020-12-10T20:03:31.297Z,1607630611.297 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Express0047.lzma.bak
2020-12-10T20:03:31.297Z,1607630611.297 [DataOverHttps](INFO): SBD MOMSN=59944
2020-12-10T20:03:32.832Z,1607630612.832 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-12-10T20:03:32.832Z,1607630612.832 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-12-10T20:03:32.832Z,1607630612.832 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-12-10T20:03:39.229Z,1607630619.229 [NAL9602](INFO): SBD MO Status=0, MOMSN=12214, MT Status=0, MTMSN=0
2020-12-10T20:03:39.229Z,1607630619.229 [NAL9602](INFO): No messages in MT queue
2020-12-10T20:04:09.937Z,1607630649.937 [NAL9602](INFO): Not Powering down - fast GPS
2020-12-10T20:06:35.381Z,1607630795.381 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2020-12-10T20:07:15.374Z,1607630835.374 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2020-12-10T20:08:18.478Z,1607630898.478 [DataOverHttps](IMPORTANT): SBD MTMSN=20201210T200818
2020-12-10T20:08:22.515Z,1607630902.515 [DataOverHttps](INFO): Received command:sched asap "load Engineering/LBLTest.xml;set LBLTest.trans1Location [41.557417,-70.714644] degree;set LBLTest.trans1Depth 6 meter;set LBLTest.trans2Location [41.57302,-70.69302] degree;set LBLTest.trans2Depth 6 meter" cnww 1 3
2020-12-10T20:08:22.612Z,1607630902.612 [CommandLine](IMPORTANT): got command schedule asap "load Engineering/LBLTest.xml;set LBLTest.trans1Location [41.557417,-70.714644] degree;set LBLTest.trans1Depth 6 meter;set LBLTest.trans2Location [41.57302,-70.69302] degree;set LBLTest.trans2Depth 6 meter" cnww 1 3.000000
2020-12-10T20:08:22.613Z,1607630902.613 [CommandLine](IMPORTANT): Scheduling command #1 of 3 with id=cnww
2020-12-10T20:08:22.614Z,1607630902.614 [CommandLine](IMPORTANT): Scheduled #6 (#1 of 3 with id='cnww'): "load Engineering/LBLTest.xml;set LBLTest.trans1Location [41.557417,-70.714644] degree;set LBLTest.trans1Depth 6 meter;set LBLTest.trans2Location [41.57302,-70.69302] degree;set LBLTest.trans2Depth 6 meter" ASAP
2020-12-10T20:08:23.517Z,1607630903.517 [DataOverHttps](IMPORTANT): SBD MTMSN=20201210T200823
2020-12-10T20:08:27.547Z,1607630907.547 [DataOverHttps](INFO): Received command:sched asap "set LBLTest.trans3Location NaN degree;set LBLTest.trans3Depth NaN meter;set transit.MissionTimeout 120 minute;set transit.NeedCommsTime 15 minute;set transit.Latitude 41.578595 degree;set transit.Longitude -70.675158 degree" cnww 2 3
2020-12-10T20:08:27.612Z,1607630907.612 [CommandLine](IMPORTANT): got command schedule asap "set LBLTest.trans3Location NaN degree;set LBLTest.trans3Depth NaN meter;set transit.MissionTimeout 120 minute;set transit.NeedCommsTime 15 minute;set transit.Latitude 41.578595 degree;set transit.Longitude -70.675158 degree" cnww 2 3.000000
2020-12-10T20:08:27.612Z,1607630907.612 [CommandLine](IMPORTANT): Scheduling command #2 of 3 with id=cnww
2020-12-10T20:08:27.613Z,1607630907.613 [CommandLine](IMPORTANT): Scheduled #7 (#2 of 3 with id='cnww'): "set LBLTest.trans3Location NaN degree;set LBLTest.trans3Depth NaN meter;set transit.MissionTimeout 120 minute;set transit.NeedCommsTime 15 minute;set transit.Latitude 41.578595 degree;set transit.Longitude -70.675158 degree" ASAP
2020-12-10T20:08:28.549Z,1607630908.549 [DataOverHttps](IMPORTANT): SBD MTMSN=20201210T200828
2020-12-10T20:08:32.575Z,1607630912.575 [DataOverHttps](INFO): Received command:sched asap "set transit.Depth 6 meter;set transit.MaxDepth 9 meter;set transit.MinOffshore 500 kilometer;set transit.MinAltitude 3 meter;run" cnww 3 3
2020-12-10T20:08:32.628Z,1607630912.628 [CommandLine](IMPORTANT): got command schedule asap "set transit.Depth 6 meter;set transit.MaxDepth 9 meter;set transit.MinOffshore 500 kilometer;set transit.MinAltitude 3 meter;run" cnww 3 3.000000
2020-12-10T20:08:32.629Z,1607630912.629 [CommandLine](IMPORTANT): Scheduling command #3 of 3 with id=cnww
2020-12-10T20:08:32.630Z,1607630912.630 [CommandLine](IMPORTANT): Scheduled #8 (#3 of 3 with id='cnww'): "set transit.Depth 6 meter;set transit.MaxDepth 9 meter;set transit.MinOffshore 500 kilometer;set transit.MinAltitude 3 meter;run" ASAP
2020-12-10T20:08:32.777Z,1607630912.777 [CommandLine](IMPORTANT): got command load ./Missions/Engineering/LBLTest.xml
2020-12-10T20:08:32.777Z,1607630912.777 [MissionManager](INFO): Loading Mission: ./Missions/Engineering/LBLTest.xml
2020-12-10T20:08:32.808Z,1607630912.808 [MissionManager](INFO): DefineArg LBLTest.trans1Location = [36.803398,-121.822304] deg
2020-12-10T20:08:32.812Z,1607630912.812 [MissionManager](INFO): DefineArg LBLTest.trans1Depth = 25.000000 m
2020-12-10T20:08:32.816Z,1607630912.816 [MissionManager](INFO): DefineArg LBLTest.trans2Location = [36.793400,-121.832199] deg
2020-12-10T20:08:32.819Z,1607630912.819 [MissionManager](INFO): DefineArg LBLTest.trans2Depth = 25.000000 m
2020-12-10T20:08:32.823Z,1607630912.823 [MissionManager](INFO): DefineArg LBLTest.trans3Location = [36.793400,-121.812202] deg
2020-12-10T20:08:32.827Z,1607630912.827 [MissionManager](INFO): DefineArg LBLTest.trans3Depth = 25.000000 m
2020-12-10T20:08:32.879Z,1607630912.879 [MissionManager](CRITICAL): Unable to find MissionComponent with name LBL at LBLTest:WhenAgg:D
2020-12-10T20:08:32.879Z,1607630912.879 [LBLTest:WhenAgg](CRITICAL): Error!!!! no component for child behavior.
2020-12-10T20:08:32.880Z,1607630912.880 [MissionManager](INFO): Inserting Stack: Missions/Transport/transit.xml
2020-12-10T20:08:33.055Z,1607630913.055 [MissionManager](INFO): DefineArg LBLTest:transit.MissionTimeout = 60.000000 min
2020-12-10T20:08:33.058Z,1607630913.058 [MissionManager](INFO): DefineArg LBLTest:transit.NeedCommsTime = 30.000000 min
2020-12-10T20:08:33.066Z,1607630913.066 [MissionManager](INFO): DefineArg LBLTest:transit.Latitude = nan deg
2020-12-10T20:08:33.070Z,1607630913.070 [MissionManager](INFO): DefineArg LBLTest:transit.Longitude = nan deg
2020-12-10T20:08:33.081Z,1607630913.081 [MissionManager](INFO): DefineArg LBLTest:transit.Northings = 0.000000 m
2020-12-10T20:08:33.089Z,1607630913.089 [MissionManager](INFO): DefineArg LBLTest:transit.Eastings = 0.000000 m
2020-12-10T20:08:33.094Z,1607630913.094 [MissionManager](INFO): DefineArg LBLTest:transit.Depth = 10.000000 m
2020-12-10T20:08:33.105Z,1607630913.105 [MissionManager](INFO): DefineArg LBLTest:transit.Speed = 1.000000 m/s
2020-12-10T20:08:33.109Z,1607630913.109 [MissionManager](INFO): DefineArg LBLTest:transit.MaxDepth = 20.000000 m
2020-12-10T20:08:33.120Z,1607630913.120 [MissionManager](INFO): DefineArg LBLTest:transit.MinOffshore = 1.000000 km
2020-12-10T20:08:33.124Z,1607630913.124 [MissionManager](INFO): DefineArg LBLTest:transit.MinAltitude = 7.000000 m
2020-12-10T20:08:33.136Z,1607630913.136 [MissionManager](INFO): DefineArg LBLTest:transit.MassHold = 1 bool
2020-12-10T20:08:33.139Z,1607630913.139 [MissionManager](INFO): DefineArg LBLTest:transit.BuoyancyHold = 1 bool
2020-12-10T20:08:33.143Z,1607630913.143 [MissionManager](INFO): Inserting Stack: Missions/Insert/NeedComms.xml
2020-12-10T20:08:33.227Z,1607630913.227 [MissionManager](INFO): DefineArg LBLTest:transit:NeedComms.DiveInterval = 3.000000 h
2020-12-10T20:08:33.231Z,1607630913.231 [MissionManager](INFO): DefineArg LBLTest:transit:NeedComms.WaitForPitchUp = 10.000000 min
2020-12-10T20:08:33.251Z,1607630913.251 [MissionManager](INFO): DefineArg LBLTest:transit:NeedComms.SurfacePitch = 20.000000 deg
2020-12-10T20:08:33.258Z,1607630913.258 [MissionManager](INFO): DefineArg LBLTest:transit:NeedComms.SurfaceDepthRate = nan m/s
2020-12-10T20:08:33.270Z,1607630913.270 [MissionManager](INFO): DefineArg LBLTest:transit:NeedComms.SurfaceSpeed = 1.000000 m/s
2020-12-10T20:08:33.274Z,1607630913.274 [MissionManager](INFO): DefineArg LBLTest:transit:NeedComms.GPSTimeout = 7.000000 min
2020-12-10T20:08:33.286Z,1607630913.286 [MissionManager](INFO): DefineArg LBLTest:transit:NeedComms.CommsTimeout = 30.000000 min
2020-12-10T20:08:33.297Z,1607630913.297 [LBLTest:transit:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-12-10T20:08:33.340Z,1607630913.340 [MissionManager](INFO): Inserting Stack: Missions/Insert/StandardEnvelopes.xml
2020-12-10T20:08:33.372Z,1607630913.372 [MissionManager](INFO): DefineArg LBLTest:transit:StandardEnvelopes.MinAltitude = 5.000000 m
2020-12-10T20:08:33.378Z,1607630913.378 [MissionManager](INFO): DefineArg LBLTest:transit:StandardEnvelopes.MaxDepth = 200.000000 m
2020-12-10T20:08:33.381Z,1607630913.381 [MissionManager](INFO): DefineArg LBLTest:transit:StandardEnvelopes.MinOffshore = 2000.000000 m
2020-12-10T20:08:33.382Z,1607630913.382 [LBLTest:transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2020-12-10T20:08:33.404Z,1607630913.404 [LBLTest:transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2020-12-10T20:08:33.439Z,1607630913.439 [LBLTest:transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2020-12-10T20:08:33.488Z,1607630913.488 [LBLTest:transit:BuoyancyHold.Buoyancy](DEBUG): Construct Buoyancy.
2020-12-10T20:08:33.496Z,1607630913.496 [LBLTest:transit:MassHold.Pitch](DEBUG): Construct.
2020-12-10T20:08:33.513Z,1607630913.513 [LBLTest:transit:Transit:A.Pitch](DEBUG): Construct.
2020-12-10T20:08:33.529Z,1607630913.529 [LBLTest:transit:Transit:B.SetSpeed](DEBUG): Construct.
2020-12-10T20:08:33.544Z,1607630913.544 [LBLTest:transit:Transit:Wpt1.Waypoint](DEBUG): Construct Waypoint.
2020-12-10T20:08:33.564Z,1607630913.564 [MissionManager](INFO): RedefineArg LBLTest:transit.MissionTimeout = value:90.000000 min
2020-12-10T20:08:33.567Z,1607630913.567 [MissionManager](INFO): RedefineArg LBLTest:transit.Latitude = value:36.804901 deg
2020-12-10T20:08:33.589Z,1607630913.589 [MissionManager](INFO): RedefineArg LBLTest:transit.Longitude = value:-121.810799 deg
2020-12-10T20:08:33.591Z,1607630913.591 [MissionManager](INFO): RedefineArg LBLTest:transit.MinOffshore = value:750.000000 m
2020-12-10T20:08:33.613Z,1607630913.613 [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="LBLTest">
       
    <DefineArg Name="trans1Location"><Units:degree/><Value>[36.8034,-121.8223]</Value></DefineArg>

    <DefineArg Name="trans1Depth"><Units:meter/><Value>25</Value></DefineArg>

    <DefineArg Name="trans2Location"><Units:degree/><Value>[36.7934,-121.8322]</Value></DefineArg>

    <DefineArg Name="trans2Depth"><Units:meter/><Value>25</Value></DefineArg>

    <DefineArg Name="trans3Location"><Units:degree/><Value>[36.7934,-121.8122]</Value></DefineArg>

    <DefineArg Name="trans3Depth"><Units:meter/><Value>25</Value></DefineArg>

    <Timeout Duration="P70M"/>

    <Aggregate Id="WhenAgg">

        <When>
            <True/>
        </When>

        <Timeout Duration="P60M">
            <Syslog>WhenAgg timed out</Syslog>
        </Timeout>

<!-- The following asssigns have no effect if #. variables are not set -->

        <Assign><Parallel/><Arg Name="trans1Location"/><CustomUri Uri="#.t1"/></Assign>

        <Assign><Parallel/><Arg Name="trans2Location"/><CustomUri Uri="#.t2"/></Assign>

        <Assign><Parallel/><Arg Name="trans3Location"/><CustomUri Uri="#.t3"/></Assign>

        <Navigation:LBL>
            <Parallel/>
            <Setting><Navigation:LBL.trans1Location /><Arg Name="trans1Location"/></Setting>
            <Setting><Navigation:LBL.trans1Depth /><Arg Name="trans1Depth"/></Setting>
            <Setting><Navigation:LBL.trans2Location /><Arg Name="trans2Location"/></Setting>
            <Setting><Navigation:LBL.trans2Depth /><Arg Name="trans2Depth"/></Setting>
            <Setting><Navigation:LBL.trans3Location /><Arg Name="trans3Location"/></Setting>
            <Setting><Navigation:LBL.trans3Depth /><Arg Name="trans3Depth"/></Setting>
        </Navigation:LBL>

    </Aggregate>

    <Insert Filename="Transport/transit.xml">
        <RedefineArg Name="MissionTimeout"><Units:minute/><Value>90</Value></RedefineArg>
        <RedefineArg Name="Latitude"><Units:degree/><Value>36.8049</Value></RedefineArg>
        <RedefineArg Name="Longitude"><Units:degree/><Value>-121.8108</Value></RedefineArg>
        <RedefineArg Name="MinOffshore"><Units:meter/><Value>750</Value></RedefineArg>
    </Insert>

</Mission>


2020-12-10T20:08:33.614Z,1607630913.614 [CommandLine](IMPORTANT): Loaded ./Missions/Engineering/LBLTest.xml
2020-12-10T20:08:39.359Z,1607630919.359 [CommandLine](IMPORTANT): got command set LBLTest.trans1Location [41.557417,-70.714644] degree
2020-12-10T20:08:39.360Z,1607630919.360 [CommandLine](IMPORTANT): got command set LBLTest.trans1Depth 6 meter
2020-12-10T20:08:39.361Z,1607630919.361 [CommandLine](IMPORTANT): got command set LBLTest.trans2Location [41.57302,-70.69302] degree
2020-12-10T20:08:39.361Z,1607630919.361 [CommandLine](IMPORTANT): got command set LBLTest.trans2Depth 6 meter
2020-12-10T20:08:39.364Z,1607630919.364 [CommandLine](FAULT): Scheduling is paused for 2 commands
2020-12-10T20:08:39.365Z,1607630919.365 [CBIT](INFO): Critical error at 20201210T200832
2020-12-10T20:08:39.365Z,1607630919.365 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2020-12-10T20:08:39.577Z,1607630919.577 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2020-12-10T20:08:39.577Z,1607630919.577 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-12-10T20:08:39.577Z,1607630919.577 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-12-10T20:08:39.577Z,1607630919.577 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2020-12-10T20:08:39.851Z,1607630919.851 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2020-12-10T20:08:39.851Z,1607630919.851 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2020-12-10T20:08:40.252Z,1607630920.252 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 92.312337 min 
2020-12-10T20:08:40.252Z,1607630920.252 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2020-12-10T20:08:40.252Z,1607630920.252 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2020-12-10T20:08:40.252Z,1607630920.252 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-12-10T20:08:40.252Z,1607630920.252 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-12-10T20:08:40.252Z,1607630920.252 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #5
2020-12-10T20:08:40.252Z,1607630920.252 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=5
2020-12-10T20:08:40.253Z,1607630920.253 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-12-10T20:08:40.253Z,1607630920.253 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-12-10T20:08:42.223Z,1607630922.223 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200842.00,A,4133.16905,N,07042.36648,W,0.350,157.68,101220,,,A*7B
2020-12-10T20:08:42.225Z,1607630922.225 [NAL9602](INFO): GPS fix at 20201210T200842: (41.552818, -70.706108)
2020-12-10T20:08:42.252Z,1607630922.252 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-12-10T20:08:42.252Z,1607630922.252 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-12-10T20:08:46.639Z,1607630926.639 [DataOverHttps](INFO): Sending 224 bytes from file Logs/20201210T180318/Courier0049.lzma
2020-12-10T20:08:47.641Z,1607630927.641 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Courier0049.lzma.bak
2020-12-10T20:08:47.641Z,1607630927.641 [DataOverHttps](INFO): SBD MOMSN=59952
2020-12-10T20:08:56.686Z,1607630936.686 [DataOverHttps](INFO): Sending 53 bytes from file Logs/20201210T180318/Courier0052.lzma
2020-12-10T20:08:57.689Z,1607630937.689 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Courier0052.lzma.bak
2020-12-10T20:08:57.689Z,1607630937.689 [DataOverHttps](INFO): SBD MOMSN=59957
2020-12-10T20:09:04.563Z,1607630944.563 [NAL9602](INFO): SBD MO Status=2, MOMSN=12215, MT Status=2, MTMSN=0
2020-12-10T20:09:04.564Z,1607630944.564 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-12-10T20:09:06.728Z,1607630946.728 [DataOverHttps](INFO): Sending 633 bytes from file Logs/20201210T180318/Express0050.lzma
2020-12-10T20:09:07.729Z,1607630947.729 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Express0050.lzma.bak
2020-12-10T20:09:07.729Z,1607630947.729 [DataOverHttps](INFO): SBD MOMSN=59959
2020-12-10T20:09:08.306Z,1607630948.306 [CommandLine](IMPORTANT): got command set LBLTest.trans3Location NaN degree
2020-12-10T20:09:08.307Z,1607630948.307 [CommandLine](IMPORTANT): got command set LBLTest.trans3Depth NaN meter
2020-12-10T20:09:08.323Z,1607630948.323 [CommandLine](IMPORTANT): got command set 
2020-12-10T20:09:08.323Z,1607630948.323 [CommandLine](FAULT): Incomplete syntax. Try: help set
2020-12-10T20:09:16.687Z,1607630956.687 [NAL9602](INFO): SBD MO Status=0, MOMSN=12215, MT Status=0, MTMSN=0
2020-12-10T20:09:16.687Z,1607630956.687 [NAL9602](INFO): No messages in MT queue
2020-12-10T20:09:16.773Z,1607630956.773 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20201210T180318/Express0053.lzma
2020-12-10T20:09:17.773Z,1607630957.773 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Express0053.lzma.bak
2020-12-10T20:09:17.773Z,1607630957.773 [DataOverHttps](INFO): SBD MOMSN=59981
2020-12-10T20:09:19.151Z,1607630959.151 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-12-10T20:09:19.151Z,1607630959.151 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-12-10T20:09:19.151Z,1607630959.151 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-12-10T20:09:28.329Z,1607630968.329 [CommandLine](IMPORTANT): got command set 
2020-12-10T20:09:28.329Z,1607630968.329 [CommandLine](FAULT): Incomplete syntax. Try: help set
2020-12-10T20:09:47.388Z,1607630987.388 [NAL9602](INFO): Not Powering down - fast GPS
2020-12-10T20:12:14.238Z,1607631134.238 [CommandLine](IMPORTANT): got command show variable LBL
2020-12-10T20:12:14.366Z,1607631134.366 [CommandLine](IMPORTANT): LBLNavigation.loadAtStartup (bool)
2020-12-10T20:12:14.366Z,1607631134.366 [CommandLine](IMPORTANT): LBLNavigation.speedOfSound (meter_per_second)
2020-12-10T20:12:14.366Z,1607631134.366 [CommandLine](IMPORTANT): LBLNavigation.pingDistanceError (meter)
2020-12-10T20:12:14.367Z,1607631134.367 [CommandLine](IMPORTANT): LBLNavigation.angleThreshold (degree)
2020-12-10T20:12:14.367Z,1607631134.367 [CommandLine](IMPORTANT): LBLNavigation.lookbackCount (count)
2020-12-10T20:12:14.368Z,1607631134.368 [CommandLine](IMPORTANT): LBLNavigation.lookbackThreshold (degree)
2020-12-10T20:12:14.548Z,1607631134.548 [CommandLine](IMPORTANT): LBLNavigation.ping1TOF (second)
2020-12-10T20:12:14.548Z,1607631134.548 [CommandLine](IMPORTANT): LBLNavigation.ping2TOF (second)
2020-12-10T20:12:14.549Z,1607631134.549 [CommandLine](IMPORTANT): LBLNavigation.ping3TOF (second)
2020-12-10T20:12:14.549Z,1607631134.549 [CommandLine](IMPORTANT): LBLNavigation.ping4TOF (second)
2020-12-10T20:12:14.644Z,1607631134.644 [CommandLine](IMPORTANT): LBLTest.trans1Location (degree)
2020-12-10T20:12:14.644Z,1607631134.644 [CommandLine](IMPORTANT): LBLTest.trans1Depth (meter)
2020-12-10T20:12:14.644Z,1607631134.644 [CommandLine](IMPORTANT): LBLTest.trans2Location (degree)
2020-12-10T20:12:14.645Z,1607631134.645 [CommandLine](IMPORTANT): LBLTest.trans2Depth (meter)
2020-12-10T20:12:14.645Z,1607631134.645 [CommandLine](IMPORTANT): LBLTest.trans3Location (degree)
2020-12-10T20:12:14.645Z,1607631134.645 [CommandLine](IMPORTANT): LBLTest.trans3Depth (meter)
2020-12-10T20:12:14.646Z,1607631134.646 [CommandLine](IMPORTANT): LBLTest:transit.MissionTimeout (minute)
2020-12-10T20:12:14.646Z,1607631134.646 [CommandLine](IMPORTANT): LBLTest:transit.NeedCommsTime (minute)
2020-12-10T20:12:14.646Z,1607631134.646 [CommandLine](IMPORTANT): LBLTest:transit.Latitude (degree)
2020-12-10T20:12:14.647Z,1607631134.647 [CommandLine](IMPORTANT): LBLTest:transit.Longitude (degree)
2020-12-10T20:12:14.655Z,1607631134.655 [CommandLine](IMPORTANT): LBLTest:transit.Northings (meter)
2020-12-10T20:12:14.656Z,1607631134.656 [CommandLine](IMPORTANT): LBLTest:transit.Eastings (meter)
2020-12-10T20:12:14.656Z,1607631134.656 [CommandLine](IMPORTANT): LBLTest:transit.Depth (meter)
2020-12-10T20:12:14.656Z,1607631134.656 [CommandLine](IMPORTANT): LBLTest:transit.Speed (meter_per_second)
2020-12-10T20:12:14.657Z,1607631134.657 [CommandLine](IMPORTANT): LBLTest:transit.MaxDepth (meter)
2020-12-10T20:12:14.657Z,1607631134.657 [CommandLine](IMPORTANT): LBLTest:transit.MinOffshore (kilometer)
2020-12-10T20:12:14.657Z,1607631134.657 [CommandLine](IMPORTANT): LBLTest:transit.MinAltitude (meter)
2020-12-10T20:12:14.658Z,1607631134.658 [CommandLine](IMPORTANT): LBLTest:transit.MassHold (bool)
2020-12-10T20:12:14.658Z,1607631134.658 [CommandLine](IMPORTANT): LBLTest:transit.BuoyancyHold (bool)
2020-12-10T20:12:14.658Z,1607631134.658 [CommandLine](IMPORTANT): LBLTest:transit:NeedComms.DiveInterval (hour)
2020-12-10T20:12:14.659Z,1607631134.659 [CommandLine](IMPORTANT): LBLTest:transit:NeedComms.WaitForPitchUp (minute)
2020-12-10T20:12:14.663Z,1607631134.663 [CommandLine](IMPORTANT): LBLTest:transit:NeedComms.SurfacePitch (degree)
2020-12-10T20:12:14.664Z,1607631134.664 [CommandLine](IMPORTANT): LBLTest:transit:NeedComms.SurfaceDepthRate (meter_per_second)
2020-12-10T20:12:14.664Z,1607631134.664 [CommandLine](IMPORTANT): LBLTest:transit:NeedComms.SurfaceSpeed (meter_per_second)
2020-12-10T20:12:14.664Z,1607631134.664 [CommandLine](IMPORTANT): LBLTest:transit:NeedComms.GPSTimeout (minute)
2020-12-10T20:12:14.665Z,1607631134.665 [CommandLine](IMPORTANT): LBLTest:transit:NeedComms.CommsTimeout (minute)
2020-12-10T20:12:14.665Z,1607631134.665 [CommandLine](IMPORTANT): LBLTest:transit:StandardEnvelopes.MinAltitude (meter)
2020-12-10T20:12:14.665Z,1607631134.665 [CommandLine](IMPORTANT): LBLTest:transit:StandardEnvelopes.MaxDepth (meter)
2020-12-10T20:12:14.666Z,1607631134.666 [CommandLine](IMPORTANT): LBLTest:transit:StandardEnvelopes.MinOffshore (meter)
2020-12-10T20:12:31.757Z,1607631151.757 [CommandLine](IMPORTANT): got command get LBLNavigation.loadAtStartup
2020-12-10T20:12:31.758Z,1607631151.758 [CommandLine](IMPORTANT): LBLNavigation.loadAtStartup 0 bool
2020-12-10T20:12:35.496Z,1607631155.496 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-12-10T20:13:25.564Z,1607631205.564 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2020-12-10T20:14:19.707Z,1607631259.707 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2020-12-10T20:14:19.707Z,1607631259.707 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-12-10T20:14:19.708Z,1607631259.708 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-12-10T20:14:19.708Z,1607631259.708 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2020-12-10T20:14:20.123Z,1607631260.123 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2020-12-10T20:14:20.123Z,1607631260.123 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2020-12-10T20:14:20.553Z,1607631260.553 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 97.983529 min 
2020-12-10T20:14:20.553Z,1607631260.553 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2020-12-10T20:14:20.553Z,1607631260.553 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2020-12-10T20:14:20.553Z,1607631260.553 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-12-10T20:14:20.554Z,1607631260.554 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-12-10T20:14:20.554Z,1607631260.554 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #6
2020-12-10T20:14:20.554Z,1607631260.554 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=6
2020-12-10T20:14:20.554Z,1607631260.554 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-12-10T20:14:20.554Z,1607631260.554 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-12-10T20:14:22.524Z,1607631262.524 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201422.00,A,4133.15056,N,07042.34805,W,0.156,107.79,101220,,,A*78
2020-12-10T20:14:22.526Z,1607631262.526 [NAL9602](INFO): GPS fix at 20201210T201422: (41.552509, -70.705801)
2020-12-10T20:14:22.546Z,1607631262.546 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-12-10T20:14:22.546Z,1607631262.546 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-12-10T20:14:26.071Z,1607631266.071 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20201210T180318/Courier0055.lzma
2020-12-10T20:14:27.073Z,1607631267.073 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Courier0055.lzma.bak
2020-12-10T20:14:27.073Z,1607631267.073 [DataOverHttps](INFO): SBD MOMSN=59984
2020-12-10T20:14:35.479Z,1607631275.479 [NAL9602](INFO): SBD MO Status=0, MOMSN=12216, MT Status=0, MTMSN=0
2020-12-10T20:14:35.479Z,1607631275.479 [NAL9602](INFO): No messages in MT queue
2020-12-10T20:14:36.112Z,1607631276.112 [DataOverHttps](INFO): Sending 738 bytes from file Logs/20201210T180318/Express0056.lzma
2020-12-10T20:14:37.113Z,1607631277.113 [DataOverHttps](INFO): Moved sent file to Logs/20201210T180318/Express0056.lzma.bak
2020-12-10T20:14:37.113Z,1607631277.113 [DataOverHttps](INFO): SBD MOMSN=59987
2020-12-10T20:14:38.316Z,1607631278.316 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-12-10T20:14:38.316Z,1607631278.316 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-12-10T20:14:38.316Z,1607631278.316 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-12-10T20:15:06.188Z,1607631306.188 [NAL9602](INFO): Not Powering down - fast GPS
2020-12-10T20:15:17.289Z,1607631317.289 [DataOverHttps](IMPORTANT): SBD MTMSN=20201210T201517
2020-12-10T20:15:21.307Z,1607631321.307 [DataOverHttps](INFO): Received command:configSet LBLNavigation.loadAtStartup 1 bool persist;restart app
2020-12-10T20:15:21.502Z,1607631321.502 [CommandLine](IMPORTANT): got command configSet LBLNavigation.loadAtStartup 1.000000 bool persist
2020-12-10T20:15:21.502Z,1607631321.502 [CommandLine](IMPORTANT): configSet LBLNavigation.loadAtStartup requires a restart to take effect.
2020-12-10T20:15:21.551Z,1607631321.551 [CommandLine](IMPORTANT): got command restart application
2020-12-10T20:15:22.571Z,1607631322.571 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2020-12-10T20:15:22.571Z,1607631322.571 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-12-10T20:15:22.719Z,1607631322.719 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2020-12-10T20:15:22.719Z,1607631322.719 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-12-10T20:15:22.720Z,1607631322.720 [CommandLine](INFO): Join timeout helper Thread ID is 1609
2020-12-10T20:15:22.720Z,1607631322.720 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2020-12-10T20:15:22.721Z,1607631322.721 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-12-10T20:15:22.721Z,1607631322.721 [NavChartDb](INFO): Join timeout helper Thread ID is 1610
2020-12-10T20:15:22.872Z,1607631322.872 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2020-12-10T20:15:22.873Z,1607631322.873 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-12-10T20:15:22.883Z,1607631322.883 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2020-12-10T20:15:22.883Z,1607631322.883 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-12-10T20:15:22.884Z,1607631322.884 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 1611
2020-12-10T20:15:22.884Z,1607631322.884 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2020-12-10T20:15:22.884Z,1607631322.884 [WetLabsSeaOWL_UV_A](INFO): Powering down
2020-12-10T20:15:22.885Z,1607631322.885 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-12-10T20:15:22.886Z,1607631322.886 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2020-12-10T20:15:22.886Z,1607631322.886 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-12-10T20:15:22.886Z,1607631322.886 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1612
2020-12-10T20:15:22.956Z,1607631322.956 [CTD_Seabird](INFO): Powering down
2020-12-10T20:15:22.971Z,1607631322.971 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2020-12-10T20:15:22.971Z,1607631322.971 [CTD_Seabird](INFO): Powering down
2020-12-10T20:15:22.983Z,1607631322.983 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-12-10T20:15:22.984Z,1607631322.984 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2020-12-10T20:15:22.984Z,1607631322.984 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-12-10T20:15:22.984Z,1607631322.984 [Radio_Surface](INFO): Join timeout helper Thread ID is 1613
2020-12-10T20:15:23.279Z,1607631323.279 [Radio_Surface](INFO): Powering down
2020-12-10T20:15:23.280Z,1607631323.280 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2020-12-10T20:15:23.280Z,1607631323.280 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-12-10T20:15:23.296Z,1607631323.296 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2020-12-10T20:15:23.296Z,1607631323.296 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-12-10T20:15:23.297Z,1607631323.297 [Onboard](INFO): Join timeout helper Thread ID is 1614
2020-12-10T20:15:23.312Z,1607631323.312 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2020-12-10T20:15:25.527Z,1607631325.527 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2020-12-10T20:15:25.528Z,1607631325.528 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-12-10T20:15:25.548Z,1607631325.548 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2020-12-10T20:15:25.548Z,1607631325.548 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-12-10T20:15:25.548Z,1607631325.548 [DataOverHttps](INFO): Join timeout helper Thread ID is 1615
2020-12-10T20:15:26.323Z,1607631326.323 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2020-12-10T20:15:26.324Z,1607631326.324 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-12-10T20:15:26.347Z,1607631326.347 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2020-12-10T20:15:26.347Z,1607631326.347 [logger ThreadHandler](INFO): Thread cancelled.
2020-12-10T20:15:26.348Z,1607631326.348 [logger](INFO): Join timeout helper Thread ID is 1616
2020-12-10T20:15:26.395Z,1607631326.395 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2020-12-10T20:15:26.396Z,1607631326.396 [logger ThreadHandler](INFO): Thread cancelled.
2020-12-10T20:15:26.413Z,1607631326.413 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2020-12-10T20:15:26.414Z,1607631326.414 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-12-10T20:15:26.414Z,1607631326.414 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2020-12-10T20:15:26.414Z,1607631326.414 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-12-10T20:15:26.415Z,1607631326.415 [controlThread](INFO): Join timeout helper Thread ID is 1617
2020-12-10T20:15:26.420Z,1607631326.420 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2020-12-10T20:15:26.420Z,1607631326.420 [controlThread](DEBUG): Uninitializing ControlThread
2020-12-10T20:15:26.421Z,1607631326.421 [AHRS_M2](INFO): Powering down
2020-12-10T20:15:26.492Z,1607631326.492 [DDM](INFO): Powering down
2020-12-10T20:15:26.564Z,1607631326.564 [DUSBL_Hydroid](INFO): Powering down
2020-12-10T20:15:26.636Z,1607631326.636 [Micromodem](INFO): Powering down
2020-12-10T20:15:26.731Z,1607631326.731 [NAL9602](INFO): Powering down
2020-12-10T20:15:26.803Z,1607631326.803 [RDI_Pathfinder](INFO): Powering down
2020-12-10T20:15:26.875Z,1607631326.875 [RDI_PathfinderUp](INFO): Powering down
2020-12-10T20:15:26.877Z,1607631326.877 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2020-12-10T20:15:26.877Z,1607631326.877 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2020-12-10T20:15:26.878Z,1607631326.878 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2020-12-10T20:15:26.879Z,1607631326.879 [MissionManager](INFO): Uninitializing Mission DefaultWithUndock
2020-12-10T20:15:26.879Z,1607631326.879 [DefaultWithUndock] Stopped
2020-12-10T20:15:26.879Z,1607631326.879 [DefaultWithUndock](DEBUG): Aggregate::uninitialize DefaultWithUndock
2020-12-10T20:15:26.879Z,1607631326.879 [DefaultWithUndock:SurfaceDefault] Stopped
2020-12-10T20:15:26.879Z,1607631326.879 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault
2020-12-10T20:15:26.879Z,1607631326.879 [DefaultWithUndock:SurfaceDefault:B.GoToSurface] Stopped
2020-12-10T20:15:26.879Z,1607631326.879 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-12-10T20:15:26.879Z,1607631326.879 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-12-10T20:15:26.879Z,1607631326.879 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-12-10T20:15:26.879Z,1607631326.879 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-12-10T20:15:26.880Z,1607631326.880 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-12-10T20:15:26.886Z,1607631326.886 [MissionManager](INFO): Uninitializing Mission LBLTest
2020-12-10T20:15:26.898Z,1607631326.898 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2020-12-10T20:15:26.899Z,1607631326.899 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2020-12-10T20:15:26.899Z,1607631326.899 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2020-12-10T20:15:26.899Z,1607631326.899 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2020-12-10T20:15:26.900Z,1607631326.900 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2020-12-10T20:15:26.900Z,1607631326.900 [BuoyancyServo](INFO): Powering down
2020-12-10T20:15:26.911Z,1607631326.911 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2020-12-10T20:15:26.911Z,1607631326.911 [ElevatorServo](INFO): Powering down
2020-12-10T20:15:26.912Z,1607631326.912 [MassServo](DEBUG): Uninitialize Mass Servo.
2020-12-10T20:15:26.912Z,1607631326.912 [MassServo](INFO): Powering down
2020-12-10T20:15:26.913Z,1607631326.913 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-12-10T20:15:26.913Z,1607631326.913 [RudderServo](INFO): Powering down
2020-12-10T20:15:26.914Z,1607631326.914 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2020-12-10T20:15:26.914Z,1607631326.914 [ThrusterServo](INFO): Powering down
2020-12-10T20:15:26.915Z,1607631326.915 [SBIT](DEBUG): Uninitialize SBIT Component.
2020-12-10T20:15:26.915Z,1607631326.915 [IBIT](DEBUG): Uninitialize IBIT Component.
2020-12-10T20:15:26.915Z,1607631326.915 [CBIT](DEBUG): Uninitialize CBIT Component.
2020-12-10T20:15:26.916Z,1607631326.916 [CBIT](DEBUG): Powering off loads.
2020-12-10T20:15:26.927Z,1607631326.927 [CBIT](DEBUG): Disabling WDT.
2020-12-10T20:15:26.939Z,1607631326.939 [CBIT](DEBUG): Opening all GF detection circuits.
2020-12-10T20:15:26.940Z,1607631326.940 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-12-10T20:15:26.947Z,1607631326.947 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-12-10T20:15:26.949Z,1607631326.949 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-12-10T20:15:26.960Z,1607631326.960 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-12-10T20:15:27.046Z,1607631327.046 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-12-10T20:15:27.049Z,1607631327.049 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-12-10T20:15:27.105Z,1607631327.105 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-12-10T20:15:27.171Z,1607631327.171 [logger ThreadHandler](INFO): Thread cancelled.