2021-02-15T16:06:27.138Z,1613405187.138 [Supervisor](DEBUG): Initializing supervisor.
2021-02-15T16:06:27.143Z,1613405187.143 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2021-02-15T16:06:27.143Z,1613405187.143 [SyncHandler](INFO): Protected caller Thread ID is 5670
2021-02-15T16:06:27.144Z,1613405187.144 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2021-02-15T16:06:27.145Z,1613405187.145 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2021-02-15T16:06:27.145Z,1613405187.145 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 5671
2021-02-15T16:06:27.150Z,1613405187.150 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2021-02-15T16:06:27.170Z,1613405187.170 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2021-02-15T16:06:27.171Z,1613405187.171 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2021-02-15T16:06:27.172Z,1613405187.172 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 5672
2021-02-15T16:06:27.174Z,1613405187.174 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2021-02-15T16:06:27.175Z,1613405187.175 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2021-02-15T16:06:27.175Z,1613405187.175 [logger ThreadHandler](INFO): Protected caller Thread ID is 5673
2021-02-15T16:06:27.179Z,1613405187.179 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2021-02-15T16:06:27.179Z,1613405187.179 [Supervisor](INFO): Looking for Config files in directory: Config/
2021-02-15T16:06:27.181Z,1613405187.181 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2021-02-15T16:06:27.589Z,1613405187.589 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2021-02-15T16:06:27.589Z,1613405187.589 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2021-02-15T16:06:27.666Z,1613405187.666 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2021-02-15T16:06:27.993Z,1613405187.993 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2021-02-15T16:06:27.993Z,1613405187.993 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2021-02-15T16:06:28.092Z,1613405188.092 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2021-02-15T16:06:28.092Z,1613405188.092 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2021-02-15T16:06:28.289Z,1613405188.289 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2021-02-15T16:06:28.289Z,1613405188.289 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2021-02-15T16:06:28.811Z,1613405188.811 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2021-02-15T16:06:28.811Z,1613405188.811 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2021-02-15T16:06:29.050Z,1613405189.050 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2021-02-15T16:06:29.050Z,1613405189.050 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2021-02-15T16:06:29.199Z,1613405189.199 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2021-02-15T16:06:29.200Z,1613405189.200 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2021-02-15T16:06:29.389Z,1613405189.389 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2021-02-15T16:06:29.390Z,1613405189.390 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2021-02-15T16:06:29.485Z,1613405189.485 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2021-02-15T16:06:29.486Z,1613405189.486 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2021-02-15T16:06:29.707Z,1613405189.707 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2021-02-15T16:06:29.707Z,1613405189.707 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2021-02-15T16:06:30.018Z,1613405190.018 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2021-02-15T16:06:30.019Z,1613405190.019 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2021-02-15T16:06:30.098Z,1613405190.098 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2021-02-15T16:06:30.224Z,1613405190.224 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2021-02-15T16:06:30.225Z,1613405190.225 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2021-02-15T16:06:30.888Z,1613405190.888 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2021-02-15T16:06:30.888Z,1613405190.888 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2021-02-15T16:06:31.252Z,1613405191.252 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2021-02-15T16:06:31.254Z,1613405191.254 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2021-02-15T16:06:31.254Z,1613405191.254 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2021-02-15T16:06:31.454Z,1613405191.454 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2021-02-15T16:06:31.552Z,1613405191.552 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2021-02-15T16:06:31.650Z,1613405191.650 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2021-02-15T16:06:31.961Z,1613405191.961 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2021-02-15T16:06:31.961Z,1613405191.961 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2021-02-15T16:06:32.227Z,1613405192.227 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2021-02-15T16:06:32.415Z,1613405192.415 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2021-02-15T16:06:32.655Z,1613405192.655 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2021-02-15T16:06:32.844Z,1613405192.844 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Dock.cfg
2021-02-15T16:06:32.945Z,1613405192.945 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2021-02-15T16:06:33.058Z,1613405193.058 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/workSite.cfg
2021-02-15T16:06:33.156Z,1613405193.156 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2021-02-15T16:06:33.345Z,1613405193.345 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2021-02-15T16:06:33.483Z,1613405193.483 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2021-02-15T16:06:33.490Z,1613405193.490 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2021-02-15T16:06:33.826Z,1613405193.826 [AHRS_M2] Loaded
2021-02-15T16:06:33.826Z,1613405193.826 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2021-02-15T16:06:34.599Z,1613405194.599 [BPC1] Loaded
2021-02-15T16:06:34.600Z,1613405194.600 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2021-02-15T16:06:34.673Z,1613405194.673 [DataOverHttps] Loaded
2021-02-15T16:06:34.674Z,1613405194.674 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2021-02-15T16:06:34.675Z,1613405194.675 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407924E0
2021-02-15T16:06:34.675Z,1613405194.675 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 5761
2021-02-15T16:06:34.697Z,1613405194.697 [DDM] Loaded
2021-02-15T16:06:34.697Z,1613405194.697 [ComponentRegistry](DEBUG): SyncComponent "DDM" handled in the control thread.
2021-02-15T16:06:34.716Z,1613405194.716 [Depth_Keller] Loaded
2021-02-15T16:06:34.717Z,1613405194.717 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2021-02-15T16:06:34.760Z,1613405194.760 [DUSBL_Hydroid] Loaded
2021-02-15T16:06:34.760Z,1613405194.760 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2021-02-15T16:06:34.796Z,1613405194.796 [Micromodem] Loaded
2021-02-15T16:06:34.796Z,1613405194.796 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2021-02-15T16:06:34.856Z,1613405194.856 [NAL9602] Loaded
2021-02-15T16:06:34.856Z,1613405194.856 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2021-02-15T16:06:34.885Z,1613405194.885 [Onboard] Loaded
2021-02-15T16:06:34.885Z,1613405194.885 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2021-02-15T16:06:34.886Z,1613405194.886 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 407C24E0
2021-02-15T16:06:34.886Z,1613405194.886 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 5762
2021-02-15T16:06:34.900Z,1613405194.900 [Radio_Surface] Loaded
2021-02-15T16:06:34.901Z,1613405194.901 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2021-02-15T16:06:34.902Z,1613405194.902 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407F24E0
2021-02-15T16:06:34.902Z,1613405194.902 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 5763
2021-02-15T16:06:34.933Z,1613405194.933 [RDI_Pathfinder] Loaded
2021-02-15T16:06:34.933Z,1613405194.933 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2021-02-15T16:06:34.959Z,1613405194.959 [RDI_PathfinderUp] Loaded
2021-02-15T16:06:34.959Z,1613405194.959 [ComponentRegistry](DEBUG): SyncComponent "RDI_PathfinderUp" handled in the control thread.
2021-02-15T16:06:34.960Z,1613405194.960 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2021-02-15T16:06:34.961Z,1613405194.961 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2021-02-15T16:06:34.972Z,1613405194.972 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2021-02-15T16:06:34.972Z,1613405194.972 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2021-02-15T16:06:35.053Z,1613405195.053 [DeadReckonUsingMultipleVelocitySources] Loaded
2021-02-15T16:06:35.053Z,1613405195.053 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2021-02-15T16:06:35.066Z,1613405195.066 [NavChart] Loaded
2021-02-15T16:06:35.066Z,1613405195.066 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2021-02-15T16:06:35.072Z,1613405195.072 [UniversalFixResidualReporter] Loaded
2021-02-15T16:06:35.072Z,1613405195.072 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2021-02-15T16:06:35.083Z,1613405195.083 [WorkSite] Loaded
2021-02-15T16:06:35.083Z,1613405195.083 [ComponentRegistry](DEBUG): SyncComponent "WorkSite" handled in the control thread.
2021-02-15T16:06:35.084Z,1613405195.084 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2021-02-15T16:06:35.084Z,1613405195.084 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2021-02-15T16:06:35.172Z,1613405195.172 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2021-02-15T16:06:35.172Z,1613405195.172 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2021-02-15T16:06:35.292Z,1613405195.292 [BuoyancyServo] Loaded
2021-02-15T16:06:35.293Z,1613405195.293 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2021-02-15T16:06:35.313Z,1613405195.313 [ElevatorServo] Loaded
2021-02-15T16:06:35.314Z,1613405195.314 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2021-02-15T16:06:35.334Z,1613405195.334 [MassServo] Loaded
2021-02-15T16:06:35.334Z,1613405195.334 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2021-02-15T16:06:35.354Z,1613405195.354 [RudderServo] Loaded
2021-02-15T16:06:35.354Z,1613405195.354 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2021-02-15T16:06:35.373Z,1613405195.373 [ThrusterServo] Loaded
2021-02-15T16:06:35.374Z,1613405195.374 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2021-02-15T16:06:35.374Z,1613405195.374 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2021-02-15T16:06:35.375Z,1613405195.375 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2021-02-15T16:06:35.549Z,1613405195.549 [CTD_Seabird] Loaded
2021-02-15T16:06:35.549Z,1613405195.549 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2021-02-15T16:06:35.550Z,1613405195.550 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409154E0
2021-02-15T16:06:35.550Z,1613405195.550 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 5764
2021-02-15T16:06:35.570Z,1613405195.570 [PAR_Licor] Loaded
2021-02-15T16:06:35.570Z,1613405195.570 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2021-02-15T16:06:35.603Z,1613405195.603 [WetLabsSeaOWL_UV_A] Loaded
2021-02-15T16:06:35.603Z,1613405195.603 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2021-02-15T16:06:35.604Z,1613405195.604 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409454E0
2021-02-15T16:06:35.604Z,1613405195.604 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 5765
2021-02-15T16:06:35.605Z,1613405195.605 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2021-02-15T16:06:35.606Z,1613405195.606 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2021-02-15T16:06:35.923Z,1613405195.923 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2021-02-15T16:06:35.923Z,1613405195.923 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2021-02-15T16:06:35.965Z,1613405195.965 [DepthRateCalculator] Loaded
2021-02-15T16:06:35.965Z,1613405195.965 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2021-02-15T16:06:35.971Z,1613405195.971 [PitchRateCalculator] Loaded
2021-02-15T16:06:35.971Z,1613405195.971 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2021-02-15T16:06:35.980Z,1613405195.980 [SpeedCalculator] Loaded
2021-02-15T16:06:35.981Z,1613405195.981 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2021-02-15T16:06:35.994Z,1613405195.994 [TempGradientCalculator] Loaded
2021-02-15T16:06:35.994Z,1613405195.994 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2021-02-15T16:06:35.999Z,1613405195.999 [YawRateCalculator] Loaded
2021-02-15T16:06:35.999Z,1613405195.999 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2021-02-15T16:06:36.021Z,1613405196.021 [ElevatorOffsetCalculator] Loaded
2021-02-15T16:06:36.021Z,1613405196.021 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2021-02-15T16:06:36.022Z,1613405196.022 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2021-02-15T16:06:36.022Z,1613405196.022 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2021-02-15T16:06:36.167Z,1613405196.167 [SBIT](DEBUG): Construct Startup Built In Test.
2021-02-15T16:06:36.179Z,1613405196.179 [SBIT] Loaded
2021-02-15T16:06:36.179Z,1613405196.179 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2021-02-15T16:06:36.182Z,1613405196.182 [IBIT](DEBUG): Construct Initiated Built In Test.
2021-02-15T16:06:36.195Z,1613405196.195 [IBIT] Loaded
2021-02-15T16:06:36.195Z,1613405196.195 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2021-02-15T16:06:36.201Z,1613405196.201 [CBIT](DEBUG): Construct Continuous Built In Test.
2021-02-15T16:06:36.302Z,1613405196.302 [CBIT] Loaded
2021-02-15T16:06:36.302Z,1613405196.302 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2021-02-15T16:06:36.303Z,1613405196.303 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2021-02-15T16:06:36.303Z,1613405196.303 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2021-02-15T16:06:36.359Z,1613405196.359 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2021-02-15T16:06:36.359Z,1613405196.359 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2021-02-15T16:06:36.463Z,1613405196.463 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2021-02-15T16:06:36.464Z,1613405196.464 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2021-02-15T16:06:36.516Z,1613405196.516 [VerticalControl](DEBUG): Construct VerticalControl.
2021-02-15T16:06:36.568Z,1613405196.568 [VerticalControl] Loaded
2021-02-15T16:06:36.568Z,1613405196.568 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2021-02-15T16:06:36.571Z,1613405196.571 [HorizontalControl](DEBUG): Construct HorizontalControl.
2021-02-15T16:06:36.607Z,1613405196.607 [HorizontalControl] Loaded
2021-02-15T16:06:36.607Z,1613405196.607 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2021-02-15T16:06:36.610Z,1613405196.610 [SpeedControl](DEBUG): Construct SpeedControl.
2021-02-15T16:06:36.611Z,1613405196.611 [SpeedControl] Loaded
2021-02-15T16:06:36.612Z,1613405196.612 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2021-02-15T16:06:36.614Z,1613405196.614 [LoopControl](DEBUG): Construct LoopControl.
2021-02-15T16:06:36.615Z,1613405196.615 [LoopControl] Loaded
2021-02-15T16:06:36.615Z,1613405196.615 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2021-02-15T16:06:36.616Z,1613405196.616 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2021-02-15T16:06:36.616Z,1613405196.616 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2021-02-15T16:06:36.645Z,1613405196.645 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2021-02-15T16:06:36.651Z,1613405196.651 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2021-02-15T16:06:36.654Z,1613405196.654 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2021-02-15T16:06:36.665Z,1613405196.665 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2021-02-15T16:06:36.666Z,1613405196.666 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AEE4E0
2021-02-15T16:06:36.666Z,1613405196.666 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 5766
2021-02-15T16:06:36.671Z,1613405196.671 [Supervisor](INFO): Main Thread ID is 5669
2021-02-15T16:06:36.671Z,1613405196.671 [Supervisor](DEBUG): Running supervisor.
2021-02-15T16:06:36.672Z,1613405196.672 [CommandLine ThreadHandler](INFO): Handler Thread ID is 5767
2021-02-15T16:06:36.674Z,1613405196.674 [controlThread ThreadHandler](INFO): Handler Thread ID is 5768
2021-02-15T16:06:36.674Z,1613405196.674 [controlThread](DEBUG): Initializing ControlThread
2021-02-15T16:06:36.681Z,1613405196.681 [NavChart](DEBUG): Initialize NavChart Navigation.
2021-02-15T16:06:36.681Z,1613405196.681 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2021-02-15T16:06:36.682Z,1613405196.682 [WorkSite](DEBUG): Initializing WorkSite component.
2021-02-15T16:06:36.687Z,1613405196.687 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2021-02-15T16:06:36.688Z,1613405196.688 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2021-02-15T16:06:36.688Z,1613405196.688 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2021-02-15T16:06:36.688Z,1613405196.688 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2021-02-15T16:06:36.689Z,1613405196.689 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2021-02-15T16:06:36.689Z,1613405196.689 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2021-02-15T16:06:36.690Z,1613405196.690 [SBIT](INFO): Initialize SBIT Component.
2021-02-15T16:06:36.690Z,1613405196.690 [SBIT](IMPORTANT): git: 2021-02-08-6-gb6c8b0586
2021-02-15T16:06:36.690Z,1613405196.690 [SBIT](INFO): git hash: b6c8b05865185e26c6453a7ea23a04ac8f50e97e
2021-02-15T16:06:36.691Z,1613405196.691 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2021-02-15T16:06:36.692Z,1613405196.692 [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
2021-02-15T16:06:36.693Z,1613405196.693 [SBIT](INFO): Beginning SBIT in 36.000000 seconds.
2021-02-15T16:06:36.694Z,1613405196.694 [IBIT](INFO): Initialize IBIT Component.
2021-02-15T16:06:36.694Z,1613405196.694 [CBIT](DEBUG): Initialize CBIT Component.
2021-02-15T16:06:36.696Z,1613405196.696 [logger ThreadHandler](INFO): Handler Thread ID is 5769
2021-02-15T16:06:36.707Z,1613405196.707 [CBIT](DEBUG): Initialized mux pins.
2021-02-15T16:06:36.707Z,1613405196.707 [CBIT](DEBUG): Initializing the watchdog timer.
2021-02-15T16:06:36.715Z,1613405196.715 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 5770
2021-02-15T16:06:36.716Z,1613405196.716 [DataOverHttps](DEBUG): dashIP=128.128.181.155 starts with a digit so assuming it is a numeric IP
2021-02-15T16:06:36.727Z,1613405196.727 [Onboard ThreadHandler](INFO): Handler Thread ID is 5771
2021-02-15T16:06:36.732Z,1613405196.732 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2021-02-15T16:06:36.732Z,1613405196.732 [CBIT](DEBUG): Initializing heartbeat.
2021-02-15T16:06:36.756Z,1613405196.756 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 5772
2021-02-15T16:06:36.763Z,1613405196.763 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 5773
2021-02-15T16:06:36.764Z,1613405196.764 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2021-02-15T16:06:36.769Z,1613405196.769 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 5775
2021-02-15T16:06:36.769Z,1613405196.769 [WetLabsSeaOWL_UV_A](INFO): Powering down
2021-02-15T16:06:36.780Z,1613405196.780 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 5776
2021-02-15T16:06:36.783Z,1613405196.783 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2021-02-15T16:06:36.783Z,1613405196.783 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2021-02-15T16:06:36.783Z,1613405196.783 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2021-02-15T16:06:36.783Z,1613405196.783 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2021-02-15T16:06:36.784Z,1613405196.784 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2021-02-15T16:06:36.784Z,1613405196.784 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2021-02-15T16:06:36.784Z,1613405196.784 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2021-02-15T16:06:36.784Z,1613405196.784 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2021-02-15T16:06:36.784Z,1613405196.784 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2021-02-15T16:06:36.784Z,1613405196.784 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2021-02-15T16:06:36.785Z,1613405196.785 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2021-02-15T16:06:36.785Z,1613405196.785 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2021-02-15T16:06:36.785Z,1613405196.785 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2021-02-15T16:06:36.785Z,1613405196.785 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2021-02-15T16:06:36.785Z,1613405196.785 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2021-02-15T16:06:36.785Z,1613405196.785 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2021-02-15T16:06:36.803Z,1613405196.803 [CBIT](DEBUG): Deactivating GF circuits.
2021-02-15T16:06:36.803Z,1613405196.803 [CBIT](DEBUG): Deactivating emergency mode.
2021-02-15T16:06:36.839Z,1613405196.839 [CBIT](DEBUG): Backplane powered.
2021-02-15T16:06:36.839Z,1613405196.839 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2021-02-15T16:06:36.841Z,1613405196.841 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2021-02-15T16:06:36.842Z,1613405196.842 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2021-02-15T16:06:36.842Z,1613405196.842 [LoopControl](DEBUG): Initialize LoopControlComponent.
2021-02-15T16:06:36.843Z,1613405196.843 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2021-02-15T16:06:36.856Z,1613405196.856 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2021-02-15T16:06:36.880Z,1613405196.880 [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>


2021-02-15T16:06:36.880Z,1613405196.880 [MissionManager](INFO): Loading Mission: Missions/underIce/DefaultWithUndock.xml
2021-02-15T16:06:37.069Z,1613405197.069 [MissionManager](INFO): DefineArg DefaultWithUndock.ElapsedSinceDefaultStarted = 0.000000 min
2021-02-15T16:06:37.075Z,1613405197.075 [MissionManager](INFO): DefineArg DefaultWithUndock.DetachTimeout = 30.000000 min
2021-02-15T16:06:37.158Z,1613405197.158 [MissionManager](INFO): DefineArg DefaultWithUndock.TransponderCode = 2.000000 count
2021-02-15T16:06:37.159Z,1613405197.159 [Radio_Surface](INFO): Powering up
2021-02-15T16:06:37.253Z,1613405197.253 [MissionManager](INFO): DefineArg DefaultWithUndock.TrackingUpdatePeriod = 2.500000 s
2021-02-15T16:06:37.260Z,1613405197.260 [MissionManager](INFO): DefineArg DefaultWithUndock.NumberOfPings = 1.000000 count
2021-02-15T16:06:37.276Z,1613405197.276 [MissionManager](INFO): DefineArg DefaultWithUndock.DetachModeDDM = 2.000000 count
2021-02-15T16:06:37.277Z,1613405197.277 [DefaultWithUndock:A.Wait](DEBUG): Construct Wait.
2021-02-15T16:06:37.495Z,1613405197.495 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Construct.
2021-02-15T16:06:37.503Z,1613405197.503 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values.
2021-02-15T16:06:37.576Z,1613405197.576 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-02-15T16:06:37.612Z,1613405197.612 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-02-15T16:06:37.614Z,1613405197.614 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-02-15T16:06:37.640Z,1613405197.640 [DefaultWithUndock:E.Execute](DEBUG): Construct Execute.
2021-02-15T16:06:37.645Z,1613405197.645 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Control="Tethys/Control"
         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/Control http://okeanids.mbari.org/tethys/Xml/Control.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>


2021-02-15T16:06:37.655Z,1613405197.655 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,DDM,Depth_Keller,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,
2021-02-15T16:06:37.667Z,1613405197.667 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2021-02-15T16:06:37.808Z,1613405197.808 [DDM](INFO): Powering up
2021-02-15T16:06:37.808Z,1613405197.808 [DDM](DEBUG): Initializing DDM.
2021-02-15T16:06:37.832Z,1613405197.832 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2021-02-15T16:06:37.832Z,1613405197.832 [DUSBL_Hydroid](INFO): Powering up
2021-02-15T16:06:37.832Z,1613405197.832 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2021-02-15T16:06:37.876Z,1613405197.876 [DepthRateCalculator](ERROR): Depth measurement is not active
2021-02-15T16:06:37.903Z,1613405197.903 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2021-02-15T16:06:37.923Z,1613405197.923 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2021-02-15T16:06:37.924Z,1613405197.924 [ElevatorServo](DEBUG): Initializing EZServoServo.
2021-02-15T16:06:37.931Z,1613405197.931 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2021-02-15T16:06:37.932Z,1613405197.932 [MassServo](DEBUG): Initializing EZServoServo.
2021-02-15T16:06:37.939Z,1613405197.939 [MassServo](DEBUG): Initializing MassServo.
2021-02-15T16:06:37.940Z,1613405197.940 [RudderServo](DEBUG): Initializing EZServoServo.
2021-02-15T16:06:37.947Z,1613405197.947 [RudderServo](DEBUG): Initializing RudderServo.
2021-02-15T16:06:37.948Z,1613405197.948 [ThrusterServo](DEBUG): Initializing EZServoServo.
2021-02-15T16:06:37.955Z,1613405197.955 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2021-02-15T16:06:38.083Z,1613405198.083 [Micromodem](INFO): Powering up
2021-02-15T16:06:38.084Z,1613405198.084 [Micromodem](DEBUG): Initializing Micromodem.
2021-02-15T16:06:38.863Z,1613405198.863 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2021-02-15T16:06:38.863Z,1613405198.863 [RudderServo](FAULT): Rudder failed to initialize
2021-02-15T16:06:38.863Z,1613405198.863 [RudderServo] Communications Fault, FailCount= 1
2021-02-15T16:06:38.863Z,1613405198.863 [RudderServo](ERROR): Communications Fault
2021-02-15T16:06:38.963Z,1613405198.963 [CBIT](ERROR): Communications Fault in component: RudderServo
2021-02-15T16:06:39.128Z,1613405199.128 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-02-15T16:06:39.128Z,1613405199.128 [RudderServo](INFO): Powering down
2021-02-15T16:06:39.808Z,1613405199.808 [RudderServo](DEBUG): Initializing EZServoServo.
2021-02-15T16:06:39.928Z,1613405199.928 [RudderServo](DEBUG): Initializing RudderServo.
2021-02-15T16:06:39.932Z,1613405199.932 [CBIT](INFO): Clearing failed state for component RudderServo
2021-02-15T16:06:39.932Z,1613405199.932 [RudderServo] No Fault, FailCount= 1
2021-02-15T16:06:43.057Z,1613405203.057 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2021-02-15T16:06:43.458Z,1613405203.458 [Micromodem](INFO): Nmea in: $CATMG,2021-02-15T16:06:43.519565Z,RTC,RTC*5A

2021-02-15T16:06:43.458Z,1613405203.458 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2021-02-15T16:06:43.519565Z,RTC,RTC*5A

2021-02-15T16:06:43.861Z,1613405203.861 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31

2021-02-15T16:06:43.861Z,1613405203.861 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31

2021-02-15T16:06:44.265Z,1613405204.265 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33

2021-02-15T16:06:44.265Z,1613405204.265 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64

2021-02-15T16:06:44.669Z,1613405204.669 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66

2021-02-15T16:06:44.669Z,1613405204.669 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F

2021-02-15T16:06:45.077Z,1613405205.077 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D

2021-02-15T16:06:45.077Z,1613405205.077 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E

2021-02-15T16:06:45.477Z,1613405205.477 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C

2021-02-15T16:06:45.477Z,1613405205.477 [Micromodem](INFO): Nmea out: $CCCFG,FC0,14500*47

2021-02-15T16:06:45.877Z,1613405205.877 [Micromodem](INFO): Nmea in: $CACFG,FC0,14500*45

2021-02-15T16:06:45.877Z,1613405205.877 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63

2021-02-15T16:06:46.273Z,1613405206.273 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61

2021-02-15T16:06:46.273Z,1613405206.273 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A

2021-02-15T16:06:46.661Z,1613405206.661 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38

2021-02-15T16:06:46.662Z,1613405206.662 [Micromodem](INFO): Nmea out: $CCCLK,2021,02,15,16,06,47*41

2021-02-15T16:06:47.061Z,1613405207.061 [Micromodem](INFO): Nmea in: $CACLK,2021,2,15,16,6,47*43

2021-02-15T16:06:47.865Z,1613405207.865 [Micromodem](INFO): Nmea in: $CATMS,0,2021-02-15T16:06:48Z*7C

2021-02-15T16:06:47.867Z,1613405207.867 [Micromodem](INFO): Nmea in: $CATMG,2021-02-15T16:06:48.027505Z,USER_CMD,RTC*1E

2021-02-15T16:06:53.516Z,1613405213.516 [DDM](INFO): Dynamic Docking Module:—	
2021-02-15T16:06:55.956Z,1613405215.956 [DUSBL_Hydroid](INFO): DUSBL Version:O
2021-02-15T16:07:05.233Z,1613405225.233 [NAL9602](INFO): Powering up NAL9602
2021-02-15T16:07:13.403Z,1613405233.403 [SBIT](IMPORTANT): Beginning Startup BIT
2021-02-15T16:07:13.417Z,1613405233.417 [CBIT](IMPORTANT): Beginning ground fault scan
2021-02-15T16:07:16.154Z,1613405236.154 [NAL9602](INFO): NAL9602 initialized
2021-02-15T16:07:24.368Z,1613405244.368 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.003371
CHAN A1 (24V): -0.029264
CHAN A2 (12V): -0.007506
CHAN A3 (5V): -0.001716
CHAN B0 (3.3V): 0.000217
CHAN B1 (3.15aV): 0.000081
CHAN B2 (3.15bV): 0.000267
CHAN B3 (GND): 0.002019
OPEN: 0.005093
Full Scale Calc: 4.765 mA, -1.589 mA
2021-02-15T16:07:44.844Z,1613405264.844 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-02-15T16:08:07.494Z,1613405287.494 [SBIT](IMPORTANT): SBIT PASSED
2021-02-15T16:08:07.495Z,1613405287.495 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2021-02-15T16:08:07.496Z,1613405287.496 [SBIT](IMPORTANT): AHRS_M2.verbosity=0 count;

2021-02-15T16:08:07.496Z,1613405287.496 [SBIT](IMPORTANT): Courier mostRecent acoustic_contact_range;

2021-02-15T16:08:07.496Z,1613405287.496 [SBIT](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2021-02-15T16:08:07.497Z,1613405287.497 [SBIT](IMPORTANT): Express none CTD_Seabird.bin_median_sea_water_salinity;

2021-02-15T16:08:07.499Z,1613405287.499 [SBIT](IMPORTANT): Express none CTD_Seabird.bin_median_sea_water_temperature;

2021-02-15T16:08:07.507Z,1613405287.507 [SBIT](IMPORTANT): PowerOnly.loadAtStartup=0 bool;

2021-02-15T16:08:07.878Z,1613405287.878 [WorkSite](IMPORTANT): Reading workSite position from Data/workSite.cfg
2021-02-15T16:08:07.881Z,1613405287.881 [WorkSite](IMPORTANT): WorkSite fix at 20210215T160259: (41.552319, -70.708603)
2021-02-15T16:08:07.882Z,1613405287.882 [MissionManager](IMPORTANT): Started mission Startup
2021-02-15T16:08:07.882Z,1613405287.882 [Startup] Running Loop=1
2021-02-15T16:08:07.883Z,1613405287.883 [Startup](DEBUG): Aggregate::initialize Startup
2021-02-15T16:08:07.883Z,1613405287.883 [Startup:A.GoToSurface] Running Loop=1
2021-02-15T16:08:07.883Z,1613405287.883 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-02-15T16:08:07.884Z,1613405287.884 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-02-15T16:08:07.884Z,1613405287.884 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-02-15T16:08:07.884Z,1613405287.884 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-02-15T16:08:07.885Z,1613405287.885 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-02-15T16:08:07.885Z,1613405287.885 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-02-15T16:08:07.886Z,1613405287.886 [Startup:StartupSatComms] Running Loop=1
2021-02-15T16:08:07.886Z,1613405287.886 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2021-02-15T16:08:07.886Z,1613405287.886 [Startup:StartupSatComms:A] Running Loop=1
2021-02-15T16:08:08.318Z,1613405288.318 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2021-02-15T16:09:08.129Z,1613405348.129 [Startup:StartupSatComms:A](INFO): Timed out from 2021-02-15T16:08:07.9Z
2021-02-15T16:09:08.129Z,1613405348.129 [Startup:StartupSatComms:A] Stopped
2021-02-15T16:09:08.129Z,1613405348.129 [Startup:StartupSatComms:B] Running Loop=1
2021-02-15T16:09:08.544Z,1613405348.544 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-02-15T16:10:08.325Z,1613405408.325 [Startup:StartupSatComms:B](INFO): Timed out from 2021-02-15T16:09:08.1Z
2021-02-15T16:10:08.325Z,1613405408.325 [Startup:StartupSatComms:B] Stopped
2021-02-15T16:10:08.326Z,1613405408.326 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2021-02-15T16:10:08.326Z,1613405408.326 [Startup:StartupSatComms] Stopped
2021-02-15T16:10:08.326Z,1613405408.326 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2021-02-15T16:10:08.326Z,1613405408.326 [Startup](INFO): Completed Startup
2021-02-15T16:10:08.327Z,1613405408.327 [MissionManager](INFO): Startup is completed.
2021-02-15T16:10:08.327Z,1613405408.327 [MissionManager](INFO): Uninitializing Mission Startup
2021-02-15T16:10:08.327Z,1613405408.327 [Startup] Stopped
2021-02-15T16:10:08.327Z,1613405408.327 [Startup](DEBUG): Aggregate::uninitialize Startup
2021-02-15T16:10:08.327Z,1613405408.327 [Startup:A.GoToSurface] Stopped
2021-02-15T16:10:08.327Z,1613405408.327 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-02-15T16:10:08.690Z,1613405408.690 [MissionManager](IMPORTANT): Started mission DefaultWithUndock
2021-02-15T16:10:08.691Z,1613405408.691 [DefaultWithUndock] Running Loop=1
2021-02-15T16:10:08.691Z,1613405408.691 [DefaultWithUndock](DEBUG): Aggregate::initialize DefaultWithUndock
2021-02-15T16:10:08.691Z,1613405408.691 [DefaultWithUndock:A.Wait] Running Loop=1
2021-02-15T16:10:08.691Z,1613405408.691 [DefaultWithUndock:A.Wait](DEBUG): Initialize Wait Component.
2021-02-15T16:10:38.971Z,1613405438.971 [DefaultWithUndock:A.Wait](INFO): Done Waiting.
2021-02-15T16:10:38.971Z,1613405438.971 [DefaultWithUndock:A.Wait] Stopped
2021-02-15T16:10:38.971Z,1613405438.971 [DefaultWithUndock:A.Wait](DEBUG): Uninitialize Wait Component.
2021-02-15T16:10:38.972Z,1613405438.972 [DefaultWithUndock:LeaveDock] Running Loop=1
2021-02-15T16:10:38.972Z,1613405438.972 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::initialize DefaultWithUndock:LeaveDock
2021-02-15T16:10:38.972Z,1613405438.972 [DefaultWithUndock:LeaveDock:A.] Running Loop=1
2021-02-15T16:10:38.972Z,1613405438.972 [DefaultWithUndock:LeaveDock:A.](INFO): Initializing TrackAcousticContact.
2021-02-15T16:10:38.972Z,1613405438.972 [DefaultWithUndock:LeaveDock:B.Undock] Running Loop=1
2021-02-15T16:10:38.972Z,1613405438.972 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize.
2021-02-15T16:10:38.972Z,1613405438.972 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values.
2021-02-15T16:10:39.544Z,1613405439.544 [DefaultWithUndock:LeaveDock:A.] Running Loop=1
2021-02-15T16:10:41.848Z,1613405441.848 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2021-02-15T16:10:42.305Z,1613405442.305 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detaching from dock.
2021-02-15T16:10:42.626Z,1613405442.626 [Micromodem](INFO): Nmea out: $CCPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*76

2021-02-15T16:10:42.690Z,1613405442.690 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detected possible detachment. Starting timer.
2021-02-15T16:10:43.039Z,1613405443.039 [Micromodem](INFO): Nmea in: $SNPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6B

2021-02-15T16:10:43.853Z,1613405443.853 [Micromodem](INFO): Nmea in: $SNTTA,,,,,161043.24*59

2021-02-15T16:10:44.659Z,1613405444.659 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2021-02-15T16:10:46.264Z,1613405446.264 [DUSBL_Hydroid](ERROR): No response from remote modem.
2021-02-15T16:10:47.518Z,1613405447.518 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2021-02-15T16:10:48.297Z,1613405448.297 [Micromodem](INFO): Nmea out: $CCPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*76

2021-02-15T16:10:48.687Z,1613405448.687 [Micromodem](INFO): Nmea in: $SNPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6B

2021-02-15T16:10:49.521Z,1613405449.521 [Micromodem](INFO): Nmea in: $SNTTA,,,,,161048.91*5C

2021-02-15T16:10:50.345Z,1613405450.345 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2021-02-15T16:10:51.916Z,1613405451.916 [DUSBL_Hydroid](ERROR): No response from remote modem.
2021-02-15T16:10:52.892Z,1613405452.892 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2021-02-15T16:10:53.553Z,1613405453.553 [Micromodem](INFO): Nmea out: $CCPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*76

2021-02-15T16:10:53.979Z,1613405453.979 [Micromodem](INFO): Nmea in: $SNPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6B

2021-02-15T16:10:54.754Z,1613405454.754 [Micromodem](INFO): Nmea in: $SNTTA,,,,,161054.17*5F

2021-02-15T16:10:55.563Z,1613405455.563 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2021-02-15T16:10:57.172Z,1613405457.172 [DUSBL_Hydroid](ERROR): No response from remote modem.
2021-02-15T16:10:58.435Z,1613405458.435 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2021-02-15T16:10:59.189Z,1613405459.189 [Micromodem](INFO): Nmea out: $CCPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*76

2021-02-15T16:10:59.606Z,1613405459.606 [Micromodem](INFO): Nmea in: $SNPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6B

2021-02-15T16:11:00.421Z,1613405460.421 [Micromodem](INFO): Nmea in: $SNTTA,,,,,161059.81*5D

2021-02-15T16:11:01.250Z,1613405461.250 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2021-02-15T16:11:02.824Z,1613405462.824 [DUSBL_Hydroid](ERROR): No response from remote modem.
2021-02-15T16:11:02.864Z,1613405462.864 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached at range: nan m. Transitioning DDM to standby.
2021-02-15T16:11:04.127Z,1613405464.127 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2021-02-15T16:11:04.845Z,1613405464.845 [Micromodem](INFO): Nmea out: $CCPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*76

2021-02-15T16:11:05.279Z,1613405465.279 [Micromodem](INFO): Nmea in: $SNPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6B

2021-02-15T16:11:05.332Z,1613405465.332 [DefaultWithUndock:LeaveDock:B.Undock](INFO): DDM at standby.
2021-02-15T16:11:05.663Z,1613405465.663 [DefaultWithUndock:LeaveDock:B.Undock](IMPORTANT): Undocking sequence complete.
2021-02-15T16:11:05.664Z,1613405465.664 [DefaultWithUndock:LeaveDock:B.Undock] Stopped
2021-02-15T16:11:05.664Z,1613405465.664 [DefaultWithUndock:LeaveDock](INFO): Completed DefaultWithUndock:LeaveDock
2021-02-15T16:11:05.664Z,1613405465.664 [DefaultWithUndock:LeaveDock] Stopped
2021-02-15T16:11:05.664Z,1613405465.664 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::uninitialize DefaultWithUndock:LeaveDock
2021-02-15T16:11:05.664Z,1613405465.664 [DefaultWithUndock:LeaveDock:A.] Stopped
2021-02-15T16:11:05.664Z,1613405465.664 [DefaultWithUndock:SurfaceDefault] Running Loop=1
2021-02-15T16:11:05.664Z,1613405465.664 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault
2021-02-15T16:11:05.664Z,1613405465.664 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen] Running Loop=1
2021-02-15T16:11:05.665Z,1613405465.665 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:HoldLatchOpen
2021-02-15T16:11:05.665Z,1613405465.665 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:A] Running Loop=1
2021-02-15T16:11:05.665Z,1613405465.665 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:B] Running Loop=1
2021-02-15T16:11:05.665Z,1613405465.665 [DefaultWithUndock:SurfaceDefault:B.GoToSurface] Running Loop=1
2021-02-15T16:11:05.665Z,1613405465.665 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-02-15T16:11:05.665Z,1613405465.665 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-02-15T16:11:05.665Z,1613405465.665 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-02-15T16:11:05.666Z,1613405465.666 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-02-15T16:11:05.666Z,1613405465.666 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-02-15T16:11:05.666Z,1613405465.666 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-02-15T16:11:06.130Z,1613405466.130 [Micromodem](INFO): Nmea in: $SNTTA,,,,,161105.46*5E

