2022-09-01T19:07:35.266Z,1662059255.266 [Supervisor](DEBUG): Initializing supervisor.
2022-09-01T19:07:35.270Z,1662059255.270 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2022-09-01T19:07:35.271Z,1662059255.271 [SyncHandler](INFO): Protected caller Thread ID is 1033
2022-09-01T19:07:35.271Z,1662059255.271 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2022-09-01T19:07:35.272Z,1662059255.272 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2022-09-01T19:07:35.273Z,1662059255.273 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1034
2022-09-01T19:07:35.277Z,1662059255.277 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2022-09-01T19:07:35.295Z,1662059255.295 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2022-09-01T19:07:35.296Z,1662059255.296 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2022-09-01T19:07:35.297Z,1662059255.297 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 1035
2022-09-01T19:07:35.301Z,1662059255.301 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2022-09-01T19:07:35.302Z,1662059255.302 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2022-09-01T19:07:35.302Z,1662059255.302 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1036
2022-09-01T19:07:35.305Z,1662059255.305 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2022-09-01T19:07:35.306Z,1662059255.306 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2022-09-01T19:07:35.306Z,1662059255.306 [logger ThreadHandler](INFO): Protected caller Thread ID is 1037
2022-09-01T19:07:35.310Z,1662059255.310 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2022-09-01T19:07:35.310Z,1662059255.310 [Supervisor](INFO): Looking for Config files in directory: Config/
2022-09-01T19:07:35.312Z,1662059255.312 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2022-09-01T19:07:35.724Z,1662059255.724 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2022-09-01T19:07:35.725Z,1662059255.725 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2022-09-01T19:07:35.803Z,1662059255.803 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2022-09-01T19:07:36.124Z,1662059256.124 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2022-09-01T19:07:36.125Z,1662059256.125 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2022-09-01T19:07:36.230Z,1662059256.230 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2022-09-01T19:07:36.231Z,1662059256.231 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2022-09-01T19:07:36.422Z,1662059256.422 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2022-09-01T19:07:36.423Z,1662059256.423 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2022-09-01T19:07:36.890Z,1662059256.890 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2022-09-01T19:07:36.891Z,1662059256.891 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2022-09-01T19:07:37.154Z,1662059257.154 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2022-09-01T19:07:37.155Z,1662059257.155 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2022-09-01T19:07:37.365Z,1662059257.365 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2022-09-01T19:07:37.366Z,1662059257.366 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2022-09-01T19:07:37.553Z,1662059257.553 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2022-09-01T19:07:37.553Z,1662059257.553 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2022-09-01T19:07:37.649Z,1662059257.649 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2022-09-01T19:07:37.650Z,1662059257.650 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2022-09-01T19:07:37.879Z,1662059257.879 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2022-09-01T19:07:37.879Z,1662059257.879 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2022-09-01T19:07:38.244Z,1662059258.244 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2022-09-01T19:07:38.244Z,1662059258.244 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2022-09-01T19:07:38.325Z,1662059258.325 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2022-09-01T19:07:38.462Z,1662059258.462 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2022-09-01T19:07:38.462Z,1662059258.462 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2022-09-01T19:07:39.154Z,1662059259.154 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2022-09-01T19:07:39.154Z,1662059259.154 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2022-09-01T19:07:39.509Z,1662059259.509 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2022-09-01T19:07:39.511Z,1662059259.511 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-polaris/
2022-09-01T19:07:39.511Z,1662059259.511 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/vehicle.cfg
2022-09-01T19:07:39.708Z,1662059259.708 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Control.cfg
2022-09-01T19:07:39.808Z,1662059259.808 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Estimation.cfg
2022-09-01T19:07:39.906Z,1662059259.906 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/BIT.cfg
2022-09-01T19:07:40.005Z,1662059260.005 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Battery.cfg
2022-09-01T19:07:40.359Z,1662059260.359 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2022-09-01T19:07:40.360Z,1662059260.360 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Simulator.cfg
2022-09-01T19:07:40.630Z,1662059260.630 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Navigation.cfg
2022-09-01T19:07:40.916Z,1662059260.916 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Derivation.cfg
2022-09-01T19:07:41.196Z,1662059261.196 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/logger.cfg
2022-09-01T19:07:41.456Z,1662059261.456 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/secure.cfg
2022-09-01T19:07:41.540Z,1662059261.540 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Dock.cfg
2022-09-01T19:07:41.625Z,1662059261.625 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Servo.cfg
2022-09-01T19:07:41.733Z,1662059261.733 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/workSite.cfg
2022-09-01T19:07:41.838Z,1662059261.838 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Sensor.cfg
2022-09-01T19:07:42.034Z,1662059262.034 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Science.cfg
2022-09-01T19:07:42.189Z,1662059262.189 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2022-09-01T19:07:42.203Z,1662059262.203 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2022-09-01T19:07:42.614Z,1662059262.614 [AHRS_M2] Loaded
2022-09-01T19:07:42.614Z,1662059262.614 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2022-09-01T19:07:43.383Z,1662059263.383 [BPC1] Loaded
2022-09-01T19:07:43.383Z,1662059263.383 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2022-09-01T19:07:43.463Z,1662059263.463 [DataOverHttps] Loaded
2022-09-01T19:07:43.463Z,1662059263.463 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2022-09-01T19:07:43.465Z,1662059263.465 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407E44E0
2022-09-01T19:07:43.465Z,1662059263.465 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1131
2022-09-01T19:07:43.489Z,1662059263.489 [DDM] Loaded
2022-09-01T19:07:43.490Z,1662059263.490 [ComponentRegistry](DEBUG): SyncComponent "DDM" handled in the control thread.
2022-09-01T19:07:43.509Z,1662059263.509 [Depth_Keller] Loaded
2022-09-01T19:07:43.510Z,1662059263.510 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2022-09-01T19:07:43.514Z,1662059263.514 [DropWeight] Loaded
2022-09-01T19:07:43.515Z,1662059263.515 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2022-09-01T19:07:43.564Z,1662059263.564 [Micromodem] Loaded
2022-09-01T19:07:43.564Z,1662059263.564 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2022-09-01T19:07:43.625Z,1662059263.625 [NAL9602] Loaded
2022-09-01T19:07:43.626Z,1662059263.626 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2022-09-01T19:07:43.654Z,1662059263.654 [Onboard] Loaded
2022-09-01T19:07:43.654Z,1662059263.654 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2022-09-01T19:07:43.655Z,1662059263.655 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408144E0
2022-09-01T19:07:43.656Z,1662059263.656 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1132
2022-09-01T19:07:43.662Z,1662059263.662 [PowerOnly](INFO): Adding load control power supply at /dev/loadC1
2022-09-01T19:07:43.673Z,1662059263.673 [PowerOnly] Loaded
2022-09-01T19:07:43.673Z,1662059263.673 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2022-09-01T19:07:43.684Z,1662059263.684 [Power24vConverter] Loaded
2022-09-01T19:07:43.685Z,1662059263.685 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2022-09-01T19:07:43.698Z,1662059263.698 [Radio_Surface] Loaded
2022-09-01T19:07:43.699Z,1662059263.699 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2022-09-01T19:07:43.699Z,1662059263.699 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408444E0
2022-09-01T19:07:43.700Z,1662059263.700 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1133
2022-09-01T19:07:43.745Z,1662059263.745 [RDI_Pathfinder] Loaded
2022-09-01T19:07:43.745Z,1662059263.745 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2022-09-01T19:07:43.772Z,1662059263.772 [RDI_PathfinderUp] Loaded
2022-09-01T19:07:43.772Z,1662059263.772 [ComponentRegistry](DEBUG): SyncComponent "RDI_PathfinderUp" handled in the control thread.
2022-09-01T19:07:43.773Z,1662059263.773 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2022-09-01T19:07:43.774Z,1662059263.774 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2022-09-01T19:07:43.784Z,1662059263.784 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2022-09-01T19:07:43.784Z,1662059263.784 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2022-09-01T19:07:43.894Z,1662059263.894 [DeadReckonUsingMultipleVelocitySources] Loaded
2022-09-01T19:07:43.894Z,1662059263.894 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2022-09-01T19:07:43.919Z,1662059263.919 [LBLNavigation] Loaded
2022-09-01T19:07:43.919Z,1662059263.919 [ComponentRegistry](DEBUG): SyncComponent "LBLNavigation" handled in the control thread.
2022-09-01T19:07:43.932Z,1662059263.932 [NavChart] Loaded
2022-09-01T19:07:43.933Z,1662059263.933 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2022-09-01T19:07:43.938Z,1662059263.938 [UniversalFixResidualReporter] Loaded
2022-09-01T19:07:43.939Z,1662059263.939 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2022-09-01T19:07:43.949Z,1662059263.949 [WorkSite] Loaded
2022-09-01T19:07:43.949Z,1662059263.949 [ComponentRegistry](DEBUG): SyncComponent "WorkSite" handled in the control thread.
2022-09-01T19:07:43.950Z,1662059263.950 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2022-09-01T19:07:43.950Z,1662059263.950 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2022-09-01T19:07:44.044Z,1662059264.044 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2022-09-01T19:07:44.045Z,1662059264.045 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2022-09-01T19:07:44.168Z,1662059264.168 [BuoyancyServo] Loaded
2022-09-01T19:07:44.168Z,1662059264.168 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2022-09-01T19:07:44.190Z,1662059264.190 [ElevatorServo] Loaded
2022-09-01T19:07:44.190Z,1662059264.190 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2022-09-01T19:07:44.216Z,1662059264.216 [DockingServo] Loaded
2022-09-01T19:07:44.217Z,1662059264.217 [ComponentRegistry](DEBUG): SyncComponent "DockingServo" handled in the control thread.
2022-09-01T19:07:44.238Z,1662059264.238 [MassServo] Loaded
2022-09-01T19:07:44.238Z,1662059264.238 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2022-09-01T19:07:44.258Z,1662059264.258 [RudderServo] Loaded
2022-09-01T19:07:44.259Z,1662059264.259 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2022-09-01T19:07:44.275Z,1662059264.275 [ThrusterHE] Loaded
2022-09-01T19:07:44.275Z,1662059264.275 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2022-09-01T19:07:44.275Z,1662059264.275 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2022-09-01T19:07:44.276Z,1662059264.276 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2022-09-01T19:07:44.443Z,1662059264.443 [CTD_Seabird] Loaded
2022-09-01T19:07:44.444Z,1662059264.444 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2022-09-01T19:07:44.445Z,1662059264.445 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409824E0
2022-09-01T19:07:44.445Z,1662059264.445 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1134
2022-09-01T19:07:44.478Z,1662059264.478 [WetLabsSeaOWL_UV_A] Loaded
2022-09-01T19:07:44.478Z,1662059264.478 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2022-09-01T19:07:44.479Z,1662059264.479 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409B24E0
2022-09-01T19:07:44.479Z,1662059264.479 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 1135
2022-09-01T19:07:44.480Z,1662059264.480 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2022-09-01T19:07:44.481Z,1662059264.481 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2022-09-01T19:07:44.782Z,1662059264.782 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2022-09-01T19:07:44.783Z,1662059264.783 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2022-09-01T19:07:44.835Z,1662059264.835 [DepthRateCalculator] Loaded
2022-09-01T19:07:44.835Z,1662059264.835 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2022-09-01T19:07:44.840Z,1662059264.840 [PitchRateCalculator] Loaded
2022-09-01T19:07:44.841Z,1662059264.841 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2022-09-01T19:07:44.850Z,1662059264.850 [SpeedCalculator] Loaded
2022-09-01T19:07:44.850Z,1662059264.850 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2022-09-01T19:07:44.863Z,1662059264.863 [TempGradientCalculator] Loaded
2022-09-01T19:07:44.863Z,1662059264.863 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2022-09-01T19:07:44.878Z,1662059264.878 [VerticalHomogeneityIndexCalculator] Loaded
2022-09-01T19:07:44.879Z,1662059264.879 [ComponentRegistry](DEBUG): SyncComponent "VerticalHomogeneityIndexCalculator" handled in the control thread.
2022-09-01T19:07:44.883Z,1662059264.883 [YawRateCalculator] Loaded
2022-09-01T19:07:44.884Z,1662059264.884 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2022-09-01T19:07:44.907Z,1662059264.907 [ElevatorOffsetCalculator] Loaded
2022-09-01T19:07:44.907Z,1662059264.907 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2022-09-01T19:07:44.907Z,1662059264.907 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2022-09-01T19:07:44.908Z,1662059264.908 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2022-09-01T19:07:45.047Z,1662059265.047 [SBIT](DEBUG): Construct Startup Built In Test.
2022-09-01T19:07:45.060Z,1662059265.060 [SBIT] Loaded
2022-09-01T19:07:45.060Z,1662059265.060 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2022-09-01T19:07:45.063Z,1662059265.063 [IBIT](DEBUG): Construct Initiated Built In Test.
2022-09-01T19:07:45.076Z,1662059265.076 [IBIT] Loaded
2022-09-01T19:07:45.076Z,1662059265.076 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2022-09-01T19:07:45.082Z,1662059265.082 [CBIT](DEBUG): Construct Continuous Built In Test.
2022-09-01T19:07:45.189Z,1662059265.189 [CBIT] Loaded
2022-09-01T19:07:45.190Z,1662059265.190 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2022-09-01T19:07:45.190Z,1662059265.190 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2022-09-01T19:07:45.191Z,1662059265.191 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2022-09-01T19:07:45.245Z,1662059265.245 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2022-09-01T19:07:45.246Z,1662059265.246 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2022-09-01T19:07:45.397Z,1662059265.397 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2022-09-01T19:07:45.398Z,1662059265.398 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2022-09-01T19:07:45.669Z,1662059265.669 [VerticalControl](DEBUG): Construct VerticalControl.
2022-09-01T19:07:45.719Z,1662059265.719 [VerticalControl] Loaded
2022-09-01T19:07:45.720Z,1662059265.720 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2022-09-01T19:07:45.723Z,1662059265.723 [HorizontalControl](DEBUG): Construct HorizontalControl.
2022-09-01T19:07:45.761Z,1662059265.761 [HorizontalControl] Loaded
2022-09-01T19:07:45.761Z,1662059265.761 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2022-09-01T19:07:45.763Z,1662059265.763 [SpeedControl](DEBUG): Construct SpeedControl.
2022-09-01T19:07:45.765Z,1662059265.765 [SpeedControl] Loaded
2022-09-01T19:07:45.766Z,1662059265.766 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2022-09-01T19:07:45.768Z,1662059265.768 [LoopControl](DEBUG): Construct LoopControl.
2022-09-01T19:07:45.769Z,1662059265.769 [LoopControl] Loaded
2022-09-01T19:07:45.769Z,1662059265.769 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2022-09-01T19:07:45.770Z,1662059265.770 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2022-09-01T19:07:45.770Z,1662059265.770 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2022-09-01T19:07:45.797Z,1662059265.797 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2022-09-01T19:07:45.804Z,1662059265.804 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2022-09-01T19:07:45.807Z,1662059265.807 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2022-09-01T19:07:45.818Z,1662059265.818 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2022-09-01T19:07:45.819Z,1662059265.819 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B6E4E0
2022-09-01T19:07:45.820Z,1662059265.820 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1136
2022-09-01T19:07:45.824Z,1662059265.824 [Supervisor](INFO): Main Thread ID is 829
2022-09-01T19:07:45.824Z,1662059265.824 [Supervisor](DEBUG): Running supervisor.
2022-09-01T19:07:45.825Z,1662059265.825 [CommandExec ThreadHandler](INFO): Handler Thread ID is 1137
2022-09-01T19:07:45.826Z,1662059265.826 [CommandExec](INFO): Initializing the command executive.
2022-09-01T19:07:45.827Z,1662059265.827 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1138
2022-09-01T19:07:45.829Z,1662059265.829 [controlThread ThreadHandler](INFO): Handler Thread ID is 1139
2022-09-01T19:07:45.830Z,1662059265.830 [controlThread](DEBUG): Initializing ControlThread
2022-09-01T19:07:45.835Z,1662059265.835 [NavChart](DEBUG): Initialize NavChart Navigation.
2022-09-01T19:07:45.835Z,1662059265.835 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2022-09-01T19:07:45.836Z,1662059265.836 [WorkSite](DEBUG): Initializing WorkSite component.
2022-09-01T19:07:45.837Z,1662059265.837 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2022-09-01T19:07:45.838Z,1662059265.838 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2022-09-01T19:07:45.838Z,1662059265.838 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2022-09-01T19:07:45.838Z,1662059265.838 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2022-09-01T19:07:45.839Z,1662059265.839 [VerticalHomogeneityIndexCalculator](DEBUG): (re)initializing
2022-09-01T19:07:45.839Z,1662059265.839 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2022-09-01T19:07:45.840Z,1662059265.840 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2022-09-01T19:07:45.841Z,1662059265.841 [SBIT](INFO): Initialize SBIT Component.
2022-09-01T19:07:45.841Z,1662059265.841 [SBIT](IMPORTANT): git: 2022-08-25
2022-09-01T19:07:45.841Z,1662059265.841 [SBIT](INFO): git hash: e1ddd60859d931066d70c4e9618f9367e52a6cfe
2022-09-01T19:07:45.842Z,1662059265.842 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2022-09-01T19:07:45.843Z,1662059265.843 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Thu Aug 6 12:04:53 PDT 2020
2022-09-01T19:07:45.844Z,1662059265.844 [SBIT](INFO): Beginning SBIT in 55.000000 seconds.
2022-09-01T19:07:45.845Z,1662059265.845 [IBIT](INFO): Initialize IBIT Component.
2022-09-01T19:07:45.845Z,1662059265.845 [CBIT](DEBUG): Initialize CBIT Component.
2022-09-01T19:07:45.846Z,1662059265.846 [logger ThreadHandler](INFO): Handler Thread ID is 1140
2022-09-01T19:07:45.860Z,1662059265.860 [CBIT](DEBUG): Initialized mux pins.
2022-09-01T19:07:45.860Z,1662059265.860 [CBIT](DEBUG): Initializing the watchdog timer.
2022-09-01T19:07:45.864Z,1662059265.864 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1141
2022-09-01T19:07:45.865Z,1662059265.865 [DataOverHttps](DEBUG): dashIP=128.128.181.226 starts with a digit so assuming it is a numeric IP
2022-09-01T19:07:45.872Z,1662059265.872 [Onboard ThreadHandler](INFO): Handler Thread ID is 1142
2022-09-01T19:07:45.885Z,1662059265.885 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2022-09-01T19:07:45.885Z,1662059265.885 [CBIT](DEBUG): Initializing heartbeat.
2022-09-01T19:07:45.936Z,1662059265.936 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1143
2022-09-01T19:07:45.941Z,1662059265.941 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1144
2022-09-01T19:07:45.941Z,1662059265.941 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 1145
2022-09-01T19:07:45.942Z,1662059265.942 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1146
2022-09-01T19:07:45.945Z,1662059265.945 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2022-09-01T19:07:45.945Z,1662059265.945 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2022-09-01T19:07:45.945Z,1662059265.945 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2022-09-01T19:07:45.946Z,1662059265.946 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2022-09-01T19:07:45.946Z,1662059265.946 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2022-09-01T19:07:45.946Z,1662059265.946 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2022-09-01T19:07:45.946Z,1662059265.946 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2022-09-01T19:07:45.946Z,1662059265.946 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2022-09-01T19:07:45.956Z,1662059265.956 [CBIT](DEBUG): Deactivating GF circuits.
2022-09-01T19:07:45.956Z,1662059265.956 [CBIT](DEBUG): Deactivating emergency mode.
2022-09-01T19:07:45.957Z,1662059265.957 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2022-09-01T19:07:45.992Z,1662059265.992 [CBIT](DEBUG): Backplane powered.
2022-09-01T19:07:45.992Z,1662059265.992 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2022-09-01T19:07:45.994Z,1662059265.994 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2022-09-01T19:07:45.994Z,1662059265.994 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2022-09-01T19:07:45.995Z,1662059265.995 [LoopControl](DEBUG): Initialize LoopControlComponent.
2022-09-01T19:07:45.996Z,1662059265.996 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2022-09-01T19:07:46.009Z,1662059266.009 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2022-09-01T19:07:46.044Z,1662059266.044 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2022-09-01T19:07:46.045Z,1662059266.045 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2022-09-01T19:07:46.119Z,1662059266.119 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2022-09-01T19:07:46.133Z,1662059266.133 [Default:A.Wait](DEBUG): Construct Wait.
2022-09-01T19:07:46.135Z,1662059266.135 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2022-09-01T19:07:46.175Z,1662059266.175 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2022-09-01T19:07:46.177Z,1662059266.177 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2022-09-01T19:07:46.195Z,1662059266.195 [Default:E.Execute](DEBUG): Construct Execute.
2022-09-01T19:07:46.198Z,1662059266.198 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn on</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2022-09-01T19:07:46.213Z,1662059266.213 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,DDM,Depth_Keller,DropWeight,Micromodem,NAL9602,PowerOnly,Power24vConverter,RDI_Pathfinder,RDI_PathfinderUp,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,WorkSite,LBLNavigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,DockingServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2022-09-01T19:07:46.228Z,1662059266.228 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2022-09-01T19:07:46.296Z,1662059266.296 [DDM](INFO): Powering up
2022-09-01T19:07:46.297Z,1662059266.297 [DDM](DEBUG): Initializing DDM.
2022-09-01T19:07:46.319Z,1662059266.319 [Power24vConverter](INFO): Powering up.
2022-09-01T19:07:46.320Z,1662059266.320 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format
2022-09-01T19:07:46.340Z,1662059266.340 [Radio_Surface](INFO): Powering up
2022-09-01T19:07:46.377Z,1662059266.377 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2022-09-01T19:07:46.385Z,1662059266.385 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2022-09-01T19:07:46.386Z,1662059266.386 [ElevatorServo](DEBUG): Initializing EZServoServo.
2022-09-01T19:07:46.392Z,1662059266.392 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2022-09-01T19:07:46.393Z,1662059266.393 [DockingServo](DEBUG): Initializing DockingServo.
2022-09-01T19:07:46.394Z,1662059266.394 [MassServo](DEBUG): Initializing EZServoServo.
2022-09-01T19:07:46.400Z,1662059266.400 [MassServo](DEBUG): Initializing MassServo.
2022-09-01T19:07:46.401Z,1662059266.401 [RudderServo](DEBUG): Initializing EZServoServo.
2022-09-01T19:07:46.408Z,1662059266.408 [RudderServo](DEBUG): Initializing RudderServo.
2022-09-01T19:07:46.409Z,1662059266.409 [ThrusterHE](DEBUG): Initializing EZServoServo.
2022-09-01T19:07:46.416Z,1662059266.416 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2022-09-01T19:07:46.666Z,1662059266.666 [Micromodem](INFO): Powering up
2022-09-01T19:07:46.666Z,1662059266.666 [Micromodem](DEBUG): Initializing Micromodem.
2022-09-01T19:07:47.356Z,1662059267.356 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2022-09-01T19:07:47.356Z,1662059267.356 [RudderServo](FAULT): Rudder failed to initialize
2022-09-01T19:07:47.356Z,1662059267.356 [RudderServo] Communications Fault, FailCount= 1
2022-09-01T19:07:47.356Z,1662059267.356 [RudderServo](ERROR): Communications Fault
2022-09-01T19:07:47.360Z,1662059267.360 [CBIT](ERROR): Communications Fault in component: RudderServo
2022-09-01T19:07:47.571Z,1662059267.571 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-09-01T19:07:47.571Z,1662059267.571 [RudderServo](INFO): Powering down
2022-09-01T19:07:48.252Z,1662059268.251 [RudderServo](DEBUG): Initializing EZServoServo.
2022-09-01T19:07:48.373Z,1662059268.373 [RudderServo](DEBUG): Initializing RudderServo.
2022-09-01T19:07:48.377Z,1662059268.377 [CBIT](INFO): Clearing failed state for component RudderServo
2022-09-01T19:07:48.377Z,1662059268.377 [RudderServo] No Fault, FailCount= 1
2022-09-01T19:07:50.298Z,1662059270.298 [Micromodem](INFO): Nmea in: $CATMG,2022-09-01T19:07:50.098453Z,RTC,RTC*53

