2020-12-09T22:30:17.996Z,1607553017.996 [Supervisor](DEBUG): Initializing supervisor.
2020-12-09T22:30:18.001Z,1607553018.001 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-12-09T22:30:18.001Z,1607553018.001 [SyncHandler](INFO): Protected caller Thread ID is 1141
2020-12-09T22:30:18.002Z,1607553018.002 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-12-09T22:30:18.002Z,1607553018.002 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-12-09T22:30:18.003Z,1607553018.003 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1142
2020-12-09T22:30:18.007Z,1607553018.007 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-12-09T22:30:18.026Z,1607553018.026 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-12-09T22:30:18.027Z,1607553018.027 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-12-09T22:30:18.027Z,1607553018.027 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1143
2020-12-09T22:30:18.030Z,1607553018.030 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-12-09T22:30:18.030Z,1607553018.030 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-12-09T22:30:18.031Z,1607553018.031 [logger ThreadHandler](INFO): Protected caller Thread ID is 1144
2020-12-09T22:30:18.035Z,1607553018.035 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-12-09T22:30:18.035Z,1607553018.035 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-12-09T22:30:18.037Z,1607553018.037 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-12-09T22:30:18.431Z,1607553018.431 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-12-09T22:30:18.432Z,1607553018.432 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-12-09T22:30:18.509Z,1607553018.509 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-12-09T22:30:18.836Z,1607553018.836 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-12-09T22:30:18.837Z,1607553018.837 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-12-09T22:30:18.936Z,1607553018.936 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-12-09T22:30:18.936Z,1607553018.936 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-12-09T22:30:19.129Z,1607553019.129 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-12-09T22:30:19.130Z,1607553019.130 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-12-09T22:30:19.642Z,1607553019.642 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-12-09T22:30:19.643Z,1607553019.643 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-12-09T22:30:19.877Z,1607553019.877 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-12-09T22:30:19.877Z,1607553019.877 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-12-09T22:30:20.024Z,1607553020.024 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-12-09T22:30:20.024Z,1607553020.024 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-12-09T22:30:20.216Z,1607553020.216 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-12-09T22:30:20.216Z,1607553020.216 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-12-09T22:30:20.312Z,1607553020.312 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-12-09T22:30:20.313Z,1607553020.313 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2020-12-09T22:30:20.840Z,1607553020.840 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2020-12-09T22:30:20.841Z,1607553020.841 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-12-09T22:30:21.224Z,1607553021.224 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-12-09T22:30:21.225Z,1607553021.225 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-12-09T22:30:21.305Z,1607553021.305 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-12-09T22:30:21.429Z,1607553021.429 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-12-09T22:30:21.430Z,1607553021.430 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-12-09T22:30:22.088Z,1607553022.088 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-12-09T22:30:22.089Z,1607553022.089 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-12-09T22:30:22.456Z,1607553022.456 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-12-09T22:30:22.458Z,1607553022.458 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2020-12-09T22:30:22.459Z,1607553022.459 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2020-12-09T22:30:22.656Z,1607553022.656 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2020-12-09T22:30:22.756Z,1607553022.756 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2020-12-09T22:30:22.855Z,1607553022.855 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2020-12-09T22:30:23.110Z,1607553023.110 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-12-09T22:30:23.111Z,1607553023.111 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2020-12-09T22:30:23.195Z,1607553023.195 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2020-12-09T22:30:23.289Z,1607553023.289 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2020-12-09T22:30:23.402Z,1607553023.402 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2020-12-09T22:30:23.486Z,1607553023.486 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Dock.cfg
2020-12-09T22:30:23.572Z,1607553023.572 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2020-12-09T22:30:23.680Z,1607553023.680 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/workSite.cfg
2020-12-09T22:30:23.778Z,1607553023.778 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2020-12-09T22:30:23.967Z,1607553023.967 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2020-12-09T22:30:24.104Z,1607553024.104 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-12-09T22:30:24.108Z,1607553024.108 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-12-09T22:30:24.464Z,1607553024.464 [AHRS_M2] Loaded
2020-12-09T22:30:24.464Z,1607553024.464 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-12-09T22:30:25.196Z,1607553025.196 [BPC1] Loaded
2020-12-09T22:30:25.196Z,1607553025.196 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-12-09T22:30:25.266Z,1607553025.266 [DataOverHttps] Loaded
2020-12-09T22:30:25.266Z,1607553025.266 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-12-09T22:30:25.267Z,1607553025.267 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407974E0
2020-12-09T22:30:25.268Z,1607553025.268 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1232
2020-12-09T22:30:25.289Z,1607553025.289 [DDM] Loaded
2020-12-09T22:30:25.289Z,1607553025.289 [ComponentRegistry](DEBUG): SyncComponent "DDM" handled in the control thread.
2020-12-09T22:30:25.307Z,1607553025.307 [Depth_Keller] Loaded
2020-12-09T22:30:25.307Z,1607553025.307 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-12-09T22:30:25.312Z,1607553025.312 [DropWeight] Loaded
2020-12-09T22:30:25.312Z,1607553025.312 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-12-09T22:30:25.353Z,1607553025.353 [DUSBL_Hydroid] Loaded
2020-12-09T22:30:25.353Z,1607553025.353 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2020-12-09T22:30:25.398Z,1607553025.398 [Micromodem] Loaded
2020-12-09T22:30:25.398Z,1607553025.398 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2020-12-09T22:30:25.454Z,1607553025.454 [NAL9602] Loaded
2020-12-09T22:30:25.454Z,1607553025.454 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-12-09T22:30:25.481Z,1607553025.481 [Onboard] Loaded
2020-12-09T22:30:25.481Z,1607553025.481 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2020-12-09T22:30:25.482Z,1607553025.482 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 407C74E0
2020-12-09T22:30:25.483Z,1607553025.483 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1233
2020-12-09T22:30:25.496Z,1607553025.496 [Radio_Surface] Loaded
2020-12-09T22:30:25.496Z,1607553025.496 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-12-09T22:30:25.497Z,1607553025.497 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407F74E0
2020-12-09T22:30:25.498Z,1607553025.498 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1234
2020-12-09T22:30:25.527Z,1607553025.527 [RDI_Pathfinder] Loaded
2020-12-09T22:30:25.527Z,1607553025.527 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2020-12-09T22:30:25.552Z,1607553025.552 [RDI_PathfinderUp] Loaded
2020-12-09T22:30:25.552Z,1607553025.552 [ComponentRegistry](DEBUG): SyncComponent "RDI_PathfinderUp" handled in the control thread.
2020-12-09T22:30:25.553Z,1607553025.553 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-12-09T22:30:25.553Z,1607553025.553 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-12-09T22:30:25.564Z,1607553025.564 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-12-09T22:30:25.564Z,1607553025.564 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-12-09T22:30:25.667Z,1607553025.667 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-12-09T22:30:25.667Z,1607553025.667 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-12-09T22:30:25.680Z,1607553025.680 [NavChart] Loaded
2020-12-09T22:30:25.680Z,1607553025.680 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-12-09T22:30:25.686Z,1607553025.686 [UniversalFixResidualReporter] Loaded
2020-12-09T22:30:25.686Z,1607553025.686 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-12-09T22:30:25.696Z,1607553025.696 [WorkSite] Loaded
2020-12-09T22:30:25.696Z,1607553025.696 [ComponentRegistry](DEBUG): SyncComponent "WorkSite" handled in the control thread.
2020-12-09T22:30:25.697Z,1607553025.697 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-12-09T22:30:25.697Z,1607553025.697 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2020-12-09T22:30:25.784Z,1607553025.784 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2020-12-09T22:30:25.785Z,1607553025.785 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-12-09T22:30:25.897Z,1607553025.897 [BuoyancyServo] Loaded
2020-12-09T22:30:25.897Z,1607553025.897 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-12-09T22:30:25.918Z,1607553025.918 [ElevatorServo] Loaded
2020-12-09T22:30:25.918Z,1607553025.918 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-12-09T22:30:25.938Z,1607553025.938 [MassServo] Loaded
2020-12-09T22:30:25.938Z,1607553025.938 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-12-09T22:30:25.957Z,1607553025.957 [RudderServo] Loaded
2020-12-09T22:30:25.957Z,1607553025.957 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-12-09T22:30:25.976Z,1607553025.976 [ThrusterServo] Loaded
2020-12-09T22:30:25.976Z,1607553025.976 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-12-09T22:30:25.976Z,1607553025.976 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-12-09T22:30:25.977Z,1607553025.977 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-12-09T22:30:26.624Z,1607553026.624 [CTD_Seabird] Loaded
2020-12-09T22:30:26.624Z,1607553026.624 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2020-12-09T22:30:26.625Z,1607553026.625 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409274E0
2020-12-09T22:30:26.625Z,1607553026.625 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1235
2020-12-09T22:30:26.644Z,1607553026.644 [PAR_Licor] Loaded
2020-12-09T22:30:26.645Z,1607553026.645 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-12-09T22:30:26.676Z,1607553026.676 [WetLabsSeaOWL_UV_A] Loaded
2020-12-09T22:30:26.676Z,1607553026.676 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2020-12-09T22:30:26.677Z,1607553026.677 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409574E0
2020-12-09T22:30:26.678Z,1607553026.678 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 1236
2020-12-09T22:30:26.678Z,1607553026.678 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-12-09T22:30:26.679Z,1607553026.679 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-12-09T22:30:27.014Z,1607553027.014 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-12-09T22:30:27.015Z,1607553027.015 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-12-09T22:30:27.055Z,1607553027.055 [DepthRateCalculator] Loaded
2020-12-09T22:30:27.055Z,1607553027.055 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-12-09T22:30:27.060Z,1607553027.060 [PitchRateCalculator] Loaded
2020-12-09T22:30:27.061Z,1607553027.061 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-12-09T22:30:27.070Z,1607553027.070 [SpeedCalculator] Loaded
2020-12-09T22:30:27.070Z,1607553027.070 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-12-09T22:30:27.084Z,1607553027.084 [TempGradientCalculator] Loaded
2020-12-09T22:30:27.084Z,1607553027.084 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-12-09T22:30:27.089Z,1607553027.089 [YawRateCalculator] Loaded
2020-12-09T22:30:27.089Z,1607553027.089 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-12-09T22:30:27.110Z,1607553027.110 [ElevatorOffsetCalculator] Loaded
2020-12-09T22:30:27.110Z,1607553027.110 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-12-09T22:30:27.111Z,1607553027.111 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-12-09T22:30:27.111Z,1607553027.111 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-12-09T22:30:27.246Z,1607553027.246 [SBIT](DEBUG): Construct Startup Built In Test.
2020-12-09T22:30:27.257Z,1607553027.257 [SBIT] Loaded
2020-12-09T22:30:27.258Z,1607553027.258 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-12-09T22:30:27.260Z,1607553027.260 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-12-09T22:30:27.273Z,1607553027.273 [IBIT] Loaded
2020-12-09T22:30:27.274Z,1607553027.274 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-12-09T22:30:27.279Z,1607553027.279 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-12-09T22:30:27.378Z,1607553027.378 [CBIT] Loaded
2020-12-09T22:30:27.378Z,1607553027.378 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-12-09T22:30:27.378Z,1607553027.378 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-12-09T22:30:27.379Z,1607553027.379 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-12-09T22:30:27.433Z,1607553027.433 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-12-09T22:30:27.434Z,1607553027.434 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-12-09T22:30:27.530Z,1607553027.530 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-12-09T22:30:27.531Z,1607553027.531 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-12-09T22:30:27.579Z,1607553027.579 [VerticalControl](DEBUG): Construct VerticalControl.
2020-12-09T22:30:27.632Z,1607553027.632 [VerticalControl] Loaded
2020-12-09T22:30:27.632Z,1607553027.632 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-12-09T22:30:27.635Z,1607553027.635 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-12-09T22:30:27.670Z,1607553027.670 [HorizontalControl] Loaded
2020-12-09T22:30:27.670Z,1607553027.670 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-12-09T22:30:27.673Z,1607553027.673 [SpeedControl](DEBUG): Construct SpeedControl.
2020-12-09T22:30:27.675Z,1607553027.675 [SpeedControl] Loaded
2020-12-09T22:30:27.675Z,1607553027.675 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-12-09T22:30:27.678Z,1607553027.678 [LoopControl](DEBUG): Construct LoopControl.
2020-12-09T22:30:27.678Z,1607553027.678 [LoopControl] Loaded
2020-12-09T22:30:27.678Z,1607553027.678 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-12-09T22:30:27.679Z,1607553027.679 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-12-09T22:30:27.679Z,1607553027.679 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-12-09T22:30:27.706Z,1607553027.706 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-12-09T22:30:27.712Z,1607553027.712 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-12-09T22:30:27.715Z,1607553027.715 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-12-09T22:30:27.725Z,1607553027.725 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-12-09T22:30:27.726Z,1607553027.726 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AFF4E0
2020-12-09T22:30:27.727Z,1607553027.727 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1237
2020-12-09T22:30:27.731Z,1607553027.731 [Supervisor](INFO): Main Thread ID is 821
2020-12-09T22:30:27.732Z,1607553027.732 [Supervisor](DEBUG): Running supervisor.
2020-12-09T22:30:27.732Z,1607553027.732 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1238
2020-12-09T22:30:27.734Z,1607553027.734 [controlThread ThreadHandler](INFO): Handler Thread ID is 1239
2020-12-09T22:30:27.735Z,1607553027.735 [controlThread](DEBUG): Initializing ControlThread
2020-12-09T22:30:27.742Z,1607553027.742 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-12-09T22:30:27.743Z,1607553027.743 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-12-09T22:30:27.743Z,1607553027.743 [WorkSite](DEBUG): Initializing WorkSite component.
2020-12-09T22:30:27.747Z,1607553027.747 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-12-09T22:30:27.748Z,1607553027.748 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-12-09T22:30:27.748Z,1607553027.748 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-12-09T22:30:27.748Z,1607553027.748 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-12-09T22:30:27.749Z,1607553027.749 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-12-09T22:30:27.749Z,1607553027.749 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-12-09T22:30:27.750Z,1607553027.750 [SBIT](INFO): Initialize SBIT Component.
2020-12-09T22:30:27.750Z,1607553027.750 [SBIT](IMPORTANT): git: 2020-12-09_polaris
2020-12-09T22:30:27.751Z,1607553027.751 [SBIT](INFO): git hash: af9a0cd533cadbfdab8ca7c32aa0f39f5c9a4f8c
2020-12-09T22:30:27.751Z,1607553027.751 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-12-09T22:30:27.752Z,1607553027.752 [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-09T22:30:27.753Z,1607553027.753 [SBIT](INFO): Beginning SBIT in 21.000000 seconds.
2020-12-09T22:30:27.754Z,1607553027.754 [IBIT](INFO): Initialize IBIT Component.
2020-12-09T22:30:27.755Z,1607553027.755 [CBIT](DEBUG): Initialize CBIT Component.
2020-12-09T22:30:27.756Z,1607553027.756 [logger ThreadHandler](INFO): Handler Thread ID is 1240
2020-12-09T22:30:27.767Z,1607553027.767 [CBIT](DEBUG): Initialized mux pins.
2020-12-09T22:30:27.767Z,1607553027.767 [CBIT](DEBUG): Initializing the watchdog timer.
2020-12-09T22:30:27.776Z,1607553027.776 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1241
2020-12-09T22:30:27.777Z,1607553027.777 [DataOverHttps](DEBUG): dashIP=128.128.181.155 starts with a digit so assuming it is a numeric IP
2020-12-09T22:30:27.788Z,1607553027.788 [Onboard ThreadHandler](INFO): Handler Thread ID is 1242
2020-12-09T22:30:27.792Z,1607553027.792 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-12-09T22:30:27.792Z,1607553027.792 [CBIT](DEBUG): Initializing heartbeat.
2020-12-09T22:30:27.823Z,1607553027.823 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1243
2020-12-09T22:30:27.832Z,1607553027.832 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1244
2020-12-09T22:30:27.832Z,1607553027.832 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2020-12-09T22:30:27.837Z,1607553027.837 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 1246
2020-12-09T22:30:27.837Z,1607553027.837 [WetLabsSeaOWL_UV_A](INFO): Powering down
2020-12-09T22:30:27.848Z,1607553027.848 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1247
2020-12-09T22:30:27.851Z,1607553027.851 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-12-09T22:30:27.851Z,1607553027.851 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-12-09T22:30:27.851Z,1607553027.851 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-12-09T22:30:27.852Z,1607553027.852 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-12-09T22:30:27.852Z,1607553027.852 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-12-09T22:30:27.852Z,1607553027.852 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-12-09T22:30:27.852Z,1607553027.852 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-12-09T22:30:27.852Z,1607553027.852 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-12-09T22:30:27.852Z,1607553027.852 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-12-09T22:30:27.853Z,1607553027.853 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-12-09T22:30:27.853Z,1607553027.853 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-12-09T22:30:27.853Z,1607553027.853 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-12-09T22:30:27.853Z,1607553027.853 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-12-09T22:30:27.853Z,1607553027.853 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-12-09T22:30:27.853Z,1607553027.853 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-12-09T22:30:27.854Z,1607553027.854 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-12-09T22:30:27.863Z,1607553027.863 [CBIT](DEBUG): Deactivating GF circuits.
2020-12-09T22:30:27.863Z,1607553027.863 [CBIT](DEBUG): Deactivating emergency mode.
2020-12-09T22:30:27.899Z,1607553027.899 [CBIT](DEBUG): Backplane powered.
2020-12-09T22:30:27.900Z,1607553027.900 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-12-09T22:30:27.901Z,1607553027.901 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-12-09T22:30:27.902Z,1607553027.902 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-12-09T22:30:27.903Z,1607553027.903 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-12-09T22:30:27.904Z,1607553027.904 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-12-09T22:30:27.924Z,1607553027.924 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-12-09T22:30:27.951Z,1607553027.951 [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-09T22:30:27.952Z,1607553027.952 [MissionManager](INFO): Loading Mission: Missions/underIce/DefaultWithUndock.xml
2020-12-09T22:30:28.091Z,1607553028.091 [MissionManager](INFO): DefineArg DefaultWithUndock.ElapsedSinceDefaultStarted = 0.000000 min
2020-12-09T22:30:28.095Z,1607553028.095 [MissionManager](INFO): DefineArg DefaultWithUndock.DetachTimeout = 30.000000 min
2020-12-09T22:30:28.119Z,1607553028.119 [MissionManager](INFO): DefineArg DefaultWithUndock.TransponderCode = 2 count
2020-12-09T22:30:28.122Z,1607553028.122 [MissionManager](INFO): DefineArg DefaultWithUndock.TrackingUpdatePeriod = 2.500000 s
2020-12-09T22:30:28.134Z,1607553028.134 [MissionManager](INFO): DefineArg DefaultWithUndock.NumberOfPings = 1.000000 count
2020-12-09T22:30:28.137Z,1607553028.137 [MissionManager](INFO): DefineArg DefaultWithUndock.DetachModeDDM = 2.000000 count
2020-12-09T22:30:28.139Z,1607553028.139 [DefaultWithUndock:A.Wait](DEBUG): Construct Wait.
2020-12-09T22:30:28.227Z,1607553028.227 [Radio_Surface](INFO): Powering up
2020-12-09T22:30:28.278Z,1607553028.278 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Construct.
2020-12-09T22:30:28.278Z,1607553028.278 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values.
2020-12-09T22:30:28.343Z,1607553028.343 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-12-09T22:30:28.379Z,1607553028.379 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-12-09T22:30:28.381Z,1607553028.381 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-12-09T22:30:28.403Z,1607553028.403 [DefaultWithUndock:E.Execute](DEBUG): Construct Execute.
2020-12-09T22:30:28.425Z,1607553028.425 [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-09T22:30:28.430Z,1607553028.430 [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-09T22:30:28.439Z,1607553028.439 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-12-09T22:30:28.500Z,1607553028.500 [DDM](INFO): Powering up
2020-12-09T22:30:28.500Z,1607553028.500 [DDM](DEBUG): Initializing DDM.
2020-12-09T22:30:28.524Z,1607553028.524 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2020-12-09T22:30:28.525Z,1607553028.525 [DUSBL_Hydroid](INFO): Powering up
2020-12-09T22:30:28.525Z,1607553028.525 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2020-12-09T22:30:28.568Z,1607553028.568 [DepthRateCalculator](ERROR): Depth measurement is not active
2020-12-09T22:30:28.605Z,1607553028.605 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-12-09T22:30:28.611Z,1607553028.611 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-12-09T22:30:28.613Z,1607553028.613 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-12-09T22:30:28.619Z,1607553028.619 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-12-09T22:30:28.620Z,1607553028.620 [MassServo](DEBUG): Initializing EZServoServo.
2020-12-09T22:30:28.627Z,1607553028.627 [MassServo](DEBUG): Initializing MassServo.
2020-12-09T22:30:28.628Z,1607553028.628 [RudderServo](DEBUG): Initializing EZServoServo.
2020-12-09T22:30:28.635Z,1607553028.635 [RudderServo](DEBUG): Initializing RudderServo.
2020-12-09T22:30:28.636Z,1607553028.636 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-12-09T22:30:28.643Z,1607553028.643 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-12-09T22:30:28.856Z,1607553028.856 [Micromodem](INFO): Powering up
2020-12-09T22:30:28.857Z,1607553028.857 [Micromodem](DEBUG): Initializing Micromodem.
2020-12-09T22:30:29.571Z,1607553029.571 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2020-12-09T22:30:29.571Z,1607553029.571 [RudderServo](FAULT): Rudder failed to initialize
2020-12-09T22:30:29.571Z,1607553029.571 [RudderServo] Communications Fault, FailCount= 1
2020-12-09T22:30:29.571Z,1607553029.571 [RudderServo](ERROR): Communications Fault
2020-12-09T22:30:29.671Z,1607553029.671 [CBIT](ERROR): Communications Fault in component: RudderServo
2020-12-09T22:30:29.872Z,1607553029.872 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-12-09T22:30:29.872Z,1607553029.872 [RudderServo](INFO): Powering down
2020-12-09T22:30:30.503Z,1607553030.503 [RudderServo](DEBUG): Initializing EZServoServo.
2020-12-09T22:30:30.624Z,1607553030.624 [RudderServo](DEBUG): Initializing RudderServo.
2020-12-09T22:30:30.628Z,1607553030.628 [CBIT](INFO): Clearing failed state for component RudderServo
2020-12-09T22:30:30.628Z,1607553030.628 [RudderServo] No Fault, FailCount= 1
2020-12-09T22:30:34.166Z,1607553034.166 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2020-12-09T22:30:33.520356Z,RTC,RTC*5E

2020-12-09T22:30:34.864Z,1607553034.864 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2020-12-09T22:30:44.223Z,1607553044.223 [DDM](INFO): Dynamic Docking Module:
2020-12-09T22:30:46.674Z,1607553046.674 [DUSBL_Hydroid](INFO): DUSBL Version:O
2020-12-09T22:30:49.498Z,1607553049.498 [SBIT](IMPORTANT): Beginning Startup BIT
2020-12-09T22:30:49.506Z,1607553049.506 [CBIT](IMPORTANT): Beginning ground fault scan
2020-12-09T22:30:55.538Z,1607553055.538 [NAL9602](INFO): Powering up NAL9602
2020-12-09T22:31:00.524Z,1607553060.524 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.009791
CHAN A1 (24V): -0.028826
CHAN A2 (12V): -0.007697
CHAN A3 (5V): -0.002577
CHAN B0 (3.3V): 0.000706
CHAN B1 (3.15aV): -0.000069
CHAN B2 (3.15bV): -0.000048
CHAN B3 (GND): 0.002060
OPEN: 0.005768
Full Scale Calc: 4.765 mA, -1.589 mA
2020-12-09T22:31:06.446Z,1607553066.446 [NAL9602](INFO): NAL9602 initialized
2020-12-09T22:31:25.031Z,1607553085.031 [NAL9602](INFO): SBD MO Status=0, MOMSN=12118, MT Status=0, MTMSN=0
2020-12-09T22:31:25.031Z,1607553085.031 [NAL9602](INFO): No messages in MT queue
2020-12-09T22:31:43.683Z,1607553103.683 [SBIT](IMPORTANT): SBIT PASSED
2020-12-09T22:31:43.684Z,1607553103.684 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-12-09T22:31:43.686Z,1607553103.686 [SBIT](IMPORTANT): Micromodem.destinationAddress=12 enum;

2020-12-09T22:31:43.687Z,1607553103.687 [SBIT](IMPORTANT): PowerOnly.loadAtStartup=0 bool;

2020-12-09T22:31:44.066Z,1607553104.066 [WorkSite](IMPORTANT): Reading workSite position from Data/workSite.cfg
2020-12-09T22:31:44.069Z,1607553104.069 [WorkSite](IMPORTANT): WorkSite fix at 20201209T222924: (41.550888, -70.708535)
2020-12-09T22:31:44.071Z,1607553104.071 [MissionManager](IMPORTANT): Started mission Startup
2020-12-09T22:31:44.091Z,1607553104.091 [Startup] Running Loop=1
2020-12-09T22:31:44.091Z,1607553104.091 [Startup](DEBUG): Aggregate::initialize Startup
2020-12-09T22:31:44.091Z,1607553104.091 [Startup:A.GoToSurface] Running Loop=1
2020-12-09T22:31:44.092Z,1607553104.092 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-12-09T22:31:44.092Z,1607553104.092 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-12-09T22:31:44.093Z,1607553104.093 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-12-09T22:31:44.093Z,1607553104.093 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-12-09T22:31:44.093Z,1607553104.093 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-12-09T22:31:44.094Z,1607553104.094 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-12-09T22:31:44.099Z,1607553104.099 [Startup:StartupSatComms] Running Loop=1
2020-12-09T22:31:44.099Z,1607553104.099 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-12-09T22:31:44.099Z,1607553104.099 [Startup:StartupSatComms:A] Running Loop=1
2020-12-09T22:31:44.469Z,1607553104.469 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-12-09T22:32:44.272Z,1607553164.272 [Startup:StartupSatComms:A](INFO): Timed out from 2020-12-09T22:31:44.1Z
2020-12-09T22:32:44.272Z,1607553164.272 [Startup:StartupSatComms:A] Stopped
2020-12-09T22:32:44.272Z,1607553164.272 [Startup:StartupSatComms:B] Running Loop=1
2020-12-09T22:32:44.752Z,1607553164.752 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-12-09T22:33:08.147Z,1607553188.147 [NAL9602](INFO): SBD MO Status=1, MOMSN=12119, MT Status=0, MTMSN=0
2020-12-09T22:33:08.203Z,1607553188.203 [NAL9602](INFO): Sent 53 bytes from file Logs/20201209T213547/Courier0034.lzma
2020-12-09T22:33:08.204Z,1607553188.204 [NAL9602](INFO): Packets left to send: 0
2020-12-09T22:33:20.044Z,1607553200.044 [NAL9602](INFO): SBD MO Status=1, MOMSN=12120, MT Status=0, MTMSN=0
2020-12-09T22:33:20.095Z,1607553200.095 [NAL9602](INFO): Sent 184 bytes from file Logs/20201209T223017/Courier0000.lzma
2020-12-09T22:33:20.096Z,1607553200.096 [NAL9602](INFO): Packets left to send: 1
2020-12-09T22:33:27.037Z,1607553207.037 [NAL9602](INFO): SBD MO Status=1, MOMSN=12121, MT Status=0, MTMSN=0
2020-12-09T22:33:27.087Z,1607553207.087 [NAL9602](INFO): Sent 73 bytes from file Logs/20201209T223017/Courier0000.lzma
2020-12-09T22:33:27.088Z,1607553207.088 [NAL9602](INFO): Packets left to send: 0
2020-12-09T22:33:43.737Z,1607553223.737 [NAL9602](INFO): SBD MO Status=2, MOMSN=12122, MT Status=2, MTMSN=0
2020-12-09T22:33:43.737Z,1607553223.737 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-12-09T22:33:44.540Z,1607553224.540 [Startup:StartupSatComms:B](INFO): Timed out from 2020-12-09T22:32:44.3Z
2020-12-09T22:33:44.540Z,1607553224.540 [Startup:StartupSatComms:B] Stopped
2020-12-09T22:33:44.540Z,1607553224.540 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-12-09T22:33:44.540Z,1607553224.540 [Startup:StartupSatComms] Stopped
2020-12-09T22:33:44.540Z,1607553224.540 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-12-09T22:33:44.541Z,1607553224.541 [Startup](INFO): Completed Startup
2020-12-09T22:33:44.541Z,1607553224.541 [MissionManager](INFO): Startup is completed.
2020-12-09T22:33:44.541Z,1607553224.541 [MissionManager](INFO): Uninitializing Mission Startup
2020-12-09T22:33:44.541Z,1607553224.541 [Startup] Stopped
2020-12-09T22:33:44.541Z,1607553224.541 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-12-09T22:33:44.541Z,1607553224.541 [Startup:A.GoToSurface] Stopped
2020-12-09T22:33:44.541Z,1607553224.541 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-12-09T22:33:45.003Z,1607553225.003 [MissionManager](IMPORTANT): Started mission DefaultWithUndock
2020-12-09T22:33:45.004Z,1607553225.004 [DefaultWithUndock] Running Loop=1
2020-12-09T22:33:45.004Z,1607553225.004 [DefaultWithUndock](DEBUG): Aggregate::initialize DefaultWithUndock
2020-12-09T22:33:45.004Z,1607553225.004 [DefaultWithUndock:A.Wait] Running Loop=1
2020-12-09T22:33:45.004Z,1607553225.004 [DefaultWithUndock:A.Wait](DEBUG): Initialize Wait Component.
2020-12-09T22:33:47.590Z,1607553227.590 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004683
2020-12-09T22:34:02.859Z,1607553242.859 [NAL9602](INFO): SBD MO Status=1, MOMSN=12122, MT Status=0, MTMSN=0
2020-12-09T22:34:02.908Z,1607553242.908 [NAL9602](INFO): Sent 133 bytes from file Logs/20201209T213547/Express0035.lzma
2020-12-09T22:34:02.908Z,1607553242.908 [NAL9602](INFO): Packets left to send: 0
2020-12-09T22:34:15.015Z,1607553255.015 [DefaultWithUndock:A.Wait](INFO): Done Waiting.
2020-12-09T22:34:15.015Z,1607553255.015 [DefaultWithUndock:A.Wait] Stopped
2020-12-09T22:34:15.019Z,1607553255.019 [DefaultWithUndock:A.Wait](DEBUG): Uninitialize Wait Component.
2020-12-09T22:34:15.019Z,1607553255.019 [DefaultWithUndock:LeaveDock] Running Loop=1
2020-12-09T22:34:15.019Z,1607553255.019 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::initialize DefaultWithUndock:LeaveDock
2020-12-09T22:34:15.019Z,1607553255.019 [DefaultWithUndock:LeaveDock:A.] Running Loop=1
2020-12-09T22:34:15.020Z,1607553255.020 [DefaultWithUndock:LeaveDock:A.](INFO): Initializing TrackAcousticContact.
2020-12-09T22:34:15.020Z,1607553255.020 [DefaultWithUndock:LeaveDock:B.Undock] Running Loop=1
2020-12-09T22:34:15.020Z,1607553255.020 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize.
2020-12-09T22:34:15.020Z,1607553255.020 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values.
2020-12-09T22:34:15.387Z,1607553255.387 [DefaultWithUndock:LeaveDock:A.] Running Loop=1
2020-12-09T22:34:17.892Z,1607553257.892 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-09T22:34:18.873Z,1607553258.873 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detaching from dock.
2020-12-09T22:34:19.109Z,1607553259.109 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detected possible detachment. Starting timer.
2020-12-09T22:34:20.665Z,1607553260.665 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-09T22:34:22.269Z,1607553262.269 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-12-09T22:34:23.508Z,1607553263.508 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-09T22:34:26.330Z,1607553266.330 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-09T22:34:27.920Z,1607553267.920 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-12-09T22:34:29.168Z,1607553269.168 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-09T22:34:32.126Z,1607553272.126 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-09T22:34:33.584Z,1607553273.584 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-12-09T22:34:33.586Z,1607553273.586 [NAL9602](INFO): Not Powering down - fast GPS
2020-12-09T22:34:34.848Z,1607553274.848 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-09T22:34:37.632Z,1607553277.632 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-09T22:34:39.237Z,1607553279.237 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-12-09T22:34:39.259Z,1607553279.259 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached at range: nan m. Transitioning DDM to standby.
2020-12-09T22:34:40.484Z,1607553280.484 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-12-09T22:34:42.517Z,1607553282.517 [DefaultWithUndock:LeaveDock:B.Undock](INFO): DDM at standby.
2020-12-09T22:34:42.900Z,1607553282.900 [DefaultWithUndock:LeaveDock:B.Undock](IMPORTANT): Undocking sequence complete.
2020-12-09T22:34:42.900Z,1607553282.900 [DefaultWithUndock:LeaveDock:B.Undock] Stopped
2020-12-09T22:34:42.901Z,1607553282.901 [DefaultWithUndock:LeaveDock](INFO): Completed DefaultWithUndock:LeaveDock
2020-12-09T22:34:42.901Z,1607553282.901 [DefaultWithUndock:LeaveDock] Stopped
2020-12-09T22:34:42.901Z,1607553282.901 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::uninitialize DefaultWithUndock:LeaveDock
2020-12-09T22:34:42.901Z,1607553282.901 [DefaultWithUndock:LeaveDock:A.] Stopped
2020-12-09T22:34:42.901Z,1607553282.901 [DefaultWithUndock:SurfaceDefault] Running Loop=1
2020-12-09T22:34:42.901Z,1607553282.901 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault
2020-12-09T22:34:42.901Z,1607553282.901 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen] Running Loop=1
2020-12-09T22:34:42.901Z,1607553282.901 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:HoldLatchOpen
2020-12-09T22:34:42.902Z,1607553282.902 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:A] Running Loop=1
2020-12-09T22:34:42.902Z,1607553282.902 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:B] Running Loop=1
2020-12-09T22:34:42.902Z,1607553282.902 [DefaultWithUndock:SurfaceDefault:B.GoToSurface] Running Loop=1
2020-12-09T22:34:42.902Z,1607553282.902 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-12-09T22:34:42.902Z,1607553282.902 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-12-09T22:34:42.902Z,1607553282.902 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-12-09T22:34:42.903Z,1607553282.903 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-12-09T22:34:42.903Z,1607553282.903 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-12-09T22:34:42.904Z,1607553282.904 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-12-09T22:34:43.264Z,1607553283.264 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=1
2020-12-09T22:34:43.264Z,1607553283.264 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-12-09T22:34:43.264Z,1607553283.264 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-12-09T22:34:43.264Z,1607553283.264 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen] Stopped
2020-12-09T22:34:43.264Z,1607553283.264 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:HoldLatchOpen
2020-12-09T22:34:43.264Z,1607553283.264 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:A] Stopped
2020-12-09T22:34:43.264Z,1607553283.264 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:B] Stopped
2020-12-09T22:34:43.762Z,1607553283.762 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-12-09T22:34:45.402Z,1607553285.402 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223444.00,A,4133.14584,N,07042.47806,W,0.603,215.44,091220,,,A*75
2020-12-09T22:34:45.406Z,1607553285.406 [NAL9602](INFO): GPS fix at 20201209T223444: (41.552431, -70.707968)
2020-12-09T22:34:45.424Z,1607553285.424 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-12-09T22:34:45.424Z,1607553285.424 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-12-09T22:34:45.804Z,1607553285.804 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-12-09T22:34:48.845Z,1607553288.845 [DataOverHttps](INFO): Sending 804 bytes from file Logs/20201209T223017/Express0001.lzma
2020-12-09T22:34:49.833Z,1607553289.833 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223017/Express0001.lzma.bak
2020-12-09T22:34:49.833Z,1607553289.833 [DataOverHttps](INFO): SBD MOMSN=59008
2020-12-09T22:34:58.898Z,1607553298.898 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20201209T223017/Courier0004.lzma
2020-12-09T22:34:59.889Z,1607553299.889 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223017/Courier0004.lzma.bak
2020-12-09T22:34:59.889Z,1607553299.889 [DataOverHttps](INFO): SBD MOMSN=59024
2020-12-09T22:35:08.927Z,1607553308.927 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20201209T223017/Express0005.lzma
2020-12-09T22:35:09.929Z,1607553309.929 [DataOverHttps](INFO): Moved sent file to Logs/20201209T223017/Express0005.lzma.bak
2020-12-09T22:35:09.929Z,1607553309.929 [DataOverHttps](INFO): SBD MOMSN=59027
2020-12-09T22:35:11.178Z,1607553311.178 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-12-09T22:35:11.178Z,1607553311.178 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-12-09T22:35:11.178Z,1607553311.178 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-12-09T22:35:11.610Z,1607553311.610 [NAL9602](INFO): SBD MO Status=0, MOMSN=12123, MT Status=0, MTMSN=0
2020-12-09T22:35:11.610Z,1607553311.610 [NAL9602](INFO): No messages in MT queue
2020-12-09T22:35:42.251Z,1607553342.251 [NAL9602](INFO): Not Powering down - fast GPS
2020-12-09T22:37:00.369Z,1607553420.369 [DataOverHttps](IMPORTANT): SBD MTMSN=20201209T223700
2020-12-09T22:37:04.387Z,1607553424.387 [DataOverHttps](INFO): Received command:restart logs