2022-12-20T16:48:01.354Z,1671554881.354 [Supervisor](DEBUG): Initializing supervisor.
2022-12-20T16:48:01.359Z,1671554881.359 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2022-12-20T16:48:01.359Z,1671554881.359 [SyncHandler](INFO): Protected caller Thread ID is 836
2022-12-20T16:48:01.360Z,1671554881.360 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2022-12-20T16:48:01.361Z,1671554881.361 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2022-12-20T16:48:01.361Z,1671554881.361 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 837
2022-12-20T16:48:01.365Z,1671554881.365 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2022-12-20T16:48:01.382Z,1671554881.382 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2022-12-20T16:48:01.383Z,1671554881.383 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2022-12-20T16:48:01.383Z,1671554881.383 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 838
2022-12-20T16:48:01.388Z,1671554881.388 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2022-12-20T16:48:01.389Z,1671554881.389 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2022-12-20T16:48:01.389Z,1671554881.389 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 839
2022-12-20T16:48:01.391Z,1671554881.391 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2022-12-20T16:48:01.392Z,1671554881.392 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2022-12-20T16:48:01.392Z,1671554881.392 [logger ThreadHandler](INFO): Protected caller Thread ID is 840
2022-12-20T16:48:01.396Z,1671554881.396 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2022-12-20T16:48:01.396Z,1671554881.396 [Supervisor](INFO): Looking for Config files in directory: Config/
2022-12-20T16:48:01.401Z,1671554881.401 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2022-12-20T16:48:01.867Z,1671554881.867 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2022-12-20T16:48:01.869Z,1671554881.869 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2022-12-20T16:48:02.080Z,1671554882.080 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2022-12-20T16:48:02.082Z,1671554882.082 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2022-12-20T16:48:02.164Z,1671554882.164 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2022-12-20T16:48:02.390Z,1671554882.390 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2022-12-20T16:48:02.392Z,1671554882.392 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2022-12-20T16:48:02.472Z,1671554882.472 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2022-12-20T16:48:02.568Z,1671554882.568 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2022-12-20T16:48:02.570Z,1671554882.570 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2022-12-20T16:48:02.940Z,1671554882.940 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2022-12-20T16:48:02.942Z,1671554882.942 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2022-12-20T16:48:03.075Z,1671554883.075 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2022-12-20T16:48:03.077Z,1671554883.077 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2022-12-20T16:48:03.576Z,1671554883.576 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2022-12-20T16:48:03.578Z,1671554883.578 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2022-12-20T16:48:03.779Z,1671554883.779 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2022-12-20T16:48:03.780Z,1671554883.780 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2022-12-20T16:48:04.211Z,1671554884.211 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2022-12-20T16:48:04.211Z,1671554884.211 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2022-12-20T16:48:04.497Z,1671554884.497 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2022-12-20T16:48:04.499Z,1671554884.499 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2022-12-20T16:48:04.610Z,1671554884.610 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2022-12-20T16:48:04.611Z,1671554884.611 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2022-12-20T16:48:06.100Z,1671554886.100 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2022-12-20T16:48:06.101Z,1671554886.101 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2022-12-20T16:48:06.534Z,1671554886.534 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2022-12-20T16:48:06.536Z,1671554886.536 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2022-12-20T16:48:06.758Z,1671554886.758 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2022-12-20T16:48:06.760Z,1671554886.760 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/
2022-12-20T16:48:06.764Z,1671554886.764 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg
2022-12-20T16:48:06.954Z,1671554886.954 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg
2022-12-20T16:48:07.038Z,1671554887.038 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg
2022-12-20T16:48:07.175Z,1671554887.175 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg
2022-12-20T16:48:07.262Z,1671554887.262 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg
2022-12-20T16:48:07.528Z,1671554887.528 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2022-12-20T16:48:07.529Z,1671554887.529 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg
2022-12-20T16:48:07.634Z,1671554887.634 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg
2022-12-20T16:48:07.746Z,1671554887.746 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg
2022-12-20T16:48:07.859Z,1671554887.859 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg
2022-12-20T16:48:08.004Z,1671554888.004 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg
2022-12-20T16:48:08.104Z,1671554888.104 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg
2022-12-20T16:48:08.197Z,1671554888.197 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2022-12-20T16:48:08.213Z,1671554888.213 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2022-12-20T16:48:08.230Z,1671554888.230 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2022-12-20T16:48:08.230Z,1671554888.230 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2022-12-20T16:48:08.358Z,1671554888.358 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2022-12-20T16:48:08.360Z,1671554888.360 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2022-12-20T16:48:08.428Z,1671554888.428 [VerticalControl](DEBUG): Construct VerticalControl.
2022-12-20T16:48:08.489Z,1671554888.489 [VerticalControl] Loaded
2022-12-20T16:48:08.489Z,1671554888.489 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2022-12-20T16:48:08.492Z,1671554888.492 [HorizontalControl](DEBUG): Construct HorizontalControl.
2022-12-20T16:48:08.533Z,1671554888.533 [HorizontalControl] Loaded
2022-12-20T16:48:08.533Z,1671554888.533 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2022-12-20T16:48:08.535Z,1671554888.535 [SpeedControl](DEBUG): Construct SpeedControl.
2022-12-20T16:48:08.539Z,1671554888.539 [SpeedControl] Loaded
2022-12-20T16:48:08.539Z,1671554888.539 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2022-12-20T16:48:08.542Z,1671554888.542 [LoopControl](DEBUG): Construct LoopControl.
2022-12-20T16:48:08.542Z,1671554888.542 [LoopControl] Loaded
2022-12-20T16:48:08.542Z,1671554888.542 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2022-12-20T16:48:08.543Z,1671554888.543 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2022-12-20T16:48:08.543Z,1671554888.543 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2022-12-20T16:48:08.729Z,1671554888.729 [BuoyancyServo] Loaded
2022-12-20T16:48:08.729Z,1671554888.729 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2022-12-20T16:48:08.749Z,1671554888.749 [ElevatorServo] Loaded
2022-12-20T16:48:08.749Z,1671554888.749 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2022-12-20T16:48:08.768Z,1671554888.768 [MassServo] Loaded
2022-12-20T16:48:08.769Z,1671554888.769 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2022-12-20T16:48:08.787Z,1671554888.787 [RudderServo] Loaded
2022-12-20T16:48:08.787Z,1671554888.787 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2022-12-20T16:48:08.802Z,1671554888.802 [ThrusterHE] Loaded
2022-12-20T16:48:08.802Z,1671554888.802 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2022-12-20T16:48:08.803Z,1671554888.803 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2022-12-20T16:48:08.803Z,1671554888.803 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2022-12-20T16:48:08.874Z,1671554888.874 [DepthRateCalculator] Loaded
2022-12-20T16:48:08.874Z,1671554888.874 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2022-12-20T16:48:08.879Z,1671554888.879 [PitchRateCalculator] Loaded
2022-12-20T16:48:08.879Z,1671554888.879 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2022-12-20T16:48:08.889Z,1671554888.889 [SpeedCalculator] Loaded
2022-12-20T16:48:08.890Z,1671554888.890 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2022-12-20T16:48:08.894Z,1671554888.894 [YawRateCalculator] Loaded
2022-12-20T16:48:08.894Z,1671554888.894 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2022-12-20T16:48:08.913Z,1671554888.913 [ElevatorOffsetCalculator] Loaded
2022-12-20T16:48:08.913Z,1671554888.913 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2022-12-20T16:48:08.913Z,1671554888.913 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2022-12-20T16:48:08.914Z,1671554888.914 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2022-12-20T16:48:09.054Z,1671554889.054 [DeadReckonUsingMultipleVelocitySources] Loaded
2022-12-20T16:48:09.054Z,1671554889.054 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2022-12-20T16:48:09.067Z,1671554889.067 [NavChart] Loaded
2022-12-20T16:48:09.068Z,1671554889.068 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2022-12-20T16:48:09.073Z,1671554889.073 [UniversalFixResidualReporter] Loaded
2022-12-20T16:48:09.074Z,1671554889.074 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2022-12-20T16:48:09.074Z,1671554889.074 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2022-12-20T16:48:09.075Z,1671554889.075 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2022-12-20T16:48:09.790Z,1671554889.790 [AHRS_M2] Loaded
2022-12-20T16:48:09.790Z,1671554889.790 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2022-12-20T16:48:10.039Z,1671554890.039 [BackseatComponent] Loaded
2022-12-20T16:48:10.040Z,1671554890.040 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2022-12-20T16:48:10.041Z,1671554890.041 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408D14E0
2022-12-20T16:48:10.041Z,1671554890.041 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 922
2022-12-20T16:48:10.044Z,1671554890.044 [LcmUniversalReporter] Loaded
2022-12-20T16:48:10.044Z,1671554890.044 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2022-12-20T16:48:10.878Z,1671554890.878 [BPC1] Loaded
2022-12-20T16:48:10.879Z,1671554890.879 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2022-12-20T16:48:11.022Z,1671554891.022 [DataOverHttps] Loaded
2022-12-20T16:48:11.022Z,1671554891.022 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2022-12-20T16:48:11.023Z,1671554891.023 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409014E0
2022-12-20T16:48:11.023Z,1671554891.023 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 923
2022-12-20T16:48:11.044Z,1671554891.044 [Depth_Keller] Loaded
2022-12-20T16:48:11.044Z,1671554891.044 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2022-12-20T16:48:11.049Z,1671554891.049 [DropWeight] Loaded
2022-12-20T16:48:11.050Z,1671554891.050 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2022-12-20T16:48:11.112Z,1671554891.112 [NAL9602] Loaded
2022-12-20T16:48:11.112Z,1671554891.112 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2022-12-20T16:48:11.142Z,1671554891.142 [Onboard] Loaded
2022-12-20T16:48:11.142Z,1671554891.142 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2022-12-20T16:48:11.143Z,1671554891.143 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409314E0
2022-12-20T16:48:11.144Z,1671554891.144 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 924
2022-12-20T16:48:11.156Z,1671554891.156 [Power24vConverter] Loaded
2022-12-20T16:48:11.156Z,1671554891.156 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2022-12-20T16:48:11.169Z,1671554891.169 [Radio_Surface] Loaded
2022-12-20T16:48:11.170Z,1671554891.170 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2022-12-20T16:48:11.171Z,1671554891.171 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409614E0
2022-12-20T16:48:11.171Z,1671554891.171 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 925
2022-12-20T16:48:11.264Z,1671554891.264 [DAT] Loaded
2022-12-20T16:48:11.264Z,1671554891.264 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2022-12-20T16:48:11.265Z,1671554891.265 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 409914E0
2022-12-20T16:48:11.265Z,1671554891.265 [DAT ThreadHandler](INFO): Protected caller Thread ID is 926
2022-12-20T16:48:11.266Z,1671554891.266 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2022-12-20T16:48:11.267Z,1671554891.267 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2022-12-20T16:48:11.821Z,1671554891.821 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2022-12-20T16:48:11.821Z,1671554891.821 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2022-12-20T16:48:12.067Z,1671554892.067 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2022-12-20T16:48:12.068Z,1671554892.068 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2022-12-20T16:48:12.110Z,1671554892.110 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2022-12-20T16:48:12.111Z,1671554892.111 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2022-12-20T16:48:12.332Z,1671554892.332 [CTD_Seabird] Loaded
2022-12-20T16:48:12.333Z,1671554892.333 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2022-12-20T16:48:12.334Z,1671554892.334 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40ABC4E0
2022-12-20T16:48:12.334Z,1671554892.334 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 927
2022-12-20T16:48:12.355Z,1671554892.355 [PAR_Licor] Loaded
2022-12-20T16:48:12.355Z,1671554892.355 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2022-12-20T16:48:12.386Z,1671554892.386 [WetLabsBB2FL] Loaded
2022-12-20T16:48:12.387Z,1671554892.387 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2022-12-20T16:48:12.387Z,1671554892.387 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AEC4E0
2022-12-20T16:48:12.388Z,1671554892.388 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 928
2022-12-20T16:48:12.389Z,1671554892.389 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2022-12-20T16:48:12.389Z,1671554892.389 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2022-12-20T16:48:12.755Z,1671554892.755 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2022-12-20T16:48:12.755Z,1671554892.755 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2022-12-20T16:48:12.929Z,1671554892.929 [SBIT](DEBUG): Construct Startup Built In Test.
2022-12-20T16:48:12.938Z,1671554892.938 [SBIT] Loaded
2022-12-20T16:48:12.939Z,1671554892.939 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2022-12-20T16:48:12.942Z,1671554892.942 [IBIT](DEBUG): Construct Initiated Built In Test.
2022-12-20T16:48:12.955Z,1671554892.955 [IBIT] Loaded
2022-12-20T16:48:12.956Z,1671554892.956 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2022-12-20T16:48:12.961Z,1671554892.961 [CBIT](DEBUG): Construct Continuous Built In Test.
2022-12-20T16:48:13.065Z,1671554893.065 [CBIT] Loaded
2022-12-20T16:48:13.066Z,1671554893.066 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2022-12-20T16:48:13.066Z,1671554893.066 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2022-12-20T16:48:13.072Z,1671554893.072 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2022-12-20T16:48:13.075Z,1671554893.075 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2022-12-20T16:48:13.087Z,1671554893.087 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2022-12-20T16:48:13.088Z,1671554893.088 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BCF4E0
2022-12-20T16:48:13.088Z,1671554893.088 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 929
2022-12-20T16:48:13.092Z,1671554893.092 [Supervisor](INFO): Main Thread ID is 831
2022-12-20T16:48:13.092Z,1671554893.092 [Supervisor](DEBUG): Running supervisor.
2022-12-20T16:48:13.093Z,1671554893.093 [CommandExec ThreadHandler](INFO): Handler Thread ID is 930
2022-12-20T16:48:13.094Z,1671554893.094 [CommandExec](INFO): Initializing the command executive.
2022-12-20T16:48:13.095Z,1671554893.095 [CommandLine ThreadHandler](INFO): Handler Thread ID is 931
2022-12-20T16:48:13.097Z,1671554893.097 [controlThread ThreadHandler](INFO): Handler Thread ID is 932
2022-12-20T16:48:13.098Z,1671554893.098 [controlThread](DEBUG): Initializing ControlThread
2022-12-20T16:48:13.098Z,1671554893.098 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2022-12-20T16:48:13.100Z,1671554893.100 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2022-12-20T16:48:13.101Z,1671554893.101 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2022-12-20T16:48:13.101Z,1671554893.101 [LoopControl](DEBUG): Initialize LoopControlComponent.
2022-12-20T16:48:13.103Z,1671554893.103 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2022-12-20T16:48:13.103Z,1671554893.103 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2022-12-20T16:48:13.103Z,1671554893.103 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2022-12-20T16:48:13.104Z,1671554893.104 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2022-12-20T16:48:13.104Z,1671554893.104 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2022-12-20T16:48:13.106Z,1671554893.106 [NavChart](DEBUG): Initialize NavChart Navigation.
2022-12-20T16:48:13.106Z,1671554893.106 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2022-12-20T16:48:13.113Z,1671554893.113 [SBIT](INFO): Initialize SBIT Component.
2022-12-20T16:48:13.114Z,1671554893.114 [SBIT](IMPORTANT): git: 2022-12-14
2022-12-20T16:48:13.114Z,1671554893.114 [SBIT](INFO): git hash: c3aea31d7798b2e77c1fbaec46e28ec3366e0fcc
2022-12-20T16:48:13.114Z,1671554893.114 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2022-12-20T16:48:13.115Z,1671554893.115 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2022-12-20T16:48:13.116Z,1671554893.116 [SBIT](INFO): Beginning SBIT in 99.000000 seconds.
2022-12-20T16:48:13.117Z,1671554893.117 [IBIT](INFO): Initialize IBIT Component.
2022-12-20T16:48:13.118Z,1671554893.118 [CBIT](DEBUG): Initialize CBIT Component.
2022-12-20T16:48:13.119Z,1671554893.119 [logger ThreadHandler](INFO): Handler Thread ID is 933
2022-12-20T16:48:13.129Z,1671554893.129 [CBIT](DEBUG): Initialized mux pins.
2022-12-20T16:48:13.129Z,1671554893.129 [CBIT](DEBUG): Initializing the watchdog timer.
2022-12-20T16:48:13.138Z,1671554893.138 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 934
2022-12-20T16:48:13.149Z,1671554893.149 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 935
2022-12-20T16:48:13.150Z,1671554893.150 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2022-12-20T16:48:13.153Z,1671554893.153 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2022-12-20T16:48:13.154Z,1671554893.154 [CBIT](DEBUG): Initializing heartbeat.
2022-12-20T16:48:13.161Z,1671554893.161 [Onboard ThreadHandler](INFO): Handler Thread ID is 936
2022-12-20T16:48:13.179Z,1671554893.179 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 937
2022-12-20T16:48:13.201Z,1671554893.201 [DAT ThreadHandler](INFO): Handler Thread ID is 938
2022-12-20T16:48:13.202Z,1671554893.202 [DAT](INFO): Powering up
2022-12-20T16:48:13.202Z,1671554893.202 [DAT](DEBUG): Initializing DAT.
2022-12-20T16:48:13.206Z,1671554893.206 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 940
2022-12-20T16:48:13.207Z,1671554893.207 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2022-12-20T16:48:13.210Z,1671554893.210 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 942
2022-12-20T16:48:13.213Z,1671554893.213 [WetLabsBB2FL](INFO): Powering up
2022-12-20T16:48:13.215Z,1671554893.215 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 944
2022-12-20T16:48:13.222Z,1671554893.222 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2022-12-20T16:48:13.222Z,1671554893.222 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2022-12-20T16:48:13.223Z,1671554893.223 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2022-12-20T16:48:13.223Z,1671554893.223 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2022-12-20T16:48:13.223Z,1671554893.223 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2022-12-20T16:48:13.223Z,1671554893.223 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2022-12-20T16:48:13.223Z,1671554893.223 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2022-12-20T16:48:13.223Z,1671554893.223 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2022-12-20T16:48:13.225Z,1671554893.225 [CBIT](DEBUG): Deactivating GF circuits.
2022-12-20T16:48:13.225Z,1671554893.225 [CBIT](DEBUG): Deactivating emergency mode.
2022-12-20T16:48:13.261Z,1671554893.261 [CBIT](DEBUG): Backplane powered.
2022-12-20T16:48:13.262Z,1671554893.262 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2022-12-20T16:48:13.290Z,1671554893.290 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2022-12-20T16:48:13.326Z,1671554893.326 [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-12-20T16:48:13.326Z,1671554893.326 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2022-12-20T16:48:13.406Z,1671554893.406 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2022-12-20T16:48:13.407Z,1671554893.407 [Default:A.Wait](DEBUG): Construct Wait.
2022-12-20T16:48:13.410Z,1671554893.410 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2022-12-20T16:48:13.444Z,1671554893.444 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2022-12-20T16:48:13.447Z,1671554893.447 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2022-12-20T16:48:13.465Z,1671554893.465 [Default:E.Execute](DEBUG): Construct Execute.
2022-12-20T16:48:13.468Z,1671554893.468 [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="P4H">
                <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-12-20T16:48:13.485Z,1671554893.485 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2022-12-20T16:48:13.492Z,1671554893.492 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2022-12-20T16:48:13.585Z,1671554893.585 [Radio_Surface](INFO): Powering up
2022-12-20T16:48:13.659Z,1671554893.659 [Power24vConverter](INFO): Powering up.
2022-12-20T16:48:13.695Z,1671554893.695 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2022-12-20T16:48:13.701Z,1671554893.701 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2022-12-20T16:48:13.702Z,1671554893.702 [ElevatorServo](DEBUG): Initializing EZServoServo.
2022-12-20T16:48:13.709Z,1671554893.709 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2022-12-20T16:48:13.710Z,1671554893.710 [MassServo](DEBUG): Initializing EZServoServo.
2022-12-20T16:48:13.718Z,1671554893.718 [MassServo](DEBUG): Initializing MassServo.
2022-12-20T16:48:13.718Z,1671554893.718 [RudderServo](DEBUG): Initializing EZServoServo.
2022-12-20T16:48:13.725Z,1671554893.725 [RudderServo](DEBUG): Initializing RudderServo.
2022-12-20T16:48:13.726Z,1671554893.726 [ThrusterHE](DEBUG): Initializing EZServoServo.
2022-12-20T16:48:13.733Z,1671554893.733 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2022-12-20T16:48:14.669Z,1671554894.669 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2022-12-20T16:48:14.669Z,1671554894.669 [RudderServo](FAULT): Rudder failed to initialize
2022-12-20T16:48:14.669Z,1671554894.669 [RudderServo] Communications Fault, FailCount= 1
2022-12-20T16:48:14.669Z,1671554894.669 [RudderServo](ERROR): Communications Fault
2022-12-20T16:48:14.673Z,1671554894.673 [CBIT](ERROR): Communications Fault in component: RudderServo
2022-12-20T16:48:14.874Z,1671554894.874 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-12-20T16:48:14.874Z,1671554894.874 [RudderServo](INFO): Powering down
2022-12-20T16:48:15.321Z,1671554895.321 [WetLabsBB2FL](INFO): Powering down
2022-12-20T16:48:15.549Z,1671554895.549 [RudderServo](DEBUG): Initializing EZServoServo.
2022-12-20T16:48:15.670Z,1671554895.670 [RudderServo](DEBUG): Initializing RudderServo.
2022-12-20T16:48:15.674Z,1671554895.674 [CBIT](INFO): Clearing failed state for component RudderServo
2022-12-20T16:48:15.674Z,1671554895.674 [RudderServo] No Fault, FailCount= 1
2022-12-20T16:48:19.506Z,1671554899.506 [ThrusterHE](ERROR): Zero Speed Commanded.
2022-12-20T16:48:25.298Z,1671554905.298 [DAT](INFO): DAT read: 

2022-12-20T16:48:25.299Z,1671554905.299 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2022-12-20T16:48:27.062Z,1671554907.062 [DAT](INFO): DAT read: MF Frequency Band

2022-12-20T16:48:27.063Z,1671554907.063 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2022-12-20T16:48:27.064Z,1671554907.064 [DAT](INFO): DAT read: Dec 20 2022 16:48:20 

2022-12-20T16:48:28.070Z,1671554908.070 [DAT](INFO): DAT read: Features enabled [Bearing]

2022-12-20T16:48:28.071Z,1671554908.071 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2022-12-20T16:48:28.072Z,1671554908.072 [DAT](INFO): commRate: 800
2022-12-20T16:48:30.137Z,1671554910.137 [DAT](INFO): entering command mode
2022-12-20T16:48:30.338Z,1671554910.338 [DAT](INFO): DAT read: 

2022-12-20T16:48:30.338Z,1671554910.338 [DAT](INFO): DAT read: user:1>

2022-12-20T16:48:30.339Z,1671554910.339 [DAT](INFO): setting verbose to 3
2022-12-20T16:48:30.590Z,1671554910.590 [DAT](INFO): DAT read: user:1>

2022-12-20T16:48:30.591Z,1671554910.591 [DAT](INFO): DAT read: Verbose         | 3           

2022-12-20T16:48:30.591Z,1671554910.591 [DAT](INFO): set verbose to 3
2022-12-20T16:48:30.591Z,1671554910.591 [DAT](INFO): setting DatVerbose to 27440
2022-12-20T16:48:30.842Z,1671554910.842 [DAT](INFO): DAT read: user:2>

2022-12-20T16:48:30.843Z,1671554910.843 [DAT](INFO): DAT read: DatVerbose      | 27440       

2022-12-20T16:48:30.843Z,1671554910.843 [DAT](INFO): set DatVerbose to 27440
2022-12-20T16:48:30.843Z,1671554910.843 [DAT](INFO): setting transmit power to 8
2022-12-20T16:48:31.094Z,1671554911.094 [DAT](INFO): DAT read: user:3>

2022-12-20T16:48:31.095Z,1671554911.095 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2022-12-20T16:48:31.095Z,1671554911.095 [DAT](INFO): set transmit power to 8
2022-12-20T16:48:31.095Z,1671554911.095 [DAT](INFO): setting local address to 5
2022-12-20T16:48:31.346Z,1671554911.346 [DAT](INFO): DAT read: user:4>

2022-12-20T16:48:31.347Z,1671554911.347 [DAT](INFO): DAT read: LocalAddr       | 5           

2022-12-20T16:48:31.347Z,1671554911.347 [DAT](INFO): set local address to 5
2022-12-20T16:48:31.348Z,1671554911.348 [DAT](INFO): Setting time to: 16:48:31 And date to:12/20/2022
2022-12-20T16:48:31.598Z,1671554911.598 [DAT](INFO): DAT read: user:5>

2022-12-20T16:48:31.599Z,1671554911.599 [DAT](INFO): DAT read: Tue Dec 20, 2022  16:48:31  

2022-12-20T16:48:31.599Z,1671554911.599 [DAT](INFO): Local DAT time set to Tue Dec 20, 2022  16:48:31  

2022-12-20T16:48:41.399Z,1671554921.399 [NAL9602](INFO): Powering up NAL9602
2022-12-20T16:48:52.307Z,1671554932.307 [NAL9602](INFO): NAL9602 initialized
2022-12-20T16:49:52.937Z,1671554992.937 [SBIT](IMPORTANT): Beginning Startup BIT
2022-12-20T16:49:52.941Z,1671554992.941 [CBIT](IMPORTANT): Beginning ground fault scan
2022-12-20T16:50:03.887Z,1671555003.887 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.010222
CHAN A1 (24V): -0.007790
CHAN A2 (12V): -0.004731
CHAN A3 (5V): -0.003019
CHAN B0 (3.3V): -0.000898
CHAN B1 (3.15aV): -0.001364
CHAN B2 (3.15bV): -0.001603
CHAN B3 (GND): -0.000098
OPEN: -0.004749
Full Scale: +/- 1 mA
2022-12-20T16:50:46.143Z,1671555046.143 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004645
2022-12-20T16:50:47.089Z,1671555047.089 [SBIT](IMPORTANT): SBIT PASSED
2022-12-20T16:50:47.089Z,1671555047.089 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2022-12-20T16:50:47.090Z,1671555047.090 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=6 count;

2022-12-20T16:50:47.090Z,1671555047.090 [SBIT](IMPORTANT): BackseatComponent.alwaysOn=0 bool;

2022-12-20T16:50:47.090Z,1671555047.090 [SBIT](IMPORTANT): CBIT.runNavErrorCritical=0 bool;

2022-12-20T16:50:47.090Z,1671555047.090 [SBIT](IMPORTANT): CTD_Seabird.minSalinityBound=0 practical_salinity_unit;

2022-12-20T16:50:47.090Z,1671555047.090 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water;

2022-12-20T16:50:47.090Z,1671555047.090 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water;

2022-12-20T16:50:47.091Z,1671555047.091 [SBIT](IMPORTANT): Express linearApproximation platform_roll_angle 5.000000 degree;

2022-12-20T16:50:47.091Z,1671555047.091 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=30 ampere_hour;

2022-12-20T16:50:47.091Z,1671555047.091 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=12 volt;

2022-12-20T16:50:47.091Z,1671555047.091 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=324.282117 cubic_centimeter;

2022-12-20T16:50:47.091Z,1671555047.091 [SBIT](IMPORTANT): VerticalControl.massDefault=20 millimeter;

2022-12-20T16:50:47.471Z,1671555047.471 [MissionManager](IMPORTANT): Started mission Startup
2022-12-20T16:50:47.472Z,1671555047.472 [Startup] Running Loop=1
2022-12-20T16:50:47.472Z,1671555047.472 [Startup](DEBUG): Aggregate::initialize Startup
2022-12-20T16:50:47.472Z,1671555047.472 [Startup:A.GoToSurface] Running Loop=1
2022-12-20T16:50:47.472Z,1671555047.472 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-12-20T16:50:47.473Z,1671555047.473 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-12-20T16:50:47.473Z,1671555047.473 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-12-20T16:50:47.474Z,1671555047.474 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-12-20T16:50:47.474Z,1671555047.474 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-12-20T16:50:47.474Z,1671555047.474 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-12-20T16:50:47.476Z,1671555047.476 [Startup:StartupSatComms] Running Loop=1
2022-12-20T16:50:47.476Z,1671555047.476 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2022-12-20T16:50:47.476Z,1671555047.476 [Startup:StartupSatComms:A] Running Loop=1
2022-12-20T16:50:47.872Z,1671555047.872 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2022-12-20T16:50:58.269Z,1671555058.269 [CommandExec](IMPORTANT): got command get Onboard.Pressure
2022-12-20T16:50:58.269Z,1671555058.269 [CommandExec](IMPORTANT): Onboard.Pressure 63485.738281 Pa
2022-12-20T16:51:06.328Z,1671555066.328 [CommandExec](IMPORTANT): got command get Onboard.Humidity
2022-12-20T16:51:06.329Z,1671555066.329 [CommandExec](IMPORTANT): Onboard.Humidity 12.904408 %
2022-12-20T16:51:13.501Z,1671555073.501 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2022-12-20T16:51:13.501Z,1671555073.501 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-12-20T16:51:13.512Z,1671555073.512 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-12-20T16:51:13.880Z,1671555073.880 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-12-20T16:51:13.880Z,1671555073.880 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2022-12-20T16:51:47.813Z,1671555107.813 [Startup:StartupSatComms:A](INFO): Timed out from 2022-12-20T16:50:47.5Z
2022-12-20T16:51:47.813Z,1671555107.813 [Startup:StartupSatComms:A] Stopped
2022-12-20T16:51:47.813Z,1671555107.813 [Startup:StartupSatComms:B] Running Loop=1
2022-12-20T16:51:48.209Z,1671555108.209 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-12-20T16:51:55.212Z,1671555115.212 [DataOverHttps](INFO): Sending 51 bytes from file Logs/20221219T224921/Courier0052.lzma
2022-12-20T16:51:56.213Z,1671555116.213 [DataOverHttps](INFO): Moved sent file to Logs/20221219T224921/Courier0052.lzma.bak
2022-12-20T16:51:56.213Z,1671555116.213 [DataOverHttps](INFO): SBD MOMSN=17399423
2022-12-20T16:52:13.439Z,1671555133.439 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20221220T164801/Courier0000.lzma
2022-12-20T16:52:14.441Z,1671555134.441 [DataOverHttps](INFO): Moved sent file to Logs/20221220T164801/Courier0000.lzma.bak
2022-12-20T16:52:14.441Z,1671555134.441 [DataOverHttps](INFO): SBD MOMSN=17399425
2022-12-20T16:52:48.069Z,1671555168.069 [Startup:StartupSatComms:B](INFO): Timed out from 2022-12-20T16:51:47.8Z
2022-12-20T16:52:48.069Z,1671555168.069 [Startup:StartupSatComms:B] Stopped
2022-12-20T16:52:48.070Z,1671555168.070 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2022-12-20T16:52:48.070Z,1671555168.070 [Startup:StartupSatComms] Stopped
2022-12-20T16:52:48.070Z,1671555168.070 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2022-12-20T16:52:48.071Z,1671555168.071 [Startup](INFO): Completed Startup
2022-12-20T16:52:48.071Z,1671555168.071 [MissionManager](INFO): Startup is completed.
2022-12-20T16:52:48.071Z,1671555168.071 [MissionManager](INFO): Uninitializing Mission Startup
2022-12-20T16:52:48.071Z,1671555168.071 [Startup] Stopped
2022-12-20T16:52:48.071Z,1671555168.071 [Startup](DEBUG): Aggregate::uninitialize Startup
2022-12-20T16:52:48.071Z,1671555168.071 [Startup:A.GoToSurface] Stopped
2022-12-20T16:52:48.071Z,1671555168.071 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-12-20T16:52:48.449Z,1671555168.449 [MissionManager](IMPORTANT): Started mission Default
2022-12-20T16:52:48.449Z,1671555168.449 [Default] Running Loop=1
2022-12-20T16:52:48.449Z,1671555168.449 [Default](DEBUG): Aggregate::initialize Default
2022-12-20T16:52:48.450Z,1671555168.450 [Default:B.GoToSurface] Running Loop=1
2022-12-20T16:52:48.450Z,1671555168.450 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-12-20T16:52:48.450Z,1671555168.450 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-12-20T16:52:48.450Z,1671555168.450 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-12-20T16:52:48.475Z,1671555168.475 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-12-20T16:52:48.479Z,1671555168.479 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-12-20T16:52:48.479Z,1671555168.479 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-12-20T16:52:48.480Z,1671555168.480 [Default:A.Wait] Running Loop=1
2022-12-20T16:52:48.480Z,1671555168.480 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-12-20T16:53:01.548Z,1671555181.548 [DataOverHttps](INFO): Sending 219 bytes from file Logs/20221219T224921/Express0053.lzma
2022-12-20T16:53:01.794Z,1671555181.794 [Default:A.Wait](INFO): Done Waiting.
2022-12-20T16:53:01.794Z,1671555181.794 [Default:A.Wait] Stopped
2022-12-20T16:53:01.794Z,1671555181.794 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T16:53:02.206Z,1671555182.206 [Default:CheckIn] Running Loop=1
2022-12-20T16:53:02.206Z,1671555182.206 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T16:53:02.206Z,1671555182.206 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T16:53:02.549Z,1671555182.549 [DataOverHttps](INFO): Moved sent file to Logs/20221219T224921/Express0053.lzma.bak
2022-12-20T16:53:02.549Z,1671555182.549 [DataOverHttps](INFO): SBD MOMSN=17399428
2022-12-20T16:53:02.632Z,1671555182.632 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2022-12-20T16:53:56.371Z,1671555236.371 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-20T16:54:14.520Z,1671555254.520 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2022-12-20T16:54:14.520Z,1671555254.520 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-12-20T16:54:14.531Z,1671555254.531 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-12-20T16:54:14.944Z,1671555254.944 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-12-20T16:54:14.944Z,1671555254.944 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2022-12-20T16:54:50.038Z,1671555290.038 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T16:55:03.370Z,1671555303.370 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T16:55:16.701Z,1671555316.701 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T16:55:30.034Z,1671555330.034 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T16:55:42.962Z,1671555342.962 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T16:55:56.299Z,1671555356.299 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T16:56:09.625Z,1671555369.625 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T16:56:22.958Z,1671555382.958 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T16:56:36.289Z,1671555396.289 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T16:56:49.623Z,1671555409.623 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T16:57:02.954Z,1671555422.954 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T16:57:15.531Z,1671555435.531 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2022-12-20T16:57:15.531Z,1671555435.531 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-12-20T16:57:15.542Z,1671555435.542 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-12-20T16:57:16.007Z,1671555436.007 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-12-20T16:57:16.007Z,1671555436.007 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2022-12-20T16:58:02.414Z,1671555482.414 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-12-20T16:53:02.2Z
2022-12-20T16:58:02.414Z,1671555482.414 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T16:58:02.414Z,1671555482.414 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T16:58:02.800Z,1671555482.800 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-12-20T16:58:09.954Z,1671555489.954 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20221220T164801/Courier0004.lzma
2022-12-20T16:58:10.957Z,1671555490.957 [DataOverHttps](INFO): Moved sent file to Logs/20221220T164801/Courier0004.lzma.bak
2022-12-20T16:58:10.957Z,1671555490.957 [DataOverHttps](INFO): SBD MOMSN=17399435
2022-12-20T16:58:26.606Z,1671555506.606 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20221220T164613/Express0001.lzma
2022-12-20T16:58:27.608Z,1671555507.608 [DataOverHttps](INFO): Moved sent file to Logs/20221220T164613/Express0001.lzma.bak
2022-12-20T16:58:27.609Z,1671555507.609 [DataOverHttps](INFO): SBD MOMSN=17399437
2022-12-20T16:58:46.401Z,1671555526.401 [DataOverHttps](INFO): Sending 1093 bytes from file Logs/20221220T164801/Express0001.lzma
2022-12-20T16:58:47.401Z,1671555527.401 [DataOverHttps](INFO): Moved sent file to Logs/20221220T164801/Express0001.lzma.bak
2022-12-20T16:58:47.401Z,1671555527.401 [DataOverHttps](INFO): SBD MOMSN=17399440
2022-12-20T16:58:54.520Z,1671555534.520 [NAL9602](FAULT): GPS failed to acquire within timeout.
2022-12-20T16:58:54.520Z,1671555534.520 [NAL9602] Data Fault, FailCount= 1
2022-12-20T16:58:54.520Z,1671555534.520 [NAL9602](ERROR): Data Fault
2022-12-20T16:58:54.537Z,1671555534.537 [CBIT](ERROR): Data Fault in component: NAL9602
2022-12-20T16:58:54.924Z,1671555534.924 [NAL9602](INFO): Powering down
2022-12-20T16:58:55.818Z,1671555535.818 [CBIT](INFO): Clearing failed state for component NAL9602
2022-12-20T16:58:55.818Z,1671555535.818 [NAL9602] No Fault, FailCount= 1
2022-12-20T16:59:03.323Z,1671555543.323 [DataOverHttps](INFO): Sending 196 bytes from file Logs/20221220T164801/Express0005.lzma
2022-12-20T16:59:04.325Z,1671555544.325 [DataOverHttps](INFO): Moved sent file to Logs/20221220T164801/Express0005.lzma.bak
2022-12-20T16:59:04.325Z,1671555544.325 [DataOverHttps](INFO): SBD MOMSN=17399467
2022-12-20T16:59:05.449Z,1671555545.449 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T16:59:05.449Z,1671555545.449 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T16:59:05.449Z,1671555545.449 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T16:59:25.276Z,1671555565.276 [NAL9602](INFO): Powering up NAL9602
2022-12-20T16:59:34.575Z,1671555574.575 [CommandExec](IMPORTANT): got command failComponent
2022-12-20T16:59:34.576Z,1671555574.576 [CommandExec](IMPORTANT): Failed components:
2022-12-20T16:59:34.576Z,1671555574.576 [CommandExec](IMPORTANT): No failed Components.
2022-12-20T16:59:36.184Z,1671555576.184 [NAL9602](INFO): NAL9602 initialized
2022-12-20T17:00:16.616Z,1671555616.616 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2022-12-20T17:00:16.616Z,1671555616.616 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-12-20T17:00:16.627Z,1671555616.627 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-12-20T17:00:17.029Z,1671555617.029 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-12-20T17:00:17.029Z,1671555617.029 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2022-12-20T17:02:04.923Z,1671555724.923 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170203.00,A,3648.16354,N,12147.28341,W,0.078,0.00,201222,,,A*74
2022-12-20T17:02:04.926Z,1671555724.926 [NAL9602](INFO): GPS fix at 20221220T170203: (36.802726, -121.788057)
2022-12-20T17:02:11.700Z,1671555731.700 [DataOverHttps](IMPORTANT): SBD MTMSN=20221220T170210
2022-12-20T17:02:19.947Z,1671555739.947 [DataOverHttps](INFO): Received command: run Maintenance/tank_ballast_and_trim.xml
2022-12-20T17:02:20.020Z,1671555740.020 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/tank_ballast_and_trim.xml
2022-12-20T17:02:20.020Z,1671555740.020 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/tank_ballast_and_trim.xml
2022-12-20T17:02:20.107Z,1671555740.107 [MissionManager](INFO): DefineArg ballast_and_trim.MissionTimeout = 120.000000 min
2022-12-20T17:02:20.110Z,1671555740.110 [MissionManager](INFO): DefineArg ballast_and_trim.SkipComms = 0 bool
2022-12-20T17:02:20.113Z,1671555740.113 [MissionManager](INFO): DefineArg ballast_and_trim.Depth1 = 7.000000 m
2022-12-20T17:02:20.116Z,1671555740.116 [MissionManager](INFO): DefineArg ballast_and_trim.Depth2 = nan m
2022-12-20T17:02:20.119Z,1671555740.119 [MissionManager](INFO): DefineArg ballast_and_trim.DepthDeadband = 0.100000 m
2022-12-20T17:02:20.122Z,1671555740.122 [MissionManager](INFO): DefineArg ballast_and_trim.SurfaceThreshold = 2.500000 m
2022-12-20T17:02:20.125Z,1671555740.125 [MissionManager](INFO): DefineArg ballast_and_trim.MaxWaitOnSurface = 20.000000 min
2022-12-20T17:02:20.128Z,1671555740.128 [MissionManager](INFO): DefineArg ballast_and_trim.SettleTime = 10.000000 min
2022-12-20T17:02:20.130Z,1671555740.130 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationTimeout = 45.000000 min
2022-12-20T17:02:20.167Z,1671555740.167 [MissionManager](INFO): DefineArg ballast_and_trim.MinEstimationTime = 10.000000 min
2022-12-20T17:02:20.170Z,1671555740.170 [MissionManager](INFO): DefineArg ballast_and_trim.MassEstimationErrorBound = 0.250000 mm
2022-12-20T17:02:20.181Z,1671555740.181 [MissionManager](INFO): DefineArg ballast_and_trim.BuoyEstimationErrorBound = 15.000000 cc
2022-12-20T17:02:20.186Z,1671555740.186 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationConfidence = 99.900002 %
2022-12-20T17:02:20.198Z,1671555740.198 [MissionManager](INFO): DefineArg ballast_and_trim.WaitToFloat = 5.000000 min
2022-12-20T17:02:20.219Z,1671555740.219 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/Science.xml
2022-12-20T17:02:20.901Z,1671555740.901 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectChlActive = 0 bool
2022-12-20T17:02:20.908Z,1671555740.908 [MissionManager](INFO): DefineArg ballast_and_trim:Science.TimeWindowPeakReport = nan min
2022-12-20T17:02:20.910Z,1671555740.910 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestChlPeakReportActive = 0 bool
2022-12-20T17:02:20.917Z,1671555740.917 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestSaltPeakReportActive = 0 bool
2022-12-20T17:02:20.924Z,1671555740.924 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestOilPeakReportActive = 0 bool
2022-12-20T17:02:20.926Z,1671555740.926 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PatchTracking = 0 bool
2022-12-20T17:02:20.933Z,1671555740.933 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DetectTrough = 0 bool
2022-12-20T17:02:20.976Z,1671555740.976 [MissionManager](INFO): DefineArg ballast_and_trim:Science.FilterWidthHorizontal = 3.000000 count
2022-12-20T17:02:20.987Z,1671555740.987 [MissionManager](INFO): DefineArg ballast_and_trim:Science.NumProfilesSlidingwindow = 100.000000 count
2022-12-20T17:02:20.990Z,1671555740.990 [MissionManager](INFO): DefineArg ballast_and_trim:Science.OffPeakFractionHorizontal = 80.000000 %
2022-12-20T17:02:21.001Z,1671555741.001 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectNO3Active = 0 bool
2022-12-20T17:02:21.036Z,1671555741.036 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectOilActive = 0 bool
2022-12-20T17:02:21.055Z,1671555741.055 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectFDOMActive = 0 bool
2022-12-20T17:02:21.058Z,1671555741.058 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectSalinityActive = 0 bool
2022-12-20T17:02:21.087Z,1671555741.087 [MissionManager](INFO): DefineArg ballast_and_trim:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2022-12-20T17:02:21.107Z,1671555741.107 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledAanderaaO2 = 0 bool
2022-12-20T17:02:21.110Z,1671555741.110 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledNeilBrown = 0 bool
2022-12-20T17:02:21.126Z,1671555741.126 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledSeabird = 1 bool
2022-12-20T17:02:21.161Z,1671555741.161 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsBB2FL = 1 bool
2022-12-20T17:02:21.185Z,1671555741.185 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsSeaOWL_UV_A = 0 bool
2022-12-20T17:02:21.192Z,1671555741.192 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsUBAT = 0 bool
2022-12-20T17:02:21.207Z,1671555741.207 [MissionManager](INFO): DefineArg ballast_and_trim:Science.LowPassWindowLength = 20.000000 count
2022-12-20T17:02:21.210Z,1671555741.210 [MissionManager](INFO): DefineArg ballast_and_trim:Science.MedianFilterLen = 5.000000 count
2022-12-20T17:02:21.230Z,1671555741.230 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakShallowBound = nan m
2022-12-20T17:02:21.237Z,1671555741.237 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDeepBound = nan m
2022-12-20T17:02:21.261Z,1671555741.261 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DepChangeThreshForAttitudeFlip = 2.000000 m
2022-12-20T17:02:21.272Z,1671555741.272 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChl = 0.000000 ug/l
2022-12-20T17:02:21.295Z,1671555741.295 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlDepth = 0.000000 m
2022-12-20T17:02:21.298Z,1671555741.298 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlTemperature = 0.000000 degC
2022-12-20T17:02:21.309Z,1671555741.309 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLatitude = nan arcdeg
2022-12-20T17:02:21.343Z,1671555741.343 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLongitude = nan arcdeg
2022-12-20T17:02:21.346Z,1671555741.346 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3 = 0.000000 umol/l
2022-12-20T17:02:21.354Z,1671555741.354 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Depth = 0.000000 m
2022-12-20T17:02:21.362Z,1671555741.362 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Latitude = nan arcdeg
2022-12-20T17:02:21.389Z,1671555741.389 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Longitude = nan arcdeg
2022-12-20T17:02:21.392Z,1671555741.392 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOil = 0.000000 kg/m3
2022-12-20T17:02:21.443Z,1671555741.443 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilDepth = 0.000000 m
2022-12-20T17:02:21.446Z,1671555741.446 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLatitude = nan arcdeg
2022-12-20T17:02:21.449Z,1671555741.449 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLongitude = nan arcdeg
2022-12-20T17:02:21.479Z,1671555741.479 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOM = 0.000000 ppb
2022-12-20T17:02:21.482Z,1671555741.482 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMDepth = 0.000000 m
2022-12-20T17:02:21.511Z,1671555741.511 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMTemperature = nan degC
2022-12-20T17:02:21.514Z,1671555741.514 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLatitude = nan arcdeg
2022-12-20T17:02:21.537Z,1671555741.537 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLongitude = nan arcdeg
2022-12-20T17:02:21.540Z,1671555741.540 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchFDOMDistance = nan m
2022-12-20T17:02:21.577Z,1671555741.577 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSalt = 0.000000 psu
2022-12-20T17:02:21.580Z,1671555741.580 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltDepth = 0.000000 m
2022-12-20T17:02:21.599Z,1671555741.599 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltTemperature = 0.000000 degC
2022-12-20T17:02:21.602Z,1671555741.602 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLatitude = nan arcdeg
2022-12-20T17:02:21.613Z,1671555741.613 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLongitude = nan arcdeg
2022-12-20T17:02:21.620Z,1671555741.620 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChl = 0.000000 ug/l
2022-12-20T17:02:21.643Z,1671555741.643 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDepth = 0.000000 m
2022-12-20T17:02:21.655Z,1671555741.655 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLatitude = nan arcdeg
2022-12-20T17:02:21.658Z,1671555741.658 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLongitude = nan arcdeg
2022-12-20T17:02:21.669Z,1671555741.669 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDistance = nan m
2022-12-20T17:02:21.677Z,1671555741.677 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSalt = 0.000000 psu
2022-12-20T17:02:21.692Z,1671555741.692 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDepth = 0.000000 m
2022-12-20T17:02:21.703Z,1671555741.703 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLatitude = nan arcdeg
2022-12-20T17:02:21.706Z,1671555741.706 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLongitude = nan arcdeg
2022-12-20T17:02:21.726Z,1671555741.726 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDistance = nan m
2022-12-20T17:02:21.734Z,1671555741.734 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOil = 0.000000 psu
2022-12-20T17:02:21.753Z,1671555741.753 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDepth = 0.000000 m
2022-12-20T17:02:21.765Z,1671555741.765 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLatitude = nan arcdeg
2022-12-20T17:02:21.772Z,1671555741.772 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLongitude = nan arcdeg
2022-12-20T17:02:21.795Z,1671555741.795 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDistance = nan m
2022-12-20T17:02:21.967Z,1671555741.967 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-12-20T17:02:22.013Z,1671555742.013 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2022-12-20T17:02:22.075Z,1671555742.075 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-12-20T17:02:22.110Z,1671555742.110 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-12-20T17:02:22.152Z,1671555742.152 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2022-12-20T17:02:22.216Z,1671555742.216 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-12-20T17:02:22.284Z,1671555742.284 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-12-20T17:02:22.344Z,1671555742.344 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2022-12-20T17:02:22.400Z,1671555742.400 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BallastAndTrim.xml
2022-12-20T17:02:22.672Z,1671555742.672 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepth = 25.000000 m
2022-12-20T17:02:22.696Z,1671555742.696 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSpeed = 0.000000 m/s
2022-12-20T17:02:22.699Z,1671555742.699 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthRate = 0.400000 m/s
2022-12-20T17:02:22.702Z,1671555742.702 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachPitchLimit = 20.000000 arcdeg
2022-12-20T17:02:22.752Z,1671555742.752 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSettleTimePreDive = 0.000000 min
2022-12-20T17:02:22.755Z,1671555742.755 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = 20.000000 min
2022-12-20T17:02:22.758Z,1671555742.758 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = 10.000000 min
2022-12-20T17:02:22.805Z,1671555742.805 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = 45.000000 min
2022-12-20T17:02:22.808Z,1671555742.808 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = 10.000000 min
2022-12-20T17:02:22.832Z,1671555742.832 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = 0.250000 mm
2022-12-20T17:02:22.837Z,1671555742.837 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = 15.000000 cc
2022-12-20T17:02:22.840Z,1671555742.840 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = 99.900002 %
2022-12-20T17:02:22.868Z,1671555742.868 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = 1.000000 m
2022-12-20T17:02:22.871Z,1671555742.871 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertMassDeadband = 0.250000 mm
2022-12-20T17:02:22.913Z,1671555742.913 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Construct.
2022-12-20T17:02:22.941Z,1671555742.941 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Construct Buoyancy.
2022-12-20T17:02:22.973Z,1671555742.973 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Construct.
2022-12-20T17:02:22.982Z,1671555742.982 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Construct Wait.
2022-12-20T17:02:23.012Z,1671555743.012 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Construct.
2022-12-20T17:02:23.015Z,1671555743.015 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Construct.
2022-12-20T17:02:23.089Z,1671555743.089 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute.
2022-12-20T17:02:23.109Z,1671555743.109 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Construct.
2022-12-20T17:02:23.114Z,1671555743.114 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Construct.
2022-12-20T17:02:23.141Z,1671555743.141 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Construct Wait.
2022-12-20T17:02:23.161Z,1671555743.161 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](DEBUG): Construct BallastAndTrim.
2022-12-20T17:02:23.226Z,1671555743.226 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = reader:ballast_and_trim.DepthDeadband
2022-12-20T17:02:23.245Z,1671555743.245 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = reader:ballast_and_trim.MaxWaitOnSurface
2022-12-20T17:02:23.251Z,1671555743.251 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = reader:ballast_and_trim.SettleTime
2022-12-20T17:02:23.252Z,1671555743.252 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = reader:ballast_and_trim.EstimationTimeout
2022-12-20T17:02:23.254Z,1671555743.254 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = reader:ballast_and_trim.MinEstimationTime
2022-12-20T17:02:23.260Z,1671555743.260 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = reader:ballast_and_trim.MassEstimationErrorBound
2022-12-20T17:02:23.262Z,1671555743.262 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = reader:ballast_and_trim.BuoyEstimationErrorBound
2022-12-20T17:02:23.268Z,1671555743.268 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = reader:ballast_and_trim.EstimationConfidence
2022-12-20T17:02:23.300Z,1671555743.300 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Construct Buoyancy.
2022-12-20T17:02:23.314Z,1671555743.314 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Construct Wait.
2022-12-20T17:02:23.396Z,1671555743.396 [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="ballast_and_trim">

    <DefineArg Name="MissionTimeout"><Description>
        Maximum duration of mission
    </Description><Units:minute/><Value>120</Value></DefineArg>

    <DefineArg Name="SkipComms"><Description>
        Skip communications at start of mission.
    </Description><False/></DefineArg>

    <DefineArg Name="Depth1"><Units:meter/><Value>7</Value></DefineArg>

    <DefineArg Name="Depth2"><Units:meter/><Value>NaN</Value></DefineArg>

    <DefineArg Name="DepthDeadband"><Description>
        How much vertical drift from the specified depth is allowed durnig the
        mission.
    </Description><Units:meter/><Value>0.1</Value></DefineArg>

    <DefineArg Name="SurfaceThreshold"><Description>
        Surface threshold depth.
    </Description><Units:meter/><Value>2.5</Value></DefineArg>

    <DefineArg Name="MaxWaitOnSurface"><Description>
        Maximum wait time for the vehicle to go under the surface (i.e., reach
        the surface threshold depth).
    </Description><Units:minute/><Value>20</Value></DefineArg>

    <DefineArg Name="SettleTime"><Description>
        How long to wait after reaching target depth before starting ballast and
        trim.
    </Description><Units:minute/><Value>10</Value></DefineArg>

    <DefineArg Name="EstimationTimeout"><Description>
        Timeout for ballast and trim estimation.
    </Description><Units:minute/><Value>45</Value></DefineArg>

    <DefineArg Name="MinEstimationTime"><Description>
        Minimum time to run ballast and trim estimation before determining
        convergence (must be shorter than timeout).
    </Description><Units:minute/><Value>10</Value></DefineArg>

    <DefineArg Name="MassEstimationErrorBound"><Description>
        Desired range of the estimated sample mean from the true mean statistic
        (smaller values take longer to converge).
    </Description><Units:millimeter/><Value>0.25</Value></DefineArg>

    <DefineArg Name="BuoyEstimationErrorBound"><Description>
        Desired range of the estimated sample mean from the true mean statistic
        (smaller values take longer to converge).
    </Description><Units:cubic_centimeter/><Value>15</Value></DefineArg>

    <DefineArg Name="EstimationConfidence"><Description>
        Confidence level that the estimator has reached the desired error range
        (larger values take longer to converge).
    </Description><Units:percent/><Value>99.9</Value></DefineArg>

    <DefineArg Name="WaitToFloat"><Units:minute/><Value>5</Value></DefineArg>

    <Timeout Duration="MissionTimeout"/>

    <Insert Filename="Insert/Science.xml"/>

    <Aggregate Id="RunBallastAndTrim">

        <Sequence/>

        <Insert Filename="Insert/BallastAndTrim.xml">
            <RedefineArg Name="InsertDepthDeadband"><Arg Name="DepthDeadband"/></RedefineArg>
            <RedefineArg Name="InsertApproachDepthTimeout"><Arg Name="MaxWaitOnSurface"/></RedefineArg>
            <RedefineArg Name="InsertSettleTime"><Arg Name="SettleTime"/></RedefineArg>
            <RedefineArg Name="EstTimeout"><Arg Name="EstimationTimeout"/></RedefineArg>
            <RedefineArg Name="MinEstTime"><Arg Name="MinEstimationTime"/></RedefineArg>
            <RedefineArg Name="MassEstErrorBound"><Arg Name="MassEstimationErrorBound"/></RedefineArg>
            <RedefineArg Name="BuoyEstErrorBound"><Arg Name="BuoyEstimationErrorBound"/></RedefineArg>
            <RedefineArg Name="EstConfidence"><Arg Name="EstimationConfidence"/></RedefineArg>
        </Insert>

        <Aggregate Id="Depth1">

            <Sequence/>

            <Break>
                <IsNaN><Arg Name="Depth1"/>
                </IsNaN>
            </Break>

            <Assign><Sequence/><Arg Name="BallastAndTrim:InsertDepth"/><Arg Name="Depth1"/></Assign>

            <Call RefId="BallastAndTrim"/>

        </Aggregate>

        <Aggregate Id="Depth2">

            <Sequence/>

            <Break>
                <IsNaN><Arg Name="Depth2"/>
                </IsNaN>
            </Break>

            <Assign><Sequence/><Arg Name="BallastAndTrim:InsertDepth"/><Arg Name="Depth1"/></Assign>

            <Call RefId="BallastAndTrim"/>

        </Aggregate>

    </Aggregate>

    <Aggregate Id="Float_Up">

        <Description>
            Float to surface instead of driving.
        </Description>

        <Sequence/>

        <Break>
            <Universal:depth/>
            <Lt><Control:VerticalControl.surfaceThreshold/></Lt>
        </Break>

        <Guidance:Buoyancy>
            <Parallel/>
            <Setting><Guidance:Buoyancy.position/><Control:VerticalControl.buoyancyDefault/></Setting>
        </Guidance:Buoyancy>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Arg Name="WaitToFloat"/></Setting>
        </Guidance:Wait>

    </Aggregate>

</Mission>


2022-12-20T17:02:23.404Z,1671555743.404 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/tank_ballast_and_trim.xml
2022-12-20T17:02:23.476Z,1671555743.476 [Default] Stopped
2022-12-20T17:02:23.476Z,1671555743.476 [Default](DEBUG): Aggregate::uninitialize Default
2022-12-20T17:02:23.476Z,1671555743.476 [Default:B.GoToSurface] Stopped
2022-12-20T17:02:23.476Z,1671555743.476 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-12-20T17:02:23.476Z,1671555743.476 [Default:CheckIn] Stopped
2022-12-20T17:02:23.476Z,1671555743.476 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T17:02:23.476Z,1671555743.476 [Default:CheckIn:C.Wait] Stopped
2022-12-20T17:02:23.476Z,1671555743.476 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T17:02:23.477Z,1671555743.477 [MissionManager](IMPORTANT): Started mission ballast_and_trim
2022-12-20T17:02:23.477Z,1671555743.477 [ballast_and_trim] Running Loop=1
2022-12-20T17:02:23.477Z,1671555743.477 [ballast_and_trim](DEBUG): Aggregate::initialize ballast_and_trim
2022-12-20T17:02:23.477Z,1671555743.477 [ballast_and_trim:Science] Running Loop=1
2022-12-20T17:02:23.477Z,1671555743.477 [ballast_and_trim:Science](DEBUG): Aggregate::initialize ballast_and_trim:Science
2022-12-20T17:02:23.477Z,1671555743.477 [ballast_and_trim:Science:A] Running Loop=1
2022-12-20T17:02:23.477Z,1671555743.477 [ballast_and_trim:Science:B] Running Loop=1
2022-12-20T17:02:23.477Z,1671555743.477 [ballast_and_trim:Science:C] Running Loop=1
2022-12-20T17:02:23.477Z,1671555743.477 [ballast_and_trim:Science:D] Running Loop=1
2022-12-20T17:02:23.477Z,1671555743.477 [ballast_and_trim:Science:E] Running Loop=1
2022-12-20T17:02:23.478Z,1671555743.478 [ballast_and_trim:Science:F] Running Loop=1
2022-12-20T17:02:23.478Z,1671555743.478 [ballast_and_trim:Science:Read_Oil] Running Loop=1
2022-12-20T17:02:23.478Z,1671555743.478 [ballast_and_trim:Science:PeakDetectChl] Running Loop=1
2022-12-20T17:02:23.478Z,1671555743.478 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectChl
2022-12-20T17:02:23.478Z,1671555743.478 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2022-12-20T17:02:23.478Z,1671555743.478 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-12-20T17:02:23.481Z,1671555743.481 [ballast_and_trim:Science:HighestChlPeakReport] Running Loop=1
2022-12-20T17:02:23.481Z,1671555743.481 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestChlPeakReport
2022-12-20T17:02:23.481Z,1671555743.481 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2022-12-20T17:02:23.481Z,1671555743.481 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2022-12-20T17:02:23.482Z,1671555743.482 [ballast_and_trim:Science:PeakDetectNO3] Running Loop=1
2022-12-20T17:02:23.482Z,1671555743.482 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectNO3
2022-12-20T17:02:23.482Z,1671555743.482 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2022-12-20T17:02:23.482Z,1671555743.482 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-12-20T17:02:23.492Z,1671555743.492 [ballast_and_trim:Science:PeakDetectOil] Running Loop=1
2022-12-20T17:02:23.492Z,1671555743.492 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectOil
2022-12-20T17:02:23.493Z,1671555743.493 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2022-12-20T17:02:23.493Z,1671555743.493 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-12-20T17:02:23.499Z,1671555743.499 [ballast_and_trim:Science:HighestOilPeakReport] Running Loop=1
2022-12-20T17:02:23.499Z,1671555743.499 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestOilPeakReport
2022-12-20T17:02:23.499Z,1671555743.499 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Running Loop=1
2022-12-20T17:02:23.499Z,1671555743.499 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2022-12-20T17:02:23.499Z,1671555743.499 [ballast_and_trim:Science:PeakDetectFDOM] Running Loop=1
2022-12-20T17:02:23.500Z,1671555743.500 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectFDOM
2022-12-20T17:02:23.500Z,1671555743.500 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1
2022-12-20T17:02:23.500Z,1671555743.500 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-12-20T17:02:23.502Z,1671555743.502 [ballast_and_trim:Science:PeakDetectSalinity] Running Loop=1
2022-12-20T17:02:23.502Z,1671555743.502 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectSalinity
2022-12-20T17:02:23.502Z,1671555743.502 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Running Loop=1
2022-12-20T17:02:23.502Z,1671555743.502 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-12-20T17:02:23.504Z,1671555743.504 [ballast_and_trim:Science:HighestSaltPeakReport] Running Loop=1
2022-12-20T17:02:23.504Z,1671555743.504 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestSaltPeakReport
2022-12-20T17:02:23.504Z,1671555743.504 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Running Loop=1
2022-12-20T17:02:23.504Z,1671555743.504 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2022-12-20T17:02:23.505Z,1671555743.505 [ballast_and_trim:Science:OceanCurrent] Running Loop=1
2022-12-20T17:02:23.505Z,1671555743.505 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::initialize ballast_and_trim:Science:OceanCurrent
2022-12-20T17:02:23.505Z,1671555743.505 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1
2022-12-20T17:02:23.505Z,1671555743.505 [ballast_and_trim:Science:OceanCurrent:A.](INFO): Initializing CurrentEstimator.
2022-12-20T17:02:23.505Z,1671555743.505 [ballast_and_trim:RunBallastAndTrim] Running Loop=1
2022-12-20T17:02:23.505Z,1671555743.505 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim
2022-12-20T17:02:23.505Z,1671555743.505 [ballast_and_trim:RunBallastAndTrim:Depth1] Running Loop=1
2022-12-20T17:02:23.506Z,1671555743.506 [ballast_and_trim:RunBallastAndTrim:Depth1](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth1
2022-12-20T17:02:23.506Z,1671555743.506 [ballast_and_trim:RunBallastAndTrim:Depth1:A] Running Loop=1
2022-12-20T17:02:23.515Z,1671555743.515 [ballast_and_trim:RunBallastAndTrim:Depth1:A] Stopped
2022-12-20T17:02:23.515Z,1671555743.515 [ballast_and_trim:RunBallastAndTrim:Depth1:B] Running Loop=1
2022-12-20T17:02:23.515Z,1671555743.515 [ballast_and_trim:RunBallastAndTrim:Depth1:B](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth1:B
2022-12-20T17:02:23.515Z,1671555743.515 [ballast_and_trim:Science] Running Loop=1
2022-12-20T17:02:23.516Z,1671555743.516 [ballast_and_trim:Science:HighestSaltPeakReport] Stopped
2022-12-20T17:02:23.516Z,1671555743.516 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestSaltPeakReport
2022-12-20T17:02:23.516Z,1671555743.516 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Stopped
2022-12-20T17:02:23.516Z,1671555743.516 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2022-12-20T17:02:23.517Z,1671555743.517 [ballast_and_trim:Science:PeakDetectSalinity] Stopped
2022-12-20T17:02:23.517Z,1671555743.517 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectSalinity
2022-12-20T17:02:23.517Z,1671555743.517 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Stopped
2022-12-20T17:02:23.517Z,1671555743.517 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-12-20T17:02:23.517Z,1671555743.517 [ballast_and_trim:Science:PeakDetectFDOM] Stopped
2022-12-20T17:02:23.517Z,1671555743.517 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectFDOM
2022-12-20T17:02:23.517Z,1671555743.517 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped
2022-12-20T17:02:23.517Z,1671555743.517 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-12-20T17:02:23.517Z,1671555743.517 [ballast_and_trim:Science:HighestOilPeakReport] Stopped
2022-12-20T17:02:23.517Z,1671555743.517 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestOilPeakReport
2022-12-20T17:02:23.517Z,1671555743.517 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Stopped
2022-12-20T17:02:23.517Z,1671555743.517 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2022-12-20T17:02:23.517Z,1671555743.517 [ballast_and_trim:Science:PeakDetectOil] Stopped
2022-12-20T17:02:23.518Z,1671555743.518 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectOil
2022-12-20T17:02:23.518Z,1671555743.518 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2022-12-20T17:02:23.518Z,1671555743.518 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-12-20T17:02:23.518Z,1671555743.518 [ballast_and_trim:Science:PeakDetectNO3] Stopped
2022-12-20T17:02:23.518Z,1671555743.518 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectNO3
2022-12-20T17:02:23.518Z,1671555743.518 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2022-12-20T17:02:23.518Z,1671555743.518 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-12-20T17:02:23.518Z,1671555743.518 [ballast_and_trim:Science:HighestChlPeakReport] Stopped
2022-12-20T17:02:23.518Z,1671555743.518 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestChlPeakReport
2022-12-20T17:02:23.518Z,1671555743.518 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2022-12-20T17:02:23.518Z,1671555743.518 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2022-12-20T17:02:23.518Z,1671555743.518 [ballast_and_trim:Science:PeakDetectChl] Stopped
2022-12-20T17:02:23.523Z,1671555743.523 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectChl
2022-12-20T17:02:23.523Z,1671555743.523 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2022-12-20T17:02:23.523Z,1671555743.523 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-12-20T17:02:23.523Z,1671555743.523 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1
2022-12-20T17:02:23.523Z,1671555743.523 [ballast_and_trim:Science:Read_Oil] Stopped
2022-12-20T17:02:23.523Z,1671555743.523 [ballast_and_trim:Science:F] Stopped
2022-12-20T17:02:23.523Z,1671555743.523 [ballast_and_trim:Science:E] Running Loop=1
2022-12-20T17:02:23.524Z,1671555743.524 [ballast_and_trim:Science:E](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2022-12-20T17:02:23.524Z,1671555743.524 [ballast_and_trim:Science:D] Stopped
2022-12-20T17:02:23.524Z,1671555743.524 [ballast_and_trim:Science:C] Running Loop=1
2022-12-20T17:02:23.525Z,1671555743.525 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature
2022-12-20T17:02:23.526Z,1671555743.526 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity
2022-12-20T17:02:23.526Z,1671555743.526 [ballast_and_trim:Science:B] Running Loop=1
2022-12-20T17:02:23.526Z,1671555743.526 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2022-12-20T17:02:23.527Z,1671555743.527 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2022-12-20T17:02:23.527Z,1671555743.527 [ballast_and_trim:Science:A] Stopped
2022-12-20T17:02:23.903Z,1671555743.903 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Running Loop=1
2022-12-20T17:02:23.903Z,1671555743.903 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2022-12-20T17:02:23.904Z,1671555743.904 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1
2022-12-20T17:02:23.904Z,1671555743.904 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1
2022-12-20T17:02:23.904Z,1671555743.904 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1
2022-12-20T17:02:23.904Z,1671555743.904 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1
2022-12-20T17:02:23.904Z,1671555743.904 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1
2022-12-20T17:02:23.904Z,1671555743.904 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Running Loop=1
2022-12-20T17:02:23.906Z,1671555743.906 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F](INFO): Going to target depth. Speed set to 0.000000 m/s 
2022-12-20T17:02:23.906Z,1671555743.906 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Stopped
2022-12-20T17:02:23.906Z,1671555743.906 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Running Loop=1
2022-12-20T17:02:23.906Z,1671555743.906 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2022-12-20T17:02:23.906Z,1671555743.906 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1
2022-12-20T17:02:23.906Z,1671555743.906 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Running Loop=1
2022-12-20T17:02:23.906Z,1671555743.906 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold
2022-12-20T17:02:23.906Z,1671555743.906 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Running Loop=1
2022-12-20T17:02:23.911Z,1671555743.911 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Initialize.
2022-12-20T17:02:23.911Z,1671555743.911 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Running Loop=1
2022-12-20T17:02:23.911Z,1671555743.911 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2022-12-20T17:02:23.911Z,1671555743.911 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Running Loop=1
2022-12-20T17:02:23.911Z,1671555743.911 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Initialize.
2022-12-20T17:02:23.912Z,1671555743.912 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Running Loop=1
2022-12-20T17:02:23.912Z,1671555743.912 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2022-12-20T17:02:23.912Z,1671555743.912 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Running Loop=1
2022-12-20T17:02:23.912Z,1671555743.912 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1
2022-12-20T17:02:23.912Z,1671555743.912 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1
2022-12-20T17:02:23.912Z,1671555743.912 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1
2022-12-20T17:02:23.913Z,1671555743.913 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1
2022-12-20T17:02:23.913Z,1671555743.913 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1
2022-12-20T17:02:23.952Z,1671555743.952 [WetLabsBB2FL](INFO): Powering up
2022-12-20T17:02:24.270Z,1671555744.270 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A](INFO): Waiting for 0.000000 min while pumping down to neutral.
2022-12-20T17:02:24.270Z,1671555744.270 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Stopped
2022-12-20T17:02:24.270Z,1671555744.270 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait] Running Loop=1
2022-12-20T17:02:24.270Z,1671555744.270 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Initialize Wait Component.
2022-12-20T17:02:24.270Z,1671555744.270 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Stopped
2022-12-20T17:02:24.270Z,1671555744.270 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold
2022-12-20T17:02:24.270Z,1671555744.270 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Stopped
2022-12-20T17:02:24.270Z,1671555744.270 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Stopped
2022-12-20T17:02:24.270Z,1671555744.270 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2022-12-20T17:02:24.270Z,1671555744.270 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Stopped
2022-12-20T17:02:24.270Z,1671555744.270 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1
2022-12-20T17:02:24.676Z,1671555744.676 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](INFO): Done Waiting.
2022-12-20T17:02:24.676Z,1671555744.676 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait] Stopped
2022-12-20T17:02:24.676Z,1671555744.676 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T17:02:24.676Z,1671555744.676 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2022-12-20T17:02:24.676Z,1671555744.676 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Stopped
2022-12-20T17:02:24.676Z,1671555744.676 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2022-12-20T17:02:24.677Z,1671555744.677 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Running Loop=1
2022-12-20T17:02:24.677Z,1671555744.677 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2022-12-20T17:02:24.677Z,1671555744.677 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1
2022-12-20T17:02:24.677Z,1671555744.677 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Initialize.
2022-12-20T17:02:24.677Z,1671555744.677 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Running Loop=1
2022-12-20T17:02:25.095Z,1671555745.095 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1
2022-12-20T17:02:25.095Z,1671555745.095 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A](INFO): Moving to 7.000000 m 
2022-12-20T17:02:25.095Z,1671555745.095 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Stopped
2022-12-20T17:02:25.095Z,1671555745.095 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Running Loop=1
2022-12-20T17:02:25.096Z,1671555745.096 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Initialize.
2022-12-20T17:02:27.080Z,1671555747.080 [CTD_Seabird](ERROR): Failed to parse device response: <!--startlogging-->
2022-12-20T17:02:37.184Z,1671555757.184 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-20T17:04:19.061Z,1671555859.061 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T17:04:28.511Z,1671555868.511 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-12-20T17:04:31.523Z,1671555871.523 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.239372
2022-12-20T17:04:32.735Z,1671555872.735 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T17:04:46.067Z,1671555886.067 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T17:04:56.335Z,1671555896.335 [Radio_Surface](INFO): Powering down
2022-12-20T17:04:59.399Z,1671555899.399 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T17:05:03.659Z,1671555903.659 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-12-20T17:05:04.663Z,1671555904.663 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2022-12-20T17:05:12.792Z,1671555912.792 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T17:05:25.427Z,1671555925.427 [Radio_Surface](INFO): Powering up
2022-12-20T17:05:26.467Z,1671555926.467 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T17:05:30.767Z,1671555930.767 [DataOverHttps](INFO): Radio surface powered ON.
2022-12-20T17:05:31.487Z,1671555931.487 [Radio_Surface](INFO): Powering down
2022-12-20T17:05:39.454Z,1671555939.454 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T17:05:52.733Z,1671555952.733 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T17:06:00.903Z,1671555960.903 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-12-20T17:06:01.907Z,1671555961.907 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2022-12-20T17:06:06.054Z,1671555966.054 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T17:06:19.383Z,1671555979.383 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T17:06:33.123Z,1671555993.123 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T17:10:46.855Z,1671556246.855 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Stopped
2022-12-20T17:10:46.856Z,1671556246.856 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2022-12-20T17:10:46.856Z,1671556246.856 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Stopped
2022-12-20T17:10:46.856Z,1671556246.856 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2022-12-20T17:10:46.856Z,1671556246.856 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Stopped
2022-12-20T17:10:46.856Z,1671556246.856 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Uninitialize.
2022-12-20T17:10:46.857Z,1671556246.857 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2022-12-20T17:10:46.857Z,1671556246.857 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Stopped
2022-12-20T17:10:46.857Z,1671556246.857 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2022-12-20T17:10:46.857Z,1671556246.857 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Stopped
2022-12-20T17:10:46.857Z,1671556246.857 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Running Loop=1
2022-12-20T17:10:46.857Z,1671556246.857 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2022-12-20T17:10:46.858Z,1671556246.858 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1
2022-12-20T17:10:46.858Z,1671556246.858 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Initialize.
2022-12-20T17:10:46.858Z,1671556246.858 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1
2022-12-20T17:10:46.858Z,1671556246.858 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Initialize.
2022-12-20T17:10:46.858Z,1671556246.858 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Running Loop=1
2022-12-20T17:10:47.321Z,1671556247.321 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C](INFO): Waiting for the vehicle to settle. Depth = 7.008698 m 
2022-12-20T17:10:47.321Z,1671556247.321 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Stopped
2022-12-20T17:10:47.321Z,1671556247.321 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Running Loop=1
2022-12-20T17:10:47.321Z,1671556247.321 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Initialize Wait Component.
2022-12-20T17:10:47.321Z,1671556247.321 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1
2022-12-20T17:10:47.321Z,1671556247.321 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1
2022-12-20T17:13:51.474Z,1671556431.474 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T17:14:04.805Z,1671556444.805 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T17:14:18.139Z,1671556458.139 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T17:14:31.475Z,1671556471.475 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T17:14:44.803Z,1671556484.803 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T17:14:58.136Z,1671556498.136 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T17:15:11.468Z,1671556511.468 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T17:15:24.799Z,1671556524.799 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T17:15:38.132Z,1671556538.132 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T17:15:51.465Z,1671556551.465 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T17:16:04.807Z,1671556564.807 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T17:18:35.119Z,1671556715.119 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file).
2022-12-20T17:19:13.892Z,1671556753.892 [BPC1](INFO): Calculating totals. Valid battery stick count: 50. Valid reserve battery stick count: 5.
2022-12-20T17:19:13.895Z,1671556753.895 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle.
2022-12-20T17:20:48.022Z,1671556848.022 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](INFO): Done Waiting.
2022-12-20T17:20:48.022Z,1671556848.022 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Stopped
2022-12-20T17:20:48.022Z,1671556848.022 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T17:20:48.023Z,1671556848.023 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E] Running Loop=1
2022-12-20T17:20:48.433Z,1671556848.433 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E](INFO): Running ballast and trim. Depth = 7.047441 m 
2022-12-20T17:20:48.433Z,1671556848.433 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E] Stopped
2022-12-20T17:20:48.433Z,1671556848.433 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.] Running Loop=1
2022-12-20T17:20:48.433Z,1671556848.433 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](INFO): Initializing BallastAndTrim.
2022-12-20T18:05:49.227Z,1671559549.227 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](FAULT): BallastAndTrim completed. Values did not meet error bound requirements requested by user. Will NOT write estimation values to config! Estimation time: 45.01 minutes (time-out limit reached).
2022-12-20T18:05:49.228Z,1671559549.228 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Estimated buoyancyNeutral: 117.723602 +/- 9.333821 cc (conf. level 99.90%, sigma: 23.479558 cc).
2022-12-20T18:05:49.229Z,1671559549.229 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Estimated massDefault: 21.536149 +/- 0.270955 mm (conf. level 99.90%, sigma: 0.681597 mm).
2022-12-20T18:05:49.229Z,1671559549.229 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.] Stopped
2022-12-20T18:05:49.229Z,1671559549.229 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](INFO): Uninitializing BallastAndTrim.
2022-12-20T18:05:49.230Z,1671559549.230 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2022-12-20T18:05:49.230Z,1671559549.230 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Stopped
2022-12-20T18:05:49.230Z,1671559549.230 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2022-12-20T18:05:49.230Z,1671559549.230 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Stopped
2022-12-20T18:05:49.230Z,1671559549.230 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Uninitialize.
2022-12-20T18:05:49.230Z,1671559549.230 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Stopped
2022-12-20T18:05:49.248Z,1671559549.248 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2022-12-20T18:05:49.248Z,1671559549.248 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Stopped
2022-12-20T18:05:49.248Z,1671559549.248 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2022-12-20T18:05:49.248Z,1671559549.248 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Stopped
2022-12-20T18:05:49.248Z,1671559549.248 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Stopped
2022-12-20T18:05:49.248Z,1671559549.248 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Stopped
2022-12-20T18:05:49.248Z,1671559549.248 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Stopped
2022-12-20T18:05:49.248Z,1671559549.248 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Stopped
2022-12-20T18:05:49.631Z,1671559549.631 [ballast_and_trim:RunBallastAndTrim:Depth1:B](INFO): Completed ballast_and_trim:RunBallastAndTrim:Depth1:B
2022-12-20T18:05:49.631Z,1671559549.631 [ballast_and_trim:RunBallastAndTrim:Depth1:B] Stopped
2022-12-20T18:05:49.631Z,1671559549.631 [ballast_and_trim:RunBallastAndTrim:Depth1:B](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth1:B
2022-12-20T18:05:49.631Z,1671559549.631 [ballast_and_trim:RunBallastAndTrim:Depth1](INFO): Completed ballast_and_trim:RunBallastAndTrim:Depth1
2022-12-20T18:05:49.632Z,1671559549.632 [ballast_and_trim:RunBallastAndTrim:Depth1] Stopped
2022-12-20T18:05:49.632Z,1671559549.632 [ballast_and_trim:RunBallastAndTrim:Depth1](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth1
2022-12-20T18:05:49.632Z,1671559549.632 [ballast_and_trim:RunBallastAndTrim:Depth2] Running Loop=1
2022-12-20T18:05:49.632Z,1671559549.632 [ballast_and_trim:RunBallastAndTrim:Depth2](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth2
2022-12-20T18:05:49.632Z,1671559549.632 [ballast_and_trim:RunBallastAndTrim:Depth2:A] Running Loop=1
2022-12-20T18:05:50.040Z,1671559550.040 [ballast_and_trim:RunBallastAndTrim:Depth2] Stopped
2022-12-20T18:05:50.040Z,1671559550.040 [ballast_and_trim:RunBallastAndTrim:Depth2](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth2
2022-12-20T18:05:50.040Z,1671559550.040 [ballast_and_trim:RunBallastAndTrim:Depth2:A] Stopped
2022-12-20T18:05:50.040Z,1671559550.040 [ballast_and_trim:RunBallastAndTrim](INFO): Completed ballast_and_trim:RunBallastAndTrim
2022-12-20T18:05:50.040Z,1671559550.040 [ballast_and_trim:RunBallastAndTrim] Stopped
2022-12-20T18:05:50.041Z,1671559550.041 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim
2022-12-20T18:05:50.041Z,1671559550.041 [ballast_and_trim:Float_Up] Running Loop=1
2022-12-20T18:05:50.041Z,1671559550.041 [ballast_and_trim:Float_Up](DEBUG): Aggregate::initialize ballast_and_trim:Float_Up
2022-12-20T18:05:50.041Z,1671559550.041 [ballast_and_trim:Float_Up:A.Buoyancy] Running Loop=1
2022-12-20T18:05:50.041Z,1671559550.041 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Initialize Buoyancy Component.
2022-12-20T18:05:50.041Z,1671559550.041 [ballast_and_trim:Float_Up:B.Wait] Running Loop=1
2022-12-20T18:05:50.041Z,1671559550.041 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Initialize Wait Component.
2022-12-20T18:05:50.456Z,1671559550.456 [ballast_and_trim:Float_Up:A.Buoyancy] Running Loop=1
2022-12-20T18:06:42.088Z,1671559602.088 [CTD_Seabird](ERROR): Failed to parse device response: 5.03,18.9587,4.582235
2022-12-20T18:07:27.410Z,1671559647.410 [ballast_and_trim:Float_Up] Stopped
2022-12-20T18:07:27.410Z,1671559647.410 [ballast_and_trim:Float_Up](DEBUG): Aggregate::uninitialize ballast_and_trim:Float_Up
2022-12-20T18:07:27.410Z,1671559647.410 [ballast_and_trim:Float_Up:A.Buoyancy] Stopped
2022-12-20T18:07:27.410Z,1671559647.410 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2022-12-20T18:07:27.410Z,1671559647.410 [ballast_and_trim:Float_Up:B.Wait] Stopped
2022-12-20T18:07:27.410Z,1671559647.410 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T18:07:27.412Z,1671559647.412 [ballast_and_trim](INFO): Completed ballast_and_trim
2022-12-20T18:07:27.412Z,1671559647.412 [MissionManager](INFO): ballast_and_trim is completed.
2022-12-20T18:07:27.412Z,1671559647.412 [MissionManager](INFO): Uninitializing Mission ballast_and_trim
2022-12-20T18:07:27.412Z,1671559647.412 [ballast_and_trim] Stopped
2022-12-20T18:07:27.412Z,1671559647.412 [ballast_and_trim](DEBUG): Aggregate::uninitialize ballast_and_trim
2022-12-20T18:07:27.412Z,1671559647.412 [ballast_and_trim:Science] Stopped
2022-12-20T18:07:27.412Z,1671559647.412 [ballast_and_trim:Science](DEBUG): Aggregate::uninitialize ballast_and_trim:Science
2022-12-20T18:07:27.413Z,1671559647.413 [ballast_and_trim:Science:B] Stopped
2022-12-20T18:07:27.413Z,1671559647.413 [ballast_and_trim:Science:C] Stopped
2022-12-20T18:07:27.413Z,1671559647.413 [ballast_and_trim:Science:E] Stopped
2022-12-20T18:07:27.413Z,1671559647.413 [ballast_and_trim:Science:OceanCurrent] Stopped
2022-12-20T18:07:27.413Z,1671559647.413 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:OceanCurrent
2022-12-20T18:07:27.413Z,1671559647.413 [ballast_and_trim:Science:OceanCurrent:A.] Stopped
2022-12-20T18:07:27.829Z,1671559647.829 [MissionManager](IMPORTANT): Started mission Default
2022-12-20T18:07:27.830Z,1671559647.830 [Default] Running Loop=1
2022-12-20T18:07:27.830Z,1671559647.830 [Default](DEBUG): Aggregate::initialize Default
2022-12-20T18:07:27.831Z,1671559647.831 [Default:B.GoToSurface] Running Loop=1
2022-12-20T18:07:27.831Z,1671559647.831 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-12-20T18:07:27.833Z,1671559647.833 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-12-20T18:07:27.834Z,1671559647.834 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-12-20T18:07:27.834Z,1671559647.834 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-12-20T18:07:27.835Z,1671559647.835 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-12-20T18:07:27.835Z,1671559647.835 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-12-20T18:07:27.836Z,1671559647.836 [Default:A.Wait] Running Loop=1
2022-12-20T18:07:27.836Z,1671559647.836 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-12-20T18:07:27.879Z,1671559647.879 [WetLabsBB2FL](INFO): Powering down
2022-12-20T18:07:27.991Z,1671559647.991 [Radio_Surface](INFO): Powering up
2022-12-20T18:07:34.223Z,1671559654.223 [DataOverHttps](INFO): Radio surface powered ON.
2022-12-20T18:07:41.135Z,1671559661.135 [Default:A.Wait](INFO): Done Waiting.
2022-12-20T18:07:41.135Z,1671559661.135 [Default:A.Wait] Stopped
2022-12-20T18:07:41.135Z,1671559661.135 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T18:07:41.547Z,1671559661.547 [Default:CheckIn] Running Loop=1
2022-12-20T18:07:41.547Z,1671559661.547 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T18:07:41.547Z,1671559661.547 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T18:08:04.355Z,1671559684.355 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-12-20T18:08:39.499Z,1671559719.499 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-12-20T18:09:14.639Z,1671559754.639 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-12-20T18:09:49.787Z,1671559789.787 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-12-20T18:10:24.927Z,1671559824.927 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-12-20T18:10:57.551Z,1671559857.551 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003063
2022-12-20T18:12:41.740Z,1671559961.740 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-12-20T18:07:41.5Z
2022-12-20T18:12:41.740Z,1671559961.740 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T18:12:41.741Z,1671559961.741 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T18:12:45.364Z,1671559965.364 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-20T18:13:16.068Z,1671559996.068 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-20T18:13:20.059Z,1671560000.059 [DataOverHttps](INFO): Sending 288 bytes from file Logs/20221220T164801/Courier0007.lzma
2022-12-20T18:13:21.060Z,1671560001.060 [DataOverHttps](INFO): Moved sent file to Logs/20221220T164801/Courier0007.lzma.bak
2022-12-20T18:13:21.061Z,1671560001.061 [DataOverHttps](INFO): SBD MOMSN=17399498
2022-12-20T18:13:37.521Z,1671560017.521 [DataOverHttps](INFO): Sending 1463 bytes from file Logs/20221220T164801/Express0008.lzma
2022-12-20T18:13:38.521Z,1671560018.521 [DataOverHttps](INFO): Moved sent file to Logs/20221220T164801/Express0008.lzma.bak
2022-12-20T18:13:38.521Z,1671560018.521 [DataOverHttps](INFO): SBD MOMSN=17399501
2022-12-20T18:13:39.917Z,1671560019.917 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T18:13:39.917Z,1671560019.917 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T18:13:39.918Z,1671560019.918 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T18:18:40.561Z,1671560320.561 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T18:18:40.561Z,1671560320.561 [Default:CheckIn:C.Wait] Stopped
2022-12-20T18:18:40.561Z,1671560320.561 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T18:18:40.561Z,1671560320.561 [Default:CheckIn:D] Running Loop=1
2022-12-20T18:18:40.964Z,1671560320.964 [Default:CheckIn:D] Stopped
2022-12-20T18:18:40.964Z,1671560320.964 [Default:CheckIn:E] Running Loop=1
2022-12-20T18:18:41.349Z,1671560321.349 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.218906 min 
2022-12-20T18:18:41.349Z,1671560321.349 [Default:CheckIn:E] Stopped
2022-12-20T18:18:41.350Z,1671560321.350 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T18:18:41.350Z,1671560321.350 [Default:CheckIn] Stopped
2022-12-20T18:18:41.350Z,1671560321.350 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T18:18:41.350Z,1671560321.350 [Default:CheckIn](INFO): Running loop #2
2022-12-20T18:18:41.350Z,1671560321.350 [Default:CheckIn] Running Loop=2
2022-12-20T18:18:41.350Z,1671560321.350 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T18:18:41.350Z,1671560321.350 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T18:18:42.957Z,1671560322.957 [NAL9602](FAULT): GPS failed to acquire within timeout.
2022-12-20T18:18:42.957Z,1671560322.957 [NAL9602] Data Fault, FailCount= 2
2022-12-20T18:18:42.957Z,1671560322.957 [NAL9602](ERROR): Data Fault
2022-12-20T18:18:42.977Z,1671560322.977 [CBIT](ERROR): Data Fault in component: NAL9602
2022-12-20T18:18:43.364Z,1671560323.364 [NAL9602](INFO): Powering down
2022-12-20T18:18:44.198Z,1671560324.198 [CBIT](INFO): Clearing failed state for component NAL9602
2022-12-20T18:18:44.198Z,1671560324.198 [NAL9602] No Fault, FailCount= 2
2022-12-20T18:19:13.720Z,1671560353.720 [NAL9602](INFO): Powering up NAL9602
2022-12-20T18:19:24.632Z,1671560364.632 [NAL9602](INFO): NAL9602 initialized
2022-12-20T18:21:42.989Z,1671560502.989 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T18:21:56.310Z,1671560516.310 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T18:22:09.629Z,1671560529.629 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T18:22:22.974Z,1671560542.974 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T18:22:36.357Z,1671560556.357 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T18:22:50.099Z,1671560570.099 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T18:23:03.910Z,1671560583.910 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T18:23:17.570Z,1671560597.570 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T18:23:30.498Z,1671560610.498 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T18:23:41.408Z,1671560621.408 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-12-20T18:18:41.4Z
2022-12-20T18:23:41.408Z,1671560621.408 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T18:23:41.408Z,1671560621.408 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T18:23:44.234Z,1671560624.234 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T18:23:49.167Z,1671560629.167 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20221220T164801/Courier0010.lzma
2022-12-20T18:23:50.170Z,1671560630.170 [DataOverHttps](INFO): Moved sent file to Logs/20221220T164801/Courier0010.lzma.bak
2022-12-20T18:23:50.170Z,1671560630.170 [DataOverHttps](INFO): SBD MOMSN=17399517
2022-12-20T18:23:57.977Z,1671560637.977 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-12-20T18:24:06.244Z,1671560646.244 [DataOverHttps](INFO): Sending 458 bytes from file Logs/20221220T164801/Express0012.lzma
2022-12-20T18:24:07.246Z,1671560647.246 [DataOverHttps](INFO): Moved sent file to Logs/20221220T164801/Express0012.lzma.bak
2022-12-20T18:24:07.246Z,1671560647.246 [DataOverHttps](IMPORTANT): SBD MOMSN=17399520, MTMSN=20221220T182406
2022-12-20T18:24:08.480Z,1671560648.480 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T18:24:08.480Z,1671560648.480 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T18:24:08.480Z,1671560648.480 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T18:24:14.888Z,1671560654.888 [DataOverHttps](INFO): Received command: ibit
2022-12-20T18:24:14.949Z,1671560654.949 [CommandExec](IMPORTANT): got command ibit
2022-12-20T18:24:14.982Z,1671560654.982 [IBIT](IMPORTANT): Beginning Initiated BIT
2022-12-20T18:24:14.982Z,1671560654.982 [IBIT](IMPORTANT): Beginning control surface checks.
2022-12-20T18:24:14.986Z,1671560654.986 [CBIT](IMPORTANT): Beginning ground fault scan
2022-12-20T18:24:25.873Z,1671560665.873 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.006271
CHAN A1 (24V): -0.008513
CHAN A2 (12V): -0.005102
CHAN A3 (5V): -0.002661
CHAN B0 (3.3V): -0.000910
CHAN B1 (3.15aV): -0.001421
CHAN B2 (3.15bV): -0.000763
CHAN B3 (GND): 0.000224
OPEN: 0.004476
Full Scale: +/- 1 mA
2022-12-20T18:24:28.663Z,1671560668.663 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-20T18:24:33.915Z,1671560673.915 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182433.00,A,3648.17186,N,12147.28054,W,0.233,0.00,201222,,,A*7A
2022-12-20T18:24:33.917Z,1671560673.917 [NAL9602](INFO): GPS fix at 20221220T182433: (36.802864, -121.788009)
2022-12-20T18:24:36.744Z,1671560676.744 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182436.00,A,3648.17178,N,12147.28043,W,0.156,0.00,201222,,,A*78
2022-12-20T18:24:36.758Z,1671560676.758 [NAL9602](INFO): GPS fix at 20221220T182436: (36.802863, -121.788007)
2022-12-20T18:24:39.975Z,1671560679.975 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182439.00,A,3648.17167,N,12147.28040,W,0.194,0.00,201222,,,A*74
2022-12-20T18:24:39.977Z,1671560679.977 [NAL9602](INFO): GPS fix at 20221220T182439: (36.802861, -121.788007)
2022-12-20T18:24:42.053Z,1671560682.053 [CommandExec](IMPORTANT): got command failComponent
2022-12-20T18:24:42.053Z,1671560682.053 [CommandExec](IMPORTANT): Failed components:
2022-12-20T18:24:42.053Z,1671560682.053 [CommandExec](IMPORTANT): No failed Components.
2022-12-20T18:24:42.803Z,1671560682.803 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182442.00,A,3648.17158,N,12147.28056,W,0.117,0.00,201222,,,A*78
2022-12-20T18:24:42.805Z,1671560682.805 [NAL9602](INFO): GPS fix at 20221220T182442: (36.802860, -121.788009)
2022-12-20T18:24:46.078Z,1671560686.078 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182445.00,A,3648.17151,N,12147.28064,W,0.156,0.00,201222,,,A*72
2022-12-20T18:24:46.092Z,1671560686.092 [NAL9602](INFO): GPS fix at 20221220T182445: (36.802858, -121.788011)
2022-12-20T18:24:48.887Z,1671560688.887 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182448.00,A,3648.17141,N,12147.28071,W,0.214,0.00,201222,,,A*7F
2022-12-20T18:24:48.898Z,1671560688.898 [NAL9602](INFO): GPS fix at 20221220T182448: (36.802857, -121.788012)
2022-12-20T18:24:51.739Z,1671560691.739 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182451.00,A,3648.17143,N,12147.28074,W,0.156,0.00,201222,,,A*75
2022-12-20T18:24:51.742Z,1671560691.742 [NAL9602](INFO): GPS fix at 20221220T182451: (36.802857, -121.788012)
2022-12-20T18:24:54.944Z,1671560694.944 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182454.00,A,3648.17143,N,12147.28078,W,0.117,0.00,201222,,,A*79
2022-12-20T18:24:54.953Z,1671560694.953 [NAL9602](INFO): GPS fix at 20221220T182454: (36.802857, -121.788013)
2022-12-20T18:24:57.779Z,1671560697.779 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182457.00,A,3648.17141,N,12147.28083,W,0.039,0.00,201222,,,A*71
2022-12-20T18:24:57.781Z,1671560697.781 [NAL9602](INFO): GPS fix at 20221220T182457: (36.802857, -121.788014)
2022-12-20T18:25:01.013Z,1671560701.013 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182500.00,A,3648.17152,N,12147.28088,W,0.156,0.00,201222,,,A*73
2022-12-20T18:25:01.015Z,1671560701.015 [NAL9602](INFO): GPS fix at 20221220T182500: (36.802859, -121.788015)
2022-12-20T18:25:04.117Z,1671560704.117 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182503.00,A,3648.17168,N,12147.28090,W,0.039,0.00,201222,,,A*78
2022-12-20T18:25:04.119Z,1671560704.119 [NAL9602](INFO): GPS fix at 20221220T182503: (36.802861, -121.788015)
2022-12-20T18:25:07.064Z,1671560707.064 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182506.00,A,3648.17177,N,12147.28087,W,0.117,0.00,201222,,,A*78
2022-12-20T18:25:07.066Z,1671560707.066 [NAL9602](INFO): GPS fix at 20221220T182506: (36.802863, -121.788015)
2022-12-20T18:25:09.908Z,1671560709.908 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182509.00,A,3648.17180,N,12147.28090,W,0.175,0.00,201222,,,A*7D
2022-12-20T18:25:09.910Z,1671560709.910 [NAL9602](INFO): GPS fix at 20221220T182509: (36.802863, -121.788015)
2022-12-20T18:25:12.723Z,1671560712.723 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182511.00,A,3648.17183,N,12147.28090,W,0.039,0.00,201222,,,A*7E
2022-12-20T18:25:12.725Z,1671560712.725 [NAL9602](INFO): GPS fix at 20221220T182511: (36.802864, -121.788015)
2022-12-20T18:25:15.951Z,1671560715.951 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182515.00,A,3648.17191,N,12147.28086,W,0.058,0.00,201222,,,A*79
2022-12-20T18:25:15.953Z,1671560715.953 [NAL9602](INFO): GPS fix at 20221220T182515: (36.802865, -121.788014)
2022-12-20T18:25:18.808Z,1671560718.808 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182518.00,A,3648.17202,N,12147.28092,W,0.117,0.00,201222,,,A*72
2022-12-20T18:25:18.810Z,1671560718.810 [NAL9602](INFO): GPS fix at 20221220T182518: (36.802867, -121.788015)
2022-12-20T18:25:22.011Z,1671560722.011 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182521.00,A,3648.17208,N,12147.28098,W,0.136,0.00,201222,,,A*7B
2022-12-20T18:25:22.013Z,1671560722.013 [NAL9602](INFO): GPS fix at 20221220T182521: (36.802868, -121.788016)
2022-12-20T18:25:24.839Z,1671560724.839 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182524.00,A,3648.17220,N,12147.28101,W,0.156,0.00,201222,,,A*73
2022-12-20T18:25:24.841Z,1671560724.841 [NAL9602](INFO): GPS fix at 20221220T182524: (36.802870, -121.788017)
2022-12-20T18:25:28.075Z,1671560728.075 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182527.00,A,3648.17240,N,12147.28100,W,0.039,0.00,201222,,,A*7F
2022-12-20T18:25:28.077Z,1671560728.077 [NAL9602](INFO): GPS fix at 20221220T182527: (36.802873, -121.788017)
2022-12-20T18:25:30.907Z,1671560730.907 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182530.00,A,3648.17250,N,12147.28101,W,0.058,0.00,201222,,,A*7E
2022-12-20T18:25:30.909Z,1671560730.909 [NAL9602](INFO): GPS fix at 20221220T182530: (36.802875, -121.788017)
2022-12-20T18:25:33.730Z,1671560733.730 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182533.00,A,3648.17255,N,12147.28101,W,0.156,0.00,201222,,,A*77
2022-12-20T18:25:33.743Z,1671560733.743 [NAL9602](INFO): GPS fix at 20221220T182533: (36.802876, -121.788017)
2022-12-20T18:25:36.967Z,1671560736.967 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182536.00,A,3648.17260,N,12147.28097,W,0.058,0.00,201222,,,A*75
2022-12-20T18:25:36.977Z,1671560736.977 [NAL9602](INFO): GPS fix at 20221220T182536: (36.802877, -121.788016)
2022-12-20T18:25:39.799Z,1671560739.799 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182539.00,A,3648.17264,N,12147.28091,W,0.175,0.00,201222,,,A*76
2022-12-20T18:25:39.802Z,1671560739.802 [NAL9602](INFO): GPS fix at 20221220T182539: (36.802877, -121.788015)
2022-12-20T18:25:43.037Z,1671560743.037 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182542.00,A,3648.17267,N,12147.28089,W,0.019,0.00,201222,,,A*7B
2022-12-20T18:25:43.039Z,1671560743.039 [NAL9602](INFO): GPS fix at 20221220T182542: (36.802878, -121.788015)
2022-12-20T18:25:45.877Z,1671560745.877 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182545.00,A,3648.17272,N,12147.28086,W,0.233,0.00,201222,,,A*7D
2022-12-20T18:25:45.879Z,1671560745.879 [NAL9602](INFO): GPS fix at 20221220T182545: (36.802879, -121.788014)
2022-12-20T18:25:49.087Z,1671560749.087 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182548.00,A,3648.17284,N,12147.28083,W,0.039,0.00,201222,,,A*74
2022-12-20T18:25:49.089Z,1671560749.089 [NAL9602](INFO): GPS fix at 20221220T182548: (36.802881, -121.788014)
2022-12-20T18:25:51.910Z,1671560751.910 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182551.00,A,3648.17285,N,12147.28083,W,0.136,0.00,201222,,,A*73
2022-12-20T18:25:51.912Z,1671560751.912 [NAL9602](INFO): GPS fix at 20221220T182551: (36.802881, -121.788014)
2022-12-20T18:25:54.753Z,1671560754.753 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182554.00,A,3648.17291,N,12147.28080,W,0.194,0.00,201222,,,A*78
2022-12-20T18:25:54.756Z,1671560754.756 [NAL9602](INFO): GPS fix at 20221220T182554: (36.802882, -121.788013)
2022-12-20T18:25:58.000Z,1671560758.000 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182557.00,A,3648.17303,N,12147.28075,W,0.233,0.00,201222,,,A*75
2022-12-20T18:25:58.002Z,1671560758.002 [NAL9602](INFO): GPS fix at 20221220T182557: (36.802884, -121.788012)
2022-12-20T18:26:00.807Z,1671560760.807 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182600.00,A,3648.17314,N,12147.28064,W,0.097,0.00,201222,,,A*7E
2022-12-20T18:26:00.809Z,1671560760.809 [NAL9602](INFO): GPS fix at 20221220T182600: (36.802886, -121.788011)
2022-12-20T18:26:04.031Z,1671560764.031 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182603.00,A,3648.17318,N,12147.28060,W,0.175,0.00,201222,,,A*78
2022-12-20T18:26:04.033Z,1671560764.033 [NAL9602](INFO): GPS fix at 20221220T182603: (36.802886, -121.788010)
2022-12-20T18:26:06.065Z,1671560766.065 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2022-12-20T18:26:06.487Z,1671560766.487 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 302.419006
Voltage: 16.334000
2022-12-20T18:26:06.487Z,1671560766.487 [IBIT](IMPORTANT): batteryCapacityThreshold: 30.000000 Ah
2022-12-20T18:26:06.487Z,1671560766.487 [IBIT](IMPORTANT): batteryVoltageThreshold: 12.000000 V
2022-12-20T18:26:06.863Z,1671560766.863 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182606.00,A,3648.17328,N,12147.28047,W,0.272,0.00,201222,,,A*7F
2022-12-20T18:26:06.874Z,1671560766.874 [NAL9602](INFO): GPS fix at 20221220T182606: (36.802888, -121.788008)
2022-12-20T18:26:06.890Z,1671560766.890 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2022-12-20T18:26:06.890Z,1671560766.890 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2022-12-20T18:26:06.891Z,1671560766.891 [IBIT](IMPORTANT): Pressure:9.097466 PSI
2022-12-20T18:26:06.891Z,1671560766.891 [IBIT](IMPORTANT): Humidity:13.099744 %
2022-12-20T18:26:07.314Z,1671560767.314 [IBIT](IMPORTANT): Vehicle Pitch:-1.704423 degrees
2022-12-20T18:26:07.315Z,1671560767.315 [IBIT](IMPORTANT): Vehicle  Roll:-1.134445 degrees
2022-12-20T18:26:07.315Z,1671560767.315 [IBIT](IMPORTANT): Vehicle  Heading:340.891266 degrees
2022-12-20T18:26:07.685Z,1671560767.685 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2022-12-20T18:26:07.685Z,1671560767.685 [IBIT](IMPORTANT): buoyancyNeutral: 324.282104 cc
2022-12-20T18:26:07.685Z,1671560767.685 [IBIT](IMPORTANT): massDefault: 2.000000 cm
2022-12-20T18:26:07.686Z,1671560767.686 [IBIT](IMPORTANT): stopDepth: 275.000000 m
2022-12-20T18:26:07.686Z,1671560767.686 [IBIT](IMPORTANT): abortDepth: 300.000000 m
2022-12-20T18:26:07.686Z,1671560767.686 [IBIT](IMPORTANT): IBIT FAILED
2022-12-20T18:26:39.252Z,1671560799.252 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 5.
2022-12-20T18:26:39.255Z,1671560799.255 [BPC1](INFO): Received data from all battery sticks.
2022-12-20T18:26:39.658Z,1671560799.658 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-20T18:29:09.159Z,1671560949.159 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T18:29:09.159Z,1671560949.159 [Default:CheckIn:C.Wait] Stopped
2022-12-20T18:29:09.159Z,1671560949.159 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T18:29:09.159Z,1671560949.159 [Default:CheckIn:D] Running Loop=1
2022-12-20T18:29:09.567Z,1671560949.567 [Default:CheckIn:D] Stopped
2022-12-20T18:29:09.567Z,1671560949.567 [Default:CheckIn:E] Running Loop=1
2022-12-20T18:29:09.979Z,1671560949.979 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.695630 min 
2022-12-20T18:29:09.979Z,1671560949.979 [Default:CheckIn:E] Stopped
2022-12-20T18:29:09.979Z,1671560949.979 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T18:29:09.980Z,1671560949.980 [Default:CheckIn] Stopped
2022-12-20T18:29:09.980Z,1671560949.980 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T18:29:09.980Z,1671560949.980 [Default:CheckIn](INFO): Running loop #3
2022-12-20T18:29:09.980Z,1671560949.980 [Default:CheckIn] Running Loop=3
2022-12-20T18:29:09.980Z,1671560949.980 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T18:29:09.980Z,1671560949.980 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T18:29:11.967Z,1671560951.967 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182911.00,A,3648.17488,N,12147.27924,W,0.097,0.00,201222,,,A*71
2022-12-20T18:29:11.970Z,1671560951.970 [NAL9602](INFO): GPS fix at 20221220T182911: (36.802915, -121.787987)
2022-12-20T18:29:12.001Z,1671560952.001 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T18:29:12.002Z,1671560952.002 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T18:29:19.484Z,1671560959.484 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20221220T164801/Courier0016.lzma
2022-12-20T18:29:20.486Z,1671560960.486 [DataOverHttps](INFO): Moved sent file to Logs/20221220T164801/Courier0016.lzma.bak
2022-12-20T18:29:20.486Z,1671560960.486 [DataOverHttps](INFO): SBD MOMSN=17399528
2022-12-20T18:29:36.357Z,1671560976.357 [DataOverHttps](INFO): Sending 889 bytes from file Logs/20221220T164801/Express0017.lzma
2022-12-20T18:29:37.358Z,1671560977.358 [DataOverHttps](INFO): Moved sent file to Logs/20221220T164801/Express0017.lzma.bak
2022-12-20T18:29:37.358Z,1671560977.358 [DataOverHttps](INFO): SBD MOMSN=17399531
2022-12-20T18:29:42.666Z,1671560982.666 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-12-20T18:29:42.740Z,1671560982.740 [NAL9602](ERROR): received: 
+CSQ:0

OK
2022-12-20T18:29:53.176Z,1671560993.176 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20221220T164801/Express0020.lzma
2022-12-20T18:29:54.198Z,1671560994.198 [DataOverHttps](INFO): Moved sent file to Logs/20221220T164801/Express0020.lzma.bak
2022-12-20T18:29:54.198Z,1671560994.198 [DataOverHttps](INFO): SBD MOMSN=17399561
2022-12-20T18:29:55.615Z,1671560995.615 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T18:29:55.615Z,1671560995.615 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T18:29:55.615Z,1671560995.615 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T18:34:14.251Z,1671561254.251 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-20T18:34:44.961Z,1671561284.961 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-20T18:34:56.295Z,1671561296.295 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T18:34:56.295Z,1671561296.295 [Default:CheckIn:C.Wait] Stopped
2022-12-20T18:34:56.295Z,1671561296.295 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T18:34:56.295Z,1671561296.295 [Default:CheckIn:D] Running Loop=1
2022-12-20T18:34:56.691Z,1671561296.691 [Default:CheckIn:D] Stopped
2022-12-20T18:34:56.691Z,1671561296.691 [Default:CheckIn:E] Running Loop=1
2022-12-20T18:34:57.090Z,1671561297.090 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 27.481026 min 
2022-12-20T18:34:57.090Z,1671561297.090 [Default:CheckIn:E] Stopped
2022-12-20T18:34:57.090Z,1671561297.090 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T18:34:57.090Z,1671561297.090 [Default:CheckIn] Stopped
2022-12-20T18:34:57.090Z,1671561297.090 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T18:34:57.091Z,1671561297.091 [Default:CheckIn](INFO): Running loop #4
2022-12-20T18:34:57.091Z,1671561297.091 [Default:CheckIn] Running Loop=4
2022-12-20T18:34:57.091Z,1671561297.091 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T18:34:57.091Z,1671561297.091 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T18:34:59.107Z,1671561299.107 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183458.00,A,3648.13678,N,12147.21510,W,0.117,90.60,201222,,,A*42
2022-12-20T18:34:59.109Z,1671561299.109 [NAL9602](INFO): GPS fix at 20221220T183458: (36.802280, -121.786918)
2022-12-20T18:34:59.138Z,1671561299.138 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T18:34:59.138Z,1671561299.138 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T18:35:10.120Z,1671561310.120 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221220T164801/Courier0022.lzma
2022-12-20T18:35:11.122Z,1671561311.122 [DataOverHttps](INFO): Moved sent file to Logs/20221220T164801/Courier0022.lzma.bak
2022-12-20T18:35:11.122Z,1671561311.122 [DataOverHttps](INFO): SBD MOMSN=17399570
2022-12-20T18:35:27.189Z,1671561327.189 [DataOverHttps](INFO): Sending 247 bytes from file Logs/20221220T164801/Express0023.lzma
2022-12-20T18:35:28.190Z,1671561328.190 [DataOverHttps](INFO): Moved sent file to Logs/20221220T164801/Express0023.lzma.bak
2022-12-20T18:35:28.190Z,1671561328.190 [DataOverHttps](INFO): SBD MOMSN=17399573
2022-12-20T18:35:29.485Z,1671561329.485 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T18:35:29.486Z,1671561329.486 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T18:35:29.486Z,1671561329.486 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T18:35:29.874Z,1671561329.874 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-12-20T18:35:29.956Z,1671561329.956 [NAL9602](ERROR): received: 
+CSQ:0

OK
2022-12-20T18:37:23.357Z,1671561443.357 [DataOverHttps](IMPORTANT): SBD MTMSN=20221220T183722
2022-12-20T18:37:30.724Z,1671561450.724 [DataOverHttps](INFO): Received command: ibit
2022-12-20T18:37:30.773Z,1671561450.773 [CommandExec](IMPORTANT): got command ibit
2022-12-20T18:37:31.107Z,1671561451.107 [IBIT](IMPORTANT): Beginning Initiated BIT
2022-12-20T18:37:31.107Z,1671561451.107 [IBIT](IMPORTANT): Beginning control surface checks.
2022-12-20T18:37:31.132Z,1671561451.132 [CBIT](IMPORTANT): Beginning ground fault scan
2022-12-20T18:37:42.041Z,1671561462.041 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.007702
CHAN A1 (24V): -0.008276
CHAN A2 (12V): -0.005352
CHAN A3 (5V): -0.001837
CHAN B0 (3.3V): -0.001052
CHAN B1 (3.15aV): -0.000516
CHAN B2 (3.15bV): -0.001338
CHAN B3 (GND): -0.000224
OPEN: 0.004505
Full Scale: +/- 1 mA
2022-12-20T18:39:22.229Z,1671561562.229 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2022-12-20T18:39:22.630Z,1671561562.630 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.334000
2022-12-20T18:39:22.630Z,1671561562.630 [IBIT](IMPORTANT): batteryCapacityThreshold: 30.000000 Ah
2022-12-20T18:39:22.630Z,1671561562.630 [IBIT](IMPORTANT): batteryVoltageThreshold: 12.000000 V
2022-12-20T18:39:23.045Z,1671561563.045 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2022-12-20T18:39:23.045Z,1671561563.045 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2022-12-20T18:39:23.045Z,1671561563.045 [IBIT](IMPORTANT): Pressure:9.017908 PSI
2022-12-20T18:39:23.046Z,1671561563.046 [IBIT](IMPORTANT): Humidity:13.099744 %
2022-12-20T18:39:23.460Z,1671561563.460 [IBIT](IMPORTANT): Vehicle Pitch:-2.191871 degrees
2022-12-20T18:39:23.464Z,1671561563.464 [IBIT](IMPORTANT): Vehicle  Roll:-2.370745 degrees
2022-12-20T18:39:23.465Z,1671561563.465 [IBIT](IMPORTANT): Vehicle  Heading:63.892990 degrees
2022-12-20T18:39:23.845Z,1671561563.845 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2022-12-20T18:39:23.845Z,1671561563.845 [IBIT](IMPORTANT): buoyancyNeutral: 324.282104 cc
2022-12-20T18:39:23.846Z,1671561563.846 [IBIT](IMPORTANT): massDefault: 2.000000 cm
2022-12-20T18:39:23.846Z,1671561563.846 [IBIT](IMPORTANT): stopDepth: 275.000000 m
2022-12-20T18:39:23.846Z,1671561563.846 [IBIT](IMPORTANT): abortDepth: 300.000000 m
2022-12-20T18:39:23.846Z,1671561563.846 [IBIT](IMPORTANT): IBIT FAILED
2022-12-20T18:40:01.399Z,1671561601.399 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-20T18:40:30.103Z,1671561630.103 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T18:40:30.103Z,1671561630.103 [Default:CheckIn:C.Wait] Stopped
2022-12-20T18:40:30.103Z,1671561630.103 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T18:40:30.103Z,1671561630.103 [Default:CheckIn:D] Running Loop=1
2022-12-20T18:40:30.499Z,1671561630.499 [Default:CheckIn:D] Stopped
2022-12-20T18:40:30.499Z,1671561630.499 [Default:CheckIn:E] Running Loop=1
2022-12-20T18:40:30.912Z,1671561630.912 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 33.044501 min 
2022-12-20T18:40:30.912Z,1671561630.912 [Default:CheckIn:E] Stopped
2022-12-20T18:40:30.912Z,1671561630.912 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T18:40:30.912Z,1671561630.912 [Default:CheckIn] Stopped
2022-12-20T18:40:30.912Z,1671561630.912 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T18:40:30.912Z,1671561630.912 [Default:CheckIn](INFO): Running loop #5
2022-12-20T18:40:30.913Z,1671561630.913 [Default:CheckIn] Running Loop=5
2022-12-20T18:40:30.913Z,1671561630.913 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T18:40:30.913Z,1671561630.913 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T18:40:32.915Z,1671561632.915 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184032.00,A,3648.13358,N,12147.21730,W,0.078,90.60,201222,,,D*47
2022-12-20T18:40:32.934Z,1671561632.934 [NAL9602](INFO): GPS fix at 20221220T184032: (36.802226, -121.786955)
2022-12-20T18:40:32.953Z,1671561632.953 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T18:40:32.953Z,1671561632.953 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T18:40:43.192Z,1671561643.192 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221220T164801/Courier0025.lzma
2022-12-20T18:40:44.194Z,1671561644.194 [DataOverHttps](INFO): Moved sent file to Logs/20221220T164801/Courier0025.lzma.bak
2022-12-20T18:40:44.194Z,1671561644.194 [DataOverHttps](INFO): SBD MOMSN=17399631
2022-12-20T18:41:00.300Z,1671561660.300 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20221220T164801/Courier0028.lzma
2022-12-20T18:41:01.303Z,1671561661.303 [DataOverHttps](INFO): Moved sent file to Logs/20221220T164801/Courier0028.lzma.bak
2022-12-20T18:41:01.303Z,1671561661.303 [DataOverHttps](INFO): SBD MOMSN=17399634
2022-12-20T18:41:05.702Z,1671561665.702 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-20T18:41:19.973Z,1671561679.973 [DataOverHttps](INFO): Sending 819 bytes from file Logs/20221220T164801/Express0026.lzma
2022-12-20T18:41:20.978Z,1671561680.978 [DataOverHttps](INFO): Moved sent file to Logs/20221220T164801/Express0026.lzma.bak
2022-12-20T18:41:20.979Z,1671561680.979 [DataOverHttps](INFO): SBD MOMSN=17399636
2022-12-20T18:41:36.909Z,1671561696.909 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20221220T164801/Express0029.lzma
2022-12-20T18:41:37.910Z,1671561697.910 [DataOverHttps](INFO): Moved sent file to Logs/20221220T164801/Express0029.lzma.bak
2022-12-20T18:41:37.910Z,1671561697.910 [DataOverHttps](INFO): SBD MOMSN=17399663
2022-12-20T18:41:39.270Z,1671561699.270 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T18:41:39.271Z,1671561699.271 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T18:41:39.271Z,1671561699.271 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T18:43:32.921Z,1671561812.921 [DataOverHttps](IMPORTANT): SBD MTMSN=20221220T184331
2022-12-20T18:43:40.436Z,1671561820.436 [DataOverHttps](INFO): Received command: ibit
2022-12-20T18:43:40.437Z,1671561820.437 [CommandExec](IMPORTANT): got command ibit
2022-12-20T18:43:40.495Z,1671561820.495 [IBIT](IMPORTANT): Beginning Initiated BIT
2022-12-20T18:43:40.495Z,1671561820.495 [IBIT](IMPORTANT): Beginning control surface checks.
2022-12-20T18:43:40.499Z,1671561820.499 [CBIT](IMPORTANT): Beginning ground fault scan
2022-12-20T18:43:42.087Z,1671561822.087 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184341.00,A,3648.13214,N,12147.21801,W,0.039,90.60,201222,,,D*41
2022-12-20T18:43:42.089Z,1671561822.089 [NAL9602](INFO): GPS fix at 20221220T184341: (36.802202, -121.786967)
2022-12-20T18:43:51.403Z,1671561831.403 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.007147
CHAN A1 (24V): -0.008604
CHAN A2 (12V): -0.004905
CHAN A3 (5V): -0.002461
CHAN B0 (3.3V): -0.000474
CHAN B1 (3.15aV): -0.001187
CHAN B2 (3.15bV): -0.000781
CHAN B3 (GND): -0.000663
OPEN: 0.004356
Full Scale: +/- 1 mA
2022-12-20T18:44:12.789Z,1671561852.789 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-12-20T18:44:12.872Z,1671561852.872 [NAL9602](ERROR): received: 
+CSQ:0

OK
2022-12-20T18:45:31.614Z,1671561931.614 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2022-12-20T18:45:32.014Z,1671561932.014 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.334000
2022-12-20T18:45:32.015Z,1671561932.015 [IBIT](IMPORTANT): batteryCapacityThreshold: 30.000000 Ah
2022-12-20T18:45:32.015Z,1671561932.015 [IBIT](IMPORTANT): batteryVoltageThreshold: 12.000000 V
2022-12-20T18:45:32.428Z,1671561932.428 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2022-12-20T18:45:32.428Z,1671561932.428 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2022-12-20T18:45:32.429Z,1671561932.429 [IBIT](IMPORTANT): Pressure:9.141403 PSI
2022-12-20T18:45:32.429Z,1671561932.429 [IBIT](IMPORTANT): Humidity:13.111952 %
2022-12-20T18:45:32.846Z,1671561932.846 [IBIT](IMPORTANT): Vehicle Pitch:-2.211447 degrees
2022-12-20T18:45:32.847Z,1671561932.847 [IBIT](IMPORTANT): Vehicle  Roll:-2.367114 degrees
2022-12-20T18:45:32.847Z,1671561932.847 [IBIT](IMPORTANT): Vehicle  Heading:63.929234 degrees
2022-12-20T18:45:33.210Z,1671561933.210 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2022-12-20T18:45:33.211Z,1671561933.211 [IBIT](IMPORTANT): buoyancyNeutral: 324.282104 cc
2022-12-20T18:45:33.211Z,1671561933.211 [IBIT](IMPORTANT): massDefault: 2.000000 cm
2022-12-20T18:45:33.211Z,1671561933.211 [IBIT](IMPORTANT): stopDepth: 275.000000 m
2022-12-20T18:45:33.212Z,1671561933.212 [IBIT](IMPORTANT): abortDepth: 300.000000 m
2022-12-20T18:45:33.212Z,1671561933.212 [IBIT](IMPORTANT): IBIT FAILED
2022-12-20T18:46:39.961Z,1671561999.961 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-12-20T18:46:39.962Z,1671561999.962 [Default:CheckIn:C.Wait] Stopped
2022-12-20T18:46:39.962Z,1671561999.962 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T18:46:39.962Z,1671561999.962 [Default:CheckIn:D] Running Loop=1
2022-12-20T18:46:40.376Z,1671562000.376 [Default:CheckIn:D] Stopped
2022-12-20T18:46:40.376Z,1671562000.376 [Default:CheckIn:E] Running Loop=1
2022-12-20T18:46:40.761Z,1671562000.761 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.209041 min 
2022-12-20T18:46:40.761Z,1671562000.761 [Default:CheckIn:E] Stopped
2022-12-20T18:46:40.761Z,1671562000.761 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-12-20T18:46:40.761Z,1671562000.761 [Default:CheckIn] Stopped
2022-12-20T18:46:40.761Z,1671562000.761 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T18:46:40.762Z,1671562000.762 [Default:CheckIn](INFO): Running loop #6
2022-12-20T18:46:40.762Z,1671562000.762 [Default:CheckIn] Running Loop=6
2022-12-20T18:46:40.762Z,1671562000.762 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-12-20T18:46:40.762Z,1671562000.762 [Default:CheckIn:Read_GPS] Running Loop=1
2022-12-20T18:48:44.321Z,1671562124.321 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-12-20T18:48:49.170Z,1671562129.170 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184848.00,A,3648.13328,N,12147.22292,W,0.058,90.60,201222,,,D*49
2022-12-20T18:48:49.173Z,1671562129.173 [NAL9602](INFO): GPS fix at 20221220T184848: (36.802221, -121.787049)
2022-12-20T18:48:49.184Z,1671562129.184 [Default:CheckIn:Read_GPS] Stopped
2022-12-20T18:48:49.184Z,1671562129.184 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-12-20T18:48:56.752Z,1671562136.752 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20221220T164801/Courier0031.lzma
2022-12-20T18:48:57.754Z,1671562137.754 [DataOverHttps](INFO): Moved sent file to Logs/20221220T164801/Courier0031.lzma.bak
2022-12-20T18:48:57.754Z,1671562137.754 [DataOverHttps](INFO): SBD MOMSN=17399673
2022-12-20T18:49:17.021Z,1671562157.021 [DataOverHttps](INFO): Sending 815 bytes from file Logs/20221220T164801/Express0032.lzma
2022-12-20T18:49:18.022Z,1671562158.022 [DataOverHttps](INFO): Moved sent file to Logs/20221220T164801/Express0032.lzma.bak
2022-12-20T18:49:18.022Z,1671562158.022 [DataOverHttps](INFO): SBD MOMSN=17399676
2022-12-20T18:49:21.521Z,1671562161.521 [NAL9602](INFO): Not Powering down - fast GPS
2022-12-20T18:49:34.036Z,1671562174.036 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20221220T164801/Express0035.lzma
2022-12-20T18:49:35.038Z,1671562175.038 [DataOverHttps](INFO): Moved sent file to Logs/20221220T164801/Express0035.lzma.bak
2022-12-20T18:49:35.038Z,1671562175.038 [DataOverHttps](INFO): SBD MOMSN=17399703
2022-12-20T18:49:36.097Z,1671562176.097 [Default:CheckIn:Read_Iridium] Stopped
2022-12-20T18:49:36.098Z,1671562176.098 [Default:CheckIn:C.Wait] Running Loop=1
2022-12-20T18:49:36.098Z,1671562176.098 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-12-20T18:52:04.134Z,1671562324.134 [CommandExec](IMPORTANT): got command restart system
2022-12-20T18:52:06.260Z,1671562326.260 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2022-12-20T18:52:06.261Z,1671562326.261 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-20T18:52:06.261Z,1671562326.261 [CommandExec](INFO): Uninitializing the command executive.
2022-12-20T18:52:06.261Z,1671562326.261 [CommandExec](INFO): Uninitializing the command scheduler.
2022-12-20T18:52:06.261Z,1671562326.261 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:06.432Z,1671562326.432 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2022-12-20T18:52:06.432Z,1671562326.432 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2022-12-20T18:52:06.432Z,1671562326.432 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:06.433Z,1671562326.433 [NavChartDb](INFO): Join timeout helper Thread ID is 1990
2022-12-20T18:52:06.552Z,1671562326.552 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-20T18:52:06.553Z,1671562326.553 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:06.556Z,1671562326.556 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2022-12-20T18:52:06.556Z,1671562326.556 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:06.557Z,1671562326.557 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1991
2022-12-20T18:52:06.716Z,1671562326.716 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-20T18:52:06.717Z,1671562326.717 [WetLabsBB2FL](INFO): Powering down
2022-12-20T18:52:06.717Z,1671562326.717 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:06.752Z,1671562326.752 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2022-12-20T18:52:06.752Z,1671562326.752 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:06.752Z,1671562326.752 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1992
2022-12-20T18:52:07.533Z,1671562327.533 [CTD_Seabird](INFO): Powering down
2022-12-20T18:52:07.548Z,1671562327.548 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-20T18:52:07.560Z,1671562327.560 [CTD_Seabird](INFO): Powering down
2022-12-20T18:52:07.572Z,1671562327.572 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:07.586Z,1671562327.586 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler
2022-12-20T18:52:07.586Z,1671562327.586 [DAT ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:07.586Z,1671562327.586 [DAT](INFO): Join timeout helper Thread ID is 1993
2022-12-20T18:52:07.768Z,1671562327.768 [DAT](INFO): Powering down
2022-12-20T18:52:07.837Z,1671562327.837 [DAT ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-20T18:52:07.837Z,1671562327.837 [DAT](INFO): Powering down
2022-12-20T18:52:07.838Z,1671562327.838 [DAT ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:07.844Z,1671562327.844 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2022-12-20T18:52:07.844Z,1671562327.844 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:07.845Z,1671562327.845 [Radio_Surface](INFO): Join timeout helper Thread ID is 1994
2022-12-20T18:52:07.880Z,1671562327.880 [Radio_Surface](INFO): Powering down
2022-12-20T18:52:07.881Z,1671562327.881 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-20T18:52:07.881Z,1671562327.881 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:07.897Z,1671562327.897 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2022-12-20T18:52:07.897Z,1671562327.897 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:07.898Z,1671562327.898 [Onboard](INFO): Join timeout helper Thread ID is 1995
2022-12-20T18:52:08.636Z,1671562328.636 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2022-12-20T18:52:09.380Z,1671562329.380 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-20T18:52:09.381Z,1671562329.381 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:09.401Z,1671562329.401 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2022-12-20T18:52:09.401Z,1671562329.401 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:09.401Z,1671562329.401 [DataOverHttps](INFO): Join timeout helper Thread ID is 1996
2022-12-20T18:52:09.640Z,1671562329.640 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-20T18:52:09.640Z,1671562329.640 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:09.645Z,1671562329.645 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2022-12-20T18:52:09.645Z,1671562329.645 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:09.645Z,1671562329.645 [BackseatComponent](INFO): Join timeout helper Thread ID is 1997
2022-12-20T18:52:09.708Z,1671562329.708 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-20T18:52:09.709Z,1671562329.709 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:09.713Z,1671562329.713 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2022-12-20T18:52:09.713Z,1671562329.713 [logger ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:09.713Z,1671562329.713 [logger](INFO): Join timeout helper Thread ID is 1998
2022-12-20T18:52:09.728Z,1671562329.728 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-20T18:52:09.728Z,1671562329.728 [logger ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:09.733Z,1671562329.733 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2022-12-20T18:52:09.733Z,1671562329.733 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:09.733Z,1671562329.733 [CommandLine](INFO): Join timeout helper Thread ID is 1999
2022-12-20T18:52:09.808Z,1671562329.808 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-20T18:52:09.808Z,1671562329.808 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:09.813Z,1671562329.813 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2022-12-20T18:52:09.813Z,1671562329.813 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:09.813Z,1671562329.813 [CommandExec](INFO): Join timeout helper Thread ID is 2000
2022-12-20T18:52:09.814Z,1671562329.814 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2022-12-20T18:52:09.814Z,1671562329.814 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:09.815Z,1671562329.815 [controlThread](INFO): Join timeout helper Thread ID is 2001
2022-12-20T18:52:09.972Z,1671562329.972 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2022-12-20T18:52:09.972Z,1671562329.972 [controlThread](DEBUG): Uninitializing ControlThread
2022-12-20T18:52:09.973Z,1671562329.973 [AHRS_M2](INFO): Powering down
2022-12-20T18:52:10.045Z,1671562330.045 [NAL9602](INFO): Powering down
2022-12-20T18:52:10.047Z,1671562330.047 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2022-12-20T18:52:10.047Z,1671562330.047 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2022-12-20T18:52:10.048Z,1671562330.048 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2022-12-20T18:52:10.049Z,1671562330.049 [MissionManager](INFO): Uninitializing Mission Default
2022-12-20T18:52:10.049Z,1671562330.049 [Default] Stopped
2022-12-20T18:52:10.049Z,1671562330.049 [Default](DEBUG): Aggregate::uninitialize Default
2022-12-20T18:52:10.049Z,1671562330.049 [Default:B.GoToSurface] Stopped
2022-12-20T18:52:10.049Z,1671562330.049 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-12-20T18:52:10.049Z,1671562330.049 [Default:CheckIn] Stopped
2022-12-20T18:52:10.049Z,1671562330.049 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-12-20T18:52:10.049Z,1671562330.049 [Default:CheckIn:C.Wait] Stopped
2022-12-20T18:52:10.050Z,1671562330.050 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-12-20T18:52:10.053Z,1671562330.053 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2022-12-20T18:52:10.053Z,1671562330.053 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2022-12-20T18:52:10.053Z,1671562330.053 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2022-12-20T18:52:10.054Z,1671562330.054 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2022-12-20T18:52:10.054Z,1671562330.054 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2022-12-20T18:52:10.054Z,1671562330.054 [BuoyancyServo](INFO): Powering down
2022-12-20T18:52:10.068Z,1671562330.068 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2022-12-20T18:52:10.068Z,1671562330.068 [ElevatorServo](INFO): Powering down
2022-12-20T18:52:10.069Z,1671562330.069 [MassServo](DEBUG): Uninitialize Mass Servo.
2022-12-20T18:52:10.069Z,1671562330.069 [MassServo](INFO): Powering down
2022-12-20T18:52:10.070Z,1671562330.070 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-12-20T18:52:10.070Z,1671562330.070 [RudderServo](INFO): Powering down
2022-12-20T18:52:10.071Z,1671562330.071 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2022-12-20T18:52:10.071Z,1671562330.071 [ThrusterHE](INFO): Powering down
2022-12-20T18:52:10.072Z,1671562330.072 [SBIT](DEBUG): Uninitialize SBIT Component.
2022-12-20T18:52:10.073Z,1671562330.073 [IBIT](DEBUG): Uninitialize IBIT Component.
2022-12-20T18:52:10.073Z,1671562330.073 [CBIT](DEBUG): Uninitialize CBIT Component.
2022-12-20T18:52:10.073Z,1671562330.073 [CBIT](DEBUG): Powering off loads.
2022-12-20T18:52:10.084Z,1671562330.084 [CBIT](DEBUG): Disabling WDT.
2022-12-20T18:52:10.096Z,1671562330.096 [CBIT](DEBUG): Opening all GF detection circuits.
2022-12-20T18:52:10.097Z,1671562330.097 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:10.154Z,1671562330.154 [DAT ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:10.159Z,1671562330.159 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:10.161Z,1671562330.161 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:10.168Z,1671562330.168 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:10.215Z,1671562330.215 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:10.253Z,1671562330.253 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:10.256Z,1671562330.256 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:10.290Z,1671562330.290 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-12-20T18:52:10.360Z,1671562330.360 [logger ThreadHandler](INFO): Thread cancelled.