2023-04-04T16:41:44.384Z,1680626504.384 [Supervisor](DEBUG): Initializing supervisor.
2023-04-04T16:41:44.388Z,1680626504.388 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-04-04T16:41:44.389Z,1680626504.389 [SyncHandler](INFO): Protected caller Thread ID is 839
2023-04-04T16:41:44.389Z,1680626504.389 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-04-04T16:41:44.390Z,1680626504.390 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-04-04T16:41:44.390Z,1680626504.390 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 840
2023-04-04T16:41:44.394Z,1680626504.394 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-04-04T16:41:44.412Z,1680626504.412 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-04-04T16:41:44.413Z,1680626504.413 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-04-04T16:41:44.414Z,1680626504.414 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 841
2023-04-04T16:41:44.418Z,1680626504.418 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-04-04T16:41:44.419Z,1680626504.419 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-04-04T16:41:44.419Z,1680626504.419 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 842
2023-04-04T16:41:44.421Z,1680626504.421 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-04-04T16:41:44.422Z,1680626504.422 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-04-04T16:41:44.423Z,1680626504.423 [logger ThreadHandler](INFO): Protected caller Thread ID is 843
2023-04-04T16:41:44.427Z,1680626504.427 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-04-04T16:41:44.427Z,1680626504.427 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-04-04T16:41:44.431Z,1680626504.431 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-04-04T16:41:44.542Z,1680626504.542 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-04-04T16:41:44.544Z,1680626504.544 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-04-04T16:41:45.255Z,1680626505.255 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-04-04T16:41:45.257Z,1680626505.257 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-04-04T16:41:45.482Z,1680626505.482 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-04-04T16:41:45.484Z,1680626505.484 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-04-04T16:41:45.564Z,1680626505.564 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-04-04T16:41:45.695Z,1680626505.695 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-04-04T16:41:45.695Z,1680626505.695 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-04-04T16:41:45.777Z,1680626505.777 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-04-04T16:41:45.883Z,1680626505.883 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-04-04T16:41:45.885Z,1680626505.885 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-04-04T16:41:46.269Z,1680626506.269 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-04-04T16:41:46.271Z,1680626506.271 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-04-04T16:41:46.751Z,1680626506.751 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-04-04T16:41:46.751Z,1680626506.751 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-04-04T16:41:46.972Z,1680626506.972 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-04-04T16:41:46.972Z,1680626506.972 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-04-04T16:41:47.157Z,1680626507.157 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-04-04T16:41:47.157Z,1680626507.157 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-04-04T16:41:47.662Z,1680626507.662 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-04-04T16:41:47.662Z,1680626507.662 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-04-04T16:41:47.961Z,1680626507.961 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-04-04T16:41:48.580Z,1680626508.580 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-04-04T16:41:49.068Z,1680626509.068 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-04-04T16:41:49.069Z,1680626509.069 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-04-04T16:41:49.429Z,1680626509.429 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-04-04T16:41:49.429Z,1680626509.429 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-04-04T16:41:49.761Z,1680626509.761 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-04-04T16:41:49.763Z,1680626509.763 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2023-04-04T16:41:49.765Z,1680626509.765 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2023-04-04T16:41:49.849Z,1680626509.849 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2023-04-04T16:41:50.001Z,1680626510.001 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2023-04-04T16:41:50.103Z,1680626510.103 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2023-04-04T16:41:50.188Z,1680626510.188 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2023-04-04T16:41:50.282Z,1680626510.282 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2023-04-04T16:41:50.461Z,1680626510.461 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2023-04-04T16:41:50.724Z,1680626510.724 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-04-04T16:41:50.724Z,1680626510.724 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2023-04-04T16:41:50.818Z,1680626510.818 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2023-04-04T16:41:50.916Z,1680626510.916 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2023-04-04T16:41:51.055Z,1680626511.055 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2023-04-04T16:41:51.154Z,1680626511.154 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-04-04T16:41:51.169Z,1680626511.169 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-04-04T16:41:51.293Z,1680626511.293 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-04-04T16:41:51.295Z,1680626511.295 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-04-04T16:41:51.362Z,1680626511.362 [VerticalControl](DEBUG): Construct VerticalControl.
2023-04-04T16:41:51.424Z,1680626511.424 [VerticalControl] Loaded
2023-04-04T16:41:51.424Z,1680626511.424 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-04-04T16:41:51.427Z,1680626511.427 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-04-04T16:41:51.469Z,1680626511.469 [HorizontalControl] Loaded
2023-04-04T16:41:51.469Z,1680626511.469 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-04-04T16:41:51.471Z,1680626511.471 [SpeedControl](DEBUG): Construct SpeedControl.
2023-04-04T16:41:51.474Z,1680626511.474 [SpeedControl] Loaded
2023-04-04T16:41:51.475Z,1680626511.475 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-04-04T16:41:51.477Z,1680626511.477 [LoopControl](DEBUG): Construct LoopControl.
2023-04-04T16:41:51.478Z,1680626511.478 [LoopControl] Loaded
2023-04-04T16:41:51.478Z,1680626511.478 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-04-04T16:41:51.478Z,1680626511.478 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-04-04T16:41:51.479Z,1680626511.479 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-04-04T16:41:51.548Z,1680626511.548 [DepthRateCalculator] Loaded
2023-04-04T16:41:51.548Z,1680626511.548 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-04-04T16:41:51.553Z,1680626511.553 [PitchRateCalculator] Loaded
2023-04-04T16:41:51.553Z,1680626511.553 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-04-04T16:41:51.563Z,1680626511.563 [SpeedCalculator] Loaded
2023-04-04T16:41:51.564Z,1680626511.564 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-04-04T16:41:51.579Z,1680626511.579 [VerticalHomogeneityIndexCalculator] Loaded
2023-04-04T16:41:51.579Z,1680626511.579 [ComponentRegistry](DEBUG): SyncComponent "VerticalHomogeneityIndexCalculator" handled in the control thread.
2023-04-04T16:41:51.583Z,1680626511.583 [YawRateCalculator] Loaded
2023-04-04T16:41:51.584Z,1680626511.584 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-04-04T16:41:51.603Z,1680626511.603 [ElevatorOffsetCalculator] Loaded
2023-04-04T16:41:51.603Z,1680626511.603 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-04-04T16:41:51.604Z,1680626511.604 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-04-04T16:41:51.604Z,1680626511.604 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-04-04T16:41:51.647Z,1680626511.647 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-04-04T16:41:51.647Z,1680626511.647 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-04-04T16:41:51.743Z,1680626511.743 [StratificationFrontDetector](INFO): thresholdVTHI set to: 0.100000 degC
2023-04-04T16:41:51.743Z,1680626511.743 [StratificationFrontDetector](DEBUG): (re)initializing
2023-04-04T16:41:51.743Z,1680626511.743 [StratificationFrontDetector] Loaded
2023-04-04T16:41:51.743Z,1680626511.743 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2023-04-04T16:41:51.744Z,1680626511.744 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-04-04T16:41:51.745Z,1680626511.745 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-04-04T16:41:52.104Z,1680626512.104 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-04-04T16:41:52.105Z,1680626512.105 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-04-04T16:41:52.285Z,1680626512.285 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-04-04T16:41:52.286Z,1680626512.286 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-04-04T16:41:53.050Z,1680626513.050 [AHRS_M2] Loaded
2023-04-04T16:41:53.050Z,1680626513.050 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-04-04T16:41:53.299Z,1680626513.299 [BackseatComponent] Loaded
2023-04-04T16:41:53.300Z,1680626513.300 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-04-04T16:41:53.301Z,1680626513.301 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 409764E0
2023-04-04T16:41:53.301Z,1680626513.301 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 925
2023-04-04T16:41:53.304Z,1680626513.304 [LcmUniversalReporter] Loaded
2023-04-04T16:41:53.304Z,1680626513.304 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-04-04T16:41:54.490Z,1680626514.490 [BPC1] Loaded
2023-04-04T16:41:54.490Z,1680626514.490 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-04-04T16:41:54.632Z,1680626514.632 [DataOverHttps] Loaded
2023-04-04T16:41:54.632Z,1680626514.632 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-04-04T16:41:54.633Z,1680626514.633 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409A64E0
2023-04-04T16:41:54.634Z,1680626514.634 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 926
2023-04-04T16:41:54.655Z,1680626514.655 [Depth_Keller] Loaded
2023-04-04T16:41:54.655Z,1680626514.655 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-04-04T16:41:54.660Z,1680626514.660 [DropWeight] Loaded
2023-04-04T16:41:54.660Z,1680626514.660 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2023-04-04T16:41:54.724Z,1680626514.724 [NAL9602] Loaded
2023-04-04T16:41:54.724Z,1680626514.724 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-04-04T16:41:54.754Z,1680626514.754 [Onboard] Loaded
2023-04-04T16:41:54.754Z,1680626514.754 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-04-04T16:41:54.755Z,1680626514.755 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409D64E0
2023-04-04T16:41:54.756Z,1680626514.756 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 927
2023-04-04T16:41:54.768Z,1680626514.768 [Power24vConverter] Loaded
2023-04-04T16:41:54.768Z,1680626514.768 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-04-04T16:41:54.781Z,1680626514.781 [Radio_Surface] Loaded
2023-04-04T16:41:54.781Z,1680626514.781 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-04-04T16:41:54.782Z,1680626514.782 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40A064E0
2023-04-04T16:41:54.783Z,1680626514.783 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 928
2023-04-04T16:41:54.828Z,1680626514.828 [RDI_Pathfinder] Loaded
2023-04-04T16:41:54.828Z,1680626514.828 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2023-04-04T16:41:55.096Z,1680626515.096 [DAT] Loaded
2023-04-04T16:41:55.096Z,1680626515.096 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2023-04-04T16:41:55.097Z,1680626515.097 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40A364E0
2023-04-04T16:41:55.098Z,1680626515.098 [DAT ThreadHandler](INFO): Protected caller Thread ID is 929
2023-04-04T16:41:55.098Z,1680626515.098 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-04-04T16:41:55.099Z,1680626515.099 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-04-04T16:41:55.460Z,1680626515.460 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-04-04T16:41:55.460Z,1680626515.460 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-04-04T16:41:55.474Z,1680626515.474 [NavChart] Loaded
2023-04-04T16:41:55.474Z,1680626515.474 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-04-04T16:41:55.480Z,1680626515.480 [UniversalFixResidualReporter] Loaded
2023-04-04T16:41:55.480Z,1680626515.480 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-04-04T16:41:55.481Z,1680626515.481 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-04-04T16:41:55.481Z,1680626515.481 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-04-04T16:41:55.656Z,1680626515.656 [SBIT](DEBUG): Construct Startup Built In Test.
2023-04-04T16:41:55.665Z,1680626515.665 [SBIT] Loaded
2023-04-04T16:41:55.665Z,1680626515.665 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-04-04T16:41:55.668Z,1680626515.668 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-04-04T16:41:55.681Z,1680626515.681 [IBIT] Loaded
2023-04-04T16:41:55.682Z,1680626515.682 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-04-04T16:41:55.687Z,1680626515.687 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-04-04T16:41:55.794Z,1680626515.794 [CBIT] Loaded
2023-04-04T16:41:55.794Z,1680626515.794 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-04-04T16:41:55.794Z,1680626515.794 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-04-04T16:41:55.795Z,1680626515.795 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-04-04T16:41:55.956Z,1680626515.956 [BuoyancyServo] Loaded
2023-04-04T16:41:55.956Z,1680626515.956 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-04-04T16:41:55.977Z,1680626515.977 [ElevatorServo] Loaded
2023-04-04T16:41:55.977Z,1680626515.977 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-04-04T16:41:55.997Z,1680626515.997 [MassServo] Loaded
2023-04-04T16:41:55.997Z,1680626515.997 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-04-04T16:41:56.016Z,1680626516.016 [RudderServo] Loaded
2023-04-04T16:41:56.016Z,1680626516.016 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-04-04T16:41:56.034Z,1680626516.034 [ThrusterServo] Loaded
2023-04-04T16:41:56.034Z,1680626516.034 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2023-04-04T16:41:56.035Z,1680626516.035 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-04-04T16:41:56.036Z,1680626516.036 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-04-04T16:41:56.051Z,1680626516.051 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-04-04T16:41:56.052Z,1680626516.052 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-04-04T16:41:56.273Z,1680626516.273 [CTD_Seabird] Loaded
2023-04-04T16:41:56.273Z,1680626516.273 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-04-04T16:41:56.274Z,1680626516.274 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B7E4E0
2023-04-04T16:41:56.275Z,1680626516.275 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 930
2023-04-04T16:41:56.295Z,1680626516.295 [PAR_Licor] Loaded
2023-04-04T16:41:56.295Z,1680626516.295 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-04-04T16:41:56.327Z,1680626516.327 [WetLabsBB2FL] Loaded
2023-04-04T16:41:56.327Z,1680626516.327 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-04-04T16:41:56.328Z,1680626516.328 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40BAE4E0
2023-04-04T16:41:56.328Z,1680626516.328 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 931
2023-04-04T16:41:56.348Z,1680626516.348 [WetLabsUBAT] Loaded
2023-04-04T16:41:56.348Z,1680626516.348 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread.
2023-04-04T16:41:56.349Z,1680626516.349 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40BDE4E0
2023-04-04T16:41:56.350Z,1680626516.350 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 932
2023-04-04T16:41:56.350Z,1680626516.350 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-04-04T16:41:56.357Z,1680626516.357 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-04-04T16:41:56.360Z,1680626516.360 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-04-04T16:41:56.371Z,1680626516.371 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-04-04T16:41:56.372Z,1680626516.372 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C0E4E0
2023-04-04T16:41:56.373Z,1680626516.373 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 933
2023-04-04T16:41:56.377Z,1680626516.377 [Supervisor](INFO): Main Thread ID is 832
2023-04-04T16:41:56.378Z,1680626516.378 [Supervisor](DEBUG): Running supervisor.
2023-04-04T16:41:56.378Z,1680626516.378 [CommandExec ThreadHandler](INFO): Handler Thread ID is 934
2023-04-04T16:41:56.379Z,1680626516.379 [CommandExec](INFO): Initializing the command executive.
2023-04-04T16:41:56.380Z,1680626516.380 [CommandLine ThreadHandler](INFO): Handler Thread ID is 935
2023-04-04T16:41:56.382Z,1680626516.382 [controlThread ThreadHandler](INFO): Handler Thread ID is 936
2023-04-04T16:41:56.383Z,1680626516.383 [controlThread](DEBUG): Initializing ControlThread
2023-04-04T16:41:56.384Z,1680626516.384 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-04-04T16:41:56.385Z,1680626516.385 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-04-04T16:41:56.386Z,1680626516.386 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-04-04T16:41:56.386Z,1680626516.386 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-04-04T16:41:56.387Z,1680626516.387 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-04-04T16:41:56.387Z,1680626516.387 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-04-04T16:41:56.388Z,1680626516.388 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-04-04T16:41:56.388Z,1680626516.388 [VerticalHomogeneityIndexCalculator](DEBUG): (re)initializing
2023-04-04T16:41:56.389Z,1680626516.389 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-04-04T16:41:56.389Z,1680626516.389 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-04-04T16:41:56.397Z,1680626516.397 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-04-04T16:41:56.397Z,1680626516.397 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-04-04T16:41:56.398Z,1680626516.398 [SBIT](INFO): Initialize SBIT Component.
2023-04-04T16:41:56.398Z,1680626516.398 [SBIT](IMPORTANT): git: 2023-04-04
2023-04-04T16:41:56.398Z,1680626516.398 [SBIT](INFO): git hash: b8e3dc7784c205eaa6d34dbcc6cfad52b0792170
2023-04-04T16:41:56.399Z,1680626516.399 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-04-04T16:41:56.400Z,1680626516.400 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2023-04-04T16:41:56.401Z,1680626516.401 [SBIT](INFO): Beginning SBIT in 39.000000 seconds.
2023-04-04T16:41:56.401Z,1680626516.401 [IBIT](INFO): Initialize IBIT Component.
2023-04-04T16:41:56.402Z,1680626516.402 [CBIT](DEBUG): Initialize CBIT Component.
2023-04-04T16:41:56.403Z,1680626516.403 [logger ThreadHandler](INFO): Handler Thread ID is 937
2023-04-04T16:41:56.414Z,1680626516.414 [CBIT](DEBUG): Initialized mux pins.
2023-04-04T16:41:56.415Z,1680626516.415 [CBIT](DEBUG): Initializing the watchdog timer.
2023-04-04T16:41:56.423Z,1680626516.423 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 938
2023-04-04T16:41:56.435Z,1680626516.435 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 939
2023-04-04T16:41:56.436Z,1680626516.436 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-04-04T16:41:56.438Z,1680626516.438 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-04-04T16:41:56.439Z,1680626516.439 [CBIT](DEBUG): Initializing heartbeat.
2023-04-04T16:41:56.447Z,1680626516.447 [Onboard ThreadHandler](INFO): Handler Thread ID is 940
2023-04-04T16:41:56.464Z,1680626516.464 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 941
2023-04-04T16:41:56.495Z,1680626516.495 [DAT ThreadHandler](INFO): Handler Thread ID is 942
2023-04-04T16:41:56.495Z,1680626516.495 [DAT](INFO): Powering up
2023-04-04T16:41:56.496Z,1680626516.496 [DAT](DEBUG): Initializing DAT.
2023-04-04T16:41:56.503Z,1680626516.503 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 944
2023-04-04T16:41:56.504Z,1680626516.504 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-04-04T16:41:56.508Z,1680626516.508 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 946
2023-04-04T16:41:56.511Z,1680626516.511 [CBIT](DEBUG): Deactivating GF circuits.
2023-04-04T16:41:56.511Z,1680626516.511 [CBIT](DEBUG): Deactivating emergency mode.
2023-04-04T16:41:56.512Z,1680626516.512 [WetLabsBB2FL](INFO): Powering up
2023-04-04T16:41:56.513Z,1680626516.513 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 948
2023-04-04T16:41:56.515Z,1680626516.515 [WetLabsUBAT](INFO): Powering up
2023-04-04T16:41:56.516Z,1680626516.516 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 950
2023-04-04T16:41:56.525Z,1680626516.525 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-04-04T16:41:56.525Z,1680626516.525 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-04-04T16:41:56.525Z,1680626516.525 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-04-04T16:41:56.525Z,1680626516.525 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-04-04T16:41:56.526Z,1680626516.526 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-04-04T16:41:56.526Z,1680626516.526 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-04-04T16:41:56.526Z,1680626516.526 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-04-04T16:41:56.526Z,1680626516.526 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-04-04T16:41:56.550Z,1680626516.550 [CBIT](DEBUG): Backplane powered.
2023-04-04T16:41:56.555Z,1680626516.555 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-04-04T16:41:56.592Z,1680626516.592 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-04-04T16:41:56.628Z,1680626516.628 [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>


2023-04-04T16:41:56.629Z,1680626516.629 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-04-04T16:41:56.708Z,1680626516.708 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-04-04T16:41:56.709Z,1680626516.709 [Default:A.Wait](DEBUG): Construct Wait.
2023-04-04T16:41:56.711Z,1680626516.711 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-04-04T16:41:56.754Z,1680626516.754 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-04-04T16:41:56.781Z,1680626516.781 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-04-04T16:41:56.814Z,1680626516.814 [Default:E.Execute](DEBUG): Construct Execute.
2023-04-04T16:41:56.818Z,1680626516.818 [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>


2023-04-04T16:41:56.823Z,1680626516.823 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,RDI_Pathfinder,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,VerticalHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2023-04-04T16:41:56.831Z,1680626516.831 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-04-04T16:41:56.871Z,1680626516.871 [Radio_Surface](INFO): Powering up
2023-04-04T16:41:57.004Z,1680626517.004 [Depth_Keller](ERROR): Pressure or depth reading out of range: -1.000394 decibar, -0.993016 m
2023-04-04T16:41:57.006Z,1680626517.006 [Power24vConverter](INFO): Powering up.
2023-04-04T16:41:57.007Z,1680626517.007 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format
2023-04-04T16:41:57.032Z,1680626517.032 [DepthRateCalculator](ERROR): Depth measurement is not active
2023-04-04T16:41:57.072Z,1680626517.072 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-04-04T16:41:57.079Z,1680626517.079 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-04-04T16:41:57.080Z,1680626517.080 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-04-04T16:41:57.087Z,1680626517.087 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-04-04T16:41:57.088Z,1680626517.088 [MassServo](DEBUG): Initializing EZServoServo.
2023-04-04T16:41:57.095Z,1680626517.095 [MassServo](DEBUG): Initializing MassServo.
2023-04-04T16:41:57.096Z,1680626517.096 [RudderServo](DEBUG): Initializing EZServoServo.
2023-04-04T16:41:57.103Z,1680626517.103 [RudderServo](DEBUG): Initializing RudderServo.
2023-04-04T16:41:57.104Z,1680626517.104 [ThrusterServo](DEBUG): Initializing EZServoServo.
2023-04-04T16:41:57.111Z,1680626517.111 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2023-04-04T16:41:59.123Z,1680626519.123 [WetLabsBB2FL](INFO): Powering down
2023-04-04T16:42:03.535Z,1680626523.535 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2023-04-04T16:42:05.815Z,1680626525.815 [WetLabsUBAT](INFO): Powering down
2023-04-04T16:42:08.591Z,1680626528.591 [DAT](INFO): DAT read: 

2023-04-04T16:42:08.592Z,1680626528.592 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2023-04-04T16:42:10.104Z,1680626530.104 [DAT](INFO): DAT read: MF Frequency Band

2023-04-04T16:42:10.105Z,1680626530.105 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2023-04-04T16:42:10.106Z,1680626530.106 [DAT](INFO): DAT read: Apr  4 2023 16:42:05 

2023-04-04T16:42:11.364Z,1680626531.364 [DAT](INFO): DAT read: Features enabled [Bearing]

2023-04-04T16:42:11.365Z,1680626531.365 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2023-04-04T16:42:11.365Z,1680626531.365 [DAT](INFO): commRate: 800
2023-04-04T16:42:13.430Z,1680626533.430 [DAT](INFO): entering command mode
2023-04-04T16:42:13.632Z,1680626533.632 [DAT](INFO): DAT read: 

2023-04-04T16:42:13.634Z,1680626533.634 [DAT](INFO): DAT read: user:1>

2023-04-04T16:42:13.635Z,1680626533.635 [DAT](INFO): setting verbose to 3
2023-04-04T16:42:13.883Z,1680626533.883 [DAT](INFO): DAT read: user:1>

2023-04-04T16:42:13.884Z,1680626533.884 [DAT](INFO): DAT read: Verbose         | 3           

2023-04-04T16:42:13.884Z,1680626533.884 [DAT](INFO): set verbose to 3
2023-04-04T16:42:13.885Z,1680626533.885 [DAT](INFO): setting DatVerbose to 27440
2023-04-04T16:42:14.135Z,1680626534.135 [DAT](INFO): DAT read: user:2>

2023-04-04T16:42:14.136Z,1680626534.136 [DAT](INFO): DAT read: DatVerbose      | 27440       

2023-04-04T16:42:14.136Z,1680626534.136 [DAT](INFO): set DatVerbose to 27440
2023-04-04T16:42:14.137Z,1680626534.137 [DAT](INFO): setting transmit power to 8
2023-04-04T16:42:14.387Z,1680626534.387 [DAT](INFO): DAT read: user:3>

2023-04-04T16:42:14.388Z,1680626534.388 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2023-04-04T16:42:14.388Z,1680626534.388 [DAT](INFO): set transmit power to 8
2023-04-04T16:42:14.389Z,1680626534.389 [DAT](INFO): setting local address to 9
2023-04-04T16:42:14.639Z,1680626534.639 [DAT](INFO): DAT read: user:4>

2023-04-04T16:42:14.640Z,1680626534.640 [DAT](INFO): DAT read: LocalAddr       | 9           

2023-04-04T16:42:14.640Z,1680626534.640 [DAT](INFO): set local address to 9
2023-04-04T16:42:14.641Z,1680626534.641 [DAT](INFO): Setting time to: 16:42:14 And date to:4/4/2023
2023-04-04T16:42:14.891Z,1680626534.891 [DAT](INFO): DAT read: user:5>

2023-04-04T16:42:14.892Z,1680626534.892 [DAT](INFO): DAT read: Tue Apr 4, 2023  16:42:14  

2023-04-04T16:42:14.892Z,1680626534.892 [DAT](INFO): Local DAT time set to Tue Apr 4, 2023  16:42:14  

2023-04-04T16:42:25.116Z,1680626545.116 [NAL9602](INFO): Powering up NAL9602
2023-04-04T16:42:36.032Z,1680626556.032 [NAL9602](INFO): NAL9602 initialized
2023-04-04T16:42:36.109Z,1680626556.109 [SBIT](IMPORTANT): Beginning Startup BIT
2023-04-04T16:42:36.117Z,1680626556.117 [CBIT](IMPORTANT): Beginning ground fault scan
2023-04-04T16:42:46.986Z,1680626566.986 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.008382
CHAN A1 (24V): 0.003835
CHAN A2 (12V): -0.005232
CHAN A3 (5V): -0.001577
CHAN B0 (3.3V): 0.000567
CHAN B1 (3.15aV): -0.000045
CHAN B2 (3.15bV): 0.000451
CHAN B3 (GND): 0.001754
OPEN: -0.003317
Full Scale: +/- 1 mA
2023-04-04T16:43:30.211Z,1680626610.211 [SBIT](IMPORTANT): SBIT PASSED
2023-04-04T16:43:30.211Z,1680626610.211 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-04-04T16:43:30.212Z,1680626610.212 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;

2023-04-04T16:43:30.212Z,1680626610.212 [SBIT](IMPORTANT): CBIT.gf24Offset=143 microampere;

2023-04-04T16:43:30.212Z,1680626610.212 [SBIT](IMPORTANT): Express linearApproximation VerticalHomogeneityIndexCalculator.vertical_temperature_homogeneity_index 0.050000 celsius;

2023-04-04T16:43:30.212Z,1680626610.212 [SBIT](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 0.300000 liter_per_second;

2023-04-04T16:43:30.213Z,1680626610.213 [SBIT](IMPORTANT): StratificationFrontDetector.loadAtStartup=1 bool;

2023-04-04T16:43:30.213Z,1680626610.213 [SBIT](IMPORTANT): StratificationFrontDetector.threshold_VTHI=0.1 celsius;

2023-04-04T16:43:30.213Z,1680626610.213 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=283.590738 cubic_centimeter;

2023-04-04T16:43:30.213Z,1680626610.213 [SBIT](IMPORTANT): VerticalControl.massDefault=0.5 centimeter;

2023-04-04T16:43:30.213Z,1680626610.213 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth3=20 meter;

2023-04-04T16:43:30.213Z,1680626610.213 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth4=30 meter;

2023-04-04T16:43:30.213Z,1680626610.213 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.loadAtStartup=1 bool;

2023-04-04T16:43:30.714Z,1680626610.714 [MissionManager](IMPORTANT): Started mission Startup
2023-04-04T16:43:30.715Z,1680626610.715 [Startup] Running Loop=1
2023-04-04T16:43:30.715Z,1680626610.715 [Startup](DEBUG): Aggregate::initialize Startup
2023-04-04T16:43:30.715Z,1680626610.715 [Startup:A.GoToSurface] Running Loop=1
2023-04-04T16:43:30.715Z,1680626610.715 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-04-04T16:43:30.715Z,1680626610.715 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-04-04T16:43:30.716Z,1680626610.716 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-04-04T16:43:30.716Z,1680626610.716 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-04-04T16:43:30.717Z,1680626610.717 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-04-04T16:43:30.717Z,1680626610.717 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-04-04T16:43:30.718Z,1680626610.718 [Startup:StartupSatComms] Running Loop=1
2023-04-04T16:43:30.719Z,1680626610.719 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-04-04T16:43:30.719Z,1680626610.719 [Startup:StartupSatComms:A] Running Loop=1
2023-04-04T16:43:31.076Z,1680626611.076 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-04-04T16:44:30.810Z,1680626670.810 [Startup:StartupSatComms:A](INFO): Timed out from 2023-04-04T16:43:30.7Z
2023-04-04T16:44:30.810Z,1680626670.810 [Startup:StartupSatComms:A] Stopped
2023-04-04T16:44:30.810Z,1680626670.810 [Startup:StartupSatComms:B] Running Loop=1
2023-04-04T16:44:31.210Z,1680626671.210 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-04-04T16:44:56.693Z,1680626696.693 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2023-04-04T16:44:56.693Z,1680626696.693 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-04T16:44:56.740Z,1680626696.740 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-04T16:44:57.048Z,1680626697.048 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-04T16:44:57.048Z,1680626697.048 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2023-04-04T16:45:24.745Z,1680626724.745 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004398
2023-04-04T16:45:31.002Z,1680626731.002 [Startup:StartupSatComms:B](INFO): Timed out from 2023-04-04T16:44:30.8Z
2023-04-04T16:45:31.002Z,1680626731.002 [Startup:StartupSatComms:B] Stopped
2023-04-04T16:45:31.003Z,1680626731.003 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-04-04T16:45:31.003Z,1680626731.003 [Startup:StartupSatComms] Stopped
2023-04-04T16:45:31.003Z,1680626731.003 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-04-04T16:45:31.004Z,1680626731.004 [Startup](INFO): Completed Startup
2023-04-04T16:45:31.004Z,1680626731.004 [MissionManager](INFO): Startup is completed.
2023-04-04T16:45:31.004Z,1680626731.004 [MissionManager](INFO): Uninitializing Mission Startup
2023-04-04T16:45:31.004Z,1680626731.004 [Startup] Stopped
2023-04-04T16:45:31.004Z,1680626731.004 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-04-04T16:45:31.004Z,1680626731.004 [Startup:A.GoToSurface] Stopped
2023-04-04T16:45:31.004Z,1680626731.004 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-04-04T16:45:31.384Z,1680626731.384 [MissionManager](IMPORTANT): Started mission Default
2023-04-04T16:45:31.384Z,1680626731.384 [Default] Running Loop=1
2023-04-04T16:45:31.385Z,1680626731.385 [Default](DEBUG): Aggregate::initialize Default
2023-04-04T16:45:31.385Z,1680626731.385 [Default:B.GoToSurface] Running Loop=1
2023-04-04T16:45:31.385Z,1680626731.385 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-04-04T16:45:31.385Z,1680626731.385 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-04-04T16:45:31.385Z,1680626731.385 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-04-04T16:45:31.386Z,1680626731.386 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-04-04T16:45:31.386Z,1680626731.386 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-04-04T16:45:31.387Z,1680626731.387 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-04-04T16:45:31.387Z,1680626731.387 [Default:A.Wait] Running Loop=1
2023-04-04T16:45:31.387Z,1680626731.387 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-04-04T16:45:44.729Z,1680626744.729 [Default:A.Wait](INFO): Done Waiting.
2023-04-04T16:45:44.729Z,1680626744.729 [Default:A.Wait] Stopped
2023-04-04T16:45:44.729Z,1680626744.729 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-04-04T16:45:45.109Z,1680626745.109 [Default:CheckIn] Running Loop=1
2023-04-04T16:45:45.109Z,1680626745.109 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-04T16:45:45.109Z,1680626745.109 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-04T16:45:45.569Z,1680626745.569 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-04-04T16:45:46.745Z,1680626746.745 [NAL9602](INFO): SBD MO Status=0, MOMSN=23404, MT Status=0, MTMSN=0
2023-04-04T16:45:46.745Z,1680626746.745 [NAL9602](INFO): No messages in MT queue
2023-04-04T16:46:33.182Z,1680626793.182 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164632.00,A,3648.17736,N,12147.28028,W,2.371,197.34,040423,,,A*7A
2023-04-04T16:46:33.193Z,1680626793.193 [NAL9602](INFO): GPS fix at 20230404T164632: (36.802956, -121.788005)
2023-04-04T16:46:33.205Z,1680626793.205 [Default:CheckIn:Read_GPS] Stopped
2023-04-04T16:46:33.205Z,1680626793.205 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-04T16:46:33.620Z,1680626793.620 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-04-04T16:47:05.601Z,1680626825.601 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2023-04-04T16:47:05.623Z,1680626825.623 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-04T16:49:40.745Z,1680626980.745 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2023-04-04T16:49:40.749Z,1680626980.749 [BPC1](INFO): Received data from all battery sticks.
2023-04-04T16:57:48.542Z,1680627468.542 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20230404T151714/Courier0046.lzma
2023-04-04T16:57:49.544Z,1680627469.544 [DataOverHttps](INFO): Moved sent file to Logs/20230404T151714/Courier0046.lzma.bak
2023-04-04T16:57:49.545Z,1680627469.545 [DataOverHttps](INFO): SBD MOMSN=18029362
2023-04-04T16:58:05.694Z,1680627485.694 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20230404T164144/Courier0000.lzma
2023-04-04T16:58:06.696Z,1680627486.696 [DataOverHttps](INFO): Moved sent file to Logs/20230404T164144/Courier0000.lzma.bak
2023-04-04T16:58:06.696Z,1680627486.696 [DataOverHttps](INFO): SBD MOMSN=18029365
2023-04-04T16:58:26.636Z,1680627506.636 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20230404T164144/Courier0004.lzma
2023-04-04T16:58:27.632Z,1680627507.632 [DataOverHttps](INFO): Moved sent file to Logs/20230404T164144/Courier0004.lzma.bak
2023-04-04T16:58:27.633Z,1680627507.633 [DataOverHttps](IMPORTANT): SBD MOMSN=18029369, MTMSN=20230404T165827
2023-04-04T16:58:35.426Z,1680627515.426 [DataOverHttps](INFO): Received command: ibit
2023-04-04T16:58:35.443Z,1680627515.443 [CommandExec](IMPORTANT): got command ibit
2023-04-04T16:58:35.534Z,1680627515.534 [IBIT](IMPORTANT): Beginning Initiated BIT
2023-04-04T16:58:35.547Z,1680627515.547 [IBIT](IMPORTANT): Beginning control surface checks.
2023-04-04T16:58:35.554Z,1680627515.554 [CBIT](IMPORTANT): Beginning ground fault scan
2023-04-04T16:58:37.129Z,1680627517.129 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165837.00,A,3648.14982,N,12147.22175,W,0.097,195.41,040423,,,D*7D
2023-04-04T16:58:37.133Z,1680627517.133 [NAL9602](INFO): GPS fix at 20230404T165837: (36.802497, -121.787029)
2023-04-04T16:58:44.230Z,1680627524.230 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20230404T151714/Express0047.lzma
2023-04-04T16:58:45.232Z,1680627525.232 [DataOverHttps](INFO): Moved sent file to Logs/20230404T151714/Express0047.lzma.bak
2023-04-04T16:58:45.233Z,1680627525.233 [DataOverHttps](IMPORTANT): SBD MOMSN=18029374, MTMSN=20230404T165845
2023-04-04T16:58:46.510Z,1680627526.510 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.007338
CHAN A1 (24V): 0.005438
CHAN A2 (12V): -0.004704
CHAN A3 (5V): -0.001136
CHAN B0 (3.3V): 0.000682
CHAN B1 (3.15aV): 0.000052
CHAN B2 (3.15bV): 0.000593
CHAN B3 (GND): 0.001722
OPEN: 0.005479
Full Scale: +/- 1 mA
2023-04-04T16:58:51.325Z,1680627531.325 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=23405, MT Status=1, MTMSN=1259
2023-04-04T16:58:51.325Z,1680627531.325 [NAL9602](INFO): Data available in MT queue
2023-04-04T16:58:51.867Z,1680627531.867 [NAL9602](INFO): Received command: ibit
2023-04-04T16:58:51.879Z,1680627531.879 [CommandExec](IMPORTANT): got command ibit
2023-04-04T16:58:51.910Z,1680627531.910 [IBIT](IMPORTANT): Beginning Initiated BIT
2023-04-04T16:58:51.910Z,1680627531.910 [IBIT](IMPORTANT): Beginning control surface checks.
2023-04-04T16:58:51.914Z,1680627531.914 [CBIT](IMPORTANT): Beginning ground fault scan
2023-04-04T16:58:52.714Z,1680627532.714 [DataOverHttps](INFO): Received command: configSet list
2023-04-04T16:58:52.745Z,1680627532.745 [CommandExec](IMPORTANT): got command configSet list
2023-04-04T16:58:52.746Z,1680627532.746 [CommandExec](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-04-04T16:58:52.748Z,1680627532.748 [CommandExec](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;

2023-04-04T16:58:52.748Z,1680627532.748 [CommandExec](IMPORTANT): CBIT.gf24Offset=143 microampere;

2023-04-04T16:58:52.748Z,1680627532.748 [CommandExec](IMPORTANT): Express linearApproximation VerticalHomogeneityIndexCalculator.vertical_temperature_homogeneity_index 0.050000 celsius;

2023-04-04T16:58:52.748Z,1680627532.748 [CommandExec](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 0.300000 liter_per_second;

2023-04-04T16:58:52.748Z,1680627532.748 [CommandExec](IMPORTANT): StratificationFrontDetector.loadAtStartup=1 bool;

2023-04-04T16:58:52.749Z,1680627532.749 [CommandExec](IMPORTANT): StratificationFrontDetector.threshold_VTHI=0.1 celsius;

2023-04-04T16:58:52.749Z,1680627532.749 [CommandExec](IMPORTANT): VerticalControl.buoyancyNeutral=283.590738 cubic_centimeter;

2023-04-04T16:58:52.749Z,1680627532.749 [CommandExec](IMPORTANT): VerticalControl.massDefault=0.5 centimeter;

2023-04-04T16:58:52.749Z,1680627532.749 [CommandExec](IMPORTANT): VerticalHomogeneityIndexCalculator.depth3=20 meter;

2023-04-04T16:58:52.749Z,1680627532.749 [CommandExec](IMPORTANT): VerticalHomogeneityIndexCalculator.depth4=30 meter;

2023-04-04T16:58:52.749Z,1680627532.749 [CommandExec](IMPORTANT): VerticalHomogeneityIndexCalculator.loadAtStartup=1 bool;

2023-04-04T16:58:52.947Z,1680627532.947 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165852.00,A,3648.15007,N,12147.22184,W,0.039,195.41,040423,,,D*71
2023-04-04T16:58:52.949Z,1680627532.949 [NAL9602](INFO): GPS fix at 20230404T165852: (36.802501, -121.787031)
2023-04-04T16:58:56.173Z,1680627536.173 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165856.00,A,3648.15002,N,12147.22173,W,0.019,195.41,040423,,,D*7A
2023-04-04T16:58:56.175Z,1680627536.175 [NAL9602](INFO): GPS fix at 20230404T165856: (36.802500, -121.787029)
2023-04-04T16:58:59.406Z,1680627539.406 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165859.00,A,3648.14999,N,12147.22170,W,0.058,195.41,040423,,,D*79
2023-04-04T16:58:59.408Z,1680627539.408 [NAL9602](INFO): GPS fix at 20230404T165859: (36.802500, -121.787028)
2023-04-04T16:59:01.686Z,1680627541.686 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20230404T164144/Courier0007.lzma
2023-04-04T16:59:02.235Z,1680627542.235 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165902.00,A,3648.14998,N,12147.22164,W,0.058,195.41,040423,,,D*72
2023-04-04T16:59:02.237Z,1680627542.237 [NAL9602](INFO): GPS fix at 20230404T165902: (36.802500, -121.787027)
2023-04-04T16:59:02.688Z,1680627542.688 [DataOverHttps](INFO): Moved sent file to Logs/20230404T164144/Courier0007.lzma.bak
2023-04-04T16:59:02.688Z,1680627542.688 [DataOverHttps](INFO): SBD MOMSN=18029377
2023-04-04T16:59:02.738Z,1680627542.738 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.006384
CHAN A1 (24V): 0.005600
CHAN A2 (12V): -0.005334
CHAN A3 (5V): -0.001644
CHAN B0 (3.3V): 0.000241
CHAN B1 (3.15aV): 0.000381
CHAN B2 (3.15bV): 0.000523
CHAN B3 (GND): 0.001074
OPEN: 0.005720
Full Scale: +/- 1 mA
2023-04-04T16:59:05.465Z,1680627545.465 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165905.00,A,3648.15002,N,12147.22156,W,0.039,195.41,040423,,,D*78
2023-04-04T16:59:05.468Z,1680627545.468 [NAL9602](INFO): GPS fix at 20230404T165905: (36.802500, -121.787026)
2023-04-04T16:59:08.293Z,1680627548.293 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165908.00,A,3648.15002,N,12147.22154,W,0.039,195.41,040423,,,D*77
2023-04-04T16:59:08.296Z,1680627548.296 [NAL9602](INFO): GPS fix at 20230404T165908: (36.802500, -121.787026)
2023-04-04T16:59:11.524Z,1680627551.524 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165911.00,A,3648.15004,N,12147.22149,W,0.019,195.41,040423,,,D*77
2023-04-04T16:59:11.527Z,1680627551.527 [NAL9602](INFO): GPS fix at 20230404T165911: (36.802501, -121.787025)
2023-04-04T16:59:14.353Z,1680627554.353 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165914.00,A,3648.15003,N,12147.22141,W,0.000,195.41,040423,,,D*75
2023-04-04T16:59:14.356Z,1680627554.356 [NAL9602](INFO): GPS fix at 20230404T165914: (36.802501, -121.787024)
2023-04-04T16:59:17.185Z,1680627557.185 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165917.00,A,3648.15000,N,12147.22143,W,0.039,195.41,040423,,,D*7D
2023-04-04T16:59:17.188Z,1680627557.188 [NAL9602](INFO): GPS fix at 20230404T165917: (36.802500, -121.787024)
2023-04-04T16:59:19.758Z,1680627559.758 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230404T164144/Courier0010.lzma
2023-04-04T16:59:20.415Z,1680627560.415 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165920.00,A,3648.14998,N,12147.22148,W,0.039,195.41,040423,,,D*7B
2023-04-04T16:59:20.417Z,1680627560.417 [NAL9602](INFO): GPS fix at 20230404T165920: (36.802500, -121.787025)
2023-04-04T16:59:20.760Z,1680627560.760 [DataOverHttps](INFO): Moved sent file to Logs/20230404T164144/Courier0010.lzma.bak
2023-04-04T16:59:20.760Z,1680627560.760 [DataOverHttps](INFO): SBD MOMSN=18029379
2023-04-04T16:59:23.241Z,1680627563.241 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165923.00,A,3648.14996,N,12147.22160,W,0.019,195.41,040423,,,D*7E
2023-04-04T16:59:23.244Z,1680627563.244 [NAL9602](INFO): GPS fix at 20230404T165923: (36.802499, -121.787027)
2023-04-04T16:59:26.474Z,1680627566.474 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165926.00,A,3648.15002,N,12147.22173,W,0.039,195.41,040423,,,D*7E
2023-04-04T16:59:26.476Z,1680627566.476 [NAL9602](INFO): GPS fix at 20230404T165926: (36.802500, -121.787029)
2023-04-04T16:59:29.300Z,1680627569.300 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165929.00,A,3648.15013,N,12147.22187,W,0.019,195.41,040423,,,D*78
2023-04-04T16:59:29.302Z,1680627569.302 [NAL9602](INFO): GPS fix at 20230404T165929: (36.802502, -121.787031)
2023-04-04T16:59:32.537Z,1680627572.537 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165932.00,A,3648.15023,N,12147.22187,W,0.019,195.41,040423,,,D*71
2023-04-04T16:59:32.540Z,1680627572.540 [NAL9602](INFO): GPS fix at 20230404T165932: (36.802504, -121.787031)
2023-04-04T16:59:35.369Z,1680627575.369 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165935.00,A,3648.15032,N,12147.22191,W,0.019,195.41,040423,,,D*71
2023-04-04T16:59:35.372Z,1680627575.372 [NAL9602](INFO): GPS fix at 20230404T165935: (36.802505, -121.787032)
2023-04-04T16:59:37.955Z,1680627577.955 [DataOverHttps](INFO): Sending 931 bytes from file Logs/20230404T164144/Express0001.lzma
2023-04-04T16:59:38.190Z,1680627578.190 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165938.00,A,3648.15040,N,12147.22200,W,0.019,195.41,040423,,,D*72
2023-04-04T16:59:38.192Z,1680627578.192 [NAL9602](INFO): GPS fix at 20230404T165938: (36.802507, -121.787033)
2023-04-04T16:59:38.210Z,1680627578.210 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 4
Latitude: 36.802505 Longitude: -121.787033
2023-04-04T16:59:38.685Z,1680627578.685 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.690001
2023-04-04T16:59:38.685Z,1680627578.685 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2023-04-04T16:59:38.686Z,1680627578.686 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2023-04-04T16:59:38.957Z,1680627578.957 [DataOverHttps](INFO): Moved sent file to Logs/20230404T164144/Express0001.lzma.bak
2023-04-04T16:59:38.957Z,1680627578.957 [DataOverHttps](INFO): SBD MOMSN=18029382
2023-04-04T16:59:39.043Z,1680627579.043 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2023-04-04T16:59:39.043Z,1680627579.043 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2023-04-04T16:59:39.043Z,1680627579.043 [IBIT](IMPORTANT): Pressure:7.731045 PSI
2023-04-04T16:59:39.044Z,1680627579.044 [IBIT](IMPORTANT): Humidity:23.385424 %
2023-04-04T16:59:39.450Z,1680627579.450 [IBIT](IMPORTANT): Vehicle Pitch:1.261404 degrees
2023-04-04T16:59:39.455Z,1680627579.455 [IBIT](IMPORTANT): Vehicle  Roll:10.742167 degrees
2023-04-04T16:59:39.455Z,1680627579.455 [IBIT](IMPORTANT): Vehicle  Heading:203.378403 degrees
2023-04-04T16:59:39.827Z,1680627579.827 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2023-04-04T16:59:39.827Z,1680627579.827 [IBIT](IMPORTANT): buoyancyNeutral: 283.590729 cc
2023-04-04T16:59:39.828Z,1680627579.828 [IBIT](IMPORTANT): massDefault: 0.500000 cm
2023-04-04T16:59:39.828Z,1680627579.828 [IBIT](IMPORTANT): stopDepth: 215.000000 m
2023-04-04T16:59:39.828Z,1680627579.828 [IBIT](IMPORTANT): abortDepth: 255.000000 m
2023-04-04T16:59:39.828Z,1680627579.828 [IBIT](IMPORTANT): IBIT PASSED
2023-04-04T16:59:55.199Z,1680627595.199 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20230404T164144/Express0005.lzma
2023-04-04T16:59:56.200Z,1680627596.200 [DataOverHttps](INFO): Moved sent file to Logs/20230404T164144/Express0005.lzma.bak
2023-04-04T16:59:56.200Z,1680627596.200 [DataOverHttps](INFO): SBD MOMSN=18029405
2023-04-04T17:00:10.911Z,1680627610.911 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-04T17:00:12.594Z,1680627612.594 [DataOverHttps](INFO): Sending 273 bytes from file Logs/20230404T164144/Express0008.lzma
2023-04-04T17:00:13.588Z,1680627613.588 [DataOverHttps](INFO): Moved sent file to Logs/20230404T164144/Express0008.lzma.bak
2023-04-04T17:00:13.589Z,1680627613.589 [DataOverHttps](INFO): SBD MOMSN=18029408
2023-04-04T17:00:33.091Z,1680627633.091 [DataOverHttps](INFO): Sending 801 bytes from file Logs/20230404T164144/Express0011.lzma
2023-04-04T17:00:34.093Z,1680627634.093 [DataOverHttps](INFO): Moved sent file to Logs/20230404T164144/Express0011.lzma.bak
2023-04-04T17:00:34.093Z,1680627634.093 [DataOverHttps](INFO): SBD MOMSN=18029417
2023-04-04T17:00:35.212Z,1680627635.212 [Default:CheckIn:Read_Iridium] Stopped
2023-04-04T17:00:35.212Z,1680627635.212 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-04T17:00:35.212Z,1680627635.212 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-04T17:05:35.834Z,1680627935.834 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-04T17:05:35.835Z,1680627935.835 [Default:CheckIn:C.Wait] Stopped
2023-04-04T17:05:35.835Z,1680627935.835 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-04T17:05:35.835Z,1680627935.835 [Default:CheckIn:D] Running Loop=1
2023-04-04T17:05:36.245Z,1680627936.245 [Default:CheckIn:D] Stopped
2023-04-04T17:05:36.245Z,1680627936.245 [Default:CheckIn:E] Running Loop=1
2023-04-04T17:05:36.682Z,1680627936.682 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.081012 min 
2023-04-04T17:05:36.682Z,1680627936.682 [Default:CheckIn:E] Stopped
2023-04-04T17:05:36.682Z,1680627936.682 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-04T17:05:36.682Z,1680627936.682 [Default:CheckIn] Stopped
2023-04-04T17:05:36.682Z,1680627936.682 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-04T17:05:36.683Z,1680627936.683 [Default:CheckIn](INFO): Running loop #2
2023-04-04T17:05:36.683Z,1680627936.683 [Default:CheckIn] Running Loop=2
2023-04-04T17:05:36.683Z,1680627936.683 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-04T17:05:36.683Z,1680627936.683 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-04T17:05:38.653Z,1680627938.653 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170538.00,A,3648.14950,N,12147.22278,W,0.039,195.41,040423,,,D*7E
2023-04-04T17:05:38.656Z,1680627938.656 [NAL9602](INFO): GPS fix at 20230404T170538: (36.802492, -121.787046)
2023-04-04T17:05:38.706Z,1680627938.706 [Default:CheckIn:Read_GPS] Stopped
2023-04-04T17:05:38.706Z,1680627938.706 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-04T17:05:46.242Z,1680627946.242 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230404T164144/Courier0013.lzma
2023-04-04T17:05:47.244Z,1680627947.244 [DataOverHttps](INFO): Moved sent file to Logs/20230404T164144/Courier0013.lzma.bak
2023-04-04T17:05:47.244Z,1680627947.244 [DataOverHttps](INFO): SBD MOMSN=18029453
2023-04-04T17:05:48.346Z,1680627948.346 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=23406, MT Status=1, MTMSN=1260
2023-04-04T17:05:48.346Z,1680627948.346 [NAL9602](INFO): Data available in MT queue
2023-04-04T17:05:48.847Z,1680627948.847 [NAL9602](INFO): Received command: configSet list
2023-04-04T17:05:48.930Z,1680627948.930 [CommandExec](IMPORTANT): got command configSet list
2023-04-04T17:05:48.930Z,1680627948.930 [CommandExec](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-04-04T17:05:48.935Z,1680627948.935 [CommandExec](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;

2023-04-04T17:05:48.935Z,1680627948.935 [CommandExec](IMPORTANT): CBIT.gf24Offset=143 microampere;

2023-04-04T17:05:48.935Z,1680627948.935 [CommandExec](IMPORTANT): Express linearApproximation VerticalHomogeneityIndexCalculator.vertical_temperature_homogeneity_index 0.050000 celsius;

2023-04-04T17:05:48.935Z,1680627948.935 [CommandExec](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 0.300000 liter_per_second;

2023-04-04T17:05:48.935Z,1680627948.935 [CommandExec](IMPORTANT): StratificationFrontDetector.loadAtStartup=1 bool;

2023-04-04T17:05:48.935Z,1680627948.935 [CommandExec](IMPORTANT): StratificationFrontDetector.threshold_VTHI=0.1 celsius;

2023-04-04T17:05:48.936Z,1680627948.936 [CommandExec](IMPORTANT): VerticalControl.buoyancyNeutral=283.590738 cubic_centimeter;

2023-04-04T17:05:48.936Z,1680627948.936 [CommandExec](IMPORTANT): VerticalControl.massDefault=0.5 centimeter;

2023-04-04T17:05:48.936Z,1680627948.936 [CommandExec](IMPORTANT): VerticalHomogeneityIndexCalculator.depth3=20 meter;

2023-04-04T17:05:48.936Z,1680627948.936 [CommandExec](IMPORTANT): VerticalHomogeneityIndexCalculator.depth4=30 meter;

2023-04-04T17:05:48.936Z,1680627948.936 [CommandExec](IMPORTANT): VerticalHomogeneityIndexCalculator.loadAtStartup=1 bool;

2023-04-04T17:06:03.731Z,1680627963.731 [DataOverHttps](INFO): Sending 700 bytes from file Logs/20230404T164144/Express0014.lzma
2023-04-04T17:06:04.732Z,1680627964.732 [DataOverHttps](INFO): Moved sent file to Logs/20230404T164144/Express0014.lzma.bak
2023-04-04T17:06:04.732Z,1680627964.732 [DataOverHttps](INFO): SBD MOMSN=18029456
2023-04-04T17:06:06.135Z,1680627966.135 [Default:CheckIn:Read_Iridium] Stopped
2023-04-04T17:06:06.136Z,1680627966.136 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-04T17:06:06.136Z,1680627966.136 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-04T17:06:19.458Z,1680627979.458 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-04T17:11:06.844Z,1680628266.844 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-04T17:11:06.844Z,1680628266.844 [Default:CheckIn:C.Wait] Stopped
2023-04-04T17:11:06.844Z,1680628266.844 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-04T17:11:06.844Z,1680628266.844 [Default:CheckIn:D] Running Loop=1
2023-04-04T17:11:07.182Z,1680628267.182 [Default:CheckIn:D] Stopped
2023-04-04T17:11:07.182Z,1680628267.182 [Default:CheckIn:E] Running Loop=1
2023-04-04T17:11:07.572Z,1680628267.572 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 25.596623 min 
2023-04-04T17:11:07.572Z,1680628267.572 [Default:CheckIn:E] Stopped
2023-04-04T17:11:07.572Z,1680628267.572 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-04T17:11:07.572Z,1680628267.572 [Default:CheckIn] Stopped
2023-04-04T17:11:07.572Z,1680628267.572 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-04T17:11:07.572Z,1680628267.572 [Default:CheckIn](INFO): Running loop #3
2023-04-04T17:11:07.572Z,1680628267.572 [Default:CheckIn] Running Loop=3
2023-04-04T17:11:07.573Z,1680628267.573 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-04T17:11:07.573Z,1680628267.573 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-04T17:11:09.587Z,1680628269.587 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171109.00,A,3648.14951,N,12147.22260,W,0.097,195.41,040423,,,D*75
2023-04-04T17:11:09.590Z,1680628269.590 [NAL9602](INFO): GPS fix at 20230404T171109: (36.802492, -121.787043)
2023-04-04T17:11:09.601Z,1680628269.601 [Default:CheckIn:Read_GPS] Stopped
2023-04-04T17:11:09.601Z,1680628269.601 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-04T17:11:17.076Z,1680628277.076 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230404T164144/Courier0016.lzma
2023-04-04T17:11:18.076Z,1680628278.076 [DataOverHttps](INFO): Moved sent file to Logs/20230404T164144/Courier0016.lzma.bak
2023-04-04T17:11:18.076Z,1680628278.076 [DataOverHttps](INFO): SBD MOMSN=18029478
2023-04-04T17:11:32.638Z,1680628292.638 [NAL9602](INFO): SBD MO Status=0, MOMSN=23407, MT Status=0, MTMSN=0
2023-04-04T17:11:32.638Z,1680628292.638 [NAL9602](INFO): No messages in MT queue
2023-04-04T17:11:34.243Z,1680628294.243 [DataOverHttps](INFO): Sending 578 bytes from file Logs/20230404T164144/Express0017.lzma
2023-04-04T17:11:35.244Z,1680628295.244 [DataOverHttps](INFO): Moved sent file to Logs/20230404T164144/Express0017.lzma.bak
2023-04-04T17:11:35.244Z,1680628295.244 [DataOverHttps](INFO): SBD MOMSN=18029481
2023-04-04T17:11:36.296Z,1680628296.296 [Default:CheckIn:Read_Iridium] Stopped
2023-04-04T17:11:36.296Z,1680628296.296 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-04T17:11:36.296Z,1680628296.296 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-04T17:12:03.344Z,1680628323.344 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-04T17:14:06.180Z,1680628446.180 [DataOverHttps](IMPORTANT): SBD MTMSN=20230404T171405
2023-04-04T17:14:13.914Z,1680628453.914 [DataOverHttps](INFO): Received command: failc
2023-04-04T17:14:14.003Z,1680628454.003 [CommandExec](IMPORTANT): got command failComponent
2023-04-04T17:14:14.003Z,1680628454.003 [CommandExec](IMPORTANT): Failed components:
2023-04-04T17:14:14.004Z,1680628454.004 [CommandExec](IMPORTANT): No failed Components.
2023-04-04T17:16:36.951Z,1680628596.951 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-04T17:16:36.951Z,1680628596.951 [Default:CheckIn:C.Wait] Stopped
2023-04-04T17:16:36.951Z,1680628596.951 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-04T17:16:36.951Z,1680628596.951 [Default:CheckIn:D] Running Loop=1
2023-04-04T17:16:37.344Z,1680628597.344 [Default:CheckIn:D] Stopped
2023-04-04T17:16:37.344Z,1680628597.344 [Default:CheckIn:E] Running Loop=1
2023-04-04T17:16:37.741Z,1680628597.741 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.099318 min 
2023-04-04T17:16:37.741Z,1680628597.741 [Default:CheckIn:E] Stopped
2023-04-04T17:16:37.741Z,1680628597.741 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-04T17:16:37.741Z,1680628597.741 [Default:CheckIn] Stopped
2023-04-04T17:16:37.742Z,1680628597.741 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-04T17:16:37.742Z,1680628597.742 [Default:CheckIn](INFO): Running loop #4
2023-04-04T17:16:37.742Z,1680628597.742 [Default:CheckIn] Running Loop=4
2023-04-04T17:16:37.742Z,1680628597.742 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-04T17:16:37.742Z,1680628597.742 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-04T17:16:39.745Z,1680628599.745 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171639.00,A,3648.15032,N,12147.22341,W,0.039,195.41,040423,,,D*7A
2023-04-04T17:16:39.748Z,1680628599.748 [NAL9602](INFO): GPS fix at 20230404T171639: (36.802505, -121.787057)
2023-04-04T17:16:39.760Z,1680628599.760 [Default:CheckIn:Read_GPS] Stopped
2023-04-04T17:16:39.760Z,1680628599.760 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-04T17:16:47.418Z,1680628607.418 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230404T164144/Courier0019.lzma
2023-04-04T17:16:48.420Z,1680628608.420 [DataOverHttps](INFO): Moved sent file to Logs/20230404T164144/Courier0019.lzma.bak
2023-04-04T17:16:48.420Z,1680628608.420 [DataOverHttps](INFO): SBD MOMSN=18029512
2023-04-04T17:17:02.773Z,1680628622.773 [NAL9602](INFO): SBD MO Status=0, MOMSN=23408, MT Status=0, MTMSN=0
2023-04-04T17:17:02.773Z,1680628622.773 [NAL9602](INFO): No messages in MT queue
2023-04-04T17:17:04.774Z,1680628624.774 [DataOverHttps](INFO): Sending 218 bytes from file Logs/20230404T164144/Express0020.lzma
2023-04-04T17:17:05.776Z,1680628625.776 [DataOverHttps](INFO): Moved sent file to Logs/20230404T164144/Express0020.lzma.bak
2023-04-04T17:17:05.777Z,1680628625.777 [DataOverHttps](INFO): SBD MOMSN=18029515
2023-04-04T17:17:22.018Z,1680628642.018 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20230404T164144/Express0023.lzma
2023-04-04T17:17:23.020Z,1680628643.020 [DataOverHttps](INFO): Moved sent file to Logs/20230404T164144/Express0023.lzma.bak
2023-04-04T17:17:23.020Z,1680628643.020 [DataOverHttps](INFO): SBD MOMSN=18029522
2023-04-04T17:17:24.245Z,1680628644.245 [Default:CheckIn:Read_Iridium] Stopped
2023-04-04T17:17:24.245Z,1680628644.245 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-04T17:17:24.245Z,1680628644.245 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-04T17:17:33.512Z,1680628653.512 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-04T17:18:24.822Z,1680628704.822 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2023-04-04T17:22:24.867Z,1680628944.867 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-04T17:22:24.867Z,1680628944.867 [Default:CheckIn:C.Wait] Stopped
2023-04-04T17:22:24.867Z,1680628944.867 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-04T17:22:24.868Z,1680628944.868 [Default:CheckIn:D] Running Loop=1
2023-04-04T17:22:25.263Z,1680628945.263 [Default:CheckIn:D] Stopped
2023-04-04T17:22:25.263Z,1680628945.263 [Default:CheckIn:E] Running Loop=1
2023-04-04T17:22:25.659Z,1680628945.659 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 36.897974 min 
2023-04-04T17:22:25.659Z,1680628945.659 [Default:CheckIn:E] Stopped
2023-04-04T17:22:25.659Z,1680628945.659 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-04T17:22:25.659Z,1680628945.659 [Default:CheckIn] Stopped
2023-04-04T17:22:25.659Z,1680628945.659 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-04T17:22:25.659Z,1680628945.659 [Default:CheckIn](INFO): Running loop #5
2023-04-04T17:22:25.659Z,1680628945.659 [Default:CheckIn] Running Loop=5
2023-04-04T17:22:25.659Z,1680628945.659 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-04T17:22:25.659Z,1680628945.659 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-04T17:22:27.669Z,1680628947.669 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172227.00,A,3648.15008,N,12147.22255,W,0.058,195.41,040423,,,D*78
2023-04-04T17:22:27.672Z,1680628947.672 [NAL9602](INFO): GPS fix at 20230404T172227: (36.802501, -121.787042)
2023-04-04T17:22:27.684Z,1680628947.684 [Default:CheckIn:Read_GPS] Stopped
2023-04-04T17:22:27.684Z,1680628947.684 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-04T17:22:35.250Z,1680628955.250 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230404T164144/Courier0025.lzma
2023-04-04T17:22:36.252Z,1680628956.252 [DataOverHttps](INFO): Moved sent file to Logs/20230404T164144/Courier0025.lzma.bak
2023-04-04T17:22:36.252Z,1680628956.252 [DataOverHttps](INFO): SBD MOMSN=18029525
2023-04-04T17:22:40.189Z,1680628960.189 [NAL9602](INFO): SBD MO Status=0, MOMSN=23409, MT Status=0, MTMSN=0
2023-04-04T17:22:40.189Z,1680628960.189 [NAL9602](INFO): No messages in MT queue
2023-04-04T17:22:52.617Z,1680628972.617 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20230404T164144/Express0026.lzma
2023-04-04T17:22:53.612Z,1680628973.612 [DataOverHttps](INFO): Moved sent file to Logs/20230404T164144/Express0026.lzma.bak
2023-04-04T17:22:53.612Z,1680628973.612 [DataOverHttps](INFO): SBD MOMSN=18029528
2023-04-04T17:22:54.787Z,1680628974.787 [Default:CheckIn:Read_Iridium] Stopped
2023-04-04T17:22:54.787Z,1680628974.787 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-04T17:22:54.787Z,1680628974.787 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-04T17:23:10.899Z,1680628990.899 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-04T17:27:55.328Z,1680629275.328 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-04T17:27:55.328Z,1680629275.328 [Default:CheckIn:C.Wait] Stopped
2023-04-04T17:27:55.328Z,1680629275.328 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-04T17:27:55.329Z,1680629275.329 [Default:CheckIn:D] Running Loop=1
2023-04-04T17:27:55.733Z,1680629275.733 [Default:CheckIn:D] Stopped
2023-04-04T17:27:55.733Z,1680629275.733 [Default:CheckIn:E] Running Loop=1
2023-04-04T17:27:56.131Z,1680629276.131 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.405811 min 
2023-04-04T17:27:56.131Z,1680629276.131 [Default:CheckIn:E] Stopped
2023-04-04T17:27:56.131Z,1680629276.131 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-04T17:27:56.131Z,1680629276.131 [Default:CheckIn] Stopped
2023-04-04T17:27:56.131Z,1680629276.131 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-04T17:27:56.132Z,1680629276.132 [Default:CheckIn](INFO): Running loop #6
2023-04-04T17:27:56.132Z,1680629276.132 [Default:CheckIn] Running Loop=6
2023-04-04T17:27:56.132Z,1680629276.132 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-04T17:27:56.132Z,1680629276.132 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-04T17:27:58.145Z,1680629278.145 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172758.00,A,3648.15424,N,12147.21765,W,1.633,37.29,040423,,,D*47
2023-04-04T17:27:58.148Z,1680629278.148 [NAL9602](INFO): GPS fix at 20230404T172758: (36.802571, -121.786961)
2023-04-04T17:27:58.159Z,1680629278.159 [Default:CheckIn:Read_GPS] Stopped
2023-04-04T17:27:58.159Z,1680629278.159 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-04T17:28:05.938Z,1680629285.938 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20230404T164144/Courier0028.lzma
2023-04-04T17:28:06.940Z,1680629286.940 [DataOverHttps](INFO): Moved sent file to Logs/20230404T164144/Courier0028.lzma.bak
2023-04-04T17:28:06.941Z,1680629286.941 [DataOverHttps](INFO): SBD MOMSN=18029544
2023-04-04T17:28:26.890Z,1680629306.890 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230404T164144/Express0029.lzma
2023-04-04T17:28:27.893Z,1680629307.893 [DataOverHttps](INFO): Moved sent file to Logs/20230404T164144/Express0029.lzma.bak
2023-04-04T17:28:27.894Z,1680629307.894 [DataOverHttps](INFO): SBD MOMSN=18029547
2023-04-04T17:28:28.958Z,1680629308.958 [Default:CheckIn:Read_Iridium] Stopped
2023-04-04T17:28:28.959Z,1680629308.959 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-04T17:28:28.959Z,1680629308.959 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-04T17:28:31.705Z,1680629311.705 [NAL9602](INFO): SBD MO Status=0, MOMSN=23410, MT Status=0, MTMSN=0
2023-04-04T17:28:31.705Z,1680629311.705 [NAL9602](INFO): No messages in MT queue
2023-04-04T17:29:02.406Z,1680629342.406 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-04T17:33:29.497Z,1680629609.497 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-04T17:33:29.497Z,1680629609.497 [Default:CheckIn:C.Wait] Stopped
2023-04-04T17:33:29.498Z,1680629609.498 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-04T17:33:29.498Z,1680629609.498 [Default:CheckIn:D] Running Loop=1
2023-04-04T17:33:29.894Z,1680629609.894 [Default:CheckIn:D] Stopped
2023-04-04T17:33:29.894Z,1680629609.894 [Default:CheckIn:E] Running Loop=1
2023-04-04T17:33:30.295Z,1680629610.295 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 47.975159 min 
2023-04-04T17:33:30.295Z,1680629610.295 [Default:CheckIn:E] Stopped
2023-04-04T17:33:30.295Z,1680629610.295 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-04T17:33:30.295Z,1680629610.295 [Default:CheckIn] Stopped
2023-04-04T17:33:30.296Z,1680629610.296 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-04T17:33:30.296Z,1680629610.296 [Default:CheckIn](INFO): Running loop #7
2023-04-04T17:33:30.296Z,1680629610.296 [Default:CheckIn] Running Loop=7
2023-04-04T17:33:30.296Z,1680629610.296 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-04T17:33:30.296Z,1680629610.296 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-04T17:33:32.304Z,1680629612.304 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173332.00,A,3648.51280,N,12147.12595,W,4.898,312.22,040423,,,D*7E
2023-04-04T17:33:32.306Z,1680629612.306 [NAL9602](INFO): GPS fix at 20230404T173332: (36.808547, -121.785432)
2023-04-04T17:33:32.338Z,1680629612.338 [Default:CheckIn:Read_GPS] Stopped
2023-04-04T17:33:32.338Z,1680629612.338 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-04T17:33:39.458Z,1680629619.458 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230404T164144/Courier0031.lzma
2023-04-04T17:33:40.460Z,1680629620.460 [DataOverHttps](INFO): Moved sent file to Logs/20230404T164144/Courier0031.lzma.bak
2023-04-04T17:33:40.460Z,1680629620.460 [DataOverHttps](INFO): SBD MOMSN=18029552
2023-04-04T17:33:54.532Z,1680629634.532 [NAL9602](INFO): SBD MO Status=0, MOMSN=23411, MT Status=0, MTMSN=0
2023-04-04T17:33:54.532Z,1680629634.532 [NAL9602](INFO): No messages in MT queue
2023-04-04T17:33:56.866Z,1680629636.866 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20230404T164144/Express0032.lzma
2023-04-04T17:33:57.868Z,1680629637.868 [DataOverHttps](INFO): Moved sent file to Logs/20230404T164144/Express0032.lzma.bak
2023-04-04T17:33:57.868Z,1680629637.868 [DataOverHttps](INFO): SBD MOMSN=18029555
2023-04-04T17:33:58.999Z,1680629638.999 [Default:CheckIn:Read_Iridium] Stopped
2023-04-04T17:33:58.999Z,1680629638.999 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-04T17:33:58.999Z,1680629638.999 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-04T17:34:25.232Z,1680629665.232 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-04T17:38:59.597Z,1680629939.597 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-04T17:38:59.597Z,1680629939.597 [Default:CheckIn:C.Wait] Stopped
2023-04-04T17:38:59.597Z,1680629939.597 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-04T17:38:59.597Z,1680629939.597 [Default:CheckIn:D] Running Loop=1
2023-04-04T17:38:59.986Z,1680629939.986 [Default:CheckIn:D] Stopped
2023-04-04T17:38:59.986Z,1680629939.986 [Default:CheckIn:E] Running Loop=1
2023-04-04T17:39:00.391Z,1680629940.391 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 53.476693 min 
2023-04-04T17:39:00.391Z,1680629940.391 [Default:CheckIn:E] Stopped
2023-04-04T17:39:00.391Z,1680629940.391 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-04T17:39:00.391Z,1680629940.391 [Default:CheckIn] Stopped
2023-04-04T17:39:00.391Z,1680629940.391 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-04T17:39:00.392Z,1680629940.392 [Default:CheckIn](INFO): Running loop #8
2023-04-04T17:39:00.392Z,1680629940.392 [Default:CheckIn] Running Loop=8
2023-04-04T17:39:00.392Z,1680629940.392 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-04T17:39:00.392Z,1680629940.392 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-04T17:39:02.411Z,1680629942.411 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173902.00,A,3648.25838,N,12147.89162,W,8.747,237.31,040423,,,D*76
2023-04-04T17:39:02.413Z,1680629942.413 [NAL9602](INFO): GPS fix at 20230404T173902: (36.804306, -121.798194)
2023-04-04T17:39:02.425Z,1680629942.425 [Default:CheckIn:Read_GPS] Stopped
2023-04-04T17:39:02.426Z,1680629942.426 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-04T17:39:09.814Z,1680629949.814 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230404T164144/Courier0034.lzma
2023-04-04T17:39:10.816Z,1680629950.816 [DataOverHttps](INFO): Moved sent file to Logs/20230404T164144/Courier0034.lzma.bak
2023-04-04T17:39:10.816Z,1680629950.816 [DataOverHttps](INFO): SBD MOMSN=18029569
2023-04-04T17:39:27.330Z,1680629967.330 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20230404T164144/Express0035.lzma
2023-04-04T17:39:28.332Z,1680629968.332 [DataOverHttps](INFO): Moved sent file to Logs/20230404T164144/Express0035.lzma.bak
2023-04-04T17:39:28.333Z,1680629968.333 [DataOverHttps](INFO): SBD MOMSN=18029572
2023-04-04T17:39:28.669Z,1680629968.669 [NAL9602](INFO): SBD MO Status=2, MOMSN=23412, MT Status=2, MTMSN=0
2023-04-04T17:39:28.669Z,1680629968.669 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-04-04T17:39:29.486Z,1680629969.486 [Default:CheckIn:Read_Iridium] Stopped
2023-04-04T17:39:29.486Z,1680629969.486 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-04T17:39:29.486Z,1680629969.486 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-04T17:39:54.534Z,1680629994.534 [NAL9602](INFO): SBD MO Status=2, MOMSN=23412, MT Status=2, MTMSN=0
2023-04-04T17:39:54.534Z,1680629994.534 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-04-04T17:40:13.513Z,1680630013.513 [NAL9602](INFO): SBD MO Status=0, MOMSN=23412, MT Status=0, MTMSN=0
2023-04-04T17:40:13.513Z,1680630013.513 [NAL9602](INFO): No messages in MT queue
2023-04-04T17:40:44.219Z,1680630044.219 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-04T17:44:30.124Z,1680630270.124 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-04T17:44:30.124Z,1680630270.124 [Default:CheckIn:C.Wait] Stopped
2023-04-04T17:44:30.124Z,1680630270.124 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-04T17:44:30.124Z,1680630270.124 [Default:CheckIn:D] Running Loop=1
2023-04-04T17:44:30.523Z,1680630270.523 [Default:CheckIn:D] Stopped
2023-04-04T17:44:30.523Z,1680630270.523 [Default:CheckIn:E] Running Loop=1
2023-04-04T17:44:30.946Z,1680630270.946 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 58.985640 min 
2023-04-04T17:44:30.946Z,1680630270.946 [Default:CheckIn:E] Stopped
2023-04-04T17:44:30.946Z,1680630270.946 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-04T17:44:30.946Z,1680630270.946 [Default:CheckIn] Stopped
2023-04-04T17:44:30.947Z,1680630270.947 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-04T17:44:30.947Z,1680630270.947 [Default:CheckIn](INFO): Running loop #9
2023-04-04T17:44:30.947Z,1680630270.947 [Default:CheckIn] Running Loop=9
2023-04-04T17:44:30.947Z,1680630270.947 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-04T17:44:30.947Z,1680630270.947 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-04T17:44:32.929Z,1680630272.929 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174432.00,A,3647.14987,N,12148.69332,W,17.300,211.57,040423,,,D*4C
2023-04-04T17:44:32.931Z,1680630272.931 [NAL9602](INFO): GPS fix at 20230404T174432: (36.785831, -121.811555)
2023-04-04T17:44:32.977Z,1680630272.977 [Default:CheckIn:Read_GPS] Stopped
2023-04-04T17:44:32.977Z,1680630272.977 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-04T17:44:40.994Z,1680630280.994 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230404T164144/Courier0037.lzma
2023-04-04T17:44:41.996Z,1680630281.996 [DataOverHttps](INFO): Moved sent file to Logs/20230404T164144/Courier0037.lzma.bak
2023-04-04T17:44:41.996Z,1680630281.996 [DataOverHttps](INFO): SBD MOMSN=18029580
2023-04-04T17:44:51.520Z,1680630291.520 [NAL9602](INFO): SBD MO Status=0, MOMSN=23413, MT Status=0, MTMSN=0
2023-04-04T17:44:51.520Z,1680630291.520 [NAL9602](INFO): No messages in MT queue
2023-04-04T17:44:58.334Z,1680630298.334 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20230404T164144/Express0038.lzma
2023-04-04T17:44:59.336Z,1680630299.336 [DataOverHttps](INFO): Moved sent file to Logs/20230404T164144/Express0038.lzma.bak
2023-04-04T17:44:59.336Z,1680630299.336 [DataOverHttps](INFO): SBD MOMSN=18029587
2023-04-04T17:45:00.419Z,1680630300.419 [Default:CheckIn:Read_Iridium] Stopped
2023-04-04T17:45:00.419Z,1680630300.419 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-04T17:45:00.419Z,1680630300.419 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-04T17:45:22.226Z,1680630322.226 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-04T17:50:01.103Z,1680630601.103 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-04T17:50:01.103Z,1680630601.103 [Default:CheckIn:C.Wait] Stopped
2023-04-04T17:50:01.103Z,1680630601.103 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-04T17:50:01.103Z,1680630601.103 [Default:CheckIn:D] Running Loop=1
2023-04-04T17:50:01.507Z,1680630601.507 [Default:CheckIn:D] Stopped
2023-04-04T17:50:01.507Z,1680630601.507 [Default:CheckIn:E] Running Loop=1
2023-04-04T17:50:01.922Z,1680630601.922 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 64.502039 min 
2023-04-04T17:50:01.922Z,1680630601.922 [Default:CheckIn:E] Stopped
2023-04-04T17:50:01.923Z,1680630601.923 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-04T17:50:01.923Z,1680630601.923 [Default:CheckIn] Stopped
2023-04-04T17:50:01.923Z,1680630601.923 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-04T17:50:01.923Z,1680630601.923 [Default:CheckIn](INFO): Running loop #10
2023-04-04T17:50:01.923Z,1680630601.923 [Default:CheckIn] Running Loop=10
2023-04-04T17:50:01.923Z,1680630601.923 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-04T17:50:01.923Z,1680630601.923 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-04T17:50:03.916Z,1680630603.916 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175003.00,A,3645.63429,N,12149.76474,W,17.339,203.99,040423,,,A*44
2023-04-04T17:50:03.919Z,1680630603.919 [NAL9602](INFO): GPS fix at 20230404T175003: (36.760571, -121.829412)
2023-04-04T17:50:03.930Z,1680630603.930 [Default:CheckIn:Read_GPS] Stopped
2023-04-04T17:50:03.930Z,1680630603.930 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-04T17:50:19.164Z,1680630619.164 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.940132
2023-04-04T17:50:23.717Z,1680630623.717 [NAL9602](INFO): SBD MO Status=0, MOMSN=23414, MT Status=0, MTMSN=0
2023-04-04T17:50:23.717Z,1680630623.717 [NAL9602](INFO): No messages in MT queue
2023-04-04T17:50:35.913Z,1680630635.913 [NAL9602](INFO): SBD MO Status=1, MOMSN=23415, MT Status=0, MTMSN=0
2023-04-04T17:50:35.963Z,1680630635.963 [NAL9602](INFO): Sent 74 bytes from file Logs/20230404T164144/Courier0040.lzma
2023-04-04T17:50:35.963Z,1680630635.963 [NAL9602](INFO): Packets left to send: 0
2023-04-04T17:50:50.287Z,1680630650.287 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-04-04T17:51:05.465Z,1680630665.465 [NAL9602](INFO): SBD MO Status=1, MOMSN=23416, MT Status=0, MTMSN=0
2023-04-04T17:51:05.527Z,1680630665.527 [NAL9602](INFO): Sent 143 bytes from file Logs/20230404T164144/Express0041.lzma
2023-04-04T17:51:05.527Z,1680630665.527 [NAL9602](INFO): Packets left to send: 0
2023-04-04T17:51:15.644Z,1680630675.644 [NAL9602](INFO): SBD MO Status=0, MOMSN=23417, MT Status=0, MTMSN=0
2023-04-04T17:51:15.720Z,1680630675.720 [Default:CheckIn:Read_Iridium] Stopped
2023-04-04T17:51:15.720Z,1680630675.720 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-04T17:51:15.720Z,1680630675.720 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-04T17:51:38.467Z,1680630698.467 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003256
2023-04-04T17:51:46.262Z,1680630706.262 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-04T17:53:50.328Z,1680630830.328 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.323723
2023-04-04T17:54:40.631Z,1680630880.631 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003272
2023-04-04T17:55:40.696Z,1680630940.696 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.067738
2023-04-04T17:56:16.155Z,1680630976.155 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-04T17:56:16.155Z,1680630976.155 [Default:CheckIn:C.Wait] Stopped
2023-04-04T17:56:16.155Z,1680630976.155 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-04T17:56:16.155Z,1680630976.155 [Default:CheckIn:D] Running Loop=1
2023-04-04T17:56:16.616Z,1680630976.616 [Default:CheckIn:D] Stopped
2023-04-04T17:56:16.616Z,1680630976.616 [Default:CheckIn:E] Running Loop=1
2023-04-04T17:56:16.998Z,1680630976.998 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 70.753866 min 
2023-04-04T17:56:16.998Z,1680630976.998 [Default:CheckIn:E] Stopped
2023-04-04T17:56:16.998Z,1680630976.998 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-04T17:56:16.998Z,1680630976.998 [Default:CheckIn] Stopped
2023-04-04T17:56:17.007Z,1680630977.007 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-04T17:56:17.007Z,1680630977.007 [Default:CheckIn](INFO): Running loop #11
2023-04-04T17:56:17.007Z,1680630977.007 [Default:CheckIn] Running Loop=11
2023-04-04T17:56:17.007Z,1680630977.007 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-04T17:56:17.007Z,1680630977.007 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-04T17:56:18.970Z,1680630978.970 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175619.00,A,3643.98217,N,12150.78301,W,18.544,205.38,040423,,,A*4D
2023-04-04T17:56:18.976Z,1680630978.976 [NAL9602](INFO): GPS fix at 20230404T175619: (36.733036, -121.846384)
2023-04-04T17:56:18.996Z,1680630978.996 [Default:CheckIn:Read_GPS] Stopped
2023-04-04T17:56:18.996Z,1680630978.996 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-04T17:56:38.163Z,1680630998.163 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003331
2023-04-04T17:56:42.602Z,1680631002.602 [NAL9602](INFO): SBD MO Status=1, MOMSN=23418, MT Status=0, MTMSN=0
2023-04-04T17:56:42.651Z,1680631002.651 [NAL9602](INFO): Sent 74 bytes from file Logs/20230404T164144/Courier0043.lzma
2023-04-04T17:56:42.651Z,1680631002.651 [NAL9602](INFO): Packets left to send: 0
2023-04-04T17:57:06.031Z,1680631026.031 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2023-04-04T17:57:06.034Z,1680631026.034 [BPC1](INFO): Received data from all battery sticks.
2023-04-04T17:57:09.030Z,1680631029.030 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20230404T164144/Express0044.lzma
2023-04-04T17:57:10.032Z,1680631030.032 [DataOverHttps](INFO): Moved sent file to Logs/20230404T164144/Express0044.lzma.bak
2023-04-04T17:57:10.033Z,1680631030.033 [DataOverHttps](INFO): SBD MOMSN=18029620
2023-04-04T17:57:11.287Z,1680631031.287 [Default:CheckIn:Read_Iridium] Stopped
2023-04-04T17:57:11.287Z,1680631031.287 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-04T17:57:11.287Z,1680631031.287 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-04T17:57:13.305Z,1680631033.305 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-04T17:57:18.784Z,1680631038.784 [DataOverHttps](IMPORTANT): SBD MTMSN=20230404T175718
2023-04-04T17:57:26.282Z,1680631046.282 [DataOverHttps](INFO): Received command: configSet Express linearApproximation VerticalHomogeneityIndexCalculator.vertical_temperature_homogeneity_index 0.05 celsius persist
2023-04-04T17:57:29.172Z,1680631049.172 [CommandExec](IMPORTANT): got command configSet Express linearApproximation VerticalHomogeneityIndexCalculator.vertical_temperature_homogeneity_index 0.05 celsius persist
2023-04-04T18:00:25.964Z,1680631225.964 [DataOverHttps](IMPORTANT): SBD MTMSN=20230404T180025
2023-04-04T18:00:40.516Z,1680631240.516 [DataOverHttps](INFO): Received command: restart logs