2023-09-08T13:33:57.900Z,1694180037.900 [Supervisor](DEBUG): Initializing supervisor. 2023-09-08T13:33:57.904Z,1694180037.904 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2023-09-08T13:33:57.904Z,1694180037.904 [SyncHandler](INFO): Protected caller Thread ID is 829 2023-09-08T13:33:57.905Z,1694180037.905 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2023-09-08T13:33:57.906Z,1694180037.906 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2023-09-08T13:33:57.906Z,1694180037.906 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 830 2023-09-08T13:33:57.910Z,1694180037.910 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2023-09-08T13:33:57.927Z,1694180037.927 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2023-09-08T13:33:57.928Z,1694180037.928 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2023-09-08T13:33:57.929Z,1694180037.929 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 831 2023-09-08T13:33:57.933Z,1694180037.933 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2023-09-08T13:33:57.934Z,1694180037.934 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2023-09-08T13:33:57.934Z,1694180037.934 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 832 2023-09-08T13:33:57.936Z,1694180037.936 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2023-09-08T13:33:57.937Z,1694180037.937 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2023-09-08T13:33:57.937Z,1694180037.937 [logger ThreadHandler](INFO): Protected caller Thread ID is 833 2023-09-08T13:33:57.941Z,1694180037.941 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2023-09-08T13:33:57.941Z,1694180037.941 [Supervisor](INFO): Looking for Config files in directory: Config/ 2023-09-08T13:33:57.947Z,1694180037.947 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2023-09-08T13:33:58.043Z,1694180038.043 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2023-09-08T13:33:58.044Z,1694180038.044 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2023-09-08T13:33:58.263Z,1694180038.263 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2023-09-08T13:33:58.265Z,1694180038.265 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2023-09-08T13:33:58.520Z,1694180038.520 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2023-09-08T13:33:58.521Z,1694180038.521 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2023-09-08T13:33:58.627Z,1694180038.627 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2023-09-08T13:33:58.628Z,1694180038.628 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2023-09-08T13:33:59.357Z,1694180039.357 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2023-09-08T13:33:59.359Z,1694180039.359 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2023-09-08T13:33:59.842Z,1694180039.842 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2023-09-08T13:33:59.844Z,1694180039.844 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2023-09-08T13:34:00.329Z,1694180040.329 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2023-09-08T13:34:00.331Z,1694180040.331 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2023-09-08T13:34:00.733Z,1694180040.733 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2023-09-08T13:34:00.734Z,1694180040.734 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2023-09-08T13:34:01.114Z,1694180041.114 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2023-09-08T13:34:01.114Z,1694180041.114 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2023-09-08T13:34:02.036Z,1694180042.036 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2023-09-08T13:34:02.037Z,1694180042.037 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2023-09-08T13:34:02.259Z,1694180042.259 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2023-09-08T13:34:02.260Z,1694180042.260 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2023-09-08T13:34:02.400Z,1694180042.400 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2023-09-08T13:34:02.400Z,1694180042.400 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2023-09-08T13:34:02.481Z,1694180042.481 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2023-09-08T13:34:02.561Z,1694180042.561 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2023-09-08T13:34:02.744Z,1694180042.744 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2023-09-08T13:34:02.745Z,1694180042.745 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2023-09-08T13:34:02.979Z,1694180042.979 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2023-09-08T13:34:02.981Z,1694180042.981 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2023-09-08T13:34:02.983Z,1694180042.983 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2023-09-08T13:34:03.066Z,1694180043.066 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2023-09-08T13:34:03.331Z,1694180043.331 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2023-09-08T13:34:03.333Z,1694180043.333 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2023-09-08T13:34:03.440Z,1694180043.440 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2023-09-08T13:34:03.599Z,1694180043.599 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2023-09-08T13:34:03.702Z,1694180043.702 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2023-09-08T13:34:03.815Z,1694180043.815 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2023-09-08T13:34:03.925Z,1694180043.925 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2023-09-08T13:34:04.029Z,1694180044.029 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2023-09-08T13:34:04.189Z,1694180044.189 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Derivation.cfg 2023-09-08T13:34:04.286Z,1694180044.286 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2023-09-08T13:34:04.382Z,1694180044.382 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2023-09-08T13:34:04.482Z,1694180044.482 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2023-09-08T13:34:04.487Z,1694180044.487 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2023-09-08T13:34:04.681Z,1694180044.681 [InternalEnvSim] Loaded 2023-09-08T13:34:04.681Z,1694180044.681 [ComponentRegistry](DEBUG): SyncComponent "InternalEnvSim" handled in the control thread. 2023-09-08T13:34:04.682Z,1694180044.682 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2023-09-08T13:34:04.683Z,1694180044.683 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2023-09-08T13:34:04.865Z,1694180044.865 [BuoyancyServo] Loaded 2023-09-08T13:34:04.865Z,1694180044.865 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2023-09-08T13:34:04.886Z,1694180044.886 [ElevatorServo] Loaded 2023-09-08T13:34:04.887Z,1694180044.887 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2023-09-08T13:34:04.907Z,1694180044.907 [MassServo] Loaded 2023-09-08T13:34:04.907Z,1694180044.907 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2023-09-08T13:34:04.927Z,1694180044.927 [RudderServo] Loaded 2023-09-08T13:34:04.927Z,1694180044.927 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2023-09-08T13:34:04.943Z,1694180044.943 [ThrusterHE] Loaded 2023-09-08T13:34:04.943Z,1694180044.943 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2023-09-08T13:34:04.944Z,1694180044.944 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2023-09-08T13:34:04.945Z,1694180044.945 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2023-09-08T13:34:05.114Z,1694180045.114 [SBIT](DEBUG): Construct Startup Built In Test. 2023-09-08T13:34:05.130Z,1694180045.130 [SBIT] Loaded 2023-09-08T13:34:05.130Z,1694180045.130 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2023-09-08T13:34:05.133Z,1694180045.133 [IBIT](DEBUG): Construct Initiated Built In Test. 2023-09-08T13:34:05.154Z,1694180045.154 [IBIT] Loaded 2023-09-08T13:34:05.154Z,1694180045.154 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2023-09-08T13:34:05.159Z,1694180045.159 [CBIT](DEBUG): Construct Continuous Built In Test. 2023-09-08T13:34:05.378Z,1694180045.378 [CBIT] Loaded 2023-09-08T13:34:05.378Z,1694180045.378 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2023-09-08T13:34:05.379Z,1694180045.379 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2023-09-08T13:34:05.380Z,1694180045.380 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2023-09-08T13:34:05.596Z,1694180045.596 [CTD_Seabird] Loaded 2023-09-08T13:34:05.596Z,1694180045.596 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2023-09-08T13:34:05.597Z,1694180045.597 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406674E0 2023-09-08T13:34:05.597Z,1694180045.597 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 919 2023-09-08T13:34:05.630Z,1694180045.630 [ESPComponent] Loaded 2023-09-08T13:34:05.630Z,1694180045.630 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2023-09-08T13:34:05.649Z,1694180045.649 [PAR_Licor] Loaded 2023-09-08T13:34:05.649Z,1694180045.649 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2023-09-08T13:34:05.690Z,1694180045.690 [WetLabsBB2FL] Loaded 2023-09-08T13:34:05.690Z,1694180045.690 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2023-09-08T13:34:05.691Z,1694180045.691 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406974E0 2023-09-08T13:34:05.692Z,1694180045.692 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 920 2023-09-08T13:34:05.721Z,1694180045.721 [WetLabsSeaOWL_UV_A] Loaded 2023-09-08T13:34:05.722Z,1694180045.722 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread. 2023-09-08T13:34:05.723Z,1694180045.723 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 406C74E0 2023-09-08T13:34:05.723Z,1694180045.723 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 921 2023-09-08T13:34:05.723Z,1694180045.723 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2023-09-08T13:34:05.724Z,1694180045.724 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2023-09-08T13:34:05.794Z,1694180045.794 [DepthRateCalculator] Loaded 2023-09-08T13:34:05.794Z,1694180045.794 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2023-09-08T13:34:05.799Z,1694180045.799 [PitchRateCalculator] Loaded 2023-09-08T13:34:05.800Z,1694180045.800 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2023-09-08T13:34:05.810Z,1694180045.810 [SpeedCalculator] Loaded 2023-09-08T13:34:05.810Z,1694180045.810 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2023-09-08T13:34:05.815Z,1694180045.815 [YawRateCalculator] Loaded 2023-09-08T13:34:05.815Z,1694180045.815 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2023-09-08T13:34:05.835Z,1694180045.835 [ElevatorOffsetCalculator] Loaded 2023-09-08T13:34:05.835Z,1694180045.835 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2023-09-08T13:34:05.836Z,1694180045.836 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2023-09-08T13:34:05.836Z,1694180045.836 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2023-09-08T13:34:05.962Z,1694180045.962 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2023-09-08T13:34:05.963Z,1694180045.963 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2023-09-08T13:34:06.005Z,1694180046.005 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2023-09-08T13:34:06.006Z,1694180046.006 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2023-09-08T13:34:06.142Z,1694180046.142 [DeadReckonUsingMultipleVelocitySources] Loaded 2023-09-08T13:34:06.142Z,1694180046.142 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2023-09-08T13:34:06.156Z,1694180046.156 [NavChart] Loaded 2023-09-08T13:34:06.156Z,1694180046.156 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2023-09-08T13:34:06.162Z,1694180046.162 [UniversalFixResidualReporter] Loaded 2023-09-08T13:34:06.162Z,1694180046.162 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2023-09-08T13:34:06.163Z,1694180046.163 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2023-09-08T13:34:06.164Z,1694180046.164 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2023-09-08T13:34:07.707Z,1694180047.707 [AHRS_M2] Loaded 2023-09-08T13:34:07.707Z,1694180047.707 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2023-09-08T13:34:07.955Z,1694180047.955 [BackseatComponent] Loaded 2023-09-08T13:34:07.956Z,1694180047.956 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2023-09-08T13:34:07.957Z,1694180047.957 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A5F4E0 2023-09-08T13:34:07.957Z,1694180047.957 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 922 2023-09-08T13:34:07.960Z,1694180047.960 [LcmUniversalReporter] Loaded 2023-09-08T13:34:07.960Z,1694180047.960 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2023-09-08T13:34:08.707Z,1694180048.707 [BPC1] Loaded 2023-09-08T13:34:08.707Z,1694180048.707 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2023-09-08T13:34:08.848Z,1694180048.848 [DataOverHttps] Loaded 2023-09-08T13:34:08.848Z,1694180048.848 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2023-09-08T13:34:08.849Z,1694180048.849 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40A8F4E0 2023-09-08T13:34:08.850Z,1694180048.850 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 923 2023-09-08T13:34:08.871Z,1694180048.871 [Depth_Keller] Loaded 2023-09-08T13:34:08.871Z,1694180048.871 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2023-09-08T13:34:08.876Z,1694180048.876 [DropWeight] Loaded 2023-09-08T13:34:08.876Z,1694180048.876 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2023-09-08T13:34:08.916Z,1694180048.916 [DVL_micro] Loaded 2023-09-08T13:34:08.917Z,1694180048.917 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2023-09-08T13:34:08.977Z,1694180048.977 [NAL9602] Loaded 2023-09-08T13:34:08.977Z,1694180048.977 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2023-09-08T13:34:09.003Z,1694180049.003 [Onboard] Loaded 2023-09-08T13:34:09.003Z,1694180049.003 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2023-09-08T13:34:09.004Z,1694180049.004 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40ABF4E0 2023-09-08T13:34:09.005Z,1694180049.005 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 924 2023-09-08T13:34:09.017Z,1694180049.017 [Power24vConverter] Loaded 2023-09-08T13:34:09.018Z,1694180049.018 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2023-09-08T13:34:09.031Z,1694180049.031 [Radio_Surface] Loaded 2023-09-08T13:34:09.031Z,1694180049.031 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2023-09-08T13:34:09.032Z,1694180049.032 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40AEF4E0 2023-09-08T13:34:09.033Z,1694180049.033 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 925 2023-09-08T13:34:09.128Z,1694180049.128 [DAT] Loaded 2023-09-08T13:34:09.128Z,1694180049.128 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2023-09-08T13:34:09.129Z,1694180049.129 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40B1F4E0 2023-09-08T13:34:09.129Z,1694180049.129 [DAT ThreadHandler](INFO): Protected caller Thread ID is 926 2023-09-08T13:34:09.130Z,1694180049.130 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2023-09-08T13:34:09.131Z,1694180049.131 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2023-09-08T13:34:09.211Z,1694180049.211 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2023-09-08T13:34:09.212Z,1694180049.212 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2023-09-08T13:34:09.279Z,1694180049.279 [VerticalControl](DEBUG): Construct VerticalControl. 2023-09-08T13:34:09.329Z,1694180049.329 [VerticalControl] Loaded 2023-09-08T13:34:09.330Z,1694180049.330 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2023-09-08T13:34:09.333Z,1694180049.333 [HorizontalControl](DEBUG): Construct HorizontalControl. 2023-09-08T13:34:09.370Z,1694180049.370 [HorizontalControl] Loaded 2023-09-08T13:34:09.370Z,1694180049.370 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2023-09-08T13:34:09.373Z,1694180049.373 [SpeedControl](DEBUG): Construct SpeedControl. 2023-09-08T13:34:09.374Z,1694180049.374 [SpeedControl] Loaded 2023-09-08T13:34:09.375Z,1694180049.375 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2023-09-08T13:34:09.378Z,1694180049.378 [LoopControl](DEBUG): Construct LoopControl. 2023-09-08T13:34:09.378Z,1694180049.378 [LoopControl] Loaded 2023-09-08T13:34:09.378Z,1694180049.378 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2023-09-08T13:34:09.379Z,1694180049.379 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2023-09-08T13:34:09.379Z,1694180049.379 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2023-09-08T13:34:09.395Z,1694180049.395 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2023-09-08T13:34:09.396Z,1694180049.396 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2023-09-08T13:34:09.749Z,1694180049.749 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2023-09-08T13:34:09.755Z,1694180049.755 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2023-09-08T13:34:09.758Z,1694180049.758 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2023-09-08T13:34:09.769Z,1694180049.769 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2023-09-08T13:34:09.770Z,1694180049.770 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C2B4E0 2023-09-08T13:34:09.770Z,1694180049.770 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 927 2023-09-08T13:34:09.774Z,1694180049.774 [Supervisor](INFO): Main Thread ID is 822 2023-09-08T13:34:09.775Z,1694180049.775 [Supervisor](DEBUG): Running supervisor. 2023-09-08T13:34:09.775Z,1694180049.775 [CommandExec ThreadHandler](INFO): Handler Thread ID is 928 2023-09-08T13:34:09.776Z,1694180049.776 [CommandExec](INFO): Initializing the command executive. 2023-09-08T13:34:09.777Z,1694180049.777 [CommandLine ThreadHandler](INFO): Handler Thread ID is 929 2023-09-08T13:34:09.779Z,1694180049.779 [controlThread ThreadHandler](INFO): Handler Thread ID is 930 2023-09-08T13:34:09.780Z,1694180049.780 [controlThread](DEBUG): Initializing ControlThread 2023-09-08T13:34:09.781Z,1694180049.781 [InternalEnvSim](DEBUG): InternaEnvlSim initializing... 2023-09-08T13:34:09.784Z,1694180049.784 [logger ThreadHandler](INFO): Handler Thread ID is 931 2023-09-08T13:34:09.816Z,1694180049.816 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 932 2023-09-08T13:34:09.818Z,1694180049.818 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2023-09-08T13:34:09.832Z,1694180049.832 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 934 2023-09-08T13:34:09.840Z,1694180049.840 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 936 2023-09-08T13:34:09.841Z,1694180049.841 [WetLabsBB2FL](INFO): Powering up 2023-09-08T13:34:09.864Z,1694180049.864 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 937 2023-09-08T13:34:09.881Z,1694180049.881 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 938 2023-09-08T13:34:09.882Z,1694180049.882 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2023-09-08T13:34:09.896Z,1694180049.896 [Onboard ThreadHandler](INFO): Handler Thread ID is 939 2023-09-08T13:34:09.913Z,1694180049.913 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 940 2023-09-08T13:34:09.932Z,1694180049.932 [SBIT](INFO): Initialize SBIT Component. 2023-09-08T13:34:09.932Z,1694180049.932 [SBIT](IMPORTANT): git: 2023-09-07 2023-09-08T13:34:09.933Z,1694180049.933 [SBIT](INFO): git hash: de73b65bba9e058a7fe4bf2bc7b950ee8b764c06 2023-09-08T13:34:09.933Z,1694180049.933 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2023-09-08T13:34:09.934Z,1694180049.934 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021 2023-09-08T13:34:09.935Z,1694180049.935 [SBIT](INFO): Beginning SBIT in 107.000000 seconds. 2023-09-08T13:34:09.936Z,1694180049.936 [DAT ThreadHandler](INFO): Handler Thread ID is 941 2023-09-08T13:34:09.937Z,1694180049.937 [DAT](INFO): Powering up 2023-09-08T13:34:09.937Z,1694180049.937 [DAT](DEBUG): Initializing DAT. 2023-09-08T13:34:09.938Z,1694180049.938 [IBIT](INFO): Initialize IBIT Component. 2023-09-08T13:34:09.939Z,1694180049.939 [CBIT](DEBUG): Initialize CBIT Component. 2023-09-08T13:34:09.940Z,1694180049.940 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 943 2023-09-08T13:34:09.946Z,1694180049.946 [NavChartDb](FAULT): Change detected in ENC collection. Wiping NavChart Directory 2023-09-08T13:34:09.952Z,1694180049.952 [CBIT](DEBUG): Initialized mux pins. 2023-09-08T13:34:09.952Z,1694180049.952 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2023-09-08T13:34:09.952Z,1694180049.952 [CBIT](DEBUG): Initializing the watchdog timer. 2023-09-08T13:34:09.973Z,1694180049.973 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2MI01M.000 2023-09-08T13:34:09.975Z,1694180049.975 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US2MI01M.000 2023-09-08T13:34:09.975Z,1694180049.975 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2MI80M.000 2023-09-08T13:34:09.976Z,1694180049.976 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET. 2023-09-08T13:34:09.976Z,1694180049.976 [CBIT](DEBUG): Initializing heartbeat. 2023-09-08T13:34:09.977Z,1694180049.977 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US2MI80M.000 2023-09-08T13:34:09.977Z,1694180049.977 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI57M.000 2023-09-08T13:34:09.979Z,1694180049.979 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4MI57M.000 2023-09-08T13:34:09.979Z,1694180049.979 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI56M.000 2023-09-08T13:34:09.980Z,1694180049.980 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4MI56M.000 2023-09-08T13:34:09.981Z,1694180049.981 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI90M.000 2023-09-08T13:34:09.982Z,1694180049.982 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4MI90M.000 2023-09-08T13:34:09.982Z,1694180049.982 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI89M.000 2023-09-08T13:34:09.984Z,1694180049.984 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4MI89M.000 2023-09-08T13:34:09.984Z,1694180049.984 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4WI03M.000 2023-09-08T13:34:09.986Z,1694180049.986 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4WI03M.000 2023-09-08T13:34:09.986Z,1694180049.986 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4WI06M.000 2023-09-08T13:34:09.988Z,1694180049.988 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4WI06M.000 2023-09-08T13:34:09.988Z,1694180049.988 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4OH01M.000 2023-09-08T13:34:09.989Z,1694180049.989 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4OH01M.000 2023-09-08T13:34:09.990Z,1694180049.990 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4OH04M.000 2023-09-08T13:34:09.991Z,1694180049.991 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4OH04M.000 2023-09-08T13:34:09.991Z,1694180049.991 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4OH02M.000 2023-09-08T13:34:09.993Z,1694180049.993 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4OH02M.000 2023-09-08T13:34:09.993Z,1694180049.993 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4PA20M.000 2023-09-08T13:34:09.995Z,1694180049.995 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4PA20M.000 2023-09-08T13:34:09.995Z,1694180049.995 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4PA21M.000 2023-09-08T13:34:10.013Z,1694180050.013 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4PA21M.000 2023-09-08T13:34:10.048Z,1694180050.048 [CBIT](DEBUG): Deactivating GF circuits. 2023-09-08T13:34:10.048Z,1694180050.048 [CBIT](DEBUG): Deactivating emergency mode. 2023-09-08T13:34:10.072Z,1694180050.072 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4PA21M.000 2023-09-08T13:34:10.089Z,1694180050.089 [CBIT](DEBUG): Backplane powered. 2023-09-08T13:34:10.092Z,1694180050.092 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2023-09-08T13:34:10.093Z,1694180050.093 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2023-09-08T13:34:10.093Z,1694180050.093 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2023-09-08T13:34:10.093Z,1694180050.093 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2023-09-08T13:34:10.094Z,1694180050.094 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2023-09-08T13:34:10.095Z,1694180050.095 [NavChart](DEBUG): Initialize NavChart Navigation. 2023-09-08T13:34:10.095Z,1694180050.095 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2023-09-08T13:34:10.109Z,1694180050.109 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2023-09-08T13:34:10.120Z,1694180050.120 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2023-09-08T13:34:10.121Z,1694180050.121 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2023-09-08T13:34:10.122Z,1694180050.122 [LoopControl](DEBUG): Initialize LoopControlComponent. 2023-09-08T13:34:10.123Z,1694180050.123 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml 2023-09-08T13:34:10.158Z,1694180050.158 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2023-09-08T13:34:10.204Z,1694180050.204 [MissionManager](DEBUG): 2023-09-08T13:34:10.205Z,1694180050.205 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml 2023-09-08T13:34:10.274Z,1694180050.274 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2023-09-08T13:34:10.275Z,1694180050.275 [Default:A.Wait](DEBUG): Construct Wait. 2023-09-08T13:34:10.278Z,1694180050.278 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2023-09-08T13:34:10.320Z,1694180050.320 [Radio_Surface](INFO): Powering up 2023-09-08T13:34:10.326Z,1694180050.326 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2023-09-08T13:34:10.331Z,1694180050.331 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2023-09-08T13:34:10.349Z,1694180050.349 [Default:E.Execute](DEBUG): Construct Execute. 2023-09-08T13:34:10.353Z,1694180050.353 [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 2023-09-08T13:34:10.357Z,1694180050.357 [controlThread](DEBUG): Component order: CycleStarter,InternalEnvSim,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2023-09-08T13:34:10.374Z,1694180050.374 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2023-09-08T13:34:10.558Z,1694180050.558 [Depth_Keller](ERROR): Pressure or depth reading out of range: 1895.894409 decibar, 0.000000 m 2023-09-08T13:34:10.560Z,1694180050.560 [Power24vConverter](INFO): Powering up. 2023-09-08T13:34:10.565Z,1694180050.565 [DepthRateCalculator](ERROR): Depth measurement is not active 2023-09-08T13:34:10.626Z,1694180050.626 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2023-09-08T13:34:10.632Z,1694180050.632 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2023-09-08T13:34:10.633Z,1694180050.633 [ElevatorServo](DEBUG): Initializing EZServoServo. 2023-09-08T13:34:10.640Z,1694180050.640 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2023-09-08T13:34:10.641Z,1694180050.641 [MassServo](DEBUG): Initializing EZServoServo. 2023-09-08T13:34:10.652Z,1694180050.652 [MassServo](DEBUG): Initializing MassServo. 2023-09-08T13:34:10.653Z,1694180050.653 [RudderServo](DEBUG): Initializing EZServoServo. 2023-09-08T13:34:10.660Z,1694180050.660 [RudderServo](DEBUG): Initializing RudderServo. 2023-09-08T13:34:10.661Z,1694180050.661 [ThrusterHE](DEBUG): Initializing EZServoServo. 2023-09-08T13:34:10.668Z,1694180050.668 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2023-09-08T13:34:10.670Z,1694180050.670 [CommandExec](FAULT): Scheduling is paused 2023-09-08T13:34:10.670Z,1694180050.670 [CBIT](INFO): Critical error at 20230908T133409 2023-09-08T13:34:10.671Z,1694180050.671 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2023-09-08T13:34:11.445Z,1694180051.445 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4PA21M.000 2023-09-08T13:34:11.944Z,1694180051.944 [WetLabsBB2FL](INFO): Powering down 2023-09-08T13:34:16.277Z,1694180056.277 [ThrusterHE](ERROR): Zero Speed Commanded. 2023-09-08T13:34:22.032Z,1694180062.032 [DAT](INFO): DAT read: 2023-09-08T13:34:22.034Z,1694180062.034 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2023-09-08T13:34:23.545Z,1694180063.545 [DAT](INFO): DAT read: MF Frequency Band 2023-09-08T13:34:23.546Z,1694180063.546 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2023-09-08T13:34:23.547Z,1694180063.547 [DAT](INFO): DAT read: Sep 8 2023 13:34:17 2023-09-08T13:34:24.805Z,1694180064.805 [DAT](INFO): DAT read: Features enabled [Bearing] 2023-09-08T13:34:24.806Z,1694180064.806 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2023-09-08T13:34:24.806Z,1694180064.806 [DAT](INFO): commRate: 1200 2023-09-08T13:34:26.446Z,1694180066.446 [NavChartDb](INFO): # of records loaded: 5000 2023-09-08T13:34:26.872Z,1694180066.872 [DAT](INFO): entering command mode 2023-09-08T13:34:27.072Z,1694180067.072 [DAT](INFO): DAT read: 2023-09-08T13:34:27.073Z,1694180067.073 [DAT](INFO): DAT read: user:1> 2023-09-08T13:34:27.073Z,1694180067.073 [DAT](INFO): setting verbose to 3 2023-09-08T13:34:27.325Z,1694180067.325 [DAT](INFO): DAT read: user:1> 2023-09-08T13:34:27.326Z,1694180067.326 [DAT](INFO): DAT read: Verbose | 3 2023-09-08T13:34:27.326Z,1694180067.326 [DAT](INFO): set verbose to 3 2023-09-08T13:34:27.326Z,1694180067.326 [DAT](INFO): setting DatVerbose to 27440 2023-09-08T13:34:27.577Z,1694180067.577 [DAT](INFO): DAT read: user:2> 2023-09-08T13:34:27.577Z,1694180067.577 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:27.828Z,1694180067.828 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:28.081Z,1694180068.081 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:28.332Z,1694180068.332 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:28.584Z,1694180068.584 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:28.836Z,1694180068.836 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:29.089Z,1694180069.089 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:29.340Z,1694180069.340 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:29.592Z,1694180069.592 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:29.844Z,1694180069.844 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:30.096Z,1694180070.096 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:30.348Z,1694180070.348 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:30.600Z,1694180070.600 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:30.852Z,1694180070.852 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:31.104Z,1694180071.104 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:31.356Z,1694180071.356 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:31.608Z,1694180071.608 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:31.860Z,1694180071.860 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:32.113Z,1694180072.113 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:32.364Z,1694180072.364 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:32.616Z,1694180072.616 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:32.868Z,1694180072.868 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:33.120Z,1694180073.120 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:33.373Z,1694180073.373 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:33.624Z,1694180073.624 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:33.877Z,1694180073.877 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:34.128Z,1694180074.128 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:34.380Z,1694180074.380 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:34.632Z,1694180074.632 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:34.884Z,1694180074.884 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:35.136Z,1694180075.136 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:35.388Z,1694180075.388 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:35.640Z,1694180075.640 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:35.900Z,1694180075.900 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:35.950Z,1694180075.950 [NavChartDb](INFO): # of records loaded: 10000 2023-09-08T13:34:36.152Z,1694180076.152 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:36.404Z,1694180076.404 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:36.656Z,1694180076.656 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:36.908Z,1694180076.908 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:37.160Z,1694180077.160 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:37.412Z,1694180077.412 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:37.665Z,1694180077.665 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:37.916Z,1694180077.916 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:38.168Z,1694180078.168 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:38.420Z,1694180078.420 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:38.673Z,1694180078.673 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:38.815Z,1694180078.815 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4PA21M.000 2023-09-08T13:34:38.927Z,1694180078.927 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:39.075Z,1694180079.075 [NAL9602](INFO): Powering up NAL9602 2023-09-08T13:34:39.176Z,1694180079.176 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:39.428Z,1694180079.428 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:39.680Z,1694180079.680 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:39.933Z,1694180079.933 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:40.184Z,1694180080.184 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:40.436Z,1694180080.436 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:40.696Z,1694180080.696 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:40.948Z,1694180080.948 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:41.201Z,1694180081.201 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:41.452Z,1694180081.452 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:41.704Z,1694180081.704 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:41.956Z,1694180081.956 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:42.208Z,1694180082.208 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:42.461Z,1694180082.461 [DAT](DEBUG): checking for DatVerbose setting acknowledgment 2023-09-08T13:34:42.461Z,1694180082.461 [DAT](FAULT): failed to set DatVerbose 2023-09-08T13:34:42.714Z,1694180082.714 [DAT](INFO): setting DatVerbose to 27440 2023-09-08T13:34:42.965Z,1694180082.965 [DAT](INFO): DAT read: user:3> 2023-09-08T13:34:42.966Z,1694180082.966 [DAT](INFO): DAT read: DatVerbose | 27440 2023-09-08T13:34:42.966Z,1694180082.966 [DAT](INFO): set DatVerbose to 27440 2023-09-08T13:34:42.966Z,1694180082.966 [DAT](INFO): setting transmit power to 8 2023-09-08T13:34:43.217Z,1694180083.217 [DAT](INFO): DAT read: user:4> 2023-09-08T13:34:43.218Z,1694180083.218 [DAT](INFO): DAT read: TxPower | 8 (Max) 2023-09-08T13:34:43.218Z,1694180083.218 [DAT](INFO): set transmit power to 8 2023-09-08T13:34:43.218Z,1694180083.218 [DAT](INFO): setting local address to 5 2023-09-08T13:34:43.468Z,1694180083.468 [DAT](INFO): DAT read: user:5> 2023-09-08T13:34:43.469Z,1694180083.469 [DAT](INFO): DAT read: LocalAddr | 5 2023-09-08T13:34:43.470Z,1694180083.470 [DAT](INFO): set local address to 5 2023-09-08T13:34:43.471Z,1694180083.471 [DAT](INFO): Setting time to: 13:34:43 And date to:9/8/2023 2023-09-08T13:34:43.721Z,1694180083.721 [DAT](INFO): DAT read: user:6> 2023-09-08T13:34:43.722Z,1694180083.722 [DAT](INFO): DAT read: Fri Sep 8, 2023 13:34:43 2023-09-08T13:34:43.722Z,1694180083.722 [DAT](INFO): Local DAT time set to Fri Sep 8, 2023 13:34:43 2023-09-08T13:34:44.865Z,1694180084.865 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4PA21M.000 2023-09-08T13:34:46.137Z,1694180086.137 [NavChartDb](INFO): # of records loaded: 15000 2023-09-08T13:34:49.314Z,1694180089.314 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4PA21M.000 2023-09-08T13:34:49.815Z,1694180089.815 [NavChartDb](INFO): # of records loaded: 16189 2023-09-08T13:34:49.818Z,1694180089.818 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4PA21M.000 2023-09-08T13:34:49.819Z,1694180089.819 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4PA20M.000 2023-09-08T13:34:49.943Z,1694180089.943 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4PA20M.000 2023-09-08T13:34:49.977Z,1694180089.977 [NAL9602](INFO): NAL9602 initialized 2023-09-08T13:34:50.135Z,1694180090.135 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4PA20M.000 2023-09-08T13:34:50.138Z,1694180090.138 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4PA20M.000 2023-09-08T13:34:50.163Z,1694180090.163 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4PA20M.000 2023-09-08T13:34:50.550Z,1694180090.550 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4PA20M.000 2023-09-08T13:34:50.940Z,1694180090.940 [NavChartDb](INFO): # of records loaded: 262 2023-09-08T13:34:50.942Z,1694180090.942 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4PA20M.000 2023-09-08T13:34:50.942Z,1694180090.942 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4OH02M.000 2023-09-08T13:34:52.141Z,1694180092.141 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4OH02M.000 2023-09-08T13:35:02.003Z,1694180102.003 [NavChartDb](INFO): # of records loaded: 5000 2023-09-08T13:35:07.964Z,1694180107.964 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4OH02M.000 2023-09-08T13:35:08.371Z,1694180108.371 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4OH02M.000 2023-09-08T13:35:11.119Z,1694180111.119 [NavChartDb](INFO): # of records loaded: 10000 2023-09-08T13:35:12.407Z,1694180112.407 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4OH02M.000 2023-09-08T13:35:14.073Z,1694180114.073 [NavChartDb](INFO): # of records loaded: 10534 2023-09-08T13:35:14.077Z,1694180114.077 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4OH02M.000 2023-09-08T13:35:14.077Z,1694180114.077 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4OH04M.000 2023-09-08T13:35:14.189Z,1694180114.189 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4OH04M.000 2023-09-08T13:35:14.391Z,1694180114.391 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4OH04M.000 2023-09-08T13:35:14.395Z,1694180114.395 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4OH04M.000 2023-09-08T13:35:14.397Z,1694180114.397 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4OH04M.000 2023-09-08T13:35:14.411Z,1694180114.411 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4OH04M.000 2023-09-08T13:35:15.062Z,1694180115.062 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4OH04M.000 2023-09-08T13:35:16.486Z,1694180116.486 [NavChartDb](INFO): # of records loaded: 473 2023-09-08T13:35:16.488Z,1694180116.488 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4OH04M.000 2023-09-08T13:35:16.489Z,1694180116.489 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4OH01M.000 2023-09-08T13:35:17.948Z,1694180117.948 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4OH01M.000 2023-09-08T13:35:27.634Z,1694180127.634 [NavChartDb](INFO): # of records loaded: 5000 2023-09-08T13:35:31.352Z,1694180131.352 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4OH01M.000 2023-09-08T13:35:34.546Z,1694180134.546 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4OH01M.000 2023-09-08T13:35:37.530Z,1694180137.530 [NavChartDb](INFO): # of records loaded: 10000 2023-09-08T13:35:38.071Z,1694180138.071 [NAL9602](INFO): SBD MO Status=0, MOMSN=9006, MT Status=0, MTMSN=0 2023-09-08T13:35:38.072Z,1694180138.072 [NAL9602](INFO): No messages in MT queue 2023-09-08T13:35:38.234Z,1694180138.234 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4OH01M.000 2023-09-08T13:35:39.290Z,1694180139.290 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,133535.00,A,4145.53350,N,08116.65049,W,0.058,0.00,080923,,,A*77 2023-09-08T13:35:39.298Z,1694180139.298 [NAL9602](INFO): GPS fix at 20230908T133535: (41.758892, -81.277508) 2023-09-08T13:35:40.135Z,1694180140.135 [NavChartDb](INFO): # of records loaded: 10183 2023-09-08T13:35:40.137Z,1694180140.137 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4OH01M.000 2023-09-08T13:35:40.138Z,1694180140.138 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4WI06M.000 2023-09-08T13:35:44.008Z,1694180144.008 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4WI06M.000 2023-09-08T13:35:52.815Z,1694180152.815 [NavChartDb](INFO): # of records loaded: 5000 2023-09-08T13:35:57.509Z,1694180157.509 [SBIT](IMPORTANT): Beginning Startup BIT 2023-09-08T13:35:57.522Z,1694180157.522 [CBIT](IMPORTANT): Beginning ground fault scan 2023-09-08T13:36:02.553Z,1694180162.553 [NavChartDb](INFO): # of records loaded: 10000 2023-09-08T13:36:08.449Z,1694180168.449 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.005972 CHAN A1 (24V): 0.002389 CHAN A2 (12V): -0.006583 CHAN A3 (5V): -0.003934 CHAN B0 (3.3V): -0.001432 CHAN B1 (3.15aV): -0.001402 CHAN B2 (3.15bV): -0.001161 CHAN B3 (GND): -0.000562 OPEN: 0.000161 Full Scale: +/- 1 mA 2023-09-08T13:36:11.230Z,1694180171.230 [NAL9602](INFO): Not Powering down - fast GPS 2023-09-08T13:36:14.221Z,1694180174.221 [NavChartDb](INFO): # of records loaded: 15000 2023-09-08T13:36:23.775Z,1694180183.775 [NavChartDb](INFO): # of records loaded: 20000 2023-09-08T13:36:32.065Z,1694180192.065 [NavChartDb](INFO): # of records loaded: 25000 2023-09-08T13:36:37.558Z,1694180197.558 [SBIT](FAULT): Elevator: EXPECTED:-15.000000 ACTUAL:-14.698703 2023-09-08T13:36:37.559Z,1694180197.559 [SBIT](FAULT): Control surface position failure. 2023-09-08T13:36:41.849Z,1694180201.849 [NavChartDb](INFO): # of records loaded: 30000 2023-09-08T13:36:50.505Z,1694180210.505 [NavChartDb](INFO): # of records loaded: 35000 2023-09-08T13:36:51.643Z,1694180211.643 [SBIT](CRITICAL): SBIT FAILED 2023-09-08T13:36:51.648Z,1694180211.648 [SBIT](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2023-09-08T13:36:51.649Z,1694180211.649 [CBIT](INFO): Critical error at 20230908T133651 2023-09-08T13:36:52.025Z,1694180212.025 [MissionManager](IMPORTANT): Started mission Startup 2023-09-08T13:36:52.026Z,1694180212.026 [Startup] Running Loop=1 2023-09-08T13:36:52.026Z,1694180212.026 [Startup](DEBUG): Aggregate::initialize Startup 2023-09-08T13:36:52.026Z,1694180212.026 [Startup:A.GoToSurface] Running Loop=1 2023-09-08T13:36:52.026Z,1694180212.026 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2023-09-08T13:36:52.027Z,1694180212.027 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2023-09-08T13:36:52.027Z,1694180212.027 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2023-09-08T13:36:52.027Z,1694180212.027 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2023-09-08T13:36:52.032Z,1694180212.032 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2023-09-08T13:36:52.032Z,1694180212.032 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2023-09-08T13:36:52.061Z,1694180212.061 [Startup:StartupSatComms] Running Loop=1 2023-09-08T13:36:52.061Z,1694180212.061 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2023-09-08T13:36:52.061Z,1694180212.061 [Startup:StartupSatComms:A] Running Loop=1 2023-09-08T13:36:52.436Z,1694180212.436 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2023-09-08T13:36:54.007Z,1694180214.007 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,133650.00,A,4145.53114,N,08116.65322,W,0.019,0.00,080923,,,A*7E 2023-09-08T13:36:54.010Z,1694180214.010 [NAL9602](INFO): GPS fix at 20230908T133650: (41.758852, -81.277554) 2023-09-08T13:36:54.047Z,1694180214.047 [Startup:StartupSatComms:A] Stopped 2023-09-08T13:36:54.047Z,1694180214.047 [Startup:StartupSatComms:B] Running Loop=1 2023-09-08T13:36:54.456Z,1694180214.456 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2023-09-08T13:36:59.558Z,1694180219.558 [NavChartDb](INFO): # of records loaded: 40000 2023-09-08T13:37:04.234Z,1694180224.234 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4WI06M.000 2023-09-08T13:37:09.649Z,1694180229.649 [NavChartDb](INFO): # of records loaded: 45000 2023-09-08T13:37:21.651Z,1694180241.651 [NavChartDb](INFO): # of records loaded: 50000 2023-09-08T13:37:26.513Z,1694180246.513 [NAL9602](INFO): SBD MO Status=2, MOMSN=9007, MT Status=2, MTMSN=0 2023-09-08T13:37:26.513Z,1694180246.513 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-09-08T13:37:32.939Z,1694180252.939 [NavChartDb](INFO): # of records loaded: 55000 2023-09-08T13:37:42.835Z,1694180262.835 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4WI06M.000 2023-09-08T13:37:44.523Z,1694180264.523 [NAL9602](INFO): SBD MO Status=1, MOMSN=9007, MT Status=0, MTMSN=0 2023-09-08T13:37:44.577Z,1694180264.577 [NAL9602](INFO): Sent 18 bytes from file Logs/20230908T132800/Courier0004.lzma 2023-09-08T13:37:44.577Z,1694180264.577 [NAL9602](INFO): Packets left to send: 0 2023-09-08T13:37:46.802Z,1694180266.802 [NavChartDb](INFO): # of records loaded: 60000 2023-09-08T13:37:54.311Z,1694180274.311 [Startup:StartupSatComms:B](INFO): Timed out from 2023-09-08T13:36:54.0Z 2023-09-08T13:37:54.311Z,1694180274.311 [Startup:StartupSatComms:B] Stopped 2023-09-08T13:37:54.311Z,1694180274.311 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2023-09-08T13:37:54.311Z,1694180274.311 [Startup:StartupSatComms] Stopped 2023-09-08T13:37:54.311Z,1694180274.311 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2023-09-08T13:37:54.319Z,1694180274.319 [Startup](INFO): Completed Startup 2023-09-08T13:37:54.324Z,1694180274.324 [MissionManager](INFO): Startup is completed. 2023-09-08T13:37:54.324Z,1694180274.324 [MissionManager](INFO): Uninitializing Mission Startup 2023-09-08T13:37:54.324Z,1694180274.324 [Startup] Stopped 2023-09-08T13:37:54.324Z,1694180274.324 [Startup](DEBUG): Aggregate::uninitialize Startup 2023-09-08T13:37:54.324Z,1694180274.324 [Startup:A.GoToSurface] Stopped 2023-09-08T13:37:54.324Z,1694180274.324 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2023-09-08T13:37:54.683Z,1694180274.683 [MissionManager](IMPORTANT): Started mission Default 2023-09-08T13:37:54.683Z,1694180274.683 [Default] Running Loop=1 2023-09-08T13:37:54.683Z,1694180274.683 [Default](DEBUG): Aggregate::initialize Default 2023-09-08T13:37:54.683Z,1694180274.683 [Default:B.GoToSurface] Running Loop=1 2023-09-08T13:37:54.683Z,1694180274.683 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2023-09-08T13:37:54.684Z,1694180274.684 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2023-09-08T13:37:54.684Z,1694180274.684 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2023-09-08T13:37:54.684Z,1694180274.684 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2023-09-08T13:37:54.685Z,1694180274.685 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2023-09-08T13:37:54.685Z,1694180274.685 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2023-09-08T13:37:54.685Z,1694180274.685 [Default:A.Wait] Running Loop=1 2023-09-08T13:37:54.685Z,1694180274.685 [Default:A.Wait](DEBUG): Initialize Wait Component. 2023-09-08T13:38:04.766Z,1694180284.766 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4WI06M.000 2023-09-08T13:38:05.819Z,1694180285.819 [NAL9602](INFO): SBD MO Status=2, MOMSN=9008, MT Status=2, MTMSN=0 2023-09-08T13:38:05.819Z,1694180285.819 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-09-08T13:38:06.664Z,1694180286.664 [NavChartDb](INFO): # of records loaded: 64244 2023-09-08T13:38:06.672Z,1694180286.672 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4WI06M.000 2023-09-08T13:38:06.673Z,1694180286.673 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4WI03M.000 2023-09-08T13:38:08.015Z,1694180288.015 [Default:A.Wait](INFO): Done Waiting. 2023-09-08T13:38:08.015Z,1694180288.015 [Default:A.Wait] Stopped 2023-09-08T13:38:08.016Z,1694180288.016 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2023-09-08T13:38:08.428Z,1694180288.428 [Default:CheckIn] Running Loop=1 2023-09-08T13:38:08.428Z,1694180288.428 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-09-08T13:38:08.428Z,1694180288.428 [Default:CheckIn:Read_GPS] Running Loop=1 2023-09-08T13:38:08.810Z,1694180288.810 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2023-09-08T13:38:10.042Z,1694180290.042 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4WI03M.000 2023-09-08T13:38:10.414Z,1694180290.414 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,133806.00,A,4145.52992,N,08116.65438,W,0.078,0.00,080923,,,D*7A 2023-09-08T13:38:10.417Z,1694180290.417 [NAL9602](INFO): GPS fix at 20230908T133806: (41.758832, -81.277573) 2023-09-08T13:38:10.427Z,1694180290.427 [Default:CheckIn:Read_GPS] Stopped 2023-09-08T13:38:10.427Z,1694180290.427 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-09-08T13:38:10.887Z,1694180290.887 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2023-09-08T13:38:32.808Z,1694180312.808 [NavChartDb](INFO): # of records loaded: 5000 2023-09-08T13:38:39.374Z,1694180319.374 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004348 2023-09-08T13:38:43.907Z,1694180323.907 [NAL9602](INFO): SBD MO Status=2, MOMSN=9008, MT Status=2, MTMSN=0 2023-09-08T13:38:43.907Z,1694180323.907 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-09-08T13:39:00.916Z,1694180340.916 [DataOverHttps](INFO): Sending 354 bytes from file Logs/20230908T133357/Courier0000.lzma 2023-09-08T13:39:01.914Z,1694180341.914 [DataOverHttps](INFO): Moved sent file to Logs/20230908T133357/Courier0000.lzma.bak 2023-09-08T13:39:01.914Z,1694180341.914 [DataOverHttps](INFO): SBD MOMSN=18637141 2023-09-08T13:39:03.135Z,1694180343.135 [NavChartDb](INFO): # of records loaded: 10000 2023-09-08T13:39:14.437Z,1694180354.437 [NAL9602](INFO): Not Powering down - fast GPS 2023-09-08T13:39:25.138Z,1694180365.138 [NavChartDb](INFO): # of records loaded: 15000 2023-09-08T13:39:38.983Z,1694180378.983 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20230908T133357/Courier0004.lzma 2023-09-08T13:39:39.986Z,1694180379.986 [DataOverHttps](INFO): Moved sent file to Logs/20230908T133357/Courier0004.lzma.bak 2023-09-08T13:39:39.986Z,1694180379.986 [DataOverHttps](INFO): SBD MOMSN=18637147 2023-09-08T13:39:41.999Z,1694180381.999 [NavChartDb](INFO): # of records loaded: 20000 2023-09-08T13:40:02.265Z,1694180402.265 [NavChartDb](INFO): # of records loaded: 25000 2023-09-08T13:40:18.749Z,1694180418.749 [NavChartDb](INFO): # of records loaded: 30000 2023-09-08T13:40:36.203Z,1694180436.203 [NavChartDb](INFO): # of records loaded: 35000 2023-09-08T13:40:58.693Z,1694180458.693 [NavChartDb](INFO): # of records loaded: 40000 2023-09-08T13:41:08.944Z,1694180468.944 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4WI03M.000 2023-09-08T13:41:14.947Z,1694180474.947 [NavChartDb](INFO): # of records loaded: 45000 2023-09-08T13:41:31.603Z,1694180491.603 [NavChartDb](INFO): # of records loaded: 50000 2023-09-08T13:41:53.078Z,1694180513.078 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4WI03M.000 2023-09-08T13:41:59.836Z,1694180519.836 [NavChartDb](INFO): # of records loaded: 55000 2023-09-08T13:42:17.081Z,1694180537.081 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2023-09-08T13:42:17.119Z,1694180537.119 [BPC1](INFO): Received data from all battery sticks. 2023-09-08T13:42:18.533Z,1694180538.533 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4WI03M.000 2023-09-08T13:42:20.870Z,1694180540.870 [NavChartDb](INFO): # of records loaded: 58175 2023-09-08T13:42:20.884Z,1694180540.884 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4WI03M.000 2023-09-08T13:42:20.885Z,1694180540.885 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4MI89M.000 2023-09-08T13:42:20.886Z,1694180540.886 [NavChartDb](FAULT): Error opening file: Resources/ElectronicNavigationCharts/US4MI89M.000 2023-09-08T13:42:20.886Z,1694180540.886 [NavChartDb](INFO): # of records loaded: 0 2023-09-08T13:42:20.904Z,1694180540.904 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4MI89M.000 2023-09-08T13:42:20.988Z,1694180540.988 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4MI90M.000 2023-09-08T13:42:20.989Z,1694180540.989 [NavChartDb](FAULT): Error opening file: Resources/ElectronicNavigationCharts/US4MI90M.000 2023-09-08T13:42:20.989Z,1694180540.989 [NavChartDb](INFO): # of records loaded: 0 2023-09-08T13:42:20.991Z,1694180540.991 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4MI90M.000 2023-09-08T13:42:21.092Z,1694180541.092 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4MI56M.000 2023-09-08T13:42:21.093Z,1694180541.093 [NavChartDb](FAULT): Error opening file: Resources/ElectronicNavigationCharts/US4MI56M.000 2023-09-08T13:42:21.093Z,1694180541.093 [NavChartDb](INFO): # of records loaded: 0 2023-09-08T13:42:21.095Z,1694180541.095 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4MI56M.000 2023-09-08T13:42:21.196Z,1694180541.196 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4MI57M.000 2023-09-08T13:42:21.197Z,1694180541.197 [NavChartDb](FAULT): Error opening file: Resources/ElectronicNavigationCharts/US4MI57M.000 2023-09-08T13:42:21.197Z,1694180541.197 [NavChartDb](INFO): # of records loaded: 0 2023-09-08T13:42:21.199Z,1694180541.199 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4MI57M.000 2023-09-08T13:42:21.300Z,1694180541.300 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US2MI80M.000 2023-09-08T13:42:21.301Z,1694180541.301 [NavChartDb](FAULT): Error opening file: Resources/ElectronicNavigationCharts/US2MI80M.000 2023-09-08T13:42:21.301Z,1694180541.301 [NavChartDb](INFO): # of records loaded: 0 2023-09-08T13:42:21.303Z,1694180541.303 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US2MI80M.000 2023-09-08T13:42:21.404Z,1694180541.404 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US2MI01M.000 2023-09-08T13:42:27.296Z,1694180547.296 [NavChartDb](FAULT): Error opening file: Resources/ElectronicNavigationCharts/US2MI01M.000 2023-09-08T13:42:27.296Z,1694180547.296 [NavChartDb](INFO): # of records loaded: 0 2023-09-08T13:42:27.298Z,1694180547.298 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US2MI01M.000 2023-09-08T13:42:31.095Z,1694180551.095 [NavChartDb](INFO): Creating index for soundings 2023-09-08T13:42:47.363Z,1694180567.363 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=187.377808 2023-09-08T13:42:47.630Z,1694180567.630 [NavChartDb](INFO): Creating index for 0p0 2023-09-08T13:42:57.098Z,1694180577.098 [NavChartDb](INFO): Creating index for 1p8 2023-09-08T13:42:59.705Z,1694180579.705 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003494 2023-09-08T13:43:03.061Z,1694180583.061 [NavChartDb](INFO): Creating index for 3p6 2023-09-08T13:43:08.838Z,1694180588.838 [NavChartDb](INFO): Creating index for 5p4 2023-09-08T13:43:16.207Z,1694180596.207 [DataOverHttps](INFO): Sending 52055 bytes from file Logs/20230908T125644/Express0008.lzma 2023-09-08T13:43:16.835Z,1694180596.835 [NavChartDb](INFO): Creating index for 7p3 2023-09-08T13:43:20.753Z,1694180600.753 [NavChartDb](INFO): Creating index for 9p1 2023-09-08T13:43:21.837Z,1694180601.837 [NavChartDb](INFO): Creating index for 20p0 2023-09-08T13:43:23.054Z,1694180603.054 [DataOverHttps](INFO): Moved sent file to Logs/20230908T125644/Express0008.lzma.bak 2023-09-08T13:43:23.054Z,1694180603.054 [DataOverHttps](INFO): SBD MOMSN=18637159 2023-09-08T13:43:29.998Z,1694180609.998 [NAL9602](INFO): Not Powering down - fast GPS 2023-09-08T13:44:42.403Z,1694180682.403 [CommandExec](IMPORTANT): got command get distance_from_shore 2023-09-08T13:44:42.404Z,1694180682.404 [CommandExec](IMPORTANT): distance_from_shore 60.558208 m 2023-09-08T13:48:20.925Z,1694180900.925 [DataOverHttps](INFO): Sending 613 bytes from file Logs/20230908T132035/Express0001.lzma 2023-09-08T13:48:21.926Z,1694180901.926 [DataOverHttps](INFO): Moved sent file to Logs/20230908T132035/Express0001.lzma.bak 2023-09-08T13:48:21.927Z,1694180901.927 [DataOverHttps](INFO): SBD MOMSN=18749799 2023-09-08T13:48:50.093Z,1694180930.093 [DataOverHttps](INFO): Sending 1486 bytes from file Logs/20230908T132150/Express0001.lzma 2023-09-08T13:48:51.090Z,1694180931.090 [DataOverHttps](INFO): Moved sent file to Logs/20230908T132150/Express0001.lzma.bak 2023-09-08T13:48:51.090Z,1694180931.090 [DataOverHttps](INFO): SBD MOMSN=18749824 2023-09-08T13:49:14.302Z,1694180954.302 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20230908T132150/Express0005.lzma 2023-09-08T13:49:15.302Z,1694180955.302 [DataOverHttps](INFO): Moved sent file to Logs/20230908T132150/Express0005.lzma.bak 2023-09-08T13:49:15.302Z,1694180955.302 [DataOverHttps](INFO): SBD MOMSN=18749882 2023-09-08T13:49:42.547Z,1694180982.547 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20230908T132150/Express0008.lzma 2023-09-08T13:49:43.550Z,1694180983.550 [DataOverHttps](INFO): Moved sent file to Logs/20230908T132150/Express0008.lzma.bak 2023-09-08T13:49:43.550Z,1694180983.550 [DataOverHttps](INFO): SBD MOMSN=18749885 2023-09-08T13:50:09.372Z,1694181009.372 [DataOverHttps](INFO): Sending 1006 bytes from file Logs/20230908T132800/Express0001.lzma 2023-09-08T13:50:10.370Z,1694181010.370 [DataOverHttps](INFO): Moved sent file to Logs/20230908T132800/Express0001.lzma.bak 2023-09-08T13:50:10.370Z,1694181010.370 [DataOverHttps](INFO): SBD MOMSN=18749887 2023-09-08T13:50:31.459Z,1694181031.459 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20230908T132800/Express0005.lzma 2023-09-08T13:50:32.463Z,1694181032.463 [DataOverHttps](INFO): Moved sent file to Logs/20230908T132800/Express0005.lzma.bak 2023-09-08T13:50:32.464Z,1694181032.464 [DataOverHttps](INFO): SBD MOMSN=18749920 2023-09-08T13:50:47.461Z,1694181047.461 [DataOverHttps](IMPORTANT): SBD MTMSN=20230908T135046 2023-09-08T13:50:55.138Z,1694181055.138 [DataOverHttps](INFO): Sending 1036 bytes from file Logs/20230908T133357/Express0001.lzma 2023-09-08T13:50:55.155Z,1694181055.155 [DataOverHttps](INFO): Received command: restart sys 2023-09-08T13:50:55.189Z,1694181055.189 [CommandExec](IMPORTANT): got command restart system 2023-09-08T13:50:56.719Z,1694181056.719 [DataOverHttps](INFO): Moved sent file to Logs/20230908T133357/Express0001.lzma.bak 2023-09-08T13:50:56.719Z,1694181056.719 [DataOverHttps](INFO): SBD MOMSN=18749923 2023-09-08T13:50:57.348Z,1694181057.348 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2023-09-08T13:50:57.348Z,1694181057.348 [CommandExec](INFO): Uninitializing the command executive. 2023-09-08T13:50:57.348Z,1694181057.348 [CommandExec](INFO): Uninitializing the command scheduler. 2023-09-08T13:50:57.349Z,1694181057.349 [CommandExec ThreadHandler](INFO): Thread cancelled. 2023-09-08T13:50:57.480Z,1694181057.480 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2023-09-08T13:50:57.480Z,1694181057.480 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2023-09-08T13:50:57.480Z,1694181057.480 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2023-09-08T13:50:57.481Z,1694181057.481 [NavChartDb](INFO): Join timeout helper Thread ID is 1051 2023-09-08T13:50:57.696Z,1694181057.696 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2023-09-08T13:50:57.696Z,1694181057.696 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2023-09-08T13:50:57.706Z,1694181057.706 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler 2023-09-08T13:50:57.706Z,1694181057.706 [DAT ThreadHandler](INFO): Thread cancelled. 2023-09-08T13:50:57.707Z,1694181057.707 [DAT](INFO): Join timeout helper Thread ID is 1052 2023-09-08T13:50:57.812Z,1694181057.812 [DAT](INFO): Powering down 2023-09-08T13:50:57.884Z,1694181057.884 [DAT ThreadHandler](INFO): Uninitializing protected caller thread. 2023-09-08T13:50:57.885Z,1694181057.885 [DAT](INFO): Powering down 2023-09-08T13:50:57.885Z,1694181057.885 [DAT ThreadHandler](INFO): Thread cancelled. 2023-09-08T13:50:57.896Z,1694181057.896 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2023-09-08T13:50:57.897Z,1694181057.897 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2023-09-08T13:50:57.898Z,1694181057.898 [Radio_Surface](INFO): Join timeout helper Thread ID is 1053 2023-09-08T13:50:57.912Z,1694181057.912 [Radio_Surface](INFO): Powering down 2023-09-08T13:50:57.913Z,1694181057.913 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2023-09-08T13:50:57.913Z,1694181057.913 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2023-09-08T13:50:57.914Z,1694181057.914 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2023-09-08T13:50:57.914Z,1694181057.914 [Onboard ThreadHandler](INFO): Thread cancelled. 2023-09-08T13:50:57.914Z,1694181057.914 [Onboard](INFO): Join timeout helper Thread ID is 1054 2023-09-08T13:50:58.278Z,1694181058.278 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2023-09-08T13:51:00.868Z,1694181060.868 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2023-09-08T13:51:00.868Z,1694181060.868 [Onboard ThreadHandler](INFO): Thread cancelled. 2023-09-08T13:51:00.872Z,1694181060.872 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2023-09-08T13:51:00.872Z,1694181060.872 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2023-09-08T13:51:00.872Z,1694181060.872 [DataOverHttps](INFO): Join timeout helper Thread ID is 1055 2023-09-08T13:51:01.288Z,1694181061.288 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2023-09-08T13:51:01.288Z,1694181061.288 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2023-09-08T13:51:01.312Z,1694181061.312 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler 2023-09-08T13:51:01.312Z,1694181061.312 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2023-09-08T13:51:01.312Z,1694181061.312 [BackseatComponent](INFO): Join timeout helper Thread ID is 1056 2023-09-08T13:51:01.404Z,1694181061.404 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread. 2023-09-08T13:51:01.404Z,1694181061.404 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2023-09-08T13:51:01.409Z,1694181061.409 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler 2023-09-08T13:51:01.409Z,1694181061.409 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2023-09-08T13:51:01.409Z,1694181061.409 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 1057 2023-09-08T13:51:01.500Z,1694181061.500 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread. 2023-09-08T13:51:01.500Z,1694181061.500 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2023-09-08T13:51:01.517Z,1694181061.517 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2023-09-08T13:51:01.517Z,1694181061.517 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2023-09-08T13:51:01.517Z,1694181061.517 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1058 2023-09-08T13:51:01.648Z,1694181061.648 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2023-09-08T13:51:01.649Z,1694181061.649 [WetLabsBB2FL](INFO): Powering down 2023-09-08T13:51:01.649Z,1694181061.649 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2023-09-08T13:51:01.653Z,1694181061.653 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2023-09-08T13:51:01.653Z,1694181061.653 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2023-09-08T13:51:01.653Z,1694181061.653 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1059 2023-09-08T13:51:01.700Z,1694181061.700 [CTD_Seabird](INFO): Powering down 2023-09-08T13:51:01.712Z,1694181061.712 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2023-09-08T13:51:01.712Z,1694181061.712 [CTD_Seabird](INFO): Powering down 2023-09-08T13:51:01.724Z,1694181061.724 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2023-09-08T13:51:01.733Z,1694181061.733 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2023-09-08T13:51:01.733Z,1694181061.733 [logger ThreadHandler](INFO): Thread cancelled. 2023-09-08T13:51:01.733Z,1694181061.733 [logger](INFO): Join timeout helper Thread ID is 1060 2023-09-08T13:51:01.736Z,1694181061.736 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2023-09-08T13:51:01.736Z,1694181061.736 [logger ThreadHandler](INFO): Thread cancelled. 2023-09-08T13:51:01.752Z,1694181061.752 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2023-09-08T13:51:01.753Z,1694181061.753 [CommandLine ThreadHandler](INFO): Thread cancelled. 2023-09-08T13:51:01.753Z,1694181061.753 [CommandLine](INFO): Join timeout helper Thread ID is 1061 2023-09-08T13:51:01.772Z,1694181061.772 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2023-09-08T13:51:01.772Z,1694181061.772 [CommandLine ThreadHandler](INFO): Thread cancelled. 2023-09-08T13:51:01.792Z,1694181061.792 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2023-09-08T13:51:01.793Z,1694181061.793 [CommandExec ThreadHandler](INFO): Thread cancelled. 2023-09-08T13:51:01.793Z,1694181061.793 [CommandExec](INFO): Join timeout helper Thread ID is 1062 2023-09-08T13:51:01.794Z,1694181061.794 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2023-09-08T13:51:01.794Z,1694181061.794 [controlThread ThreadHandler](INFO): Thread cancelled. 2023-09-08T13:51:01.795Z,1694181061.795 [controlThread](INFO): Join timeout helper Thread ID is 1063 2023-09-08T13:51:01.836Z,1694181061.836 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2023-09-08T13:51:01.836Z,1694181061.836 [controlThread](DEBUG): Uninitializing ControlThread 2023-09-08T13:51:01.839Z,1694181061.839 [AHRS_M2](INFO): Powering down 2023-09-08T13:51:02.008Z,1694181062.008 [DVL_micro](INFO): Powering down 2023-09-08T13:51:02.009Z,1694181062.009 [NAL9602](INFO): Powering down 2023-09-08T13:51:02.011Z,1694181062.011 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2023-09-08T13:51:02.011Z,1694181062.011 [ElevatorOffsetCalculator](DEBUG)