2022-09-01T19:07:51.514Z,1662059271.514 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2022-09-01T19:07:51.922Z,1662059271.922 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31

2022-09-01T19:07:51.922Z,1662059271.922 [Micromodem](INFO): Nmea out: $CCCFG,POW,20*08

2022-09-01T19:07:52.244Z,1662059272.244 [ThrusterHE](ERROR): Zero Speed Commanded.
2022-09-01T19:07:52.358Z,1662059272.358 [Micromodem](INFO): Nmea in: $CACFG,POW,20*0A

2022-09-01T19:07:52.358Z,1662059272.358 [Micromodem](INFO): Nmea out: $CCCFG,SRC,0*30

2022-09-01T19:07:52.758Z,1662059272.758 [Micromodem](INFO): Nmea in: $CACFG,SRC,0*32

2022-09-01T19:07:52.758Z,1662059272.758 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64

2022-09-01T19:07:53.162Z,1662059273.162 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66

2022-09-01T19:07:53.162Z,1662059273.162 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F

2022-09-01T19:07:53.570Z,1662059273.570 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D

2022-09-01T19:07:53.570Z,1662059273.570 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E

2022-09-01T19:07:53.977Z,1662059273.977 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2022-09-01T19:07:53.980Z,1662059273.980 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C

2022-09-01T19:07:53.980Z,1662059273.980 [Micromodem](INFO): Nmea out: $CCCFG,FC0,14500*47