2021-02-15T16:11:06.177Z,1613405466.177 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=1
2021-02-15T16:11:06.177Z,1613405466.177 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2021-02-15T16:11:06.177Z,1613405466.177 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2021-02-15T16:11:06.177Z,1613405466.177 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen] Stopped
2021-02-15T16:11:06.177Z,1613405466.177 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:HoldLatchOpen
2021-02-15T16:11:06.178Z,1613405466.178 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:A] Stopped
2021-02-15T16:11:06.178Z,1613405466.178 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:B] Stopped
2021-02-15T16:11:06.566Z,1613405466.566 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2021-02-15T16:11:47.316Z,1613405507.316 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2021-02-15T16:12:18.749Z,1613405538.749 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-02-15T16:13:42.395Z,1613405622.395 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-02-15T16:13:59.760Z,1613405639.760 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2021-02-15T16:13:59.767Z,1613405639.767 [BPC1](INFO): Received data from all battery sticks.
2021-02-15T16:14:32.489Z,1613405672.489 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2021-02-15T16:14:57.526Z,1613405697.526 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-02-15T16:15:07.220Z,1613405707.220 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-02-15T16:15:17.348Z,1613405717.348 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2021-02-15T16:16:06.249Z,1613405766.249 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS](INFO): Timed out from 2021-02-15T16:11:06.2Z
2021-02-15T16:16:06.250Z,1613405766.250 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2021-02-15T16:16:06.250Z,1613405766.250 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2021-02-15T16:16:06.639Z,1613405766.639 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-02-15T16:16:37.305Z,1613405797.305 [NAL9602](ERROR): Queried for signal strength and failed to receive proper response. 
2021-02-15T16:16:37.387Z,1613405797.387 [NAL9602](ERROR): received: 
+CSQ:0

