2021-09-17T16:33:23.193Z,1631896403.193 [Supervisor](DEBUG): Initializing supervisor.
2021-09-17T16:33:23.197Z,1631896403.197 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2021-09-17T16:33:23.198Z,1631896403.198 [SyncHandler](INFO): Protected caller Thread ID is 835
2021-09-17T16:33:23.198Z,1631896403.198 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2021-09-17T16:33:23.199Z,1631896403.199 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2021-09-17T16:33:23.199Z,1631896403.199 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 836
2021-09-17T16:33:23.204Z,1631896403.204 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2021-09-17T16:33:23.225Z,1631896403.225 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2021-09-17T16:33:23.226Z,1631896403.226 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2021-09-17T16:33:23.226Z,1631896403.226 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 837
2021-09-17T16:33:23.228Z,1631896403.228 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2021-09-17T16:33:23.229Z,1631896403.229 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2021-09-17T16:33:23.230Z,1631896403.230 [logger ThreadHandler](INFO): Protected caller Thread ID is 838
2021-09-17T16:33:23.234Z,1631896403.234 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2021-09-17T16:33:23.234Z,1631896403.234 [Supervisor](INFO): Looking for Config files in directory: Config/
2021-09-17T16:33:23.239Z,1631896403.239 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2021-09-17T16:33:23.661Z,1631896403.661 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2021-09-17T16:33:23.662Z,1631896403.662 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2021-09-17T16:33:23.742Z,1631896403.742 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2021-09-17T16:33:24.077Z,1631896404.077 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2021-09-17T16:33:24.079Z,1631896404.079 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2021-09-17T16:33:24.232Z,1631896404.232 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2021-09-17T16:33:24.234Z,1631896404.234 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2021-09-17T16:33:24.437Z,1631896404.437 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2021-09-17T16:33:24.439Z,1631896404.439 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2021-09-17T16:33:24.965Z,1631896404.965 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2021-09-17T16:33:24.967Z,1631896404.967 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2021-09-17T16:33:25.212Z,1631896405.212 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2021-09-17T16:33:25.214Z,1631896405.214 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2021-09-17T16:33:25.371Z,1631896405.371 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2021-09-17T16:33:25.372Z,1631896405.372 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2021-09-17T16:33:25.566Z,1631896405.566 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2021-09-17T16:33:25.567Z,1631896405.567 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2021-09-17T16:33:25.665Z,1631896405.665 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2021-09-17T16:33:25.665Z,1631896405.665 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2021-09-17T16:33:25.895Z,1631896405.895 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2021-09-17T16:33:25.895Z,1631896405.895 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2021-09-17T16:33:26.282Z,1631896406.282 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2021-09-17T16:33:26.282Z,1631896406.282 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2021-09-17T16:33:26.365Z,1631896406.365 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2021-09-17T16:33:26.495Z,1631896406.495 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2021-09-17T16:33:26.496Z,1631896406.496 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2021-09-17T16:33:27.715Z,1631896407.715 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2021-09-17T16:33:27.717Z,1631896407.717 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2021-09-17T16:33:28.097Z,1631896408.097 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2021-09-17T16:33:28.099Z,1631896408.099 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-polaris/
2021-09-17T16:33:28.104Z,1631896408.104 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/vehicle.cfg
2021-09-17T16:33:28.309Z,1631896408.309 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Control.cfg
2021-09-17T16:33:28.440Z,1631896408.440 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Estimation.cfg
2021-09-17T16:33:28.541Z,1631896408.541 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/BIT.cfg
2021-09-17T16:33:28.642Z,1631896408.642 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Battery.cfg
2021-09-17T16:33:28.906Z,1631896408.906 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2021-09-17T16:33:28.907Z,1631896408.907 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Simulator.cfg
2021-09-17T16:33:28.994Z,1631896408.994 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Navigation.cfg
2021-09-17T16:33:29.090Z,1631896409.090 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Derivation.cfg
2021-09-17T16:33:29.217Z,1631896409.217 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/logger.cfg
2021-09-17T16:33:29.330Z,1631896409.330 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/secure.cfg
2021-09-17T16:33:29.418Z,1631896409.418 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Dock.cfg
2021-09-17T16:33:29.505Z,1631896409.505 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Servo.cfg
2021-09-17T16:33:29.615Z,1631896409.615 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/workSite.cfg
2021-09-17T16:33:29.714Z,1631896409.714 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Sensor.cfg
2021-09-17T16:33:29.913Z,1631896409.913 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Science.cfg
2021-09-17T16:33:30.078Z,1631896410.078 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2021-09-17T16:33:30.082Z,1631896410.082 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2021-09-17T16:33:30.788Z,1631896410.788 [AHRS_M2] Loaded
2021-09-17T16:33:30.788Z,1631896410.788 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2021-09-17T16:33:31.252Z,1631896411.252 [BackseatComponent] Loaded
2021-09-17T16:33:31.253Z,1631896411.253 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2021-09-17T16:33:31.254Z,1631896411.254 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 4079A4E0
2021-09-17T16:33:31.254Z,1631896411.254 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 933
2021-09-17T16:33:31.257Z,1631896411.257 [LcmUniversalReporter] Loaded
2021-09-17T16:33:31.257Z,1631896411.257 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2021-09-17T16:33:32.445Z,1631896412.445 [BPC1] Loaded
2021-09-17T16:33:32.445Z,1631896412.445 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2021-09-17T16:33:32.648Z,1631896412.648 [DataOverHttps] Loaded
2021-09-17T16:33:32.648Z,1631896412.648 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2021-09-17T16:33:32.649Z,1631896412.649 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407CA4E0
2021-09-17T16:33:32.650Z,1631896412.650 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 934
2021-09-17T16:33:32.669Z,1631896412.669 [Depth_Keller] Loaded
2021-09-17T16:33:32.670Z,1631896412.670 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2021-09-17T16:33:32.674Z,1631896412.674 [DropWeight] Loaded
2021-09-17T16:33:32.675Z,1631896412.675 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2021-09-17T16:33:32.812Z,1631896412.812 [Micromodem] Loaded
2021-09-17T16:33:32.812Z,1631896412.812 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2021-09-17T16:33:32.987Z,1631896412.987 [NAL9602] Loaded
2021-09-17T16:33:32.987Z,1631896412.987 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2021-09-17T16:33:33.197Z,1631896413.197 [Onboard] Loaded
2021-09-17T16:33:33.197Z,1631896413.197 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2021-09-17T16:33:33.198Z,1631896413.198 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 407FA4E0
2021-09-17T16:33:33.198Z,1631896413.198 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 935
2021-09-17T16:33:33.208Z,1631896413.208 [PowerOnly](INFO): Adding load control power supply at /dev/loadC1
2021-09-17T16:33:33.220Z,1631896413.220 [PowerOnly] Loaded
2021-09-17T16:33:33.221Z,1631896413.221 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2021-09-17T16:33:33.232Z,1631896413.232 [Power24vConverter] Loaded
2021-09-17T16:33:33.233Z,1631896413.233 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2021-09-17T16:33:33.246Z,1631896413.246 [Radio_Surface] Loaded
2021-09-17T16:33:33.247Z,1631896413.247 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2021-09-17T16:33:33.248Z,1631896413.248 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4082A4E0
2021-09-17T16:33:33.248Z,1631896413.248 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 936
2021-09-17T16:33:33.292Z,1631896413.292 [RDI_Pathfinder] Loaded
2021-09-17T16:33:33.292Z,1631896413.292 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2021-09-17T16:33:33.319Z,1631896413.319 [RDI_PathfinderUp] Loaded
2021-09-17T16:33:33.319Z,1631896413.319 [ComponentRegistry](DEBUG): SyncComponent "RDI_PathfinderUp" handled in the control thread.
2021-09-17T16:33:33.320Z,1631896413.320 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2021-09-17T16:33:33.321Z,1631896413.321 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2021-09-17T16:33:33.337Z,1631896413.337 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2021-09-17T16:33:33.338Z,1631896413.338 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2021-09-17T16:33:33.437Z,1631896413.437 [DeadReckonUsingMultipleVelocitySources] Loaded
2021-09-17T16:33:33.437Z,1631896413.437 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2021-09-17T16:33:33.451Z,1631896413.451 [NavChart] Loaded
2021-09-17T16:33:33.451Z,1631896413.451 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2021-09-17T16:33:33.457Z,1631896413.457 [UniversalFixResidualReporter] Loaded
2021-09-17T16:33:33.458Z,1631896413.458 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2021-09-17T16:33:33.468Z,1631896413.468 [WorkSite] Loaded
2021-09-17T16:33:33.469Z,1631896413.469 [ComponentRegistry](DEBUG): SyncComponent "WorkSite" handled in the control thread.
2021-09-17T16:33:33.469Z,1631896413.469 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2021-09-17T16:33:33.470Z,1631896413.470 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2021-09-17T16:33:33.594Z,1631896413.594 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2021-09-17T16:33:33.594Z,1631896413.594 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2021-09-17T16:33:33.756Z,1631896413.756 [BuoyancyServo] Loaded
2021-09-17T16:33:33.756Z,1631896413.756 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2021-09-17T16:33:33.778Z,1631896413.778 [ElevatorServo] Loaded
2021-09-17T16:33:33.779Z,1631896413.779 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2021-09-17T16:33:33.799Z,1631896413.799 [MassServo] Loaded
2021-09-17T16:33:33.800Z,1631896413.800 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2021-09-17T16:33:33.820Z,1631896413.820 [RudderServo] Loaded
2021-09-17T16:33:33.821Z,1631896413.821 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2021-09-17T16:33:33.840Z,1631896413.840 [ThrusterServo] Loaded
2021-09-17T16:33:33.840Z,1631896413.840 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2021-09-17T16:33:33.841Z,1631896413.841 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2021-09-17T16:33:33.841Z,1631896413.841 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2021-09-17T16:33:34.072Z,1631896414.072 [CTD_Seabird] Loaded
2021-09-17T16:33:34.072Z,1631896414.072 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2021-09-17T16:33:34.073Z,1631896414.073 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409544E0
2021-09-17T16:33:34.074Z,1631896414.074 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 937
2021-09-17T16:33:34.094Z,1631896414.094 [PAR_Licor] Loaded
2021-09-17T16:33:34.095Z,1631896414.095 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2021-09-17T16:33:34.128Z,1631896414.128 [WetLabsSeaOWL_UV_A] Loaded
2021-09-17T16:33:34.128Z,1631896414.128 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2021-09-17T16:33:34.129Z,1631896414.129 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409844E0
2021-09-17T16:33:34.130Z,1631896414.130 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 938
2021-09-17T16:33:34.130Z,1631896414.130 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2021-09-17T16:33:34.131Z,1631896414.131 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2021-09-17T16:33:34.524Z,1631896414.524 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2021-09-17T16:33:34.525Z,1631896414.525 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2021-09-17T16:33:34.588Z,1631896414.588 [DepthRateCalculator] Loaded
2021-09-17T16:33:34.589Z,1631896414.589 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2021-09-17T16:33:34.594Z,1631896414.594 [PitchRateCalculator] Loaded
2021-09-17T16:33:34.595Z,1631896414.595 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2021-09-17T16:33:34.604Z,1631896414.604 [SpeedCalculator] Loaded
2021-09-17T16:33:34.604Z,1631896414.604 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2021-09-17T16:33:34.618Z,1631896414.618 [TempGradientCalculator] Loaded
2021-09-17T16:33:34.619Z,1631896414.619 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2021-09-17T16:33:34.635Z,1631896414.635 [VerticalHomogeneityIndexCalculator] Loaded
2021-09-17T16:33:34.635Z,1631896414.635 [ComponentRegistry](DEBUG): SyncComponent "VerticalHomogeneityIndexCalculator" handled in the control thread.
2021-09-17T16:33:34.640Z,1631896414.640 [YawRateCalculator] Loaded
2021-09-17T16:33:34.640Z,1631896414.640 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2021-09-17T16:33:34.677Z,1631896414.677 [ElevatorOffsetCalculator] Loaded
2021-09-17T16:33:34.677Z,1631896414.677 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2021-09-17T16:33:34.678Z,1631896414.678 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2021-09-17T16:33:34.679Z,1631896414.679 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2021-09-17T16:33:34.860Z,1631896414.860 [SBIT](DEBUG): Construct Startup Built In Test.
2021-09-17T16:33:34.873Z,1631896414.873 [SBIT] Loaded
2021-09-17T16:33:34.873Z,1631896414.873 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2021-09-17T16:33:34.876Z,1631896414.876 [IBIT](DEBUG): Construct Initiated Built In Test.
2021-09-17T16:33:34.890Z,1631896414.890 [IBIT] Loaded
2021-09-17T16:33:34.890Z,1631896414.890 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2021-09-17T16:33:34.896Z,1631896414.896 [CBIT](DEBUG): Construct Continuous Built In Test.
2021-09-17T16:33:35.003Z,1631896415.003 [CBIT] Loaded
2021-09-17T16:33:35.003Z,1631896415.003 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2021-09-17T16:33:35.003Z,1631896415.003 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2021-09-17T16:33:35.004Z,1631896415.004 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2021-09-17T16:33:35.100Z,1631896415.100 [StratificationFrontDetector](IMPORTANT): thresholdVTHI set to: 0.399988 degC
2021-09-17T16:33:35.100Z,1631896415.100 [StratificationFrontDetector](INFO): (re)initializing
2021-09-17T16:33:35.101Z,1631896415.101 [StratificationFrontDetector] Loaded
2021-09-17T16:33:35.101Z,1631896415.101 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2021-09-17T16:33:35.101Z,1631896415.101 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2021-09-17T16:33:35.102Z,1631896415.102 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2021-09-17T16:33:35.240Z,1631896415.240 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2021-09-17T16:33:35.241Z,1631896415.241 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2021-09-17T16:33:35.313Z,1631896415.313 [VerticalControl](DEBUG): Construct VerticalControl.
2021-09-17T16:33:35.369Z,1631896415.369 [VerticalControl] Loaded
2021-09-17T16:33:35.369Z,1631896415.369 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2021-09-17T16:33:35.372Z,1631896415.372 [HorizontalControl](DEBUG): Construct HorizontalControl.
2021-09-17T16:33:35.410Z,1631896415.410 [HorizontalControl] Loaded
2021-09-17T16:33:35.410Z,1631896415.410 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2021-09-17T16:33:35.413Z,1631896415.413 [SpeedControl](DEBUG): Construct SpeedControl.
2021-09-17T16:33:35.414Z,1631896415.414 [SpeedControl] Loaded
2021-09-17T16:33:35.415Z,1631896415.415 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2021-09-17T16:33:35.417Z,1631896415.417 [LoopControl](DEBUG): Construct LoopControl.
2021-09-17T16:33:35.418Z,1631896415.418 [LoopControl] Loaded
2021-09-17T16:33:35.418Z,1631896415.418 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2021-09-17T16:33:35.419Z,1631896415.419 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2021-09-17T16:33:35.419Z,1631896415.419 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2021-09-17T16:33:35.463Z,1631896415.463 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2021-09-17T16:33:35.470Z,1631896415.470 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2021-09-17T16:33:35.473Z,1631896415.473 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2021-09-17T16:33:35.484Z,1631896415.484 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2021-09-17T16:33:35.485Z,1631896415.485 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B324E0
2021-09-17T16:33:35.485Z,1631896415.485 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 939
2021-09-17T16:33:35.490Z,1631896415.490 [Supervisor](INFO): Main Thread ID is 829
2021-09-17T16:33:35.490Z,1631896415.490 [Supervisor](DEBUG): Running supervisor.
2021-09-17T16:33:35.491Z,1631896415.491 [CommandLine ThreadHandler](INFO): Handler Thread ID is 940
2021-09-17T16:33:35.493Z,1631896415.493 [controlThread ThreadHandler](INFO): Handler Thread ID is 941
2021-09-17T16:33:35.494Z,1631896415.494 [controlThread](DEBUG): Initializing ControlThread
2021-09-17T16:33:35.499Z,1631896415.499 [NavChart](DEBUG): Initialize NavChart Navigation.
2021-09-17T16:33:35.499Z,1631896415.499 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2021-09-17T16:33:35.500Z,1631896415.500 [WorkSite](DEBUG): Initializing WorkSite component.
2021-09-17T16:33:35.504Z,1631896415.504 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2021-09-17T16:33:35.505Z,1631896415.505 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2021-09-17T16:33:35.505Z,1631896415.505 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2021-09-17T16:33:35.505Z,1631896415.505 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2021-09-17T16:33:35.506Z,1631896415.506 [VerticalHomogeneityIndexCalculator](DEBUG): (re)initializing
2021-09-17T16:33:35.507Z,1631896415.507 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2021-09-17T16:33:35.507Z,1631896415.507 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2021-09-17T16:33:35.508Z,1631896415.508 [SBIT](INFO): Initialize SBIT Component.
2021-09-17T16:33:35.509Z,1631896415.509 [SBIT](IMPORTANT): git: 2021-09-08a
2021-09-17T16:33:35.509Z,1631896415.509 [SBIT](INFO): git hash: bad7acd522f33fafb57bb68c86a88bc7b3656cfc
2021-09-17T16:33:35.509Z,1631896415.509 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2021-09-17T16:33:35.511Z,1631896415.511 [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-09-17T16:33:35.512Z,1631896415.512 [SBIT](INFO): Beginning SBIT in 36.000000 seconds.
2021-09-17T16:33:35.512Z,1631896415.512 [IBIT](INFO): Initialize IBIT Component.
2021-09-17T16:33:35.513Z,1631896415.513 [CBIT](DEBUG): Initialize CBIT Component.
2021-09-17T16:33:35.514Z,1631896415.514 [logger ThreadHandler](INFO): Handler Thread ID is 942
2021-09-17T16:33:35.528Z,1631896415.528 [CBIT](DEBUG): Initialized mux pins.
2021-09-17T16:33:35.528Z,1631896415.528 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2021-09-17T16:33:35.528Z,1631896415.528 [CBIT](DEBUG): Initializing the watchdog timer.
2021-09-17T16:33:35.532Z,1631896415.532 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 943
2021-09-17T16:33:35.540Z,1631896415.540 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 944
2021-09-17T16:33:35.541Z,1631896415.541 [DataOverHttps](DEBUG): dashIP=128.128.181.155 starts with a digit so assuming it is a numeric IP
2021-09-17T16:33:35.548Z,1631896415.548 [Onboard ThreadHandler](INFO): Handler Thread ID is 945
2021-09-17T16:33:35.553Z,1631896415.553 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2021-09-17T16:33:35.561Z,1631896415.561 [CBIT](FAULT): Found backtrace file:
1631896266.603016 [NAL9602]: SIGSEGV: address not mapped to object
1631896266.603016 [NAL9602]: Backtrace:
./bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x1a11d0]
2021-09-17T16:33:35.579Z,1631896415.579 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 946
2021-09-17T16:33:35.581Z,1631896415.581 [CBIT](FAULT): Renaming backtrace file to Data/backtrace19
2021-09-17T16:33:35.582Z,1631896415.582 [CBIT](DEBUG): Initializing heartbeat.
2021-09-17T16:33:35.585Z,1631896415.585 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 947
2021-09-17T16:33:35.586Z,1631896415.586 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2021-09-17T16:33:35.598Z,1631896415.598 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 949
2021-09-17T16:33:35.598Z,1631896415.598 [WetLabsSeaOWL_UV_A](INFO): Powering down
2021-09-17T16:33:35.612Z,1631896415.612 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 950
2021-09-17T16:33:35.621Z,1631896415.621 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2021-09-17T16:33:35.622Z,1631896415.622 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2021-09-17T16:33:35.622Z,1631896415.622 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2021-09-17T16:33:35.622Z,1631896415.622 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2021-09-17T16:33:35.622Z,1631896415.622 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2021-09-17T16:33:35.622Z,1631896415.622 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2021-09-17T16:33:35.622Z,1631896415.622 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2021-09-17T16:33:35.623Z,1631896415.623 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2021-09-17T16:33:35.623Z,1631896415.623 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2021-09-17T16:33:35.623Z,1631896415.623 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2021-09-17T16:33:35.623Z,1631896415.623 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2021-09-17T16:33:35.623Z,1631896415.623 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2021-09-17T16:33:35.624Z,1631896415.624 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2021-09-17T16:33:35.624Z,1631896415.624 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2021-09-17T16:33:35.624Z,1631896415.624 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2021-09-17T16:33:35.624Z,1631896415.624 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2021-09-17T16:33:35.652Z,1631896415.652 [CBIT](DEBUG): Deactivating GF circuits.
2021-09-17T16:33:35.652Z,1631896415.652 [CBIT](DEBUG): Deactivating emergency mode.
2021-09-17T16:33:35.688Z,1631896415.688 [CBIT](DEBUG): Backplane powered.
2021-09-17T16:33:35.688Z,1631896415.688 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2021-09-17T16:33:35.690Z,1631896415.690 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2021-09-17T16:33:35.691Z,1631896415.691 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2021-09-17T16:33:35.692Z,1631896415.692 [LoopControl](DEBUG): Initialize LoopControlComponent.
2021-09-17T16:33:35.693Z,1631896415.693 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2021-09-17T16:33:35.721Z,1631896415.721 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2021-09-17T16:33:35.768Z,1631896415.768 [MissionManager](DEBUG):
2021-09-17T16:33:35.769Z,1631896415.769 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2021-09-17T16:33:35.835Z,1631896415.835 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2021-09-17T16:33:35.851Z,1631896415.851 [Default:A.Wait](DEBUG): Construct Wait.
2021-09-17T16:33:35.854Z,1631896415.854 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-09-17T16:33:35.902Z,1631896415.902 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-09-17T16:33:35.925Z,1631896415.925 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-09-17T16:33:35.931Z,1631896415.931 [Default:E.Execute](DEBUG): Construct Execute.
2021-09-17T16:33:35.951Z,1631896415.951 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2021-09-17T16:33:35.957Z,1631896415.957 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,Micromodem,NAL9602,PowerOnly,Power24vConverter,RDI_Pathfinder,RDI_PathfinderUp,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,WorkSite,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2021-09-17T16:33:35.972Z,1631896415.972 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2021-09-17T16:33:35.984Z,1631896415.984 [Radio_Surface](INFO): Powering up
2021-09-17T16:33:36.117Z,1631896416.117 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2021-09-17T16:33:36.119Z,1631896416.119 [Power24vConverter](INFO): Powering up.
2021-09-17T16:33:36.150Z,1631896416.150 [DepthRateCalculator](ERROR): Depth measurement is not active
2021-09-17T16:33:36.174Z,1631896416.174 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2021-09-17T16:33:36.180Z,1631896416.180 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2021-09-17T16:33:36.181Z,1631896416.181 [ElevatorServo](DEBUG): Initializing EZServoServo.
2021-09-17T16:33:36.188Z,1631896416.188 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2021-09-17T16:33:36.189Z,1631896416.189 [MassServo](DEBUG): Initializing EZServoServo.
2021-09-17T16:33:36.196Z,1631896416.196 [MassServo](DEBUG): Initializing MassServo.
2021-09-17T16:33:36.197Z,1631896416.197 [RudderServo](DEBUG): Initializing EZServoServo.
2021-09-17T16:33:36.204Z,1631896416.204 [RudderServo](DEBUG): Initializing RudderServo.
2021-09-17T16:33:36.205Z,1631896416.205 [ThrusterServo](DEBUG): Initializing EZServoServo.
2021-09-17T16:33:36.212Z,1631896416.212 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2021-09-17T16:33:36.214Z,1631896416.214 [CommandLine](FAULT): Scheduling is paused
2021-09-17T16:33:36.215Z,1631896416.215 [CBIT](INFO): Critical error at 20210917T163335
2021-09-17T16:33:36.215Z,1631896416.215 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2021-09-17T16:33:36.387Z,1631896416.387 [Micromodem](INFO): Powering up
2021-09-17T16:33:36.387Z,1631896416.387 [Micromodem](DEBUG): Initializing Micromodem.
2021-09-17T16:33:37.124Z,1631896417.124 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2021-09-17T16:33:37.124Z,1631896417.124 [RudderServo](FAULT): Rudder failed to initialize
2021-09-17T16:33:37.124Z,1631896417.124 [RudderServo] Communications Fault, FailCount= 1
2021-09-17T16:33:37.124Z,1631896417.124 [RudderServo](ERROR): Communications Fault
2021-09-17T16:33:37.224Z,1631896417.224 [CBIT](ERROR): Communications Fault in component: RudderServo
2021-09-17T16:33:37.455Z,1631896417.455 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-09-17T16:33:37.455Z,1631896417.455 [RudderServo](INFO): Powering down
2021-09-17T16:33:38.061Z,1631896418.061 [RudderServo](DEBUG): Initializing EZServoServo.
2021-09-17T16:33:38.181Z,1631896418.181 [RudderServo](DEBUG): Initializing RudderServo.
2021-09-17T16:33:38.185Z,1631896418.185 [CBIT](INFO): Clearing failed state for component RudderServo
2021-09-17T16:33:38.185Z,1631896418.185 [RudderServo] No Fault, FailCount= 1
2021-09-17T16:33:41.314Z,1631896421.314 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33
2021-09-17T16:33:44.538Z,1631896424.538 [Micromodem](INFO): Nmea in: $CATMG,2021-09-17T16:33:43.136359Z,RTC,RTC*55
2021-09-17T16:33:44.539Z,1631896424.539 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2021-09-17T16:33:43.136359Z,RTC,RTC*55
2021-09-17T16:33:50.689Z,1631896430.689 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2021-09-17T16:33:52.631Z,1631896432.631 [Micromodem](ERROR): Nmea resend: $CCCFG,ALL,0*33
2021-09-17T16:33:53.398Z,1631896433.398 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31
2021-09-17T16:33:53.398Z,1631896433.398 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31
2021-09-17T16:33:53.802Z,1631896433.802 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33
2021-09-17T16:33:53.802Z,1631896433.802 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64
2021-09-17T16:33:54.206Z,1631896434.206 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66
2021-09-17T16:33:54.206Z,1631896434.206 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F
2021-09-17T16:33:54.634Z,1631896434.634 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D
2021-09-17T16:33:54.634Z,1631896434.634 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E
2021-09-17T16:33:55.018Z,1631896435.018 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C
2021-09-17T16:33:55.018Z,1631896435.018 [Micromodem](INFO): Nmea out: $CCCFG,FC0,14500*47
2021-09-17T16:33:55.418Z,1631896435.418 [Micromodem](INFO): Nmea in: $CACFG,FC0,14500*45
2021-09-17T16:33:55.418Z,1631896435.418 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63
2021-09-17T16:33:55.822Z,1631896435.822 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61
2021-09-17T16:33:55.822Z,1631896435.822 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A
2021-09-17T16:33:56.226Z,1631896436.226 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38
2021-09-17T16:33:56.227Z,1631896436.227 [Micromodem](INFO): Nmea out: $CCCLK,2021,09,17,16,33,57*4F
2021-09-17T16:33:56.642Z,1631896436.642 [Micromodem](INFO): Nmea in: $CACLK,2021,9,17,16,33,57*7D
2021-09-17T16:33:56.644Z,1631896436.644 [Micromodem](INFO): Nmea in: $CATMS,0,2021-09-17T16:33:58Z*72
2021-09-17T16:33:56.646Z,1631896436.646 [Micromodem](INFO): Nmea in: $CATMG,2021-09-17T16:33:58.027342Z,USER_CMD,RTC*15
2021-09-17T16:34:00.693Z,1631896440.693 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2021-09-17T16:34:03.114Z,1631896443.114 [NAL9602](INFO): Powering up NAL9602
2021-09-17T16:34:10.809Z,1631896450.809 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout
2021-09-17T16:34:10.809Z,1631896450.809 [RDI_Pathfinder] Communications Fault, FailCount= 1
2021-09-17T16:34:10.809Z,1631896450.809 [RDI_Pathfinder](ERROR): Communications Fault
2021-09-17T16:34:10.849Z,1631896450.849 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2021-09-17T16:34:11.244Z,1631896451.244 [RDI_Pathfinder](INFO): Powering down
2021-09-17T16:34:12.029Z,1631896452.029 [SBIT](IMPORTANT): Beginning Startup BIT
2021-09-17T16:34:12.037Z,1631896452.037 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2021-09-17T16:34:12.037Z,1631896452.037 [RDI_Pathfinder] No Fault, FailCount= 1
2021-09-17T16:34:12.038Z,1631896452.038 [CBIT](IMPORTANT): Beginning ground fault scan
2021-09-17T16:34:14.002Z,1631896454.002 [NAL9602](INFO): NAL9602 initialized
2021-09-17T16:34:23.081Z,1631896463.081 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.039272
CHAN A1 (24V): 0.043455
CHAN A2 (12V): 0.024977
CHAN A3 (5V): 0.009414
CHAN B0 (3.3V): 0.007202
CHAN B1 (3.15aV): 0.006725
CHAN B2 (3.15bV): 0.007014
CHAN B3 (GND): -0.002519
OPEN: 0.007097
Full Scale Calc: 4.765 mA, -1.589 mA
2021-09-17T16:34:25.729Z,1631896465.729 [NAL9602](INFO): SBD MO Status=0, MOMSN=25541, MT Status=0, MTMSN=0
2021-09-17T16:34:25.729Z,1631896465.729 [NAL9602](INFO): No messages in MT queue
2021-09-17T16:35:06.141Z,1631896506.141 [SBIT](IMPORTANT): SBIT PASSED
2021-09-17T16:35:06.142Z,1631896506.142 [SBIT](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2021-09-17T16:35:06.615Z,1631896506.615 [WorkSite](IMPORTANT): Reading workSite position from Data/workSite.cfg
2021-09-17T16:35:06.619Z,1631896506.619 [WorkSite](IMPORTANT): WorkSite fix at 20210917T163026: (40.964226, -71.231468)
2021-09-17T16:35:06.621Z,1631896506.621 [MissionManager](IMPORTANT): Started mission Startup
2021-09-17T16:35:06.621Z,1631896506.621 [Startup] Running Loop=1
2021-09-17T16:35:06.621Z,1631896506.621 [Startup](DEBUG): Aggregate::initialize Startup
2021-09-17T16:35:06.622Z,1631896506.622 [Startup:A.GoToSurface] Running Loop=1
2021-09-17T16:35:06.622Z,1631896506.622 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-09-17T16:35:06.622Z,1631896506.622 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-09-17T16:35:06.623Z,1631896506.623 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-09-17T16:35:06.623Z,1631896506.623 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-09-17T16:35:06.623Z,1631896506.623 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-09-17T16:35:06.624Z,1631896506.624 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-09-17T16:35:06.626Z,1631896506.626 [Startup:StartupSatComms] Running Loop=1
2021-09-17T16:35:06.626Z,1631896506.626 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2021-09-17T16:35:06.626Z,1631896506.626 [Startup:StartupSatComms:A] Running Loop=1
2021-09-17T16:35:06.978Z,1631896506.978 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2021-09-17T16:36:06.794Z,1631896566.794 [Startup:StartupSatComms:A](INFO): Timed out from 2021-09-17T16:35:06.6Z
2021-09-17T16:36:06.794Z,1631896566.794 [Startup:StartupSatComms:A] Stopped
2021-09-17T16:36:06.795Z,1631896566.795 [Startup:StartupSatComms:B] Running Loop=1
2021-09-17T16:36:07.205Z,1631896567.205 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-09-17T16:36:35.013Z,1631896595.013 [NAL9602](INFO): SBD MO Status=2, MOMSN=25542, MT Status=2, MTMSN=0
2021-09-17T16:36:35.014Z,1631896595.014 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-09-17T16:36:54.950Z,1631896614.950 [NAL9602](INFO): SBD MO Status=1, MOMSN=25542, MT Status=0, MTMSN=0
2021-09-17T16:36:55.072Z,1631896615.072 [NAL9602](INFO): Sent 18 bytes from file Logs/20210917T162349/Courier0006.lzma
2021-09-17T16:36:55.072Z,1631896615.072 [NAL9602](INFO): Packets left to send: 0
2021-09-17T16:37:06.889Z,1631896626.889 [Startup:StartupSatComms:B](INFO): Timed out from 2021-09-17T16:36:06.8Z
2021-09-17T16:37:06.889Z,1631896626.889 [Startup:StartupSatComms:B] Stopped
2021-09-17T16:37:06.889Z,1631896626.889 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2021-09-17T16:37:06.889Z,1631896626.889 [Startup:StartupSatComms] Stopped
2021-09-17T16:37:06.889Z,1631896626.889 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2021-09-17T16:37:06.890Z,1631896626.890 [Startup](INFO): Completed Startup
2021-09-17T16:37:06.890Z,1631896626.890 [MissionManager](INFO): Startup is completed.
2021-09-17T16:37:06.891Z,1631896626.891 [MissionManager](INFO): Uninitializing Mission Startup
2021-09-17T16:37:06.891Z,1631896626.891 [Startup] Stopped
2021-09-17T16:37:06.891Z,1631896626.891 [Startup](DEBUG): Aggregate::uninitialize Startup
2021-09-17T16:37:06.891Z,1631896626.891 [Startup:A.GoToSurface] Stopped
2021-09-17T16:37:06.891Z,1631896626.891 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-09-17T16:37:07.259Z,1631896627.259 [MissionManager](IMPORTANT): Started mission Default
2021-09-17T16:37:07.259Z,1631896627.259 [Default] Running Loop=1
2021-09-17T16:37:07.259Z,1631896627.259 [Default](DEBUG): Aggregate::initialize Default
2021-09-17T16:37:07.259Z,1631896627.259 [Default:B.GoToSurface] Running Loop=1
2021-09-17T16:37:07.259Z,1631896627.259 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-09-17T16:37:07.260Z,1631896627.260 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-09-17T16:37:07.260Z,1631896627.260 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-09-17T16:37:07.260Z,1631896627.260 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-09-17T16:37:07.261Z,1631896627.261 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-09-17T16:37:07.261Z,1631896627.261 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-09-17T16:37:07.261Z,1631896627.261 [Default:A.Wait] Running Loop=1
2021-09-17T16:37:07.262Z,1631896627.262 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-09-17T16:37:08.034Z,1631896628.034 [NAL9602](INFO): SBD MO Status=1, MOMSN=25543, MT Status=0, MTMSN=0
2021-09-17T16:37:08.084Z,1631896628.084 [NAL9602](INFO): Sent 184 bytes from file Logs/20210917T163323/Courier0000.lzma
2021-09-17T16:37:08.084Z,1631896628.084 [NAL9602](INFO): Packets left to send: 1
2021-09-17T16:37:20.620Z,1631896640.620 [Default:A.Wait](INFO): Done Waiting.
2021-09-17T16:37:20.620Z,1631896640.620 [Default:A.Wait] Stopped
2021-09-17T16:37:20.620Z,1631896640.620 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-09-17T16:37:20.979Z,1631896640.979 [Default:CheckIn] Running Loop=1
2021-09-17T16:37:20.979Z,1631896640.979 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-09-17T16:37:20.979Z,1631896640.979 [Default:CheckIn:Read_GPS] Running Loop=1
2021-09-17T16:37:21.385Z,1631896641.385 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2021-09-17T16:40:54.680Z,1631896854.680 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164055.00,A,4057.92323,N,07114.08353,W,1.011,188.16,170921,,,A*75
2021-09-17T16:40:54.683Z,1631896854.683 [NAL9602](INFO): GPS fix at 20210917T164055: (40.965387, -71.234725)
2021-09-17T16:40:54.762Z,1631896854.762 [Default:CheckIn:Read_GPS] Stopped
2021-09-17T16:40:54.762Z,1631896854.762 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-09-17T16:40:55.129Z,1631896855.129 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-09-17T16:41:13.817Z,1631896873.817 [NAL9602](INFO): SBD MO Status=1, MOMSN=25544, MT Status=0, MTMSN=0
2021-09-17T16:41:13.865Z,1631896873.865 [NAL9602](INFO): Sent 140 bytes from file Logs/20210917T163323/Courier0000.lzma
2021-09-17T16:41:13.865Z,1631896873.865 [NAL9602](INFO): Packets left to send: 0
2021-09-17T16:41:20.231Z,1631896880.231 [NAL9602](INFO): SBD MO Status=1, MOMSN=25545, MT Status=0, MTMSN=0
2021-09-17T16:41:20.292Z,1631896880.292 [NAL9602](INFO): Sent 72 bytes from file Logs/20210917T163323/Courier0004.lzma
2021-09-17T16:41:20.292Z,1631896880.292 [NAL9602](INFO): Packets left to send: 0
2021-09-17T16:41:29.448Z,1631896889.448 [NAL9602](INFO): SBD MO Status=1, MOMSN=25546, MT Status=0, MTMSN=0
2021-09-17T16:41:29.496Z,1631896889.496 [NAL9602](INFO): Sent 18 bytes from file Logs/20210917T162349/Express0007.lzma
2021-09-17T16:41:29.496Z,1631896889.496 [NAL9602](INFO): Packets left to send: 0
2021-09-17T16:41:39.236Z,1631896899.236 [NAL9602](INFO): SBD MO Status=1, MOMSN=25547, MT Status=0, MTMSN=0
2021-09-17T16:41:39.292Z,1631896899.292 [NAL9602](INFO): Sent 184 bytes from file Logs/20210917T163323/Express0001.lzma
2021-09-17T16:41:39.292Z,1631896899.292 [NAL9602](INFO): Packets left to send: 5
2021-09-17T16:41:51.151Z,1631896911.151 [NAL9602](INFO): SBD MO Status=1, MOMSN=25548, MT Status=0, MTMSN=0
2021-09-17T16:41:51.196Z,1631896911.196 [NAL9602](INFO): Sent 184 bytes from file Logs/20210917T163323/Express0001.lzma
2021-09-17T16:41:51.196Z,1631896911.196 [NAL9602](INFO): Packets left to send: 4
2021-09-17T16:42:02.620Z,1631896922.620 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2021-09-17T16:42:02.640Z,1631896922.640 [BPC1](INFO): Received data from all battery sticks.
2021-09-17T16:42:03.417Z,1631896923.417 [NAL9602](INFO): SBD MO Status=1, MOMSN=25549, MT Status=0, MTMSN=0
2021-09-17T16:42:03.474Z,1631896923.474 [NAL9602](INFO): Sent 184 bytes from file Logs/20210917T163323/Express0001.lzma
2021-09-17T16:42:03.474Z,1631896923.474 [NAL9602](INFO): Packets left to send: 3
2021-09-17T16:42:13.353Z,1631896933.353 [NAL9602](INFO): SBD MO Status=1, MOMSN=25550, MT Status=0, MTMSN=0
2021-09-17T16:42:13.400Z,1631896933.400 [NAL9602](INFO): Sent 184 bytes from file Logs/20210917T163323/Express0001.lzma
2021-09-17T16:42:13.400Z,1631896933.400 [NAL9602](INFO): Packets left to send: 2
2021-09-17T16:42:21.676Z,1631896941.676 [NAL9602](INFO): SBD MO Status=1, MOMSN=25551, MT Status=0, MTMSN=0
2021-09-17T16:42:21.732Z,1631896941.732 [NAL9602](INFO): Sent 184 bytes from file Logs/20210917T163323/Express0001.lzma
2021-09-17T16:42:21.732Z,1631896941.732 [NAL9602](INFO): Packets left to send: 1
2021-09-17T16:42:31.276Z,1631896951.276 [NAL9602](INFO): SBD MO Status=1, MOMSN=25552, MT Status=0, MTMSN=0
2021-09-17T16:42:31.332Z,1631896951.332 [NAL9602](INFO): Sent 100 bytes from file Logs/20210917T163323/Express0001.lzma
2021-09-17T16:42:31.332Z,1631896951.332 [NAL9602](INFO): Packets left to send: 0
2021-09-17T16:42:38.333Z,1631896958.333 [NAL9602](INFO): SBD MO Status=1, MOMSN=25553, MT Status=0, MTMSN=0
2021-09-17T16:42:38.385Z,1631896958.385 [NAL9602](INFO): Sent 95 bytes from file Logs/20210917T163323/Express0005.lzma
2021-09-17T16:42:38.385Z,1631896958.385 [NAL9602](INFO): Packets left to send: 0
2021-09-17T16:42:46.651Z,1631896966.651 [NAL9602](INFO): SBD MO Status=0, MOMSN=25554, MT Status=0, MTMSN=0
2021-09-17T16:42:46.774Z,1631896966.774 [Default:CheckIn:Read_Iridium] Stopped
2021-09-17T16:42:46.774Z,1631896966.774 [Default:CheckIn:C.Wait] Running Loop=1
2021-09-17T16:42:46.774Z,1631896966.774 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-09-17T16:43:17.358Z,1631896997.358 [NAL9602](INFO): Not Powering down - fast GPS
2021-09-17T16:44:24.477Z,1631897064.477 [RDI_Pathfinder](ERROR): only read 1 of 4 data items
2021-09-17T16:44:57.151Z,1631897097.151 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
2021-09-17T16:44:57.151Z,1631897097.151 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
expected 41
2021-09-17T16:44:57.153Z,1631897097.153 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31
2021-09-17T16:44:57.551Z,1631897097.551 [Micromodem](INFO): Nmea in: $CACST,6,1,20210917164458.029365,06,822,23,0100,0150,149,02,02,01,02,-1,-01,-01,1,3,1,0,150,-100.0,0.44,-100,2.56,-01,-0.79,-2147483648,14500,4000*5C
2021-09-17T16:47:47.243Z,1631897267.243 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-09-17T16:47:47.243Z,1631897267.243 [Default:CheckIn:C.Wait] Stopped
2021-09-17T16:47:47.243Z,1631897267.243 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-09-17T16:47:47.243Z,1631897267.243 [Default:CheckIn:D] Running Loop=1
2021-09-17T16:47:47.653Z,1631897267.653 [Default:CheckIn:D] Stopped
2021-09-17T16:47:47.653Z,1631897267.653 [Default:CheckIn:E] Running Loop=1
2021-09-17T16:47:48.060Z,1631897268.060 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.673236 min
2021-09-17T16:47:48.060Z,1631897268.060 [Default:CheckIn:E] Stopped
2021-09-17T16:47:48.060Z,1631897268.060 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-09-17T16:47:48.060Z,1631897268.060 [Default:CheckIn] Stopped
2021-09-17T16:47:48.060Z,1631897268.060 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-09-17T16:47:48.061Z,1631897268.061 [Default:CheckIn](INFO): Running loop #2
2021-09-17T16:47:48.061Z,1631897268.061 [Default:CheckIn] Running Loop=2
2021-09-17T16:47:48.061Z,1631897268.061 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-09-17T16:47:48.061Z,1631897268.061 [Default:CheckIn:Read_GPS] Running Loop=1
2021-09-17T16:47:50.060Z,1631897270.060 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164750.00,A,4057.98296,N,07114.19883,W,1.555,320.41,170921,,,D*76
2021-09-17T16:47:50.062Z,1631897270.062 [NAL9602](INFO): GPS fix at 20210917T164750: (40.966383, -71.236647)
2021-09-17T16:47:50.104Z,1631897270.104 [Default:CheckIn:Read_GPS] Stopped
2021-09-17T16:47:50.104Z,1631897270.104 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-09-17T16:48:06.768Z,1631897286.768 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=25555, MT Status=1, MTMSN=904
2021-09-17T16:48:06.816Z,1631897286.816 [NAL9602](INFO): Sent 184 bytes from file Logs/20210917T163323/Courier0007.lzma
2021-09-17T16:48:06.816Z,1631897286.816 [NAL9602](INFO): Packets left to send: 1
2021-09-17T16:48:07.345Z,1631897287.345 [NAL9602](INFO): Received command:sched asap "restart sys" 4iei2 1 2
2021-09-17T16:48:07.357Z,1631897287.357 [CommandLine](IMPORTANT): got command schedule asap "restart sys" 4iei2 1 2.000000
2021-09-17T16:48:07.358Z,1631897287.358 [CommandLine](IMPORTANT): Scheduling command #1 of 2 with id=4iei2
2021-09-17T16:48:07.359Z,1631897287.359 [CommandLine](IMPORTANT): Scheduled #1 (#1 of 2 with id='4iei2'): "restart sys" ASAP
2021-09-17T16:48:22.736Z,1631897302.736 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=25556, MT Status=1, MTMSN=905
2021-09-17T16:48:22.784Z,1631897302.784 [NAL9602](INFO): Sent 17 bytes from file Logs/20210917T163323/Courier0007.lzma
2021-09-17T16:48:22.784Z,1631897302.784 [NAL9602](INFO): Packets left to send: 0
2021-09-17T16:48:23.304Z,1631897303.304 [NAL9602](INFO): Received command:sched asap "" 4iei2 2 2
2021-09-17T16:48:23.321Z,1631897303.321 [CommandLine](IMPORTANT): got command schedule asap "" 4iei2 2 2.000000
2021-09-17T16:48:23.321Z,1631897303.321 [CommandLine](IMPORTANT): Scheduling command #2 of 2 with id=4iei2
2021-09-17T16:48:23.322Z,1631897303.322 [CommandLine](IMPORTANT): Scheduled #2 (#2 of 2 with id='4iei2'): "" ASAP
2021-09-17T16:48:23.433Z,1631897303.433 [CommandLine](IMPORTANT): got command restart system
2021-09-17T16:48:25.576Z,1631897305.576 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2021-09-17T16:48:25.576Z,1631897305.576 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-09-17T16:48:25.592Z,1631897305.592 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2021-09-17T16:48:25.592Z,1631897305.592 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-09-17T16:48:25.593Z,1631897305.593 [CommandLine](INFO): Join timeout helper Thread ID is 983
2021-09-17T16:48:25.608Z,1631897305.608 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2021-09-17T16:48:25.608Z,1631897305.608 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-09-17T16:48:25.608Z,1631897305.608 [NavChartDb](INFO): Join timeout helper Thread ID is 984
2021-09-17T16:48:25.700Z,1631897305.700 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2021-09-17T16:48:25.700Z,1631897305.700 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-09-17T16:48:25.712Z,1631897305.712 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2021-09-17T16:48:25.712Z,1631897305.712 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2021-09-17T16:48:25.712Z,1631897305.712 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 985
2021-09-17T16:48:25.732Z,1631897305.732 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2021-09-17T16:48:25.732Z,1631897305.732 [WetLabsSeaOWL_UV_A](INFO): Powering down
2021-09-17T16:48:25.733Z,1631897305.733 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2021-09-17T16:48:25.752Z,1631897305.752 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2021-09-17T16:48:25.752Z,1631897305.752 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-09-17T16:48:25.752Z,1631897305.752 [CTD_Seabird](INFO): Join timeout helper Thread ID is 986
2021-09-17T16:48:26.240Z,1631897306.240 [CTD_Seabird](INFO): Powering down
2021-09-17T16:48:26.252Z,1631897306.252 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2021-09-17T16:48:26.252Z,1631897306.252 [CTD_Seabird](INFO): Powering down
2021-09-17T16:48:26.264Z,1631897306.264 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-09-17T16:48:26.264Z,1631897306.264 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2021-09-17T16:48:26.264Z,1631897306.264 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-09-17T16:48:26.265Z,1631897306.265 [Radio_Surface](INFO): Join timeout helper Thread ID is 987
2021-09-17T16:48:26.529Z,1631897306.529 [Radio_Surface](INFO): Powering down
2021-09-17T16:48:26.532Z,1631897306.532 [Radio_Sur