2022-09-01T19:07:54.374Z,1662059274.374 [Micromodem](INFO): Nmea in: $CACFG,FC0,14500*45

2022-09-01T19:07:54.375Z,1662059274.375 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63

2022-09-01T19:07:54.770Z,1662059274.770 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61

2022-09-01T19:07:54.770Z,1662059274.770 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A

2022-09-01T19:07:55.162Z,1662059275.162 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38

2022-09-01T19:07:55.163Z,1662059275.163 [Micromodem](INFO): Nmea out: $CCCLK,2022,09,01,19,07,56*42

2022-09-01T19:07:55.557Z,1662059275.557 [Micromodem](INFO): Nmea in: $CACLK,2022,9,1,19,7,56*70

2022-09-01T19:07:55.560Z,1662059275.560 [Micromodem](INFO): Nmea in: $CATMS,0,2022-09-01T19:07:57Z*71

2022-09-01T19:07:55.562Z,1662059275.562 [Micromodem](INFO): Nmea in: $CATMG,2022-09-01T19:07:57.028776Z,USER_CMD,RTC*1A

2022-09-01T19:08:02.013Z,1662059282.013 [DDM](INFO): Latch/Whisker Boards:V1,H_RECOVERY_LATCH
!V2,H_RECOVERY_WHISKERS
2022-09-01T19:08:02.112Z,1662059282.112 [DDM](INFO): Dynamic Docking Module:C REMUS Capture Rev 1.1
2022-09-01T19:08:13.734Z,1662059293.734 [NAL9602](INFO): Powering up NAL9602
2022-09-01T19:08:24.646Z,1662059304.646 [NAL9602](INFO): NAL9602 initialized
2022-09-01T19:08:40.404Z,1662059320.404 [NAL9602](INFO): SBD MO Status=0, MOMSN=44784, MT Status=0, MTMSN=0
2022-09-01T19:08:40.404Z,1662059320.404 [NAL9602](INFO): No messages in MT queue
2022-09-01T19:08:41.251Z,1662059321.251 [SBIT](IMPORTANT): Beginning Startup BIT
2022-09-01T19:08:41.256Z,1662059321.256 [CBIT](IMPORTANT): Beginning ground fault scan
2022-09-01T19:08:52.218Z,1662059332.218 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.008200
CHAN A1 (24V): -0.003139
CHAN A2 (12V): 0.002635
CHAN A3 (5V): 0.000164
CHAN B0 (3.3V): 0.001103
CHAN B1 (3.15aV): 0.000873
CHAN B2 (3.15bV): 0.000945
CHAN B3 (GND): -0.000486
OPEN: 0.005479
Full Scale: +/- 1 mA
2022-09-01T19:08:56.160Z,1662059336.160 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190902.00,A,4030.07259,N,07054.99802,W,1.244,0.00,010922,,,A*76
2022-09-01T19:08:56.163Z,1662059336.163 [NAL9602](INFO): GPS fix at 20220901T190902: (40.501210, -70.916634)
2022-09-01T19:08:56.192Z,1662059336.192 [LBLNavigation](INFO): Reset ping filters
2022-09-01T19:08:56.193Z,1662059336.193 [LBLNavigation](INFO): Reset fix filter
2022-09-01T19:09:28.534Z,1662059368.534 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-01T19:09:35.364Z,1662059375.364 [SBIT](IMPORTANT): SBIT PASSED
2022-09-01T19:09:35.364Z,1662059375.364 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2022-09-01T19:09:35.365Z,1662059375.365 [SBIT](IMPORTANT): CBIT.abortDepth=250 meter;

2022-09-01T19:09:35.365Z,1662059375.365 [SBIT](IMPORTANT): CBIT.gfScanTimeout=2 hour;

2022-09-01T19:09:35.365Z,1662059375.365 [SBIT](IMPORTANT): CBIT.stopDepth=200 meter;

2022-09-01T19:09:35.365Z,1662059375.365 [SBIT](IMPORTANT): DDM.loadAtStartup=1 bool;

2022-09-01T19:09:35.366Z,1662059375.366 [SBIT](IMPORTANT): DockingServo.loadAtStartup=1 bool;

2022-09-01T19:09:35.366Z,1662059375.366 [SBIT](IMPORTANT): Express linearApproximation CTD_Seabird.bin_median_sea_water_salinity 0.050000 practical_salinity_unit;

2022-09-01T19:09:35.366Z,1662059375.366 [SBIT](IMPORTANT): Express linearApproximation CTD_Seabird.bin_median_sea_water_temperature 0.500000 celsius;

2022-09-01T19:09:35.366Z,1662059375.366 [SBIT](IMPORTANT): LineCapture.armSpeed=1.2 meter_per_second;

2022-09-01T19:09:35.366Z,1662059375.366 [SBIT](IMPORTANT): LineCapture.midcourseSpeed=1.2 meter_per_second;

2022-09-01T19:09:35.366Z,1662059375.366 [SBIT](IMPORTANT): LineCapture.rolloutTimeout=6 minute;

2022-09-01T19:09:35.366Z,1662059375.366 [SBIT](IMPORTANT): LineCapture.shortFinalRange=-1 meter;

2022-09-01T19:09:35.366Z,1662059375.366 [SBIT](IMPORTANT): LineCapture.terminalRange=300 meter;

2022-09-01T19:09:35.367Z,1662059375.367 [SBIT](IMPORTANT): LineCapture.verbose=1 bool;

2022-09-01T19:09:35.367Z,1662059375.367 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=152.268921 cubic_centimeter;

2022-09-01T19:09:35.367Z,1662059375.367 [SBIT](IMPORTANT): VerticalControl.massDefault=8.973020 millimeter;