OK
2021-02-15T16:16:37.387Z,1613405797.387 [NAL9602] Data Fault, FailCount= 1
2021-02-15T16:16:37.387Z,1613405797.387 [NAL9602](ERROR): Data Fault
2021-02-15T16:16:37.447Z,1613405797.447 [CBIT](ERROR): Data Fault in component: NAL9602
2021-02-15T16:16:37.709Z,1613405797.709 [NAL9602](INFO): Powering down
2021-02-15T16:16:38.560Z,1613405798.560 [CBIT](INFO): Clearing failed state for component NAL9602
2021-02-15T16:16:38.560Z,1613405798.560 [NAL9602] No Fault, FailCount= 1
2021-02-15T16:17:08.013Z,1613405828.013 [NAL9602](INFO): Powering up NAL9602
2021-02-15T16:17:18.927Z,1613405838.927 [NAL9602](INFO): NAL9602 initialized
2021-02-15T16:24:03.000Z,1613406243.000 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude
2021-02-15T16:30:03.335Z,1613406603.335 [RDI_PathfinderUp](ERROR): only read 0 of 4 data items
2021-02-15T16:36:38.413Z,1613406998.413 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-02-15T16:37:08.325Z,1613407028.325 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2021-02-15T16:41:12.427Z,1613407272.427 [RDI_PathfinderUp](ERROR): DVL uart error: serial timeout
2021-02-15T16:41:12.427Z,1613407272.427 [RDI_PathfinderUp] Communications Fault, FailCount= 1
2021-02-15T16:41:12.427Z,1613407272.427 [RDI_PathfinderUp](ERROR): Communications Fault
2021-02-15T16:41:12.472Z,1613407272.472 [CBIT](ERROR): Communications Fault in component: RDI_PathfinderUp
2021-02-15T16:41:12.795Z,1613407272.795 [RDI_PathfinderUp](INFO): Powering down
2021-02-15T16:41:13.604Z,1613407273.604 [CBIT](INFO): Clearing failed state for component RDI_PathfinderUp
2021-02-15T16:41:13.604Z,1613407273.604 [RDI_PathfinderUp] No Fault, FailCount= 1
2021-02-15T16:42:04.047Z,1613407324.047 [RDI_PathfinderUp](ERROR): only read 1 of 4 data items
2021-02-15T16:47:09.071Z,1613407629.071 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2021-02-15T16:51:56.321Z,1613407916.321 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2021-02-15T16:55:36.881Z,1613408136.881 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CAREV,165537,AUV,2.0.3273AREV,165537,COPROC,0.10.0.46*43
 expected 29
