2021-11-10T17:45:55.890Z,1636566355.890 [Supervisor](DEBUG): Initializing supervisor. 2021-11-10T17:45:55.894Z,1636566355.894 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2021-11-10T17:45:55.895Z,1636566355.895 [SyncHandler](INFO): Protected caller Thread ID is 1015 2021-11-10T17:45:55.895Z,1636566355.895 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2021-11-10T17:45:55.897Z,1636566355.897 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2021-11-10T17:45:55.897Z,1636566355.897 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1016 2021-11-10T17:45:55.901Z,1636566355.901 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2021-11-10T17:45:55.920Z,1636566355.920 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2021-11-10T17:45:55.921Z,1636566355.921 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2021-11-10T17:45:55.921Z,1636566355.921 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 1017 2021-11-10T17:45:55.925Z,1636566355.925 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2021-11-10T17:45:55.926Z,1636566355.926 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2021-11-10T17:45:55.927Z,1636566355.927 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1018 2021-11-10T17:45:55.929Z,1636566355.929 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2021-11-10T17:45:55.930Z,1636566355.930 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2021-11-10T17:45:55.930Z,1636566355.930 [logger ThreadHandler](INFO): Protected caller Thread ID is 1019 2021-11-10T17:45:55.934Z,1636566355.934 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2021-11-10T17:45:55.935Z,1636566355.935 [Supervisor](INFO): Looking for Config files in directory: Config/ 2021-11-10T17:45:55.936Z,1636566355.936 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2021-11-10T17:45:56.033Z,1636566356.033 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2021-11-10T17:45:56.033Z,1636566356.033 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2021-11-10T17:45:56.624Z,1636566356.624 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2021-11-10T17:45:56.625Z,1636566356.625 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2021-11-10T17:45:56.835Z,1636566356.835 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2021-11-10T17:45:56.836Z,1636566356.836 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2021-11-10T17:45:56.915Z,1636566356.915 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2021-11-10T17:45:57.037Z,1636566357.037 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2021-11-10T17:45:57.037Z,1636566357.037 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2021-11-10T17:45:57.117Z,1636566357.117 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2021-11-10T17:45:57.224Z,1636566357.224 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2021-11-10T17:45:57.224Z,1636566357.224 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2021-11-10T17:45:57.578Z,1636566357.578 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2021-11-10T17:45:57.578Z,1636566357.578 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2021-11-10T17:45:58.145Z,1636566358.145 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2021-11-10T17:45:58.145Z,1636566358.145 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2021-11-10T17:45:58.393Z,1636566358.393 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2021-11-10T17:45:58.394Z,1636566358.394 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2021-11-10T17:45:58.678Z,1636566358.678 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2021-11-10T17:45:58.679Z,1636566358.679 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2021-11-10T17:45:59.134Z,1636566359.134 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2021-11-10T17:45:59.135Z,1636566359.135 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2021-11-10T17:45:59.370Z,1636566359.370 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2021-11-10T17:45:59.371Z,1636566359.371 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2021-11-10T17:45:59.572Z,1636566359.572 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2021-11-10T17:45:59.573Z,1636566359.573 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2021-11-10T17:45:59.923Z,1636566359.923 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2021-11-10T17:45:59.923Z,1636566359.923 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2021-11-10T17:46:00.258Z,1636566360.258 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2021-11-10T17:46:00.260Z,1636566360.260 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/ 2021-11-10T17:46:00.261Z,1636566360.261 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg 2021-11-10T17:46:00.344Z,1636566360.344 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg 2021-11-10T17:46:00.495Z,1636566360.495 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg 2021-11-10T17:46:00.603Z,1636566360.603 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg 2021-11-10T17:46:00.688Z,1636566360.688 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg 2021-11-10T17:46:00.782Z,1636566360.782 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg 2021-11-10T17:46:00.965Z,1636566360.965 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg 2021-11-10T17:46:01.222Z,1636566361.222 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2021-11-10T17:46:01.223Z,1636566361.223 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg 2021-11-10T17:46:01.317Z,1636566361.317 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg 2021-11-10T17:46:01.416Z,1636566361.416 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg 2021-11-10T17:46:01.556Z,1636566361.556 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg 2021-11-10T17:46:01.656Z,1636566361.656 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2021-11-10T17:46:01.665Z,1636566361.665 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2021-11-10T17:46:01.763Z,1636566361.763 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2021-11-10T17:46:01.763Z,1636566361.763 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2021-11-10T17:46:01.818Z,1636566361.818 [VerticalControl](DEBUG): Construct VerticalControl. 2021-11-10T17:46:01.880Z,1636566361.880 [VerticalControl] Loaded 2021-11-10T17:46:01.880Z,1636566361.880 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2021-11-10T17:46:01.883Z,1636566361.883 [HorizontalControl](DEBUG): Construct HorizontalControl. 2021-11-10T17:46:01.922Z,1636566361.922 [HorizontalControl] Loaded 2021-11-10T17:46:01.923Z,1636566361.923 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2021-11-10T17:46:01.925Z,1636566361.925 [SpeedControl](DEBUG): Construct SpeedControl. 2021-11-10T17:46:01.928Z,1636566361.928 [SpeedControl] Loaded 2021-11-10T17:46:01.928Z,1636566361.928 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2021-11-10T17:46:01.931Z,1636566361.931 [LoopControl](DEBUG): Construct LoopControl. 2021-11-10T17:46:01.931Z,1636566361.931 [LoopControl] Loaded 2021-11-10T17:46:01.932Z,1636566361.932 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2021-11-10T17:46:01.932Z,1636566361.932 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2021-11-10T17:46:01.933Z,1636566361.933 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2021-11-10T17:46:01.975Z,1636566361.975 [DepthRateCalculator] Loaded 2021-11-10T17:46:01.975Z,1636566361.975 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2021-11-10T17:46:01.980Z,1636566361.980 [PitchRateCalculator] Loaded 2021-11-10T17:46:01.980Z,1636566361.980 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2021-11-10T17:46:01.990Z,1636566361.990 [SpeedCalculator] Loaded 2021-11-10T17:46:01.991Z,1636566361.991 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2021-11-10T17:46:02.004Z,1636566362.004 [TempGradientCalculator] Loaded 2021-11-10T17:46:02.004Z,1636566362.004 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2021-11-10T17:46:02.009Z,1636566362.009 [YawRateCalculator] Loaded 2021-11-10T17:46:02.009Z,1636566362.009 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2021-11-10T17:46:02.026Z,1636566362.026 [ElevatorOffsetCalculator] Loaded 2021-11-10T17:46:02.027Z,1636566362.027 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2021-11-10T17:46:02.027Z,1636566362.027 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2021-11-10T17:46:02.028Z,1636566362.028 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2021-11-10T17:46:02.055Z,1636566362.055 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2021-11-10T17:46:02.056Z,1636566362.056 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2021-11-10T17:46:02.114Z,1636566362.114 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2021-11-10T17:46:02.114Z,1636566362.114 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2021-11-10T17:46:02.440Z,1636566362.440 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2021-11-10T17:46:02.440Z,1636566362.440 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2021-11-10T17:46:02.545Z,1636566362.545 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2021-11-10T17:46:02.545Z,1636566362.545 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2021-11-10T17:46:02.948Z,1636566362.948 [AHRS_M2] Loaded 2021-11-10T17:46:02.948Z,1636566362.948 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2021-11-10T17:46:02.981Z,1636566362.981 [BackseatComponent] Loaded 2021-11-10T17:46:02.981Z,1636566362.981 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2021-11-10T17:46:02.982Z,1636566362.982 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 409444E0 2021-11-10T17:46:02.983Z,1636566362.983 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 1101 2021-11-10T17:46:02.986Z,1636566362.986 [LcmUniversalReporter] Loaded 2021-11-10T17:46:02.986Z,1636566362.986 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2021-11-10T17:46:03.758Z,1636566363.758 [BPC1] Loaded 2021-11-10T17:46:03.758Z,1636566363.758 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2021-11-10T17:46:03.927Z,1636566363.927 [DataOverHttps] Loaded 2021-11-10T17:46:03.927Z,1636566363.927 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2021-11-10T17:46:03.928Z,1636566363.928 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409744E0 2021-11-10T17:46:03.928Z,1636566363.928 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1102 2021-11-10T17:46:04.005Z,1636566364.005 [Depth_Keller] Loaded 2021-11-10T17:46:04.006Z,1636566364.006 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2021-11-10T17:46:04.010Z,1636566364.010 [DropWeight] Loaded 2021-11-10T17:46:04.010Z,1636566364.010 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2021-11-10T17:46:04.149Z,1636566364.149 [NAL9602] Loaded 2021-11-10T17:46:04.149Z,1636566364.149 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2021-11-10T17:46:04.227Z,1636566364.227 [Onboard] Loaded 2021-11-10T17:46:04.227Z,1636566364.227 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2021-11-10T17:46:04.236Z,1636566364.236 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409A44E0 2021-11-10T17:46:04.237Z,1636566364.237 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1103 2021-11-10T17:46:04.285Z,1636566364.285 [Power24vConverter] Loaded 2021-11-10T17:46:04.285Z,1636566364.285 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2021-11-10T17:46:04.340Z,1636566364.340 [Radio_Surface] Loaded 2021-11-10T17:46:04.340Z,1636566364.340 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2021-11-10T17:46:04.341Z,1636566364.341 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409D44E0 2021-11-10T17:46:04.342Z,1636566364.342 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1104 2021-11-10T17:46:04.408Z,1636566364.408 [RDI_Pathfinder] Loaded 2021-11-10T17:46:04.408Z,1636566364.408 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread. 2021-11-10T17:46:04.629Z,1636566364.629 [DAT] Loaded 2021-11-10T17:46:04.629Z,1636566364.629 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2021-11-10T17:46:04.629Z,1636566364.629 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2021-11-10T17:46:04.630Z,1636566364.630 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2021-11-10T17:46:04.709Z,1636566364.709 [DeadReckonUsingMultipleVelocitySources] Loaded 2021-11-10T17:46:04.709Z,1636566364.709 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2021-11-10T17:46:04.722Z,1636566364.722 [NavChart] Loaded 2021-11-10T17:46:04.722Z,1636566364.722 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2021-11-10T17:46:04.728Z,1636566364.728 [UniversalFixResidualReporter] Loaded 2021-11-10T17:46:04.729Z,1636566364.729 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2021-11-10T17:46:04.729Z,1636566364.729 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2021-11-10T17:46:04.730Z,1636566364.730 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2021-11-10T17:46:04.875Z,1636566364.875 [SBIT](DEBUG): Construct Startup Built In Test. 2021-11-10T17:46:04.884Z,1636566364.884 [SBIT] Loaded 2021-11-10T17:46:04.884Z,1636566364.884 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2021-11-10T17:46:04.887Z,1636566364.887 [IBIT](DEBUG): Construct Initiated Built In Test. 2021-11-10T17:46:04.901Z,1636566364.901 [IBIT] Loaded 2021-11-10T17:46:04.902Z,1636566364.902 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2021-11-10T17:46:04.907Z,1636566364.907 [CBIT](DEBUG): Construct Continuous Built In Test. 2021-11-10T17:46:05.009Z,1636566365.009 [CBIT] Loaded 2021-11-10T17:46:05.009Z,1636566365.009 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2021-11-10T17:46:05.009Z,1636566365.009 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2021-11-10T17:46:05.010Z,1636566365.010 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2021-11-10T17:46:05.139Z,1636566365.139 [BuoyancyServo] Loaded 2021-11-10T17:46:05.139Z,1636566365.139 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2021-11-10T17:46:05.159Z,1636566365.159 [ElevatorServo] Loaded 2021-11-10T17:46:05.159Z,1636566365.159 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2021-11-10T17:46:05.178Z,1636566365.178 [MassServo] Loaded 2021-11-10T17:46:05.178Z,1636566365.178 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2021-11-10T17:46:05.197Z,1636566365.197 [RudderServo] Loaded 2021-11-10T17:46:05.197Z,1636566365.197 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2021-11-10T17:46:05.216Z,1636566365.216 [ThrusterServo] Loaded 2021-11-10T17:46:05.216Z,1636566365.216 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2021-11-10T17:46:05.217Z,1636566365.217 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2021-11-10T17:46:05.217Z,1636566365.217 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2021-11-10T17:46:05.228Z,1636566365.228 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2021-11-10T17:46:05.228Z,1636566365.228 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2021-11-10T17:46:05.402Z,1636566365.402 [CTD_Seabird] Loaded 2021-11-10T17:46:05.402Z,1636566365.402 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2021-11-10T17:46:05.403Z,1636566365.403 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B0D4E0 2021-11-10T17:46:05.404Z,1636566365.404 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1105 2021-11-10T17:46:05.423Z,1636566365.423 [PAR_Licor] Loaded 2021-11-10T17:46:05.424Z,1636566365.424 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2021-11-10T17:46:05.456Z,1636566365.456 [WetLabsBB2FL] Loaded 2021-11-10T17:46:05.456Z,1636566365.456 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2021-11-10T17:46:05.457Z,1636566365.457 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B3D4E0 2021-11-10T17:46:05.457Z,1636566365.457 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1106 2021-11-10T17:46:05.478Z,1636566365.478 [WetLabsUBAT] Loaded 2021-11-10T17:46:05.478Z,1636566365.478 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread. 2021-11-10T17:46:05.479Z,1636566365.479 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40B6D4E0 2021-11-10T17:46:05.479Z,1636566365.479 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 1107 2021-11-10T17:46:05.480Z,1636566365.480 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2021-11-10T17:46:05.486Z,1636566365.486 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2021-11-10T17:46:05.489Z,1636566365.489 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2021-11-10T17:46:05.500Z,1636566365.500 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2021-11-10T17:46:05.501Z,1636566365.501 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B9D4E0 2021-11-10T17:46:05.501Z,1636566365.501 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1108 2021-11-10T17:46:05.506Z,1636566365.506 [Supervisor](INFO): Main Thread ID is 830 2021-11-10T17:46:05.506Z,1636566365.506 [Supervisor](DEBUG): Running supervisor. 2021-11-10T17:46:05.506Z,1636566365.506 [CommandExec ThreadHandler](INFO): Handler Thread ID is 1109 2021-11-10T17:46:05.507Z,1636566365.507 [CommandExec](INFO): Initializing the command executive. 2021-11-10T17:46:05.508Z,1636566365.508 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1110 2021-11-10T17:46:05.510Z,1636566365.510 [controlThread ThreadHandler](INFO): Handler Thread ID is 1111 2021-11-10T17:46:05.511Z,1636566365.511 [controlThread](DEBUG): Initializing ControlThread 2021-11-10T17:46:05.512Z,1636566365.512 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2021-11-10T17:46:05.514Z,1636566365.514 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2021-11-10T17:46:05.515Z,1636566365.515 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2021-11-10T17:46:05.515Z,1636566365.515 [LoopControl](DEBUG): Initialize LoopControlComponent. 2021-11-10T17:46:05.515Z,1636566365.515 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2021-11-10T17:46:05.516Z,1636566365.516 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2021-11-10T17:46:05.516Z,1636566365.516 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2021-11-10T17:46:05.517Z,1636566365.517 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2021-11-10T17:46:05.517Z,1636566365.517 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2021-11-10T17:46:05.518Z,1636566365.518 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2021-11-10T17:46:05.523Z,1636566365.523 [NavChart](DEBUG): Initialize NavChart Navigation. 2021-11-10T17:46:05.523Z,1636566365.523 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2021-11-10T17:46:05.524Z,1636566365.524 [SBIT](INFO): Initialize SBIT Component. 2021-11-10T17:46:05.524Z,1636566365.524 [SBIT](IMPORTANT): git: 2021-11-09A 2021-11-10T17:46:05.525Z,1636566365.525 [SBIT](INFO): git hash: 0f0d2425d2b814912a05763138617759beb4d0e7 2021-11-10T17:46:05.525Z,1636566365.525 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2021-11-10T17:46:05.526Z,1636566365.526 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019 Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021 2021-11-10T17:46:05.527Z,1636566365.527 [SBIT](INFO): Beginning SBIT in 55.000000 seconds. 2021-11-10T17:46:05.528Z,1636566365.528 [IBIT](INFO): Initialize IBIT Component. 2021-11-10T17:46:05.529Z,1636566365.529 [CBIT](DEBUG): Initialize CBIT Component. 2021-11-10T17:46:05.530Z,1636566365.530 [logger ThreadHandler](INFO): Handler Thread ID is 1112 2021-11-10T17:46:05.540Z,1636566365.540 [CBIT](DEBUG): Initialized mux pins. 2021-11-10T17:46:05.540Z,1636566365.540 [CBIT](DEBUG): Initializing the watchdog timer. 2021-11-10T17:46:05.548Z,1636566365.548 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 1113 2021-11-10T17:46:05.561Z,1636566365.561 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1114 2021-11-10T17:46:05.562Z,1636566365.562 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2021-11-10T17:46:05.564Z,1636566365.564 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2021-11-10T17:46:05.564Z,1636566365.564 [CBIT](DEBUG): Initializing heartbeat. 2021-11-10T17:46:05.572Z,1636566365.572 [Onboard ThreadHandler](INFO): Handler Thread ID is 1115 2021-11-10T17:46:05.589Z,1636566365.589 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1116 2021-11-10T17:46:05.609Z,1636566365.609 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1117 2021-11-10T17:46:05.610Z,1636566365.610 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2021-11-10T17:46:05.614Z,1636566365.614 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1119 2021-11-10T17:46:05.616Z,1636566365.616 [WetLabsBB2FL](INFO): Powering up 2021-11-10T17:46:05.617Z,1636566365.617 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 1121 2021-11-10T17:46:05.620Z,1636566365.620 [WetLabsUBAT](INFO): Powering up 2021-11-10T17:46:05.621Z,1636566365.621 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1123 2021-11-10T17:46:05.625Z,1636566365.625 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2021-11-10T17:46:05.625Z,1636566365.625 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2021-11-10T17:46:05.625Z,1636566365.625 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2021-11-10T17:46:05.626Z,1636566365.626 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2021-11-10T17:46:05.626Z,1636566365.626 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2021-11-10T17:46:05.626Z,1636566365.626 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2021-11-10T17:46:05.626Z,1636566365.626 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2021-11-10T17:46:05.626Z,1636566365.626 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2021-11-10T17:46:05.626Z,1636566365.626 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2021-11-10T17:46:05.627Z,1636566365.627 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2021-11-10T17:46:05.627Z,1636566365.627 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2021-11-10T17:46:05.627Z,1636566365.627 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2021-11-10T17:46:05.627Z,1636566365.627 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2021-11-10T17:46:05.627Z,1636566365.627 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2021-11-10T17:46:05.627Z,1636566365.627 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2021-11-10T17:46:05.627Z,1636566365.627 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2021-11-10T17:46:05.636Z,1636566365.636 [CBIT](DEBUG): Deactivating GF circuits. 2021-11-10T17:46:05.637Z,1636566365.637 [CBIT](DEBUG): Deactivating emergency mode. 2021-11-10T17:46:05.672Z,1636566365.672 [CBIT](DEBUG): Backplane powered. 2021-11-10T17:46:05.677Z,1636566365.677 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2021-11-10T17:46:05.702Z,1636566365.702 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2021-11-10T17:46:05.743Z,1636566365.743 [MissionManager](DEBUG): 2021-11-10T17:46:05.744Z,1636566365.744 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2021-11-10T17:46:05.825Z,1636566365.825 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2021-11-10T17:46:05.826Z,1636566365.826 [Default:A.Wait](DEBUG): Construct Wait. 2021-11-10T17:46:05.845Z,1636566365.845 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2021-11-10T17:46:05.885Z,1636566365.885 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2021-11-10T17:46:05.888Z,1636566365.888 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2021-11-10T17:46:05.918Z,1636566365.918 [Default:E.Execute](DEBUG): Construct Execute. 2021-11-10T17:46:05.922Z,1636566365.922 [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-11-10T17:46:05.927Z,1636566365.927 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,RDI_Pathfinder,DAT,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2021-11-10T17:46:05.954Z,1636566365.954 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2021-11-10T17:46:06.012Z,1636566366.012 [Radio_Surface](INFO): Powering up 2021-11-10T17:46:06.026Z,1636566366.026 [Power24vConverter](INFO): Powering up. 2021-11-10T17:46:06.037Z,1636566366.037 [DAT](INFO): Powering up 2021-11-10T17:46:06.037Z,1636566366.037 [DAT](DEBUG): Initializing DAT. 2021-11-10T17:46:06.118Z,1636566366.118 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2021-11-10T17:46:06.124Z,1636566366.124 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2021-11-10T17:46:06.125Z,1636566366.125 [ElevatorServo](DEBUG): Initializing EZServoServo. 2021-11-10T17:46:06.133Z,1636566366.133 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2021-11-10T17:46:06.134Z,1636566366.134 [MassServo](DEBUG): Initializing EZServoServo. 2021-11-10T17:46:06.140Z,1636566366.140 [MassServo](DEBUG): Initializing MassServo. 2021-11-10T17:46:06.141Z,1636566366.141 [RudderServo](DEBUG): Initializing EZServoServo. 2021-11-10T17:46:06.152Z,1636566366.152 [RudderServo](DEBUG): Initializing RudderServo. 2021-11-10T17:46:06.153Z,1636566366.153 [ThrusterServo](DEBUG): Initializing EZServoServo. 2021-11-10T17:46:06.164Z,1636566366.164 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2021-11-10T17:46:07.072Z,1636566367.072 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2021-11-10T17:46:07.072Z,1636566367.072 [RudderServo](FAULT): Rudder failed to initialize 2021-11-10T17:46:07.072Z,1636566367.072 [RudderServo] Communications Fault, FailCount= 1 2021-11-10T17:46:07.072Z,1636566367.072 [RudderServo](ERROR): Communications Fault 2021-11-10T17:46:07.173Z,1636566367.173 [CBIT](ERROR): Communications Fault in component: RudderServo 2021-11-10T17:46:07.341Z,1636566367.341 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2021-11-10T17:46:07.341Z,1636566367.341 [RudderServo](INFO): Powering down 2021-11-10T17:46:08.009Z,1636566368.009 [RudderServo](DEBUG): Initializing EZServoServo. 2021-11-10T17:46:08.129Z,1636566368.129 [RudderServo](DEBUG): Initializing RudderServo. 2021-11-10T17:46:08.134Z,1636566368.134 [CBIT](INFO): Clearing failed state for component RudderServo 2021-11-10T17:46:08.134Z,1636566368.134 [RudderServo] No Fault, FailCount= 1 2021-11-10T17:46:08.228Z,1636566368.228 [WetLabsBB2FL](INFO): Powering down 2021-11-10T17:46:14.888Z,1636566374.888 [WetLabsUBAT](INFO): Powering down 2021-11-10T17:46:20.521Z,1636566380.521 [DAT](INFO): commRate: 800 2021-11-10T17:46:22.538Z,1636566382.538 [DAT](INFO): entering command mode 2021-11-10T17:46:22.943Z,1636566382.943 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:23.346Z,1636566383.346 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:23.772Z,1636566383.772 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:24.154Z,1636566384.154 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:24.558Z,1636566384.558 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:24.962Z,1636566384.962 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:25.366Z,1636566385.366 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:25.818Z,1636566385.818 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:26.174Z,1636566386.174 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:26.579Z,1636566386.579 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:26.982Z,1636566386.982 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:27.394Z,1636566387.394 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:27.840Z,1636566387.840 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:28.194Z,1636566388.194 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:28.605Z,1636566388.605 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:29.003Z,1636566389.003 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:29.406Z,1636566389.406 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:29.867Z,1636566389.867 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:30.219Z,1636566390.219 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:30.618Z,1636566390.618 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:31.022Z,1636566391.022 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:31.427Z,1636566391.427 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:31.859Z,1636566391.859 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:32.245Z,1636566392.245 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:32.643Z,1636566392.643 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:33.042Z,1636566393.042 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:33.448Z,1636566393.448 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:33.921Z,1636566393.921 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:34.254Z,1636566394.254 [NAL9602](INFO): Powering up NAL9602 2021-11-10T17:46:34.256Z,1636566394.256 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:34.750Z,1636566394.750 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:35.062Z,1636566395.062 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:35.470Z,1636566395.470 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:35.870Z,1636566395.870 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:36.275Z,1636566396.275 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:36.751Z,1636566396.751 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:37.090Z,1636566397.090 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:37.487Z,1636566397.487 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:37.890Z,1636566397.890 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-10T17:46:37.891Z,1636566397.891 [DAT](FAULT): failed to enter command mode 2021-11-10T17:46:38.295Z,1636566398.295 [DAT](INFO): entering command mode 2021-11-10T17:46:38.761Z,1636566398.761 [DAT](INFO): setting verbose to 3 2021-11-10T17:46:39.104Z,1636566399.104 [DAT](INFO): set verbose to 3 2021-11-10T17:46:39.104Z,1636566399.104 [DAT](INFO): setting DatVerbose to 27440 2021-11-10T17:46:39.507Z,1636566399.507 [DAT](INFO): set DatVerbose to 27440 2021-11-10T17:46:39.507Z,1636566399.507 [DAT](INFO): setting transmit power to 8 2021-11-10T17:46:39.912Z,1636566399.912 [DAT](INFO): set transmit power to 8 2021-11-10T17:46:39.912Z,1636566399.912 [DAT](INFO): setting local address to 9 2021-11-10T17:46:40.322Z,1636566400.322 [DAT](INFO): set local address to 9 2021-11-10T17:46:45.166Z,1636566405.166 [NAL9602](INFO): NAL9602 initialized 2021-11-10T17:47:00.969Z,1636566420.969 [SBIT](IMPORTANT): Beginning Startup BIT 2021-11-10T17:47:00.973Z,1636566420.973 [CBIT](IMPORTANT): Beginning ground fault scan 2021-11-10T17:47:03.347Z,1636566423.347 [NAL9602](INFO): SBD MO Status=0, MOMSN=17342, MT Status=0, MTMSN=0 2021-11-10T17:47:03.347Z,1636566423.347 [NAL9602](INFO): No messages in MT queue 2021-11-10T17:47:04.559Z,1636566424.559 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174703.00,A,3649.02757,N,12209.31475,W,1.497,271.29,101121,,,A*7F 2021-11-10T17:47:04.563Z,1636566424.563 [NAL9602](INFO): GPS fix at 20211110T174703: (36.817126, -122.155246) 2021-11-10T17:47:11.909Z,1636566431.909 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.010904 CHAN A1 (24V): 0.000289 CHAN A2 (12V): -0.008194 CHAN A3 (5V): -0.002684 CHAN B0 (3.3V): 0.000105 CHAN B1 (3.15aV): -0.000132 CHAN B2 (3.15bV): -0.000007 CHAN B3 (GND): 0.001769 OPEN: 0.005083 Full Scale: +/- 1 mA 2021-11-10T17:47:36.879Z,1636566456.879 [NAL9602](INFO): Not Powering down - fast GPS 2021-11-10T17:47:54.732Z,1636566474.732 [SBIT](IMPORTANT): SBIT PASSED 2021-11-10T17:47:54.732Z,1636566474.732 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2021-11-10T17:47:54.733Z,1636566474.733 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=6 count; 2021-11-10T17:47:54.733Z,1636566474.733 [SBIT](IMPORTANT): CBIT.gf24Offset=143 microampere; 2021-11-10T17:47:54.733Z,1636566474.733 [SBIT](IMPORTANT): DAT.loadAtStartup=1 bool; 2021-11-10T17:47:54.734Z,1636566474.734 [SBIT](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 0.300000 liter_per_second; 2021-11-10T17:47:54.734Z,1636566474.734 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=24 ampere_hour; 2021-11-10T17:47:54.734Z,1636566474.734 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=13 volt; 2021-11-10T17:47:54.734Z,1636566474.734 [SBIT](IMPORTANT): Power24vConverter.simulateHardware=0 bool; 2021-11-10T17:47:54.734Z,1636566474.734 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=231.913961 cubic_centimeter; 2021-11-10T17:47:54.734Z,1636566474.734 [SBIT](IMPORTANT): VerticalControl.massDefault=8.903467 millimeter; 2021-11-10T17:47:55.081Z,1636566475.081 [MissionManager](IMPORTANT): Started mission Startup 2021-11-10T17:47:55.081Z,1636566475.081 [Startup] Running Loop=1 2021-11-10T17:47:55.082Z,1636566475.082 [Startup](DEBUG): Aggregate::initialize Startup 2021-11-10T17:47:55.082Z,1636566475.082 [Startup:A.GoToSurface] Running Loop=1 2021-11-10T17:47:55.082Z,1636566475.082 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2021-11-10T17:47:55.083Z,1636566475.083 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2021-11-10T17:47:55.083Z,1636566475.083 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2021-11-10T17:47:55.083Z,1636566475.083 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2021-11-10T17:47:55.084Z,1636566475.084 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2021-11-10T17:47:55.084Z,1636566475.084 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2021-11-10T17:47:55.086Z,1636566475.086 [Startup:StartupSatComms] Running Loop=1 2021-11-10T17:47:55.086Z,1636566475.086 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2021-11-10T17:47:55.086Z,1636566475.086 [Startup:StartupSatComms:A] Running Loop=1 2021-11-10T17:47:55.482Z,1636566475.482 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2021-11-10T17:47:57.083Z,1636566477.083 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174755.00,A,3649.02636,N,12209.31550,W,0.855,99.70,101121,,,A*47 2021-11-10T17:47:57.085Z,1636566477.085 [NAL9602](INFO): GPS fix at 20211110T174755: (36.817106, -122.155258) 2021-11-10T17:47:57.121Z,1636566477.121 [Startup:StartupSatComms:A] Stopped 2021-11-10T17:47:57.121Z,1636566477.121 [Startup:StartupSatComms:B] Running Loop=1 2021-11-10T17:47:57.515Z,1636566477.515 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2021-11-10T17:48:12.939Z,1636566492.939 [NAL9602](INFO): SBD MO Status=1, MOMSN=17343, MT Status=0, MTMSN=0 2021-11-10T17:48:12.992Z,1636566492.992 [NAL9602](INFO): Sent 219 bytes from file Logs/20211110T173701/Courier0007.lzma 2021-11-10T17:48:12.992Z,1636566492.992 [NAL9602](INFO): Packets left to send: 0 2021-11-10T17:48:26.340Z,1636566506.340 [NAL9602](INFO): SBD MO Status=1, MOMSN=17344, MT Status=0, MTMSN=0 2021-11-10T17:48:26.388Z,1636566506.388 [NAL9602](INFO): Sent 267 bytes from file Logs/20211110T174555/Courier0000.lzma 2021-11-10T17:48:26.388Z,1636566506.388 [NAL9602](INFO): Packets left to send: 0 2021-11-10T17:48:36.519Z,1636566516.519 [NAL9602](INFO): SBD MO Status=1, MOMSN=17345, MT Status=0, MTMSN=0 2021-11-10T17:48:36.572Z,1636566516.572 [NAL9602](INFO): Sent 332 bytes from file Logs/20211110T173701/Express0008.lzma 2021-11-10T17:48:36.572Z,1636566516.572 [NAL9602](INFO): Packets left to send: 1 2021-11-10T17:48:47.503Z,1636566527.503 [NAL9602](INFO): SBD MO Status=1, MOMSN=17346, MT Status=0, MTMSN=0 2021-11-10T17:48:47.564Z,1636566527.564 [NAL9602](INFO): Sent 160 bytes from file Logs/20211110T173701/Express0008.lzma 2021-11-10T17:48:47.564Z,1636566527.564 [NAL9602](INFO): Packets left to send: 0 2021-11-10T17:48:57.342Z,1636566537.342 [Startup:StartupSatComms:B](INFO): Timed out from 2021-11-10T17:47:57.1Z 2021-11-10T17:48:57.342Z,1636566537.342 [Startup:StartupSatComms:B] Stopped 2021-11-10T17:48:57.342Z,1636566537.342 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2021-11-10T17:48:57.343Z,1636566537.343 [Startup:StartupSatComms] Stopped 2021-11-10T17:48:57.343Z,1636566537.343 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2021-11-10T17:48:57.348Z,1636566537.348 [Startup](INFO): Completed Startup 2021-11-10T17:48:57.348Z,1636566537.348 [MissionManager](INFO): Startup is completed. 2021-11-10T17:48:57.348Z,1636566537.348 [MissionManager](INFO): Uninitializing Mission Startup 2021-11-10T17:48:57.348Z,1636566537.348 [Startup] Stopped 2021-11-10T17:48:57.348Z,1636566537.348 [Startup](DEBUG): Aggregate::uninitialize Startup 2021-11-10T17:48:57.348Z,1636566537.348 [Startup:A.GoToSurface] Stopped 2021-11-10T17:48:57.349Z,1636566537.349 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2021-11-10T17:48:57.753Z,1636566537.753 [MissionManager](IMPORTANT): Started mission Default 2021-11-10T17:48:57.753Z,1636566537.753 [Default] Running Loop=1 2021-11-10T17:48:57.753Z,1636566537.753 [Default](DEBUG): Aggregate::initialize Default 2021-11-10T17:48:57.753Z,1636566537.753 [Default:B.GoToSurface] Running Loop=1 2021-11-10T17:48:57.753Z,1636566537.753 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2021-11-10T17:48:57.754Z,1636566537.754 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2021-11-10T17:48:57.754Z,1636566537.754 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2021-11-10T17:48:57.754Z,1636566537.754 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2021-11-10T17:48:57.755Z,1636566537.755 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2021-11-10T17:48:57.755Z,1636566537.755 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2021-11-10T17:48:57.755Z,1636566537.755 [Default:A.Wait] Running Loop=1 2021-11-10T17:48:57.755Z,1636566537.755 [Default:A.Wait](DEBUG): Initialize Wait Component. 2021-11-10T17:49:02.551Z,1636566542.551 [NAL9602](INFO): SBD MO Status=1, MOMSN=17347, MT Status=0, MTMSN=0 2021-11-10T17:49:02.608Z,1636566542.608 [NAL9602](INFO): Sent 332 bytes from file Logs/20211110T174555/Express0001.lzma 2021-11-10T17:49:02.608Z,1636566542.608 [NAL9602](INFO): Packets left to send: 2 2021-11-10T17:49:11.046Z,1636566551.046 [Default:A.Wait](INFO): Done Waiting. 2021-11-10T17:49:11.046Z,1636566551.046 [Default:A.Wait] Stopped 2021-11-10T17:49:11.046Z,1636566551.046 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2021-11-10T17:49:11.446Z,1636566551.446 [Default:CheckIn] Running Loop=1 2021-11-10T17:49:11.446Z,1636566551.446 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-10T17:49:11.446Z,1636566551.446 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-10T17:49:11.869Z,1636566551.869 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2021-11-10T17:49:13.443Z,1636566553.443 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174912.00,A,3649.02260,N,12209.31653,W,0.991,195.55,101121,,,A*7E 2021-11-10T17:49:13.445Z,1636566553.445 [NAL9602](INFO): GPS fix at 20211110T174912: (36.817043, -122.155276) 2021-11-10T17:49:13.478Z,1636566553.478 [Default:CheckIn:Read_GPS] Stopped 2021-11-10T17:49:13.478Z,1636566553.478 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-10T17:49:13.902Z,1636566553.902 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2021-11-10T17:49:30.262Z,1636566570.262 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004550 2021-11-10T17:49:38.155Z,1636566578.155 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20211110T174555/Courier0004.lzma 2021-11-10T17:49:39.158Z,1636566579.158 [DataOverHttps](INFO): Moved sent file to Logs/20211110T174555/Courier0004.lzma.bak 2021-11-10T17:49:39.158Z,1636566579.158 [DataOverHttps](INFO): SBD MOMSN=16230578 2021-11-10T17:49:42.231Z,1636566582.231 [NAL9602](INFO): SBD MO Status=1, MOMSN=17348, MT Status=0, MTMSN=0 2021-11-10T17:49:42.280Z,1636566582.280 [NAL9602](INFO): Sent 71 bytes from file Logs/20211110T174555/Courier0004.lzma 2021-11-10T17:49:42.280Z,1636566582.280 [NAL9602](INFO): Packets left to send: 0 2021-11-10T17:49:42.336Z,1636566582.336 [Default:CheckIn:Read_Iridium] Stopped 2021-11-10T17:49:42.336Z,1636566582.336 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-10T17:49:42.336Z,1636566582.336 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-10T17:49:55.870Z,1636566595.870 [DataOverHttps](INFO): Sending 972 bytes from file Logs/20211110T174555/Express0001.lzma 2021-11-10T17:49:56.870Z,1636566596.870 [DataOverHttps](INFO): Moved sent file to Logs/20211110T174555/Express0001.lzma.bak 2021-11-10T17:49:56.870Z,1636566596.870 [DataOverHttps](INFO): SBD MOMSN=16230583 2021-11-10T17:50:12.926Z,1636566612.926 [NAL9602](INFO): Not Powering down - fast GPS 2021-11-10T17:54:07.333Z,1636566847.333 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2021-11-10T17:54:07.353Z,1636566847.353 [BPC1](INFO): Received data from all battery sticks. 2021-11-10T17:54:42.888Z,1636566882.888 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-10T17:54:42.888Z,1636566882.888 [Default:CheckIn:C.Wait] Stopped 2021-11-10T17:54:42.888Z,1636566882.888 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-10T17:54:42.888Z,1636566882.888 [Default:CheckIn:D] Running Loop=1 2021-11-10T17:54:43.289Z,1636566883.289 [Default:CheckIn:D] Stopped 2021-11-10T17:54:43.290Z,1636566883.290 [Default:CheckIn:E] Running Loop=1 2021-11-10T17:54:43.711Z,1636566883.711 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.758942 min 2021-11-10T17:54:43.711Z,1636566883.711 [Default:CheckIn:E] Stopped 2021-11-10T17:54:43.711Z,1636566883.711 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-10T17:54:43.711Z,1636566883.711 [Default:CheckIn] Stopped 2021-11-10T17:54:43.712Z,1636566883.712 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-10T17:54:43.713Z,1636566883.713 [Default:CheckIn](INFO): Running loop #2 2021-11-10T17:54:43.713Z,1636566883.713 [Default:CheckIn] Running Loop=2 2021-11-10T17:54:43.713Z,1636566883.713 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-10T17:54:43.714Z,1636566883.714 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-10T17:54:45.747Z,1636566885.747 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175444.00,A,3649.00541,N,12209.32070,W,1.477,266.46,101121,,,A*7A 2021-11-10T17:54:45.762Z,1636566885.762 [NAL9602](INFO): GPS fix at 20211110T175444: (36.816757, -122.155345) 2021-11-10T17:54:45.815Z,1636566885.815 [Default:CheckIn:Read_GPS] Stopped 2021-11-10T17:54:45.815Z,1636566885.815 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-10T17:54:53.248Z,1636566893.248 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20211110T174555/Courier0007.lzma 2021-11-10T17:54:54.250Z,1636566894.250 [DataOverHttps](INFO): Moved sent file to Logs/20211110T174555/Courier0007.lzma.bak 2021-11-10T17:54:54.250Z,1636566894.250 [DataOverHttps](INFO): SBD MOMSN=16230646 2021-11-10T17:55:04.691Z,1636566904.691 [NAL9602](INFO): SBD MO Status=0, MOMSN=17349, MT Status=0, MTMSN=0 2021-11-10T17:55:04.691Z,1636566904.691 [NAL9602](INFO): No messages in MT queue 2021-11-10T17:55:10.468Z,1636566910.468 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20211110T174555/Express0005.lzma 2021-11-10T17:55:11.470Z,1636566911.470 [DataOverHttps](INFO): Moved sent file to Logs/20211110T174555/Express0005.lzma.bak 2021-11-10T17:55:11.470Z,1636566911.470 [DataOverHttps](IMPORTANT): SBD MOMSN=16230654, MTMSN=20211110T175511 2021-11-10T17:55:18.992Z,1636566918.992 [DataOverHttps](INFO): Received command: restart logs