2022-09-01T19:09:35.760Z,1662059375.760 [WorkSite](INFO): Already have valid position. Ignoring workSite position from Data/workSite.cfg
2022-09-01T19:09:35.777Z,1662059375.777 [MissionManager](IMPORTANT): Started mission Startup
2022-09-01T19:09:35.777Z,1662059375.777 [Startup] Running Loop=1
2022-09-01T19:09:35.777Z,1662059375.777 [Startup](DEBUG): Aggregate::initialize Startup
2022-09-01T19:09:35.777Z,1662059375.777 [Startup:A.GoToSurface] Running Loop=1
2022-09-01T19:09:35.777Z,1662059375.777 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-09-01T19:09:35.778Z,1662059375.778 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-09-01T19:09:35.778Z,1662059375.778 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-09-01T19:09:35.778Z,1662059375.778 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-09-01T19:09:35.779Z,1662059375.779 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-09-01T19:09:35.779Z,1662059375.779 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-09-01T19:09:35.785Z,1662059375.785 [Startup:StartupSatComms] Running Loop=1
2022-09-01T19:09:35.785Z,1662059375.785 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2022-09-01T19:09:35.785Z,1662059375.785 [Startup:StartupSatComms:A] Running Loop=1
2022-09-01T19:09:36.179Z,1662059376.179 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2022-09-01T19:09:37.776Z,1662059377.776 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190943.00,A,4030.05974,N,07055.00694,W,1.108,208.13,010922,,,A*76
2022-09-01T19:09:37.778Z,1662059377.778 [NAL9602](INFO): GPS fix at 20220901T190943: (40.500996, -70.916782)
2022-09-01T19:09:37.790Z,1662059377.790 [Startup:StartupSatComms:A] Stopped
2022-09-01T19:09:37.790Z,1662059377.790 [Startup:StartupSatComms:B] Running Loop=1
2022-09-01T19:09:38.241Z,1662059378.241 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-09-01T19:10:09.546Z,1662059409.546 [NAL9602](INFO): SBD MO Status=2, MOMSN=44785, MT Status=2, MTMSN=0
2022-09-01T19:10:09.546Z,1662059409.546 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-01T19:10:26.078Z,1662059426.078 [NAL9602](INFO): SBD MO Status=1, MOMSN=44785, MT Status=0, MTMSN=0
2022-09-01T19:10:26.152Z,1662059426.152 [NAL9602](INFO): Sent 52 bytes from file Logs/20220901T182530/Courier0022.lzma
2022-09-01T19:10:26.152Z,1662059426.152 [NAL9602](INFO): Packets left to send: 0
2022-09-01T19:10:38.058Z,1662059438.058 [Startup:StartupSatComms:B](INFO): Timed out from 2022-09-01T19:09:37.8Z
2022-09-01T19:10:38.058Z,1662059438.058 [Startup:StartupSatComms:B] Stopped
2022-09-01T19:10:38.058Z,1662059438.058 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2022-09-01T19:10:38.058Z,1662059438.058 [Startup:StartupSatComms] Stopped
2022-09-01T19:10:38.058Z,1662059438.058 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2022-09-01T19:10:38.059Z,1662059438.059 [Startup](INFO): Completed Startup
2022-09-01T19:10:38.059Z,1662059438.059 [MissionManager](INFO): Startup is completed.
2022-09-01T19:10:38.059Z,1662059438.059 [MissionManager](INFO): Uninitializing Mission Startup
2022-09-01T19:10:38.059Z,1662059438.059 [Startup] Stopped
2022-09-01T19:10:38.059Z,1662059438.059 [Startup](DEBUG): Aggregate::uninitialize Startup
2022-09-01T19:10:38.059Z,1662059438.059 [Startup:A.GoToSurface] Stopped
2022-09-01T19:10:38.059Z,1662059438.059 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-09-01T19:10:38.500Z,1662059438.500 [MissionManager](IMPORTANT): Started mission Default
2022-09-01T19:10:38.501Z,1662059438.501 [Default] Running Loop=1
2022-09-01T19:10:38.501Z,1662059438.501 [Default](DEBUG): Aggregate::initialize Default
2022-09-01T19:10:38.501Z,1662059438.501 [Default:B.GoToSurface] Running Loop=1
2022-09-01T19:10:38.501Z,1662059438.501 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-09-01T19:10:38.502Z,1662059438.502 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-09-01T19:10:38.503Z,1662059438.503 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-09-01T19:10:38.508Z,1662059438.508 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-09-01T19:10:38.510Z,1662059438.510 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-09-01T19:10:38.510Z,1662059438.510 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-09-01T19:10:38.511Z,1662059438.511 [Default:A.Wait] Running Loop=1
2022-09-01T19:10:38.511Z,1662059438.511 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-09-01T19:10:43.753Z,1662059443.753 [NAL9602](INFO): SBD MO Status=2, MOMSN=44786, MT Status=2, MTMSN=0
2022-09-01T19:10:43.754Z,1662059443.754 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-01T19:10:51.782Z,1662059451.782 [Default:A.Wait](INFO): Done Waiting.
2022-09-01T19:10:51.782Z,1662059451.782 [Default:A.Wait] Stopped
2022-09-01T19:10:51.783Z,1662059451.783 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-09-01T19:10:52.187Z,1662059452.187 [Default:CheckIn] Running Loop=1
2022-09-01T19:10:52.187Z,1662059452.187 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-01T19:10:52.188Z,1662059452.188 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-01T19:10:52.678Z,1662059452.678 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2022-09-01T19:10:54.192Z,1662059454.192 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191100.00,A,4030.05129,N,07055.02095,W,0.797,235.92,010922,,,A*7B
2022-09-01T19:10:54.194Z,1662059454.194 [NAL9602](INFO): GPS fix at 20220901T191100: (40.500855, -70.917016)
2022-09-01T19:10:54.230Z,1662059454.230 [Default:CheckIn:Read_GPS] Stopped
2022-09-01T19:10:54.230Z,1662059454.230 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-01T19:10:54.702Z,1662059454.702 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-09-01T19:11:19.487Z,1662059479.487 [NAL9602](INFO): SBD MO Status=1, MOMSN=44786, MT Status=0, MTMSN=0
2022-09-01T19:11:19.540Z,1662059479.540 [NAL9602](INFO): Sent 184 bytes from file Logs/20220901T190735/Courier0000.lzma
2022-09-01T19:11:19.540Z,1662059479.540 [NAL9602](INFO): Packets left to send: 1
2022-09-01T19:11:24.982Z,1662059484.982 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file).
2022-09-01T19:11:29.822Z,1662059489.822 [NAL9602](INFO): SBD MO Status=1, MOMSN=44787, MT Status=0, MTMSN=0
2022-09-01T19:11:29.884Z,1662059489.884 [NAL9602](INFO): Sent 66 bytes from file Logs/20220901T190735/Courier0000.lzma
2022-09-01T19:11:29.884Z,1662059489.884 [NAL9602](INFO): Packets left to send: 0
2022-09-01T19:11:36.542Z,1662059496.542 [NAL9602](INFO): SBD MO Status=1, MOMSN=44788, MT Status=0, MTMSN=0
2022-09-01T19:11:36.593Z,1662059496.593 [NAL9602](INFO): Sent 71 bytes from file Logs/20220901T190735/Courier0004.lzma
2022-09-01T19:11:36.593Z,1662059496.593 [NAL9602](INFO): Packets left to send: 0
2022-09-01T19:11:58.143Z,1662059518.143 [NAL9602](INFO): SBD MO Status=2, MOMSN=44789, MT Status=2, MTMSN=0
2022-09-01T19:11:58.143Z,1662059518.143 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-01T19:12:32.536Z,1662059552.536 [NAL9602](INFO): SBD MO Status=1, MOMSN=44789, MT Status=0, MTMSN=0
2022-09-01T19:12:32.585Z,1662059552.585 [NAL9602](INFO): Sent 163 bytes from file Logs/20220901T182530/Express0023.lzma
2022-09-01T19:12:32.585Z,1662059552.585 [NAL9602](INFO): Packets left to send: 0
2022-09-01T19:12:51.703Z,1662059571.703 [NAL9602](INFO): SBD MO Status=1, MOMSN=44790, MT Status=0, MTMSN=0
2022-09-01T19:12:51.760Z,1662059571.760 [NAL9602](INFO): Sent 184 bytes from file Logs/20220901T190735/Express0001.lzma
2022-09-01T19:12:51.760Z,1662059571.760 [NAL9602](INFO): Packets left to send: 5
2022-09-01T19:13:01.403Z,1662059581.403 [NAL9602](INFO): SBD MO Status=1, MOMSN=44791, MT Status=0, MTMSN=0
2022-09-01T19:13:01.464Z,1662059581.464 [NAL9602](INFO): Sent 184 bytes from file Logs/20220901T190735/Express0001.lzma
2022-09-01T19:13:01.464Z,1662059581.464 [NAL9602](INFO): Packets left to send: 4
2022-09-01T19:13:19.463Z,1662059599.463 [NAL9602](INFO): SBD MO Status=1, MOMSN=44792, MT Status=0, MTMSN=0
2022-09-01T19:13:19.516Z,1662059599.516 [NAL9602](INFO): Sent 184 bytes from file Logs/20220901T190735/Express0001.lzma
2022-09-01T19:13:19.516Z,1662059599.516 [NAL9602](INFO): Packets left to send: 3
2022-09-01T19:13:27.209Z,1662059607.209 [NAL9602](INFO): SBD MO Status=1, MOMSN=44793, MT Status=0, MTMSN=0
2022-09-01T19:13:27.261Z,1662059607.261 [NAL9602](INFO): Sent 184 bytes from file Logs/20220901T190735/Express0001.lzma
2022-09-01T19:13:27.262Z,1662059607.262 [NAL9602](INFO): Packets left to send: 2
2022-09-01T19:13:36.943Z,1662059616.943 [NAL9602](INFO): SBD MO Status=1, MOMSN=44794, MT Status=0, MTMSN=0
2022-09-01T19:13:37.003Z,1662059617.003 [NAL9602](INFO): Sent 184 bytes from file Logs/20220901T190735/Express0001.lzma
2022-09-01T19:13:37.010Z,1662059617.010 [NAL9602](INFO): Packets left to send: 1
2022-09-01T19:13:47.487Z,1662059627.487 [NAL9602](INFO): SBD MO Status=1, MOMSN=44795, MT Status=0, MTMSN=0
2022-09-01T19:13:47.540Z,1662059627.540 [NAL9602](INFO): Sent 127 bytes from file Logs/20220901T190735/Express0001.lzma
2022-09-01T19:13:47.540Z,1662059627.540 [NAL9602](INFO): Packets left to send: 0
2022-09-01T19:13:57.715Z,1662059637.715 [NAL9602](INFO): SBD MO Status=1, MOMSN=44796, MT Status=0, MTMSN=0
2022-09-01T19:13:57.772Z,1662059637.772 [NAL9602](INFO): Sent 94 bytes from file Logs/20220901T190735/Express0005.lzma
2022-09-01T19:13:57.772Z,1662059637.772 [NAL9602](INFO): Packets left to send: 0
2022-09-01T19:14:18.708Z,1662059658.708 [NAL9602](INFO): SBD MO Status=0, MOMSN=44797, MT Status=0, MTMSN=0
2022-09-01T19:14:18.816Z,1662059658.816 [Default:CheckIn:Read_Iridium] Stopped
2022-09-01T19:14:18.816Z,1662059658.816 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-01T19:14:18.816Z,1662059658.816 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-01T19:14:49.410Z,1662059689.410 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-01T19:15:12.843Z,1662059712.843 [BPC1](ERROR): Battery stick #62 (s/n: 0138) reported TERMINATE_CHARGE_ALARM. Status code: 0x40C0.
2022-09-01T19:15:12.843Z,1662059712.843 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6.
2022-09-01T19:15:12.846Z,1662059712.846 [BPC1](INFO): Received data from all battery sticks.
2022-09-01T19:19:16.876Z,1662059956.876 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range.
2022-09-01T19:19:19.292Z,1662059959.292 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-01T19:19:19.293Z,1662059959.293 [Default:CheckIn:C.Wait] Stopped
2022-09-01T19:19:19.293Z,1662059959.293 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-01T19:19:19.293Z,1662059959.293 [Default:CheckIn:D] Running Loop=1
2022-09-01T19:19:19.736Z,1662059959.736 [Default:CheckIn:D] Stopped
2022-09-01T19:19:19.736Z,1662059959.736 [Default:CheckIn:E] Running Loop=1
2022-09-01T19:19:20.098Z,1662059960.098 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 8.687251 min 
2022-09-01T19:19:20.098Z,1662059960.098 [Default:CheckIn:E] Stopped
2022-09-01T19:19:20.098Z,1662059960.098 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-01T19:19:20.098Z,1662059960.098 [Default:CheckIn] Stopped
2022-09-01T19:19:20.098Z,1662059960.098 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-01T19:19:20.098Z,1662059960.098 [Default:CheckIn](INFO): Running loop #2
2022-09-01T19:19:20.098Z,1662059960.098 [Default:CheckIn] Running Loop=2
2022-09-01T19:19:20.098Z,1662059960.098 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-01T19:19:20.099Z,1662059960.099 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-01T19:19:22.126Z,1662059962.126 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191928.00,A,4029.97741,N,07055.10143,W,0.816,201.05,010922,,,A*74
2022-09-01T19:19:22.128Z,1662059962.128 [NAL9602](INFO): GPS fix at 20220901T191928: (40.499623, -70.918357)
2022-09-01T19:19:22.149Z,1662059962.149 [Default:CheckIn:Read_GPS] Stopped
2022-09-01T19:19:22.149Z,1662059962.149 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-01T19:19:39.206Z,1662059979.206 [NAL9602](INFO): SBD MO Status=1, MOMSN=44798, MT Status=0, MTMSN=0
2022-09-01T19:19:39.256Z,1662059979.256 [NAL9602](INFO): Sent 184 bytes from file Logs/20220901T190735/Courier0007.lzma
2022-09-01T19:19:39.256Z,1662059979.256 [NAL9602](INFO): Packets left to send: 1
2022-09-01T19:19:47.132Z,1662059987.132 [NAL9602](INFO): SBD MO Status=1, MOMSN=44799, MT Status=0, MTMSN=0
2022-09-01T19:19:47.188Z,1662059987.188 [NAL9602](INFO): Sent 19 bytes from file Logs/20220901T190735/Courier0007.lzma
2022-09-01T19:19:47.188Z,1662059987.188 [NAL9602](INFO): Packets left to send: 0
2022-09-01T19:19:56.603Z,1662059996.603 [NAL9602](INFO): SBD MO Status=1, MOMSN=44800, MT Status=0, MTMSN=0
2022-09-01T19:19:56.652Z,1662059996.652 [NAL9602](INFO): Sent 149 bytes from file Logs/20220901T190735/Express0008.lzma
2022-09-01T19:19:56.652Z,1662059996.652 [NAL9602](INFO): Packets left to send: 0
2022-09-01T19:20:04.927Z,1662060004.927 [NAL9602](INFO): SBD MO Status=0, MOMSN=44801, MT Status=0, MTMSN=0
2022-09-01T19:20:05.024Z,1662060005.024 [Default:CheckIn:Read_Iridium] Stopped
2022-09-01T19:20:05.024Z,1662060005.024 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-01T19:20:05.024Z,1662060005.024 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-01T19:20:35.648Z,1662060035.648 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-01T19:21:45.132Z,1662060105.132 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-09-01T19:21:45.524Z,1662060105.524 [Micromodem](INFO): Nmea in: $CACST,6,1,20220901192146.170716,06,765,22,0106,0150,149,01,01,01,01,-1,-01,-01,1,3,3,0,150,23.3,0.05,-100,2.95,-01,-1.42,58,14500,4000*64