2021-02-15T16:58:26.965Z,1613408306.965 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CAREV,165827,AUV,2.0.34F
 expected 66
2021-02-15T17:00:19.694Z,1613408419.694 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2021-02-15T17:00:59.708Z,1613408459.708 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2021-02-15T17:02:09.979Z,1613408529.979 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2021-02-15T17:06:34.621Z,1613408794.621 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004792
2021-02-15T17:06:38.635Z,1613408798.635 [DataOverHttps](INFO): Sending 257 bytes from file Logs/20210215T160627/Courier0000.lzma
2021-02-15T17:06:39.637Z,1613408799.637 [DataOverHttps](INFO): Moved sent file to Logs/20210215T160627/Courier0000.lzma.bak
2021-02-15T17:06:39.637Z,1613408799.637 [DataOverHttps](INFO): SBD MOMSN=80376
2021-02-15T17:07:05.293Z,1613408825.293 [NAL9602](INFO): Not Powering down - fast GPS
2021-02-15T17:07:09.836Z,1613408829.836 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items
2021-02-15T17:07:15.780Z,1613408835.780 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-02-15T17:07:19.802Z,1613408839.802 [DataOverHttps](INFO): Sending 179 bytes from file Logs/20210215T160627/Courier0004.lzma
2021-02-15T17:07:20.801Z,1613408840.801 [DataOverHttps](INFO): Moved sent file to Logs/20210215T160627/Courier0004.lzma.bak
2021-02-15T17:07:20.801Z,1613408840.801 [DataOverHttps](INFO): SBD MOMSN=80380
2021-02-15T17:07:29.850Z,1613408849.850 [DataOverHttps](INFO): Sending 903 bytes from file Logs/20210215T160627/Express0001.lzma
2021-02-15T17:07:30.841Z,1613408850.841 [DataOverHttps](INFO): Moved sent file to Logs/20210215T160627/Express0001.lzma.bak
2021-02-15T17:07:30.841Z,1613408850.841 [DataOverHttps](INFO): SBD MOMSN=80382
2021-02-15T17:07:39.879Z,1613408859.879 [DataOverHttps](INFO): Sending 257 bytes from file Logs/20210215T160627/Express0005.lzma
2021-02-15T17:07:40.881Z,1613408860.881 [DataOverHttps](INFO): Moved sent file to Logs/20210215T160627/Express0005.lzma.bak
2021-02-15T17:07:40.881Z,1613408860.881 [DataOverHttps](INFO): SBD MOMSN=80402
2021-02-15T17:07:42.145Z,1613408862.145 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2021-02-15T17:07:42.145Z,1613408862.145 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2021-02-15T17:07:42.145Z,1613408862.145 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-02-15T17:07:49.914Z,1613408869.914 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2021-02-15T17:09:42.401Z,1613408982.401 [CommandLine](IMPORTANT): got command DDM armed
2021-02-15T17:09:42.401Z,1613408982.401 [CommandLine](IMPORTANT): Commanding DDM Armed
2021-02-15T17:09:48.353Z,1613408988.353 [CommandLine](IMPORTANT): got command DDM armed
2021-02-15T17:09:48.353Z,1613408988.353 [CommandLine](IMPORTANT): Commanding DDM Armed
2021-02-15T17:11:59.873Z,1613409119.873 [CommandLine](IMPORTANT): got command DDM standby
2021-02-15T17:11:59.873Z,1613409119.873 [CommandLine](IMPORTANT): Commanding DDM Standby
2021-02-15T17:12:42.707Z,1613409162.707 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2021-02-15T17:12:42.707Z,1613409162.707 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2021-02-15T17:12:42.707Z,1613409162.707 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-02-15T17:12:42.707Z,1613409162.707 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2021-02-15T17:12:43.160Z,1613409163.160 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2021-02-15T17:12:43.160Z,1613409163.160 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2021-02-15T17:12:43.520Z,1613409163.520 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 62.574495 min 
2021-02-15T17:12:43.520Z,1613409163.520 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2021-02-15T17:12:43.520Z,1613409163.520 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2021-02-15T17:12:43.520Z,1613409163.520 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2021-02-15T17:12:43.520Z,1613409163.520 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2021-02-15T17:12:43.520Z,1613409163.520 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #2
2021-02-15T17:12:43.520Z,1613409163.520 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=2
2021-02-15T17:12:43.520Z,1613409163.520 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2021-02-15T17:12:43.520Z,1613409163.520 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2021-02-15T17:12:45.129Z,1613409165.129 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-02-15T17:12:45.129Z,1613409165.129 [NAL9602] Data Fault, FailCount= 2
2021-02-15T17:12:45.129Z,1613409165.129 [NAL9602](ERROR): Data Fault
2021-02-15T17:12:45.215Z,1613409165.215 [CBIT](ERROR): Data Fault in component: NAL9602
2021-02-15T17:12:45.534Z,1613409165.534 [NAL9602](INFO): Powering down
2021-02-15T17:12:46.401Z,1613409166.401 [CBIT](INFO): Clearing failed state for component NAL9602
2021-02-15T17:12:46.401Z,1613409166.401 [NAL9602] No Fault, FailCount= 2
2021-02-15T17:12:49.165Z,1613409169.165 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2021-02-15T17:13:15.834Z,1613409195.834 [NAL9602](INFO): Powering up NAL9602
2021-02-15T17:13:26.740Z,1613409206.740 [NAL9602](INFO): NAL9602 initialized
2021-02-15T17:13:45.344Z,1613409225.344 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2021-02-15T17:15:34.399Z,1613409334.399 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2021-02-15T17:17:43.711Z,1613409463.711 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS](INFO): Timed out from 2021-02-15T17:12:43.5Z
2021-02-15T17:17:43.712Z,1613409463.712 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2021-02-15T17:17:43.712Z,1613409463.712 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2021-02-15T17:17:47.470Z,1613409467.470 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20210215T160627/Courier0007.lzma
2021-02-15T17:17:48.473Z,1613409468.473 [DataOverHttps](INFO): Moved sent file to Logs/20210215T160627/Courier0007.lzma.bak
2021-02-15T17:17:48.473Z,1613409468.473 [DataOverHttps](INFO): SBD MOMSN=80409
2021-02-15T17:17:57.520Z,1613409477.520 [DataOverHttps](INFO): Sending 289 bytes from file Logs/20210215T160627/Express0008.lzma
2021-02-15T17:17:58.517Z,1613409478.517 [DataOverHttps](INFO): Moved sent file to Logs/20210215T160627/Express0008.lzma.bak
2021-02-15T17:17:58.517Z,1613409478.517 [DataOverHttps](INFO): SBD MOMSN=80411
2021-02-15T17:17:59.622Z,1613409479.622 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2021-02-15T17:17:59.622Z,1613409479.622 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2021-02-15T17:17:59.622Z,1613409479.622 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-02-15T17:18:21.880Z,1613409501.880 [CommandLine](IMPORTANT): got command restart application
2021-02-15T17:18:22.887Z,1613409502.887 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2021-02-15T17:18:22.887Z,1613409502.887 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2021-02-15T17:18:22.888Z,1613409502.888 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-02-15T17:18:23.039Z,1613409503.039 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2021-02-15T17:18:23.040Z,1613409503.040 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-02-15T17:18:23.042Z,1613409503.042 [CommandLine](INFO): Join timeout helper Thread ID is 5867
2021-02-15T17:18:23.047Z,1613409503.047 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2021-02-15T17:18:23.048Z,1613409503.048 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-02-15T17:18:23.049Z,1613409503.049 [NavChartDb](INFO): Join timeout helper Thread ID is 5868
2021-02-15T17:18:23.179Z,1613409503.179 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2021-02-15T17:18:23.179Z,1613409503.179 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-02-15T17:18:23.195Z,1613409503.195 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2021-02-15T17:18:23.195Z,1613409503.195 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2021-02-15T17:18:23.195Z,1613409503.195 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 5869
2021-02-15T17:18:23.591Z,1613409503.591 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2021-02-15T17:18:23.591Z,1613409503.591 [WetLabsSeaOWL_UV_A](INFO): Powering down
2021-02-15T17:18:23.592Z,1613409503.592 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2021-02-15T17:18:23.607Z,1613409503.607 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2021-02-15T17:18:23.607Z,1613409503.607 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-02-15T17:18:23.607Z,1613409503.607 [CTD_Seabird](INFO): Join timeout helper Thread ID is 5870
2021-02-15T17:18:23.635Z,1613409503.635 [CTD_Seabird](INFO): Powering down
2021-02-15T17:18:23.647Z,1613409503.647 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2021-02-15T17:18:23.647Z,1613409503.647 [CTD_Seabird](INFO): Powering down
2021-02-15T17:18:23.663Z,1613409503.663 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-02-15T17:18:23.667Z,1613409503.667 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2021-02-15T17:18:23.667Z,1613409503.667 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-02-15T17:18:23.668Z,1613409503.668 [Radio_Surface](INFO): Join timeout helper Thread ID is 5871
2021-02-15T17:18:23.911Z,1613409503.911 [Radio_Surface](INFO): Powering down
2021-02-15T17:18:23.912Z,1613409503.912 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2021-02-15T17:18:23.912Z,1613409503.912 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-02-15T17:18:23.926Z,1613409503.926 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2021-02-15T17:18:23.926Z,1613409503.926 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-02-15T17:18:23.927Z,1613409503.927 [Onboard](INFO): Join timeout helper Thread ID is 5872
2021-02-15T17:18:24.619Z,1613409504.619 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2021-02-15T17:18:25.307Z,1613409505.307 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2021-02-15T17:18:25.307Z,1613409505.307 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-02-15T17:18:25.320Z,1613409505.320 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2021-02-15T17:18:25.320Z,1613409505.320 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-02-15T17:18:25.320Z,1613409505.320 [DataOverHttps](INFO): Join timeout helper Thread ID is 5873
2021-02-15T17:18:25.623Z,1613409505.623 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2021-02-15T17:18:25.624Z,1613409505.624 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-02-15T17:18:25.644Z,1613409505.644 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2021-02-15T17:18:25.644Z,1613409505.644 [logger ThreadHandler](INFO): Thread cancelled.
2021-02-15T17:18:25.644Z,1613409505.644 [logger](INFO): Join timeout helper Thread ID is 5874
2021-02-15T17:18:25.691Z,1613409505.691 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2021-02-15T17:18:25.691Z,1613409505.691 [logger ThreadHandler](INFO): Thread cancelled.
2021-02-15T17:18:25.704Z,1613409505.704 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2021-02-15T17:18:25.704Z,1613409505.704 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-02-15T17:18:25.704Z,1613409505.704 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2021-02-15T17:18:25.704Z,1613409505.704 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-02-15T17:18:25.704Z,1613409505.704 [controlThread](INFO): Join timeout helper Thread ID is 5875
2021-02-15T17:18:25.795Z,1613409505.795 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2021-02-15T17:18:25.795Z,1613409505.795 [controlThread](DEBUG): Uninitializing ControlThread
2021-02-15T17:18:25.796Z,1613409505.796 [AHRS_M2](INFO): Powering down
2021-02-15T17:18:25.868Z,1613409505.868 [DDM](INFO): Powering down
2021-02-15T17:18:25.940Z,1613409505.940 [DUSBL_Hydroid](INFO): Powering down
2021-02-15T17:18:26.011Z,1613409506.011 [Micromodem](INFO): Powering down
2021-02-15T17:18:26.108Z,1613409506.108 [NAL9602](INFO): Powering down
2021-02-15T17:18:26.179Z,1613409506.179 [RDI_Pathfinder](INFO): Powering down
2021-02-15T17:18:26.251Z,1613409506.251 [RDI_PathfinderUp](INFO): Powering down
2021-02-15T17:18:26.252Z,1613409506.252 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2021-02-15T17:18:26.253Z,1613409506.253 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2021-02-15T17:18:26.254Z,1613409506.254 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2021-02-15T17:18:26.255Z,1613409506.255 [MissionManager](INFO): Uninitializing Mission DefaultWithUndock
2021-02-15T17:18:26.255Z,1613409506.255 [DefaultWithUndock] Stopped
2021-02-15T17:18:26.255Z,1613409506.255 [DefaultWithUndock](DEBUG): Aggregate::uninitialize DefaultWithUndock
2021-02-15T17:18:26.255Z,1613409506.255 [DefaultWithUndock:SurfaceDefault] Stopped
2021-02-15T17:18:26.255Z,1613409506.255 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault
2021-02-15T17:18:26.255Z,1613409506.255 [DefaultWithUndock:SurfaceDefault:B.GoToSurface] Stopped
2021-02-15T17:18:26.255Z,1613409506.255 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-02-15T17:18:26.255Z,1613409506.255 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2021-02-15T17:18:26.255Z,1613409506.255 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2021-02-15T17:18:26.255Z,1613409506.255 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2021-02-15T17:18:26.255Z,1613409506.255 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-02-15T17:18:26.263Z,1613409506.263 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2021-02-15T17:18:26.263Z,1613409506.263 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2021-02-15T17:18:26.264Z,1613409506.264 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2021-02-15T17:18:26.264Z,1613409506.264 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2021-02-15T17:18:26.264Z,1613409506.264 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2021-02-15T17:18:26.264Z,1613409506.264 [BuoyancyServo](INFO): Powering down
2021-02-15T17:18:26.279Z,1613409506.279 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2021-02-15T17:18:26.279Z,1613409506.279 [ElevatorServo](INFO): Powering down
2021-02-15T17:18:26.280Z,1613409506.280 [MassServo](DEBUG): Uninitialize Mass Servo.
2021-02-15T17:18:26.280Z,1613409506.280 [MassServo](INFO): Powering down
2021-02-15T17:18:26.281Z,1613409506.281 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-02-15T17:18:26.281Z,1613409506.281 [RudderServo](INFO): Powering down
2021-02-15T17:18:26.282Z,1613409506.282 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2021-02-15T17:18:26.282Z,1613409506.282 [ThrusterServo](INFO): Powering down
2021-02-15T17:18:26.283Z,1613409506.283 [SBIT](DEBUG): Uninitialize SBIT Component.
2021-02-15T17:18:26.283Z,1613409506.283 [IBIT](DEBUG): Uninitialize IBIT Component.
2021-02-15T17:18:26.283Z,1613409506.283 [CBIT](DEBUG): Uninitialize CBIT Component.
2021-02-15T17:18:26.283Z,1613409506.283 [CBIT](DEBUG): Powering off loads.
2021-02-15T17:18:26.295Z,1613409506.295 [CBIT](DEBUG): Disabling WDT.
2021-02-15T17:18:26.307Z,1613409506.307 [CBIT](DEBUG): Opening all GF detection circuits.
2021-02-15T17:18:26.308Z,1613409506.308 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-02-15T17:18:26.327Z,1613409506.327 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-02-15T17:18:26.329Z,1613409506.329 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-02-15T17:18:26.339Z,1613409506.339 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-02-15T17:18:26.430Z,1613409506.430 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2021-02-15T17:18:26.434Z,1613409506.434 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-02-15T17:18:26.498Z,1613409506.498 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-02-15T17:18:26.567Z,1613409506.567 [logger ThreadHandler](INFO): Thread cancelled.