2022-09-01T19:22:46.938Z,1662060166.938 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2022-09-01T19:25:05.522Z,1662060305.522 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-01T19:25:05.522Z,1662060305.522 [Default:CheckIn:C.Wait] Stopped
2022-09-01T19:25:05.522Z,1662060305.522 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-01T19:25:05.523Z,1662060305.523 [Default:CheckIn:D] Running Loop=1
2022-09-01T19:25:05.929Z,1662060305.929 [Default:CheckIn:D] Stopped
2022-09-01T19:25:05.929Z,1662060305.929 [Default:CheckIn:E] Running Loop=1
2022-09-01T19:25:06.333Z,1662060306.333 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 14.457145 min 
2022-09-01T19:25:06.333Z,1662060306.333 [Default:CheckIn:E] Stopped
2022-09-01T19:25:06.334Z,1662060306.334 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-01T19:25:06.334Z,1662060306.334 [Default:CheckIn] Stopped
2022-09-01T19:25:06.334Z,1662060306.334 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-01T19:25:06.334Z,1662060306.334 [Default:CheckIn](INFO): Running loop #3
2022-09-01T19:25:06.334Z,1662060306.334 [Default:CheckIn] Running Loop=3
2022-09-01T19:25:06.334Z,1662060306.334 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-01T19:25:06.334Z,1662060306.334 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-01T19:25:08.336Z,1662060308.336 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192515.00,A,4029.96341,N,07055.40164,W,7.659,276.38,010922,,,A*7C
2022-09-01T19:25:08.338Z,1662060308.338 [NAL9602](INFO): GPS fix at 20220901T192515: (40.499390, -70.923361)
2022-09-01T19:25:08.370Z,1662060308.370 [Default:CheckIn:Read_GPS] Stopped
2022-09-01T19:25:08.370Z,1662060308.370 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-01T19:25:23.969Z,1662060323.969 [NAL9602](INFO): SBD MO Status=1, MOMSN=44802, MT Status=0, MTMSN=0
2022-09-01T19:25:24.022Z,1662060324.022 [NAL9602](INFO): Sent 72 bytes from file Logs/20220901T190735/Courier0010.lzma
2022-09-01T19:25:24.022Z,1662060324.022 [NAL9602](INFO): Packets left to send: 0
2022-09-01T19:25:31.266Z,1662060331.266 [NAL9602](INFO): SBD MO Status=1, MOMSN=44803, MT Status=0, MTMSN=0
2022-09-01T19:25:31.320Z,1662060331.320 [NAL9602](INFO): Sent 119 bytes from file Logs/20220901T190735/Express0011.lzma
2022-09-01T19:25:31.320Z,1662060331.320 [NAL9602](INFO): Packets left to send: 0
2022-09-01T19:25:41.267Z,1662060341.267 [NAL9602](INFO): SBD MO Status=0, MOMSN=44804, MT Status=0, MTMSN=0
2022-09-01T19:25:41.360Z,1662060341.360 [Default:CheckIn:Read_Iridium] Stopped
2022-09-01T19:25:41.360Z,1662060341.360 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-01T19:25:41.360Z,1662060341.360 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-01T19:26:11.711Z,1662060371.711 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-01T19:26:30.720Z,1662060390.720 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2022-09-01T19:30:41.991Z,1662060641.991 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-01T19:30:41.992Z,1662060641.992 [Default:CheckIn:C.Wait] Stopped
2022-09-01T19:30:41.992Z,1662060641.992 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-01T19:30:41.992Z,1662060641.992 [Default:CheckIn:D] Running Loop=1
2022-09-01T19:30:42.406Z,1662060642.406 [Default:CheckIn:D] Stopped
2022-09-01T19:30:42.406Z,1662060642.406 [Default:CheckIn:E] Running Loop=1
2022-09-01T19:30:42.824Z,1662060642.824 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.065094 min 
2022-09-01T19:30:42.825Z,1662060642.825 [Default:CheckIn:E] Stopped
2022-09-01T19:30:42.825Z,1662060642.825 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-01T19:30:42.825Z,1662060642.825 [Default:CheckIn] Stopped
2022-09-01T19:30:42.825Z,1662060642.825 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-01T19:30:42.825Z,1662060642.825 [Default:CheckIn](INFO): Running loop #4
2022-09-01T19:30:42.825Z,1662060642.825 [Default:CheckIn] Running Loop=4
2022-09-01T19:30:42.825Z,1662060642.825 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-01T19:30:42.825Z,1662060642.825 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-01T19:30:44.812Z,1662060644.812 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193051.00,A,4030.01610,N,07056.49509,W,9.622,270.72,010922,,,A*70
2022-09-01T19:30:44.814Z,1662060644.814 [NAL9602](INFO): GPS fix at 20220901T193051: (40.500268, -70.941585)
2022-09-01T19:30:44.905Z,1662060644.905 [Default:CheckIn:Read_GPS] Stopped
2022-09-01T19:30:44.906Z,1662060644.906 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-01T19:30:57.761Z,1662060657.761 [RDI_PathfinderUp](ERROR): only read -1 of 1 data item for altitude
2022-09-01T19:31:24.505Z,1662060684.505 [NAL9602](INFO): SBD MO Status=1, MOMSN=44805, MT Status=0, MTMSN=0
2022-09-01T19:31:24.560Z,1662060684.560 [NAL9602](INFO): Sent 72 bytes from file Logs/20220901T190735/Courier0013.lzma
2022-09-01T19:31:24.560Z,1662060684.560 [NAL9602](INFO): Packets left to send: 0
2022-09-01T19:31:41.166Z,1662060701.166 [NAL9602](INFO): SBD MO Status=2, MOMSN=44806, MT Status=2, MTMSN=0
2022-09-01T19:31:41.166Z,1662060701.166 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-01T19:32:19.236Z,1662060739.236 [NAL9602](INFO): SBD MO Status=1, MOMSN=44806, MT Status=0, MTMSN=0
2022-09-01T19:32:19.288Z,1662060739.288 [NAL9602](INFO): Sent 132 bytes from file Logs/20220901T190735/Express0014.lzma
2022-09-01T19:32:19.288Z,1662060739.288 [NAL9602](INFO): Packets left to send: 0
2022-09-01T19:32:35.396Z,1662060755.396 [NAL9602](INFO): SBD MO Status=2, MOMSN=44807, MT Status=2, MTMSN=0
2022-09-01T19:32:35.396Z,1662060755.396 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-01T19:32:41.665Z,1662060761.665 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2022-09-01T19:32:49.251Z,1662060769.251 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2022-09-01T19:32:53.294Z,1662060773.294 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2022-09-01T19:33:02.061Z,1662060782.061 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2022-09-01T19:33:25.071Z,1662060805.071 [NAL9602](INFO): SBD MO Status=0, MOMSN=44807, MT Status=0, MTMSN=0
2022-09-01T19:33:25.156Z,1662060805.156 [Default:CheckIn:Read_Iridium] Stopped
2022-09-01T19:33:25.156Z,1662060805.156 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-01T19:33:25.156Z,1662060805.156 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-01T19:33:55.770Z,1662060835.770 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-01T19:38:25.681Z,1662061105.681 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-01T19:38:25.681Z,1662061105.681 [Default:CheckIn:C.Wait] Stopped
2022-09-01T19:38:25.681Z,1662061105.681 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-01T19:38:25.681Z,1662061105.681 [Default:CheckIn:D] Running Loop=1
2022-09-01T19:38:26.068Z,1662061106.068 [Default:CheckIn:D] Stopped
2022-09-01T19:38:26.068Z,1662061106.068 [Default:CheckIn:E] Running Loop=1
2022-09-01T19:38:26.522Z,1662061106.522 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 27.792794 min 
2022-09-01T19:38:26.522Z,1662061106.522 [Default:CheckIn:E] Stopped
2022-09-01T19:38:26.522Z,1662061106.522 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-01T19:38:26.522Z,1662061106.522 [Default:CheckIn] Stopped
2022-09-01T19:38:26.522Z,1662061106.522 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-01T19:38:26.522Z,1662061106.522 [Default:CheckIn](INFO): Running loop #5
2022-09-01T19:38:26.522Z,1662061106.522 [Default:CheckIn] Running Loop=5
2022-09-01T19:38:26.522Z,1662061106.522 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-01T19:38:26.523Z,1662061106.523 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-01T19:38:28.510Z,1662061108.510 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193835.00,A,4030.04774,N,07058.08145,W,9.156,270.53,010922,,,A*7C
2022-09-01T19:38:28.513Z,1662061108.513 [NAL9602](INFO): GPS fix at 20220901T193835: (40.500796, -70.968024)
2022-09-01T19:38:28.567Z,1662061108.567 [Default:CheckIn:Read_GPS] Stopped
2022-09-01T19:38:28.567Z,1662061108.567 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-01T19:38:51.263Z,1662061131.263 [NAL9602](INFO): SBD MO Status=1, MOMSN=44808, MT Status=0, MTMSN=0
2022-09-01T19:38:51.316Z,1662061131.316 [NAL9602](INFO): Sent 73 bytes from file Logs/20220901T190735/Courier0016.lzma
2022-09-01T19:38:51.316Z,1662061131.316 [NAL9602](INFO): Packets left to send: 0
2022-09-01T19:39:03.403Z,1662061143.403 [NAL9602](INFO): SBD MO Status=1, MOMSN=44809, MT Status=0, MTMSN=0
2022-09-01T19:39:03.452Z,1662061143.452 [NAL9602](INFO): Sent 132 bytes from file Logs/20220901T190735/Express0017.lzma
2022-09-01T19:39:03.452Z,1662061143.452 [NAL9602](INFO): Packets left to send: 0
2022-09-01T19:39:14.606Z,1662061154.606 [NAL9602](INFO): SBD MO Status=0, MOMSN=44810, MT Status=0, MTMSN=0
2022-09-01T19:39:14.726Z,1662061154.726 [Default:CheckIn:Read_Iridium] Stopped
2022-09-01T19:39:14.726Z,1662061154.726 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-01T19:39:14.726Z,1662061154.726 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-01T19:39:45.315Z,1662061185.315 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-01T19:40:57.645Z,1662061257.645 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2022-09-01T19:41:07.755Z,1662061267.755 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items
2022-09-01T19:44:15.197Z,1662061455.197 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-01T19:44:15.197Z,1662061455.197 [Default:CheckIn:C.Wait] Stopped
2022-09-01T19:44:15.198Z,1662061455.198 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-01T19:44:15.198Z,1662061455.198 [Default:CheckIn:D] Running Loop=1
2022-09-01T19:44:15.634Z,1662061455.634 [Default:CheckIn:D] Stopped
2022-09-01T19:44:15.634Z,1662061455.634 [Default:CheckIn:E] Running Loop=1
2022-09-01T19:44:16.004Z,1662061456.004 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 33.618890 min 
2022-09-01T19:44:16.004Z,1662061456.004 [Default:CheckIn:E] Stopped
2022-09-01T19:44:16.004Z,1662061456.004 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-01T19:44:16.005Z,1662061456.005 [Default:CheckIn] Stopped
2022-09-01T19:44:16.005Z,1662061456.005 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-01T19:44:16.005Z,1662061456.005 [Default:CheckIn](INFO): Running loop #6
2022-09-01T19:44:16.005Z,1662061456.005 [Default:CheckIn] Running Loop=6
2022-09-01T19:44:16.005Z,1662061456.005 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-01T19:44:16.005Z,1662061456.005 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-01T19:44:18.014Z,1662061458.014 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194425.00,A,4030.06704,N,07059.27658,W,9.350,271.50,010922,,,A*72
2022-09-01T19:44:18.016Z,1662061458.016 [NAL9602](INFO): GPS fix at 20220901T194425: (40.501117, -70.987943)
2022-09-01T19:44:18.027Z,1662061458.027 [Default:CheckIn:Read_GPS] Stopped
2022-09-01T19:44:18.027Z,1662061458.027 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-01T19:44:35.091Z,1662061475.091 [NAL9602](INFO): SBD MO Status=1, MOMSN=44811, MT Status=0, MTMSN=0
2022-09-01T19:44:35.140Z,1662061475.140 [NAL9602](INFO): Sent 72 bytes from file Logs/20220901T190735/Courier0019.lzma
2022-09-01T19:44:35.140Z,1662061475.140 [NAL9602](INFO): Packets left to send: 0
2022-09-01T19:44:52.136Z,1662061492.136 [NAL9602](INFO): SBD MO Status=2, MOMSN=44812, MT Status=2, MTMSN=0
2022-09-01T19:44:52.136Z,1662061492.136 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-01T19:45:13.606Z,1662061513.606 [NAL9602](INFO): SBD MO Status=1, MOMSN=44812, MT Status=0, MTMSN=0
2022-09-01T19:45:13.656Z,1662061513.656 [NAL9602](INFO): Sent 130 bytes from file Logs/20220901T190735/Express0020.lzma
2022-09-01T19:45:13.656Z,1662061513.656 [NAL9602](INFO): Packets left to send: 0
2022-09-01T19:45:28.043Z,1662061528.043 [NAL9602](INFO): SBD MO Status=0, MOMSN=44813, MT Status=0, MTMSN=0
2022-09-01T19:45:28.129Z,1662061528.129 [Default:CheckIn:Read_Iridium] Stopped
2022-09-01T19:45:28.129Z,1662061528.129 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-01T19:45:28.129Z,1662061528.129 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-01T19:45:58.759Z,1662061558.759 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-01T19:47:23.833Z,1662061643.833 [CommandExec](IMPORTANT): got command configSet
2022-09-01T19:47:23.833Z,1662061643.833 [CommandExec](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2022-09-01T19:47:23.834Z,1662061643.834 [CommandExec](IMPORTANT): CBIT.abortDepth=250 meter;

2022-09-01T19:47:23.834Z,1662061643.834 [CommandExec](IMPORTANT): CBIT.gfScanTimeout=2 hour;

2022-09-01T19:47:23.834Z,1662061643.834 [CommandExec](IMPORTANT): CBIT.stopDepth=200 meter;

2022-09-01T19:47:23.834Z,1662061643.834 [CommandExec](IMPORTANT): DDM.loadAtStartup=1 bool;

2022-09-01T19:47:23.834Z,1662061643.834 [CommandExec](IMPORTANT): DockingServo.loadAtStartup=1 bool;

2022-09-01T19:47:23.835Z,1662061643.835 [CommandExec](IMPORTANT): Express linearApproximation CTD_Seabird.bin_median_sea_water_salinity 0.050000 practical_salinity_unit;

2022-09-01T19:47:23.835Z,1662061643.835 [CommandExec](IMPORTANT): Express linearApproximation CTD_Seabird.bin_median_sea_water_temperature 0.500000 celsius;

2022-09-01T19:47:23.835Z,1662061643.835 [CommandExec](IMPORTANT): LineCapture.armSpeed=1.2 meter_per_second;

2022-09-01T19:47:23.835Z,1662061643.835 [CommandExec](IMPORTANT): LineCapture.midcourseSpeed=1.2 meter_per_second;

2022-09-01T19:47:23.835Z,1662061643.835 [CommandExec](IMPORTANT): LineCapture.rolloutTimeout=6 minute;

2022-09-01T19:47:23.835Z,1662061643.835 [CommandExec](IMPORTANT): LineCapture.shortFinalRange=-1 meter;

2022-09-01T19:47:23.835Z,1662061643.835 [CommandExec](IMPORTANT): LineCapture.terminalRange=300 meter;

2022-09-01T19:47:23.835Z,1662061643.835 [CommandExec](IMPORTANT): LineCapture.verbose=1 bool;

2022-09-01T19:47:23.835Z,1662061643.835 [CommandExec](IMPORTANT): VerticalControl.buoyancyNeutral=152.268921 cubic_centimeter;

2022-09-01T19:47:23.836Z,1662061643.836 [CommandExec](IMPORTANT): VerticalControl.massDefault=8.973020 millimeter;

2022-09-01T19:50:28.647Z,1662061828.647 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-01T19:50:28.647Z,1662061828.647 [Default:CheckIn:C.Wait] Stopped
2022-09-01T19:50:28.647Z,1662061828.647 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-01T19:50:28.647Z,1662061828.647 [Default:CheckIn:D] Running Loop=1
2022-09-01T19:50:29.043Z,1662061829.043 [Default:CheckIn:D] Stopped
2022-09-01T19:50:29.043Z,1662061829.043 [Default:CheckIn:E] Running Loop=1
2022-09-01T19:50:29.445Z,1662061829.445 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.842367 min 
2022-09-01T19:50:29.445Z,1662061829.445 [Default:CheckIn:E] Stopped
2022-09-01T19:50:29.445Z,1662061829.445 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-01T19:50:29.445Z,1662061829.445 [Default:CheckIn] Stopped
2022-09-01T19:50:29.445Z,1662061829.445 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-01T19:50:29.445Z,1662061829.445 [Default:CheckIn](INFO): Running loop #7
2022-09-01T19:50:29.445Z,1662061829.445 [Default:CheckIn] Running Loop=7
2022-09-01T19:50:29.446Z,1662061829.446 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-01T19:50:29.446Z,1662061829.446 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-01T19:50:31.447Z,1662061831.447 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195038.00,A,4030.00961,N,07059.99275,W,1.419,218.32,010922,,,A*77
2022-09-01T19:50:31.449Z,1662061831.449 [NAL9602](INFO): GPS fix at 20220901T195038: (40.500160, -70.999879)
2022-09-01T19:50:31.495Z,1662061831.495 [Default:CheckIn:Read_GPS] Stopped
2022-09-01T19:50:31.495Z,1662061831.495 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-01T19:50:52.559Z,1662061852.559 [NAL9602](INFO): SBD MO Status=1, MOMSN=44814, MT Status=0, MTMSN=0
2022-09-01T19:50:52.624Z,1662061852.624 [NAL9602](INFO): Sent 72 bytes from file Logs/20220901T190735/Courier0022.lzma
2022-09-01T19:50:52.624Z,1662061852.624 [NAL9602](INFO): Packets left to send: 0
2022-09-01T19:51:00.658Z,1662061860.658 [NAL9602](INFO): SBD MO Status=1, MOMSN=44815, MT Status=0, MTMSN=0
2022-09-01T19:51:00.709Z,1662061860.709 [NAL9602](INFO): Sent 184 bytes from file Logs/20220901T190735/Express0023.lzma
2022-09-01T19:51:00.709Z,1662061860.709 [NAL9602](INFO): Packets left to send: 3
2022-09-01T19:51:11.203Z,1662061871.203 [NAL9602](INFO): SBD MO Status=1, MOMSN=44816, MT Status=0, MTMSN=0
2022-09-01T19:51:11.260Z,1662061871.260 [NAL9602](INFO): Sent 184 bytes from file Logs/20220901T190735/Express0023.lzma
2022-09-01T19:51:11.260Z,1662061871.260 [NAL9602](INFO): Packets left to send: 2
2022-09-01T19:51:21.485Z,1662061881.485 [NAL9602](INFO): SBD MO Status=1, MOMSN=44817, MT Status=0, MTMSN=0
2022-09-01T19:51:21.534Z,1662061881.534 [NAL9602](INFO): Sent 184 bytes from file Logs/20220901T190735/Express0023.lzma
2022-09-01T19:51:21.534Z,1662061881.534 [NAL9602](INFO): Packets left to send: 1
2022-09-01T19:51:28.430Z,1662061888.430 [NAL9602](INFO): SBD MO Status=1, MOMSN=44818, MT Status=0, MTMSN=0
2022-09-01T19:51:28.489Z,1662061888.489 [NAL9602](INFO): Sent 32 bytes from file Logs/20220901T190735/Express0023.lzma
2022-09-01T19:51:28.490Z,1662061888.490 [NAL9602](INFO): Packets left to send: 0
2022-09-01T19:51:35.534Z,1662061895.534 [NAL9602](INFO): SBD MO Status=0, MOMSN=44819, MT Status=0, MTMSN=0
2022-09-01T19:51:35.646Z,1662061895.646 [Default:CheckIn:Read_Iridium] Stopped
2022-09-01T19:51:35.646Z,1662061895.646 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-01T19:51:35.646Z,1662061895.646 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-01T19:52:06.262Z,1662061926.262 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-01T19:56:36.156Z,1662062196.156 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-01T19:56:36.156Z,1662062196.156 [Default:CheckIn:C.Wait] Stopped
2022-09-01T19:56:36.157Z,1662062196.157 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-01T19:56:36.157Z,1662062196.157 [Default:CheckIn:D] Running Loop=1
2022-09-01T19:56:36.587Z,1662062196.587 [Default:CheckIn:D] Stopped
2022-09-01T19:56:36.587Z,1662062196.587 [Default:CheckIn:E] Running Loop=1
2022-09-01T19:56:36.990Z,1662062196.990 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.968115 min 
2022-09-01T19:56:36.990Z,1662062196.990 [Default:CheckIn:E] Stopped
2022-09-01T19:56:36.990Z,1662062196.990 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-01T19:56:36.990Z,1662062196.990 [Default:CheckIn] Stopped
2022-09-01T19:56:36.990Z,1662062196.990 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-01T19:56:36.990Z,1662062196.990 [Default:CheckIn](INFO): Running loop #8
2022-09-01T19:56:36.990Z,1662062196.990 [Default:CheckIn] Running Loop=8
2022-09-01T19:56:36.990Z,1662062196.990 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-01T19:56:36.990Z,1662062196.990 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-01T19:56:38.968Z,1662062198.968 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195646.00,A,4029.92439,N,07100.02629,W,0.875,191.69,010922,,,A*72
2022-09-01T19:56:38.970Z,1662062198.970 [NAL9602](INFO): GPS fix at 20220901T195646: (40.498740, -71.000438)
2022-09-01T19:56:38.986Z,1662062198.986 [Default:CheckIn:Read_GPS] Stopped
2022-09-01T19:56:38.986Z,1662062198.986 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-01T19:56:54.190Z,1662062214.190 [NAL9602](INFO): SBD MO Status=1, MOMSN=44820, MT Status=0, MTMSN=0
2022-09-01T19:56:54.244Z,1662062214.244 [NAL9602](INFO): Sent 73 bytes from file Logs/20220901T190735/Courier0025.lzma
2022-09-01T19:56:54.244Z,1662062214.244 [NAL9602](INFO): Packets left to send: 0
2022-09-01T19:57:04.395Z,1662062224.395 [NAL9602](INFO): SBD MO Status=1, MOMSN=44821, MT Status=0, MTMSN=0
2022-09-01T19:57:04.449Z,1662062224.449 [NAL9602](INFO): Sent 119 bytes from file Logs/20220901T190735/Express0026.lzma
2022-09-01T19:57:04.450Z,1662062224.450 [NAL9602](INFO): Packets left to send: 0
2022-09-01T19:57:15.339Z,1662062235.339 [NAL9602](INFO): SBD MO Status=0, MOMSN=44822, MT Status=0, MTMSN=0
2022-09-01T19:57:15.427Z,1662062235.427 [Default:CheckIn:Read_Iridium] Stopped
2022-09-01T19:57:15.427Z,1662062235.427 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-01T19:57:15.427Z,1662062235.427 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-01T19:57:46.039Z,1662062266.039 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-01T19:58:08.748Z,1662062288.748 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2022-09-01T20:01:53.352Z,1662062513.352 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00

2022-09-01T20:01:53.357Z,1662062513.357 [Micromodem](INFO): Nmea in: $CACST,6,1,20220901200152.158363,06,821,23,0111,0150,208,02,02,01,02,6,-01,-01,2,3,3,0,150,0.7,1.06,06,1.94,-01,-4.26,63,14500,4000*61

2022-09-01T20:02:15.994Z,1662062535.994 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-01T20:02:15.994Z,1662062535.994 [Default:CheckIn:C.Wait] Stopped
2022-09-01T20:02:15.994Z,1662062535.994 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-01T20:02:15.994Z,1662062535.994 [Default:CheckIn:D] Running Loop=1
2022-09-01T20:02:16.393Z,1662062536.393 [Default:CheckIn:D] Stopped
2022-09-01T20:02:16.393Z,1662062536.393 [Default:CheckIn:E] Running Loop=1
2022-09-01T20:02:16.819Z,1662062536.819 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.631539 min 
2022-09-01T20:02:16.819Z,1662062536.819 [Default:CheckIn:E] Stopped
2022-09-01T20:02:16.819Z,1662062536.819 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-01T20:02:16.820Z,1662062536.820 [Default:CheckIn] Stopped
2022-09-01T20:02:16.820Z,1662062536.820 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-01T20:02:16.820Z,1662062536.820 [Default:CheckIn](INFO): Running loop #9
2022-09-01T20:02:16.820Z,1662062536.820 [Default:CheckIn] Running Loop=9
2022-09-01T20:02:16.820Z,1662062536.820 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-01T20:02:16.820Z,1662062536.820 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-01T20:02:18.803Z,1662062538.803 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200225.00,A,4029.85113,N,07100.04664,W,0.292,185.04,010922,,,A*75
2022-09-01T20:02:18.806Z,1662062538.806 [NAL9602](INFO): GPS fix at 20220901T200225: (40.497519, -71.000777)
2022-09-01T20:02:18.870Z,1662062538.870 [Default:CheckIn:Read_GPS] Stopped
2022-09-01T20:02:18.870Z,1662062538.870 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-01T20:02:31.957Z,1662062551.957 [NAL9602](INFO): SBD MO Status=1, MOMSN=44823, MT Status=0, MTMSN=0
2022-09-01T20:02:32.004Z,1662062552.004 [NAL9602](INFO): Sent 72 bytes from file Logs/20220901T190735/Courier0028.lzma
2022-09-01T20:02:32.004Z,1662062552.004 [NAL9602](INFO): Packets left to send: 0
2022-09-01T20:02:52.834Z,1662062572.834 [NAL9602](INFO): SBD MO Status=1, MOMSN=44824, MT Status=0, MTMSN=0
2022-09-01T20:02:52.884Z,1662062572.884 [NAL9602](INFO): Sent 120 bytes from file Logs/20220901T190735/Express0029.lzma
2022-09-01T20:02:52.884Z,1662062572.884 [NAL9602](INFO): Packets left to send: 0
2022-09-01T20:03:03.339Z,1662062583.339 [NAL9602](INFO): SBD MO Status=0, MOMSN=44825, MT Status=0, MTMSN=0
2022-09-01T20:03:03.421Z,1662062583.421 [Default:CheckIn:Read_Iridium] Stopped
2022-09-01T20:03:03.421Z,1662062583.421 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-01T20:03:03.421Z,1662062583.421 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-01T20:03:34.122Z,1662062614.122 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-01T20:07:09.063Z,1662062829.063 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-09-01T20:07:09.457Z,1662062829.457 [Micromodem](INFO): Nmea in: $CACST,6,1,20220901200710.157214,06,997,23,0095,0150,208,02,02,01,02,-1,-01,-01,1,3,4,0,150,10.4,0.01,-100,2.99,-01,0.31,64,14500,4000*48

2022-09-01T20:08:04.013Z,1662062884.013 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-01T20:08:04.013Z,1662062884.013 [Default:CheckIn:C.Wait] Stopped
2022-09-01T20:08:04.013Z,1662062884.013 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-01T20:08:04.013Z,1662062884.013 [Default:CheckIn:D] Running Loop=1
2022-09-01T20:08:04.431Z,1662062884.431 [Default:CheckIn:D] Stopped
2022-09-01T20:08:04.431Z,1662062884.431 [Default:CheckIn:E] Running Loop=1
2022-09-01T20:08:04.851Z,1662062884.851 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 57.432170 min 
2022-09-01T20:08:04.851Z,1662062884.851 [Default:CheckIn:E] Stopped
2022-09-01T20:08:04.851Z,1662062884.851 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-01T20:08:04.852Z,1662062884.852 [Default:CheckIn] Stopped
2022-09-01T20:08:04.852Z,1662062884.852 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-01T20:08:04.852Z,1662062884.852 [Default:CheckIn](INFO): Running loop #10
2022-09-01T20:08:04.852Z,1662062884.852 [Default:CheckIn] Running Loop=10
2022-09-01T20:08:04.852Z,1662062884.852 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-01T20:08:04.852Z,1662062884.852 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-01T20:08:06.824Z,1662062886.824 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200813.00,A,4029.77703,N,07100.07833,W,0.641,201.61,010922,,,A*79
2022-09-01T20:08:06.826Z,1662062886.826 [NAL9602](INFO): GPS fix at 20220901T200813: (40.496284, -71.001306)
2022-09-01T20:08:06.907Z,1662062886.907 [Default:CheckIn:Read_GPS] Stopped
2022-09-01T20:08:06.907Z,1662062886.907 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-01T20:08:27.618Z,1662062907.618 [NAL9602](INFO): SBD MO Status=1, MOMSN=44826, MT Status=0, MTMSN=0
2022-09-01T20:08:27.668Z,1662062907.668 [NAL9602](INFO): Sent 72 bytes from file Logs/20220901T190735/Courier0031.lzma
2022-09-01T20:08:27.668Z,1662062907.668 [NAL9602](INFO): Packets left to send: 0
2022-09-01T20:08:37.771Z,1662062917.771 [NAL9602](INFO): SBD MO Status=1, MOMSN=44827, MT Status=0, MTMSN=0
2022-09-01T20:08:37.824Z,1662062917.824 [NAL9602](INFO): Sent 125 bytes from file Logs/20220901T190735/Express0032.lzma
2022-09-01T20:08:37.824Z,1662062917.824 [NAL9602](INFO): Packets left to send: 0
2022-09-01T20:08:44.587Z,1662062924.587 [NAL9602](INFO): SBD MO Status=0, MOMSN=44828, MT Status=0, MTMSN=0
2022-09-01T20:08:44.677Z,1662062924.677 [Default:CheckIn:Read_Iridium] Stopped
2022-09-01T20:08:44.678Z,1662062924.678 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-01T20:08:44.678Z,1662062924.678 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-01T20:09:15.101Z,1662062955.101 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-01T20:11:30.502Z,1662063090.502 [RDI_Pathfinder](ERROR): only read 1 of 4 data items
2022-09-01T20:11:39.339Z,1662063099.339 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00

2022-09-01T20:11:39.343Z,1662063099.343 [Micromodem](INFO): Nmea in: $CACST,6,1,20220901201136.174579,06,810,23,0094,0150,223,02,02,01,02,6,-01,-01,2,3,6,0,150,-0.5,0.73,05,2.27,-01,1.64,65,14500,4000*6F

2022-09-01T20:13:29.236Z,1662063209.236 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items
2022-09-01T20:13:45.026Z,1662063225.026 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-01T20:13:45.026Z,1662063225.026 [Default:CheckIn:C.Wait] Stopped
2022-09-01T20:13:45.026Z,1662063225.026 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-01T20:13:45.027Z,1662063225.027 [Default:CheckIn:D] Running Loop=1
2022-09-01T20:13:45.396Z,1662063225.396 [Default:CheckIn:D] Stopped
2022-09-01T20:13:45.396Z,1662063225.396 [Default:CheckIn:E] Running Loop=1
2022-09-01T20:13:45.800Z,1662063225.800 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 63.114917 min 
2022-09-01T20:13:45.801Z,1662063225.801 [Default:CheckIn:E] Stopped
2022-09-01T20:13:45.801Z,1662063225.801 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-01T20:13:45.801Z,1662063225.801 [Default:CheckIn] Stopped
2022-09-01T20:13:45.801Z,1662063225.801 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-01T20:13:45.801Z,1662063225.801 [Default:CheckIn](INFO): Running loop #11
2022-09-01T20:13:45.801Z,1662063225.801 [Default:CheckIn] Running Loop=11
2022-09-01T20:13:45.801Z,1662063225.801 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-01T20:13:45.801Z,1662063225.801 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-01T20:13:47.821Z,1662063227.821 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201354.00,A,4029.71637,N,07100.11732,W,0.583,192.13,010922,,,A*78
2022-09-01T20:13:47.823Z,1662063227.823 [NAL9602](INFO): GPS fix at 20220901T201354: (40.495273, -71.001955)
2022-09-01T20:13:47.845Z,1662063227.845 [Default:CheckIn:Read_GPS] Stopped
2022-09-01T20:13:47.845Z,1662063227.845 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-01T20:14:03.319Z,1662063243.319 [NAL9602](INFO): SBD MO Status=1, MOMSN=44829, MT Status=0, MTMSN=0
2022-09-01T20:14:03.376Z,1662063243.376 [NAL9602](INFO): Sent 72 bytes from file Logs/20220901T190735/Courier0034.lzma
2022-09-01T20:14:03.376Z,1662063243.376 [NAL9602](INFO): Packets left to send: 0
2022-09-01T20:14:20.374Z,1662063260.374 [NAL9602](INFO): SBD MO Status=1, MOMSN=44830, MT Status=0, MTMSN=0
2022-09-01T20:14:20.433Z,1662063260.433 [NAL9602](INFO): Sent 120 bytes from file Logs/20220901T190735/Express0035.lzma
2022-09-01T20:14:20.433Z,1662063260.433 [NAL9602](INFO): Packets left to send: 0
2022-09-01T20:14:25.931Z,1662063265.931 [NAL9602](INFO): SBD MO Status=0, MOMSN=44831, MT Status=0, MTMSN=0
2022-09-01T20:14:26.016Z,1662063266.016 [Default:CheckIn:Read_Iridium] Stopped
2022-09-01T20:14:26.016Z,1662063266.016 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-01T20:14:26.016Z,1662063266.016 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-01T20:14:56.629Z,1662063296.629 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-01T20:17:15.241Z,1662063435.241 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error

2022-09-01T20:17:15.242Z,1662063435.242 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
 expected 41
2022-09-01T20:17:15.243Z,1662063435.243 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-09-01T20:17:15.637Z,1662063435.637 [Micromodem](INFO): Nmea in: $CACST,6,1,20220901201716.167505,06,783,22,0101,0150,149,01,01,01,01,-1,-01,-01,1,3,8,0,150,61.5,1.94,-100,1.06,-01,-0.37,-6,14500,4000*79

2022-09-01T20:18:03.278Z,1662063483.278 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-09-01T20:18:03.283Z,1662063483.283 [Micromodem](INFO): Nmea in: $CACST,6,1,20220901201804.167926,06,791,22,0090,0150,149,01,01,01,01,-1,-01,-01,1,3,3,0,150,24.6,-0.09,-100,3.09,-01,-0.34,55,14500,4000*46

2022-09-01T20:18:44.531Z,1662063524.531 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range.
2022-09-01T20:18:45.298Z,1662063525.298 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-09-01T20:18:45.307Z,1662063525.307 [Micromodem](INFO): Nmea in: $CACST,6,1,20220901201846.171650,06,195,22,0120,0150,216,02,02,00,02,-1,-01,-01,1,3,1,0,150,8.8,0.10,-100,2.90,-01,-2.47,64,14500,4000*58

2022-09-01T20:18:54.631Z,1662063534.631 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2022-09-01T20:19:09.139Z,1662063549.139 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error

2022-09-01T20:19:09.139Z,1662063549.139 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
 expected 41
2022-09-01T20:19:09.142Z,1662063549.142 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-09-01T20:19:09.545Z,1662063549.545 [Micromodem](INFO): Nmea in: $CACST,6,1,20220901201910.167362,06,651,22,0105,0150,208,02,02,01,02,-1,-01,-01,1,3,1,0,150,-100.0,0.41,-100,2.59,-01,-2.38,-2147483648,14500,4000*50

2022-09-01T20:19:19.240Z,1662063559.240 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error

2022-09-01T20:19:19.240Z,1662063559.240 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
 expected 41
2022-09-01T20:19:19.242Z,1662063559.242 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-09-01T20:19:19.638Z,1662063559.638 [Micromodem](INFO): Nmea in: $CACST,6,1,20220901201920.155793,06,443,26,0094,0150,208,02,02,00,02,-1,-01,-01,1,3,1,0,150,-100.0,0.40,-100,2.60,-01,2.19,-2147483648,14500,4000*70

2022-09-01T20:19:26.537Z,1662063566.537 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-01T20:19:26.538Z,1662063566.538 [Default:CheckIn:C.Wait] Stopped
2022-09-01T20:19:26.538Z,1662063566.538 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-01T20:19:26.538Z,1662063566.538 [Default:CheckIn:D] Running Loop=1
2022-09-01T20:19:26.942Z,1662063566.942 [Default:CheckIn:D] Stopped
2022-09-01T20:19:26.942Z,1662063566.942 [Default:CheckIn:E] Running Loop=1
2022-09-01T20:19:27.318Z,1662063567.318 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 68.807357 min 
2022-09-01T20:19:27.318Z,1662063567.318 [Default:CheckIn:E] Stopped
2022-09-01T20:19:27.318Z,1662063567.318 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-01T20:19:27.318Z,1662063567.318 [Default:CheckIn] Stopped
2022-09-01T20:19:27.318Z,1662063567.318 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-01T20:19:27.319Z,1662063567.319 [Default:CheckIn](INFO): Running loop #12
2022-09-01T20:19:27.319Z,1662063567.319 [Default:CheckIn] Running Loop=12
2022-09-01T20:19:27.319Z,1662063567.319 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-01T20:19:27.319Z,1662063567.319 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-01T20:19:29.407Z,1662063569.407 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201936.00,A,4029.94698,N,07100.13850,W,8.981,33.87,010922,,,A*40
2022-09-01T20:19:29.410Z,1662063569.410 [NAL9602](INFO): GPS fix at 20220901T201936: (40.499116, -71.002308)
2022-09-01T20:19:29.431Z,1662063569.431 [Default:CheckIn:Read_GPS] Stopped
2022-09-01T20:19:29.431Z,1662063569.431 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-01T20:19:43.805Z,1662063583.805 [RDI_PathfinderUp](ERROR): only read 1 of 4 data items
2022-09-01T20:19:50.660Z,1662063590.660 [NAL9602](INFO): SBD MO Status=1, MOMSN=44832, MT Status=0, MTMSN=0
2022-09-01T20:19:50.708Z,1662063590.708 [NAL9602](INFO): Sent 71 bytes from file Logs/20220901T190735/Courier0037.lzma
2022-09-01T20:19:50.708Z,1662063590.708 [NAL9602](INFO): Packets left to send: 0
2022-09-01T20:19:59.947Z,1662063599.947 [NAL9602](INFO): SBD MO Status=1, MOMSN=44833, MT Status=0, MTMSN=0
2022-09-01T20:19:59.996Z,1662063599.996 [NAL9602](INFO): Sent 120 bytes from file Logs/20220901T190735/Express0038.lzma
2022-09-01T20:19:59.996Z,1662063599.996 [NAL9602](INFO): Packets left to send: 0
2022-09-01T20:20:18.203Z,1662063618.203 [NAL9602](INFO): SBD MO Status=0, MOMSN=44834, MT Status=0, MTMSN=0
2022-09-01T20:20:18.349Z,1662063618.349 [Default:CheckIn:Read_Iridium] Stopped
2022-09-01T20:20:18.349Z,1662063618.349 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-01T20:20:18.349Z,1662063618.349 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-01T20:20:44.873Z,1662063644.873 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2022-09-01T20:20:48.970Z,1662063648.970 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-01T20:21:09.917Z,1662063669.917 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2022-09-01T20:21:44.724Z,1662063704.724 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2022-09-01T20:24:59.842Z,1662063899.842 [RDI_PathfinderUp](ERROR): only read 1 of 4 data items
2022-09-01T20:25:18.815Z,1662063918.815 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-01T20:25:18.815Z,1662063918.815 [Default:CheckIn:C.Wait] Stopped
2022-09-01T20:25:18.815Z,1662063918.815 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-01T20:25:18.815Z,1662063918.815 [Default:CheckIn:D] Running Loop=1
2022-09-01T20:25:19.204Z,1662063919.204 [Default:CheckIn:D] Stopped
2022-09-01T20:25:19.204Z,1662063919.204 [Default:CheckIn:E] Running Loop=1
2022-09-01T20:25:19.595Z,1662063919.595 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 74.678385 min 
2022-09-01T20:25:19.595Z,1662063919.595 [Default:CheckIn:E] Stopped
2022-09-01T20:25:19.595Z,1662063919.595 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-01T20:25:19.595Z,1662063919.595 [Default:CheckIn] Stopped
2022-09-01T20:25:19.596Z,1662063919.596 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-01T20:25:19.596Z,1662063919.596 [Default:CheckIn](INFO): Running loop #13
2022-09-01T20:25:19.596Z,1662063919.596 [Default:CheckIn] Running Loop=13
2022-09-01T20:25:19.596Z,1662063919.596 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-01T20:25:19.596Z,1662063919.596 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-01T20:25:21.618Z,1662063921.618 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202528.00,A,4030.71873,N,07059.40919,W,9.972,32.88,010922,,,D*49
2022-09-01T20:25:21.620Z,1662063921.620 [NAL9602](INFO): GPS fix at 20220901T202528: (40.511979, -70.990153)
2022-09-01T20:25:21.641Z,1662063921.641 [Default:CheckIn:Read_GPS] Stopped
2022-09-01T20:25:21.641Z,1662063921.641 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-01T20:25:36.138Z,1662063936.138 [NAL9602](INFO): SBD MO Status=1, MOMSN=44835, MT Status=0, MTMSN=0
2022-09-01T20:25:36.190Z,1662063936.190 [NAL9602](INFO): Sent 71 bytes from file Logs/20220901T190735/Courier0040.lzma
2022-09-01T20:25:36.190Z,1662063936.190 [NAL9602](INFO): Packets left to send: 0
2022-09-01T20:25:44.968Z,1662063944.968 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude
2022-09-01T20:25:53.847Z,1662063953.847 [NAL9602](INFO): SBD MO Status=1, MOMSN=44836, MT Status=0, MTMSN=0
2022-09-01T20:25:53.896Z,1662063953.896 [NAL9602](INFO): Sent 136 bytes from file Logs/20220901T190735/Express0041.lzma
2022-09-01T20:25:53.896Z,1662063953.896 [NAL9602](INFO): Packets left to send: 0
2022-09-01T20:26:04.238Z,1662063964.238 [NAL9602](INFO): SBD MO Status=0, MOMSN=44837, MT Status=0, MTMSN=0
2022-09-01T20:26:04.324Z,1662063964.324 [Default:CheckIn:Read_Iridium] Stopped
2022-09-01T20:26:04.324Z,1662063964.324 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-01T20:26:04.324Z,1662063964.324 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-01T20:26:34.733Z,1662063994.733 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-01T20:27:25.234Z,1662064045.234 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-09-01T20:27:25.239Z,1662064045.239 [Micromodem](INFO): Nmea in: $CACST,6,1,20220901202726.149087,06,2331,27,0139,0150,149,01,01,01,01,-1,-01,-01,1,3,6,0,150,25.6,0.02,-100,2.98,-01,-0.33,55,14500,4000*53

2022-09-01T20:27:29.861Z,1662064049.861 [CommandExec](IMPORTANT): got command quit
2022-09-01T20:27:30.864Z,1662064050.864 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2022-09-01T20:27:30.864Z,1662064050.864 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T20:27:30.864Z,1662064050.864 [CommandExec](INFO): Uninitializing the command executive.
2022-09-01T20:27:30.864Z,1662064050.864 [CommandExec](INFO): Uninitializing the command scheduler.
2022-09-01T20:27:30.865Z,1662064050.865 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-09-01T20:27:30.904Z,1662064050.904 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2022-09-01T20:27:30.904Z,1662064050.904 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2022-09-01T20:27:30.904Z,1662064050.904 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-09-01T20:27:30.905Z,1662064050.905 [NavChartDb](INFO): Join timeout helper Thread ID is 1181
2022-09-01T20:27:31.036Z,1662064051.036 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T20:27:31.036Z,1662064051.036 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-09-01T20:27:31.044Z,1662064051.044 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2022-09-01T20:27:31.044Z,1662064051.044 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2022-09-01T20:27:31.044Z,1662064051.044 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 1182
2022-09-01T20:27:31.112Z,1662064051.112 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T20:27:31.112Z,1662064051.112 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2022-09-01T20:27:31.124Z,1662064051.124 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2022-09-01T20:27:31.124Z,1662064051.124 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-09-01T20:27:31.124Z,1662064051.124 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1183
2022-09-01T20:27:31.488Z,1662064051.488 [CTD_Seabird](INFO): Powering down
2022-09-01T20:27:31.500Z,1662064051.500 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T20:27:31.500Z,1662064051.500 [CTD_Seabird](INFO): Powering down
2022-09-01T20:27:31.512Z,1662064051.512 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-09-01T20:27:31.527Z,1662064051.527 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2022-09-01T20:27:31.527Z,1662064051.527 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-09-01T20:27:31.527Z,1662064051.527 [Radio_Surface](INFO): Join timeout helper Thread ID is 1184
2022-09-01T20:27:31.808Z,1662064051.808 [Radio_Surface](INFO): Powering down
2022-09-01T20:27:31.809Z,1662064051.809 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T20:27:31.809Z,1662064051.809 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-09-01T20:27:31.820Z,1662064051.820 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2022-09-01T20:27:31.820Z,1662064051.820 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-09-01T20:27:31.820Z,1662064051.820 [Onboard](INFO): Join timeout helper Thread ID is 1185
2022-09-01T20:27:34.876Z,1662064054.876 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T20:27:34.876Z,1662064054.876 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-09-01T20:27:34.897Z,1662064054.897 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2022-09-01T20:27:34.897Z,1662064054.897 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-09-01T20:27:34.897Z,1662064054.897 [DataOverHttps](INFO): Join timeout helper Thread ID is 1187
2022-09-01T20:27:35.562Z,1662064055.562 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T20:27:35.563Z,1662064055.563 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-09-01T20:27:35.566Z,1662064055.566 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2022-09-01T20:27:35.566Z,1662064055.566 [logger ThreadHandler](INFO): Thread cancelled.
2022-09-01T20:27:35.567Z,1662064055.567 [logger](INFO): Join timeout helper Thread ID is 1189
2022-09-01T20:27:35.612Z,1662064055.612 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T20:27:35.612Z,1662064055.612 [logger ThreadHandler](INFO): Thread cancelled.
2022-09-01T20:27:35.628Z,1662064055.628 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2022-09-01T20:27:35.629Z,1662064055.629 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-09-01T20:27:35.629Z,1662064055.629 [CommandLine](INFO): Join timeout helper Thread ID is 1190
2022-09-01T20:27:35.632Z,1662064055.632 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T20:27:35.632Z,1662064055.632 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-09-01T20:27:35.648Z,1662064055.648 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2022-09-01T20:27:35.649Z,1662064055.649 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-09-01T20:27:35.649Z,1662064055.649 [CommandExec](INFO): Join timeout helper Thread ID is 1191
2022-09-01T20:27:35.650Z,1662064055.650 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2022-09-01T20:27:35.650Z,1662064055.650 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-09-01T20:27:35.651Z,1662064055.651 [controlThread](INFO): Join timeout helper Thread ID is 1192
2022-09-01T20:27:35.716Z,1662064055.716 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T20:27:35.716Z,1662064055.716 [controlThread](DEBUG): Uninitializing ControlThread
2022-09-01T20:27:35.717Z,1662064055.717 [AHRS_M2](INFO): Powering down
2022-09-01T20:27:35.789Z,1662064055.789 [DDM](INFO): Powering down
2022-09-01T20:27:35.861Z,1662064055.861 [Micromodem](INFO): Powering down
2022-09-01T20:27:35.956Z,1662064055.956 [NAL9602](INFO): Powering down
2022-09-01T20:27:36.028Z,1662064056.028 [RDI_Pathfinder](INFO): Powering down
2022-09-01T20:27:36.100Z,1662064056.100 [RDI_PathfinderUp](INFO): Powering down
2022-09-01T20:27:36.101Z,1662064056.101 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2022-09-01T20:27:36.102Z,1662064056.102 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2022-09-01T20:27:36.103Z,1662064056.103 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2022-09-01T20:27:36.104Z,1662064056.104 [MissionManager](INFO): Uninitializing Mission Default
2022-09-01T20:27:36.104Z,1662064056.104 [Default] Stopped
2022-09-01T20:27:36.104Z,1662064056.104 [Default](DEBUG): Aggregate::uninitialize Default
2022-09-01T20:27:36.104Z,1662064056.104 [Default:B.GoToSurface] Stopped
2022-09-01T20:27:36.104Z,1662064056.104 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-09-01T20:27:36.104Z,1662064056.104 [Default:CheckIn] Stopped
2022-09-01T20:27:36.104Z,1662064056.104 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-01T20:27:36.104Z,1662064056.104 [Default:CheckIn:C.Wait] Stopped
2022-09-01T20:27:36.104Z,1662064056.104 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-01T20:27:36.107Z,1662064056.107 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2022-09-01T20:27:36.107Z,1662064056.107 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2022-09-01T20:27:36.108Z,1662064056.108 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2022-09-01T20:27:36.109Z,1662064056.109 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2022-09-01T20:27:36.109Z,1662064056.109 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2022-09-01T20:27:36.109Z,1662064056.109 [BuoyancyServo](INFO): Powering down
2022-09-01T20:27:36.124Z,1662064056.124 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2022-09-01T20:27:36.124Z,1662064056.124 [ElevatorServo](INFO): Powering down
2022-09-01T20:27:36.125Z,1662064056.125 [DockingServo](DEBUG): Uninitialize Docking Servo.
2022-09-01T20:27:36.125Z,1662064056.125 [MassServo](DEBUG): Uninitialize Mass Servo.
2022-09-01T20:27:36.125Z,1662064056.125 [MassServo](INFO): Powering down
2022-09-01T20:27:36.126Z,1662064056.126 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-09-01T20:27:36.126Z,1662064056.126 [RudderServo](INFO): Powering down
2022-09-01T20:27:36.127Z,1662064056.127 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2022-09-01T20:27:36.127Z,1662064056.127 [ThrusterHE](INFO): Powering down
2022-09-01T20:27:36.128Z,1662064056.128 [SBIT](DEBUG): Uninitialize SBIT Component.
2022-09-01T20:27:36.128Z,1662064056.128 [IBIT](DEBUG): Uninitialize IBIT Component.
2022-09-01T20:27:36.129Z,1662064056.129 [CBIT](DEBUG): Uninitialize CBIT Component.
2022-09-01T20:27:36.129Z,1662064056.129 [CBIT](DEBUG): Powering off loads.
2022-09-01T20:27:36.140Z,1662064056.140 [CBIT](DEBUG): Disabling WDT.
2022-09-01T20:27:36.152Z,1662064056.152 [CBIT](DEBUG): Opening all GF detection circuits.
2022-09-01T20:27:36.153Z,1662064056.153 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-09-01T20:27:36.172Z,1662064056.172 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-09-01T20:27:36.176Z,1662064056.176 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-09-01T20:27:36.185Z,1662064056.185 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-09-01T20:27:36.329Z,1662064056.329 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2022-09-01T20:27:36.331Z,1662064056.331 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-09-01T20:27:36.391Z,1662064056.391 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-09-01T20:27:36.457Z,1662064056.457 [logger ThreadHandler](INFO): Thread cancelled.