2022-04-25T20:34:31.716Z,1650918871.716 [Supervisor](DEBUG): Initializing supervisor.
2022-04-25T20:34:31.720Z,1650918871.720 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2022-04-25T20:34:31.721Z,1650918871.721 [SyncHandler](INFO): Protected caller Thread ID is 4929
2022-04-25T20:34:31.721Z,1650918871.721 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2022-04-25T20:34:31.722Z,1650918871.722 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2022-04-25T20:34:31.723Z,1650918871.723 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 4930
2022-04-25T20:34:31.727Z,1650918871.727 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2022-04-25T20:34:31.745Z,1650918871.745 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2022-04-25T20:34:31.746Z,1650918871.746 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2022-04-25T20:34:31.747Z,1650918871.747 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 4931
2022-04-25T20:34:31.751Z,1650918871.751 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2022-04-25T20:34:31.752Z,1650918871.752 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2022-04-25T20:34:31.752Z,1650918871.752 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 4932
2022-04-25T20:34:31.755Z,1650918871.755 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2022-04-25T20:34:31.755Z,1650918871.755 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2022-04-25T20:34:31.756Z,1650918871.756 [logger ThreadHandler](INFO): Protected caller Thread ID is 4933
2022-04-25T20:34:31.760Z,1650918871.760 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2022-04-25T20:34:31.760Z,1650918871.760 [Supervisor](INFO): Looking for Config files in directory: Config/
2022-04-25T20:34:31.762Z,1650918871.762 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2022-04-25T20:34:32.260Z,1650918872.260 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2022-04-25T20:34:32.260Z,1650918872.260 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2022-04-25T20:34:32.475Z,1650918872.475 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2022-04-25T20:34:32.476Z,1650918872.476 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2022-04-25T20:34:32.556Z,1650918872.556 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2022-04-25T20:34:32.781Z,1650918872.781 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2022-04-25T20:34:32.782Z,1650918872.782 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2022-04-25T20:34:32.860Z,1650918872.860 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2022-04-25T20:34:32.955Z,1650918872.955 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2022-04-25T20:34:32.956Z,1650918872.956 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2022-04-25T20:34:33.303Z,1650918873.303 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2022-04-25T20:34:33.303Z,1650918873.303 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2022-04-25T20:34:33.429Z,1650918873.429 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2022-04-25T20:34:33.430Z,1650918873.430 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2022-04-25T20:34:34.008Z,1650918874.008 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2022-04-25T20:34:34.009Z,1650918874.009 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2022-04-25T20:34:34.210Z,1650918874.210 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2022-04-25T20:34:34.210Z,1650918874.210 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2022-04-25T20:34:34.601Z,1650918874.601 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2022-04-25T20:34:34.602Z,1650918874.602 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2022-04-25T20:34:34.880Z,1650918874.880 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2022-04-25T20:34:34.881Z,1650918874.881 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2022-04-25T20:34:34.993Z,1650918874.993 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2022-04-25T20:34:34.993Z,1650918874.993 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2022-04-25T20:34:35.715Z,1650918875.715 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2022-04-25T20:34:35.715Z,1650918875.715 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2022-04-25T20:34:36.087Z,1650918876.087 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2022-04-25T20:34:36.088Z,1650918876.088 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2022-04-25T20:34:36.975Z,1650918876.975 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2022-04-25T20:34:36.977Z,1650918876.977 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/
2022-04-25T20:34:36.978Z,1650918876.978 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg
2022-04-25T20:34:37.173Z,1650918877.173 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg
2022-04-25T20:34:37.256Z,1650918877.256 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg
2022-04-25T20:34:37.394Z,1650918877.394 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg
2022-04-25T20:34:37.479Z,1650918877.479 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg
2022-04-25T20:34:37.746Z,1650918877.746 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2022-04-25T20:34:37.747Z,1650918877.747 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg
2022-04-25T20:34:37.852Z,1650918877.852 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg
2022-04-25T20:34:37.964Z,1650918877.964 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg
2022-04-25T20:34:38.058Z,1650918878.058 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg
2022-04-25T20:34:38.204Z,1650918878.204 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg
2022-04-25T20:34:38.303Z,1650918878.303 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg
2022-04-25T20:34:38.397Z,1650918878.397 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2022-04-25T20:34:38.416Z,1650918878.416 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2022-04-25T20:34:38.428Z,1650918878.428 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2022-04-25T20:34:38.428Z,1650918878.428 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2022-04-25T20:34:38.530Z,1650918878.530 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2022-04-25T20:34:38.530Z,1650918878.530 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2022-04-25T20:34:38.586Z,1650918878.586 [VerticalControl](DEBUG): Construct VerticalControl.
2022-04-25T20:34:38.646Z,1650918878.646 [VerticalControl] Loaded
2022-04-25T20:34:38.647Z,1650918878.647 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2022-04-25T20:34:38.649Z,1650918878.649 [HorizontalControl](DEBUG): Construct HorizontalControl.
2022-04-25T20:34:38.689Z,1650918878.689 [HorizontalControl] Loaded
2022-04-25T20:34:38.689Z,1650918878.689 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2022-04-25T20:34:38.692Z,1650918878.692 [SpeedControl](DEBUG): Construct SpeedControl.
2022-04-25T20:34:38.695Z,1650918878.695 [SpeedControl] Loaded
2022-04-25T20:34:38.695Z,1650918878.695 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2022-04-25T20:34:38.698Z,1650918878.698 [LoopControl](DEBUG): Construct LoopControl.
2022-04-25T20:34:38.698Z,1650918878.698 [LoopControl] Loaded
2022-04-25T20:34:38.698Z,1650918878.698 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2022-04-25T20:34:38.699Z,1650918878.699 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2022-04-25T20:34:38.699Z,1650918878.699 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2022-04-25T20:34:38.857Z,1650918878.857 [BuoyancyServo] Loaded
2022-04-25T20:34:38.857Z,1650918878.857 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2022-04-25T20:34:38.877Z,1650918878.877 [ElevatorServo] Loaded
2022-04-25T20:34:38.877Z,1650918878.877 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2022-04-25T20:34:38.896Z,1650918878.896 [MassServo] Loaded
2022-04-25T20:34:38.896Z,1650918878.896 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2022-04-25T20:34:38.914Z,1650918878.914 [RudderServo] Loaded
2022-04-25T20:34:38.914Z,1650918878.914 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2022-04-25T20:34:38.930Z,1650918878.930 [ThrusterHE] Loaded
2022-04-25T20:34:38.930Z,1650918878.930 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2022-04-25T20:34:38.930Z,1650918878.930 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2022-04-25T20:34:38.931Z,1650918878.931 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2022-04-25T20:34:38.986Z,1650918878.986 [DepthRateCalculator] Loaded
2022-04-25T20:34:38.986Z,1650918878.986 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2022-04-25T20:34:38.991Z,1650918878.991 [PitchRateCalculator] Loaded
2022-04-25T20:34:38.991Z,1650918878.991 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2022-04-25T20:34:39.001Z,1650918879.001 [SpeedCalculator] Loaded
2022-04-25T20:34:39.001Z,1650918879.001 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2022-04-25T20:34:39.017Z,1650918879.017 [VerticalHomogeneityIndexCalculator] Loaded
2022-04-25T20:34:39.017Z,1650918879.017 [ComponentRegistry](DEBUG): SyncComponent "VerticalHomogeneityIndexCalculator" handled in the control thread.
2022-04-25T20:34:39.022Z,1650918879.022 [YawRateCalculator] Loaded
2022-04-25T20:34:39.022Z,1650918879.022 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2022-04-25T20:34:39.040Z,1650918879.040 [ElevatorOffsetCalculator] Loaded
2022-04-25T20:34:39.040Z,1650918879.040 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2022-04-25T20:34:39.040Z,1650918879.040 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2022-04-25T20:34:39.041Z,1650918879.041 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2022-04-25T20:34:39.155Z,1650918879.155 [DeadReckonUsingMultipleVelocitySources] Loaded
2022-04-25T20:34:39.155Z,1650918879.155 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2022-04-25T20:34:39.169Z,1650918879.169 [NavChart] Loaded
2022-04-25T20:34:39.169Z,1650918879.169 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2022-04-25T20:34:39.175Z,1650918879.175 [UniversalFixResidualReporter] Loaded
2022-04-25T20:34:39.175Z,1650918879.175 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2022-04-25T20:34:39.176Z,1650918879.176 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2022-04-25T20:34:39.176Z,1650918879.176 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2022-04-25T20:34:39.592Z,1650918879.592 [AHRS_M2] Loaded
2022-04-25T20:34:39.592Z,1650918879.592 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2022-04-25T20:34:39.628Z,1650918879.628 [BackseatComponent] Loaded
2022-04-25T20:34:39.628Z,1650918879.628 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2022-04-25T20:34:39.629Z,1650918879.629 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408CE4E0
2022-04-25T20:34:39.630Z,1650918879.630 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 5015
2022-04-25T20:34:39.632Z,1650918879.632 [LcmUniversalReporter] Loaded
2022-04-25T20:34:39.633Z,1650918879.633 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2022-04-25T20:34:40.477Z,1650918880.477 [BPC1] Loaded
2022-04-25T20:34:40.477Z,1650918880.477 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2022-04-25T20:34:40.549Z,1650918880.549 [DataOverHttps] Loaded
2022-04-25T20:34:40.549Z,1650918880.549 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2022-04-25T20:34:40.550Z,1650918880.550 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408FE4E0
2022-04-25T20:34:40.551Z,1650918880.551 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 5016
2022-04-25T20:34:40.571Z,1650918880.571 [Depth_Keller] Loaded
2022-04-25T20:34:40.571Z,1650918880.571 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2022-04-25T20:34:40.576Z,1650918880.576 [DropWeight] Loaded
2022-04-25T20:34:40.576Z,1650918880.576 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2022-04-25T20:34:40.638Z,1650918880.638 [NAL9602] Loaded
2022-04-25T20:34:40.638Z,1650918880.638 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2022-04-25T20:34:40.668Z,1650918880.668 [Onboard] Loaded
2022-04-25T20:34:40.668Z,1650918880.668 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2022-04-25T20:34:40.669Z,1650918880.669 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4092E4E0
2022-04-25T20:34:40.669Z,1650918880.669 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 5017
2022-04-25T20:34:40.681Z,1650918880.681 [Power24vConverter] Loaded
2022-04-25T20:34:40.682Z,1650918880.682 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2022-04-25T20:34:40.695Z,1650918880.695 [Radio_Surface] Loaded
2022-04-25T20:34:40.695Z,1650918880.695 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2022-04-25T20:34:40.696Z,1650918880.696 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4095E4E0
2022-04-25T20:34:40.697Z,1650918880.697 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 5018
2022-04-25T20:34:40.698Z,1650918880.698 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2022-04-25T20:34:40.698Z,1650918880.698 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2022-04-25T20:34:40.774Z,1650918880.774 [StratificationFrontDetector](INFO): thresholdVTHI set to: 0.399988 degC
2022-04-25T20:34:40.774Z,1650918880.774 [StratificationFrontDetector](DEBUG): (re)initializing
2022-04-25T20:34:40.774Z,1650918880.774 [StratificationFrontDetector] Loaded
2022-04-25T20:34:40.775Z,1650918880.775 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2022-04-25T20:34:40.775Z,1650918880.775 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2022-04-25T20:34:40.776Z,1650918880.776 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2022-04-25T20:34:40.891Z,1650918880.891 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2022-04-25T20:34:40.891Z,1650918880.891 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2022-04-25T20:34:40.919Z,1650918880.919 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2022-04-25T20:34:40.919Z,1650918880.919 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2022-04-25T20:34:41.055Z,1650918881.055 [PAR_Licor] Loaded
2022-04-25T20:34:41.055Z,1650918881.055 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2022-04-25T20:34:41.087Z,1650918881.087 [WetLabsBB2FL] Loaded
2022-04-25T20:34:41.088Z,1650918881.088 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2022-04-25T20:34:41.089Z,1650918881.089 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A8D4E0
2022-04-25T20:34:41.089Z,1650918881.089 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 5019
2022-04-25T20:34:41.090Z,1650918881.090 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2022-04-25T20:34:41.091Z,1650918881.091 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2022-04-25T20:34:41.774Z,1650918881.774 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2022-04-25T20:34:41.775Z,1650918881.775 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2022-04-25T20:34:41.927Z,1650918881.927 [SBIT](DEBUG): Construct Startup Built In Test.
2022-04-25T20:34:41.936Z,1650918881.936 [SBIT] Loaded
2022-04-25T20:34:41.936Z,1650918881.936 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2022-04-25T20:34:41.939Z,1650918881.939 [IBIT](DEBUG): Construct Initiated Built In Test.
2022-04-25T20:34:41.952Z,1650918881.952 [IBIT] Loaded
2022-04-25T20:34:41.953Z,1650918881.953 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2022-04-25T20:34:41.959Z,1650918881.959 [CBIT](DEBUG): Construct Continuous Built In Test.
2022-04-25T20:34:42.064Z,1650918882.064 [CBIT] Loaded
2022-04-25T20:34:42.065Z,1650918882.065 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2022-04-25T20:34:42.065Z,1650918882.065 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2022-04-25T20:34:42.071Z,1650918882.071 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2022-04-25T20:34:42.074Z,1650918882.074 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2022-04-25T20:34:42.085Z,1650918882.085 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2022-04-25T20:34:42.086Z,1650918882.086 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B774E0
2022-04-25T20:34:42.086Z,1650918882.086 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 5020
2022-04-25T20:34:42.091Z,1650918882.091 [Supervisor](INFO): Main Thread ID is 4696
2022-04-25T20:34:42.091Z,1650918882.091 [Supervisor](DEBUG): Running supervisor.
2022-04-25T20:34:42.092Z,1650918882.092 [CommandExec ThreadHandler](INFO): Handler Thread ID is 5021
2022-04-25T20:34:42.092Z,1650918882.092 [CommandExec](INFO): Initializing the command executive.
2022-04-25T20:34:42.094Z,1650918882.094 [CommandLine ThreadHandler](INFO): Handler Thread ID is 5022
2022-04-25T20:34:42.096Z,1650918882.096 [controlThread ThreadHandler](INFO): Handler Thread ID is 5023
2022-04-25T20:34:42.096Z,1650918882.096 [controlThread](DEBUG): Initializing ControlThread
2022-04-25T20:34:42.097Z,1650918882.097 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2022-04-25T20:34:42.099Z,1650918882.099 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2022-04-25T20:34:42.100Z,1650918882.100 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2022-04-25T20:34:42.100Z,1650918882.100 [LoopControl](DEBUG): Initialize LoopControlComponent.
2022-04-25T20:34:42.102Z,1650918882.102 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2022-04-25T20:34:42.102Z,1650918882.102 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2022-04-25T20:34:42.102Z,1650918882.102 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2022-04-25T20:34:42.103Z,1650918882.103 [VerticalHomogeneityIndexCalculator](DEBUG): (re)initializing
2022-04-25T20:34:42.103Z,1650918882.103 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2022-04-25T20:34:42.104Z,1650918882.104 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2022-04-25T20:34:42.105Z,1650918882.105 [NavChart](DEBUG): Initialize NavChart Navigation.
2022-04-25T20:34:42.105Z,1650918882.105 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2022-04-25T20:34:42.114Z,1650918882.114 [SBIT](INFO): Initialize SBIT Component.
2022-04-25T20:34:42.114Z,1650918882.114 [SBIT](IMPORTANT): git: 2022-04-20
2022-04-25T20:34:42.114Z,1650918882.114 [SBIT](INFO): git hash: 17b9e0401aa943d1c74ec99193b02e6257598627
2022-04-25T20:34:42.115Z,1650918882.115 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2022-04-25T20:34:42.116Z,1650918882.116 [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-04-25T20:34:42.117Z,1650918882.117 [SBIT](INFO): Beginning SBIT in 52.000000 seconds.
2022-04-25T20:34:42.117Z,1650918882.117 [IBIT](INFO): Initialize IBIT Component.
2022-04-25T20:34:42.118Z,1650918882.118 [CBIT](DEBUG): Initialize CBIT Component.
2022-04-25T20:34:42.119Z,1650918882.119 [logger ThreadHandler](INFO): Handler Thread ID is 5024
2022-04-25T20:34:42.129Z,1650918882.129 [CBIT](DEBUG): Initialized mux pins.
2022-04-25T20:34:42.130Z,1650918882.130 [CBIT](DEBUG): Initializing the watchdog timer.
2022-04-25T20:34:42.138Z,1650918882.138 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 5025
2022-04-25T20:34:42.150Z,1650918882.150 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 5026
2022-04-25T20:34:42.151Z,1650918882.151 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2022-04-25T20:34:42.153Z,1650918882.153 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2022-04-25T20:34:42.154Z,1650918882.154 [CBIT](DEBUG): Initializing heartbeat.
2022-04-25T20:34:42.162Z,1650918882.162 [Onboard ThreadHandler](INFO): Handler Thread ID is 5027
2022-04-25T20:34:42.192Z,1650918882.192 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 5028
2022-04-25T20:34:42.202Z,1650918882.202 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 5029
2022-04-25T20:34:42.206Z,1650918882.206 [WetLabsBB2FL](INFO): Powering up
2022-04-25T20:34:42.207Z,1650918882.207 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 5031
2022-04-25T20:34:42.210Z,1650918882.210 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2022-04-25T20:34:42.211Z,1650918882.211 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2022-04-25T20:34:42.211Z,1650918882.211 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2022-04-25T20:34:42.211Z,1650918882.211 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2022-04-25T20:34:42.211Z,1650918882.211 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2022-04-25T20:34:42.211Z,1650918882.211 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2022-04-25T20:34:42.211Z,1650918882.211 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2022-04-25T20:34:42.212Z,1650918882.212 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2022-04-25T20:34:42.212Z,1650918882.212 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2022-04-25T20:34:42.212Z,1650918882.212 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2022-04-25T20:34:42.212Z,1650918882.212 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2022-04-25T20:34:42.212Z,1650918882.212 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2022-04-25T20:34:42.212Z,1650918882.212 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2022-04-25T20:34:42.212Z,1650918882.212 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2022-04-25T20:34:42.213Z,1650918882.213 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2022-04-25T20:34:42.213Z,1650918882.213 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2022-04-25T20:34:42.225Z,1650918882.225 [CBIT](DEBUG): Deactivating GF circuits.
2022-04-25T20:34:42.226Z,1650918882.226 [CBIT](DEBUG): Deactivating emergency mode.
2022-04-25T20:34:42.261Z,1650918882.261 [CBIT](DEBUG): Backplane powered.
2022-04-25T20:34:42.262Z,1650918882.262 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2022-04-25T20:34:42.275Z,1650918882.275 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2022-04-25T20:34:42.303Z,1650918882.303 [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-04-25T20:34:42.310Z,1650918882.310 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2022-04-25T20:34:42.378Z,1650918882.378 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2022-04-25T20:34:42.379Z,1650918882.379 [Default:A.Wait](DEBUG): Construct Wait.
2022-04-25T20:34:42.382Z,1650918882.382 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2022-04-25T20:34:42.429Z,1650918882.429 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2022-04-25T20:34:42.432Z,1650918882.432 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2022-04-25T20:34:42.458Z,1650918882.458 [Default:E.Execute](DEBUG): Construct Execute.
2022-04-25T20:34:42.462Z,1650918882.462 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2022-04-25T20:34:42.466Z,1650918882.466 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,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,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2022-04-25T20:34:42.486Z,1650918882.486 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2022-04-25T20:34:42.557Z,1650918882.557 [Power24vConverter](INFO): Powering up.
2022-04-25T20:34:42.594Z,1650918882.594 [Radio_Surface](INFO): Powering up
2022-04-25T20:34:42.634Z,1650918882.634 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2022-04-25T20:34:42.642Z,1650918882.642 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2022-04-25T20:34:42.643Z,1650918882.643 [ElevatorServo](DEBUG): Initializing EZServoServo.
2022-04-25T20:34:42.650Z,1650918882.650 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2022-04-25T20:34:42.651Z,1650918882.651 [MassServo](DEBUG): Initializing EZServoServo.
2022-04-25T20:34:42.658Z,1650918882.658 [MassServo](DEBUG): Initializing MassServo.
2022-04-25T20:34:42.658Z,1650918882.658 [RudderServo](DEBUG): Initializing EZServoServo.
2022-04-25T20:34:42.666Z,1650918882.666 [RudderServo](DEBUG): Initializing RudderServo.
2022-04-25T20:34:42.667Z,1650918882.667 [ThrusterHE](DEBUG): Initializing EZServoServo.
2022-04-25T20:34:42.674Z,1650918882.674 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2022-04-25T20:34:43.617Z,1650918883.617 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2022-04-25T20:34:43.618Z,1650918883.618 [RudderServo](FAULT): Rudder failed to initialize
2022-04-25T20:34:43.618Z,1650918883.618 [RudderServo] Communications Fault, FailCount= 1
2022-04-25T20:34:43.618Z,1650918883.618 [RudderServo](ERROR): Communications Fault
2022-04-25T20:34:43.621Z,1650918883.621 [CBIT](ERROR): Communications Fault in component: RudderServo
2022-04-25T20:34:43.860Z,1650918883.860 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-04-25T20:34:43.861Z,1650918883.861 [RudderServo](INFO): Powering down
2022-04-25T20:34:44.314Z,1650918884.314 [WetLabsBB2FL](INFO): Powering down
2022-04-25T20:34:44.514Z,1650918884.514 [RudderServo](DEBUG): Initializing EZServoServo.
2022-04-25T20:34:44.634Z,1650918884.634 [RudderServo](DEBUG): Initializing RudderServo.
2022-04-25T20:34:44.638Z,1650918884.638 [CBIT](INFO): Clearing failed state for component RudderServo
2022-04-25T20:34:44.638Z,1650918884.638 [RudderServo] No Fault, FailCount= 1
2022-04-25T20:34:48.282Z,1650918888.282 [ThrusterHE](ERROR): Zero Speed Commanded.
2022-04-25T20:35:10.760Z,1650918910.760 [NAL9602](INFO): Powering up NAL9602
2022-04-25T20:35:21.667Z,1650918921.667 [NAL9602](INFO): NAL9602 initialized
2022-04-25T20:35:34.660Z,1650918934.660 [SBIT](IMPORTANT): Beginning Startup BIT
2022-04-25T20:35:34.664Z,1650918934.664 [CBIT](IMPORTANT): Beginning ground fault scan
2022-04-25T20:35:45.552Z,1650918945.552 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.006858
CHAN A1 (24V): 0.168146
CHAN A2 (12V): -0.004981
CHAN A3 (5V): -0.003235
CHAN B0 (3.3V): -0.000692
CHAN B1 (3.15aV): -0.001063
CHAN B2 (3.15bV): -0.000775
CHAN B3 (GND): -0.000127
OPEN: 0.004717
Full Scale: +/- 1 mA
2022-04-25T20:36:28.806Z,1650918988.806 [SBIT](IMPORTANT): SBIT PASSED
2022-04-25T20:36:28.807Z,1650918988.807 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2022-04-25T20:36:28.807Z,1650918988.807 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=32 count;

2022-04-25T20:36:28.808Z,1650918988.808 [SBIT](IMPORTANT): BPC1.batterySamplingInterval=1 hour;

2022-04-25T20:36:28.808Z,1650918988.808 [SBIT](IMPORTANT): BackseatComponent.alwaysOn=0 bool;

2022-04-25T20:36:28.808Z,1650918988.808 [SBIT](IMPORTANT): BackseatComponent.loadAtStartup=1 bool;

2022-04-25T20:36:28.808Z,1650918988.808 [SBIT](IMPORTANT): CBIT.gf24Offset=-18.106 microampere;

2022-04-25T20:36:28.808Z,1650918988.808 [SBIT](IMPORTANT): CBIT.stopDepth=295 meter;

2022-04-25T20:36:28.808Z,1650918988.808 [SBIT](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool;

2022-04-25T20:36:28.808Z,1650918988.808 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;

2022-04-25T20:36:28.808Z,1650918988.808 [SBIT](IMPORTANT): Express linearApproximation VerticalHomogeneityIndexCalculator.vertical_temperature_homogeneity_index 0.050000 celsius;

2022-04-25T20:36:28.809Z,1650918988.809 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water;

2022-04-25T20:36:28.809Z,1650918988.809 [SBIT](IMPORTANT): Express linearApproximation platform_roll_angle 5.000000 degree;

2022-04-25T20:36:28.809Z,1650918988.809 [SBIT](IMPORTANT): HorizontalControl.rudDeadband=0.001 degree;

2022-04-25T20:36:28.809Z,1650918988.809 [SBIT](IMPORTANT): PAR_Licor.loadAtStartup=1 bool;

2022-04-25T20:36:28.809Z,1650918988.809 [SBIT](IMPORTANT): PAR_Licor.parCal=1.38207 none;

2022-04-25T20:36:28.814Z,1650918988.814 [SBIT](IMPORTANT): RudderServo.deviationAngle=0.1 degree;

2022-04-25T20:36:28.814Z,1650918988.814 [SBIT](IMPORTANT): StratificationFrontDetector.loadAtStartup=1 bool;

2022-04-25T20:36:28.814Z,1650918988.814 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=255.152614 cubic_centimeter;

2022-04-25T20:36:28.814Z,1650918988.814 [SBIT](IMPORTANT): VerticalControl.elevDeadband=0.001 degree;

2022-04-25T20:36:28.814Z,1650918988.814 [SBIT](IMPORTANT): VerticalControl.massDefault=8.108730 millimeter;

2022-04-25T20:36:28.814Z,1650918988.814 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.loadAtStartup=1 bool;

2022-04-25T20:36:28.814Z,1650918988.814 [SBIT](IMPORTANT): WetLabsBB2FL.loadAtStartup=1 bool;

2022-04-25T20:36:29.155Z,1650918989.155 [MissionManager](IMPORTANT): Started mission Startup
2022-04-25T20:36:29.156Z,1650918989.156 [Startup] Running Loop=1
2022-04-25T20:36:29.156Z,1650918989.156 [Startup](DEBUG): Aggregate::initialize Startup
2022-04-25T20:36:29.156Z,1650918989.156 [Startup:A.GoToSurface] Running Loop=1
2022-04-25T20:36:29.156Z,1650918989.156 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-04-25T20:36:29.156Z,1650918989.156 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-04-25T20:36:29.157Z,1650918989.157 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-04-25T20:36:29.157Z,1650918989.157 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-04-25T20:36:29.158Z,1650918989.158 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-04-25T20:36:29.158Z,1650918989.158 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-04-25T20:36:29.159Z,1650918989.159 [Startup:StartupSatComms] Running Loop=1
2022-04-25T20:36:29.160Z,1650918989.160 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2022-04-25T20:36:29.160Z,1650918989.160 [Startup:StartupSatComms:A] Running Loop=1
2022-04-25T20:36:29.559Z,1650918989.559 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2022-04-25T20:37:10.354Z,1650919030.354 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-04-25T20:37:18.428Z,1650919038.428 [NAL9602](INFO): SBD MO Status=2, MOMSN=7647, MT Status=2, MTMSN=0
2022-04-25T20:37:18.429Z,1650919038.429 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-25T20:37:23.672Z,1650919043.672 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-04-25T20:37:29.348Z,1650919049.348 [Startup:StartupSatComms:A](INFO): Timed out from 2022-04-25T20:36:29.2Z
2022-04-25T20:37:29.348Z,1650919049.348 [Startup:StartupSatComms:A] Stopped
2022-04-25T20:37:29.348Z,1650919049.348 [Startup:StartupSatComms:B] Running Loop=1
2022-04-25T20:37:29.759Z,1650919049.759 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-04-25T20:37:37.008Z,1650919057.008 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-04-25T20:37:42.270Z,1650919062.270 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2022-04-25T20:37:42.270Z,1650919062.270 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-04-25T20:37:42.342Z,1650919062.342 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-04-25T20:37:42.750Z,1650919062.750 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-04-25T20:37:42.750Z,1650919062.750 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2022-04-25T20:37:50.335Z,1650919070.335 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-04-25T20:38:04.138Z,1650919084.138 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-04-25T20:38:05.379Z,1650919085.379 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004162
2022-04-25T20:38:12.701Z,1650919092.701 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20220425T201537/Courier0013.lzma
2022-04-25T20:38:13.703Z,1650919093.703 [DataOverHttps](INFO): Moved sent file to Logs/20220425T201537/Courier0013.lzma.bak
2022-04-25T20:38:13.704Z,1650919093.704 [DataOverHttps](INFO): SBD MOMSN=16660991
2022-04-25T20:38:17.000Z,1650919097.000 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-04-25T20:38:29.469Z,1650919109.469 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20220425T203431/Courier0000.lzma
2022-04-25T20:38:29.599Z,1650919109.599 [Startup:StartupSatComms:B](INFO): Timed out from 2022-04-25T20:37:29.3Z
2022-04-25T20:38:29.600Z,1650919109.600 [Startup:StartupSatComms:B] Stopped
2022-04-25T20:38:29.600Z,1650919109.600 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2022-04-25T20:38:29.600Z,1650919109.600 [Startup:StartupSatComms] Stopped
2022-04-25T20:38:29.600Z,1650919109.600 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2022-04-25T20:38:29.601Z,1650919109.601 [Startup](INFO): Completed Startup
2022-04-25T20:38:29.601Z,1650919109.601 [MissionManager](INFO): Startup is completed.
2022-04-25T20:38:29.601Z,1650919109.601 [MissionManager](INFO): Uninitializing Mission Startup
2022-04-25T20:38:29.601Z,1650919109.601 [Startup] Stopped
2022-04-25T20:38:29.601Z,1650919109.601 [Startup](DEBUG): Aggregate::uninitialize Startup
2022-04-25T20:38:29.602Z,1650919109.602 [Startup:A.GoToSurface] Stopped
2022-04-25T20:38:29.602Z,1650919109.602 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-04-25T20:38:29.927Z,1650919109.927 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-04-25T20:38:29.971Z,1650919109.971 [MissionManager](IMPORTANT): Started mission Default
2022-04-25T20:38:29.971Z,1650919109.971 [Default] Running Loop=1
2022-04-25T20:38:29.971Z,1650919109.971 [Default](DEBUG): Aggregate::initialize Default
2022-04-25T20:38:29.971Z,1650919109.971 [Default:B.GoToSurface] Running Loop=1
2022-04-25T20:38:29.971Z,1650919109.971 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-04-25T20:38:29.972Z,1650919109.972 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-04-25T20:38:29.972Z,1650919109.972 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-04-25T20:38:29.972Z,1650919109.972 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-04-25T20:38:29.973Z,1650919109.973 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-04-25T20:38:29.973Z,1650919109.973 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-04-25T20:38:29.973Z,1650919109.973 [Default:A.Wait] Running Loop=1
2022-04-25T20:38:29.974Z,1650919109.974 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-04-25T20:38:30.471Z,1650919110.471 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Courier0000.lzma.bak
2022-04-25T20:38:30.471Z,1650919110.471 [DataOverHttps](INFO): SBD MOMSN=16660994
2022-04-25T20:38:43.260Z,1650919123.260 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-04-25T20:38:43.305Z,1650919123.305 [Default:A.Wait](INFO): Done Waiting.
2022-04-25T20:38:43.305Z,1650919123.305 [Default:A.Wait] Stopped
2022-04-25T20:38:43.305Z,1650919123.305 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-04-25T20:38:43.712Z,1650919123.712 [Default:CheckIn] Running Loop=1
2022-04-25T20:38:43.713Z,1650919123.713 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-04-25T20:38:43.713Z,1650919123.713 [Default:CheckIn:Read_GPS] Running Loop=1
2022-04-25T20:38:44.156Z,1650919124.156 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2022-04-25T20:38:56.593Z,1650919136.593 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-04-25T20:39:09.923Z,1650919149.923 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-04-25T20:39:23.256Z,1650919163.256 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-04-25T20:39:36.998Z,1650919176.998 [BPC1](INFO): Calculating totals. Valid battery stick count: 31. Valid reserve battery stick count: 4.
2022-04-25T20:39:37.001Z,1650919177.001 [BPC1](INFO): Received data from all battery sticks.
2022-04-25T20:40:25.071Z,1650919225.071 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-04-25T20:40:31.937Z,1650919231.937 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204031.00,A,3648.16637,N,12147.27306,W,0.039,358.37,250422,,,A*76
2022-04-25T20:40:31.940Z,1650919231.940 [NAL9602](INFO): GPS fix at 20220425T204031: (36.802773, -121.787884)
2022-04-25T20:40:31.959Z,1650919231.959 [Default:CheckIn:Read_GPS] Stopped
2022-04-25T20:40:31.959Z,1650919231.959 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-04-25T20:40:32.921Z,1650919232.921 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-04-25T20:40:42.315Z,1650919242.315 [DataOverHttps](INFO): Sending 286 bytes from file Logs/20220425T203431/Courier0004.lzma
2022-04-25T20:40:43.317Z,1650919243.317 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Courier0004.lzma.bak
2022-04-25T20:40:43.317Z,1650919243.317 [DataOverHttps](INFO): SBD MOMSN=16660997
2022-04-25T20:41:00.903Z,1650919260.903 [DataOverHttps](INFO): Sending 396 bytes from file Logs/20220425T201537/Express0014.lzma
2022-04-25T20:41:01.905Z,1650919261.905 [DataOverHttps](INFO): Moved sent file to Logs/20220425T201537/Express0014.lzma.bak
2022-04-25T20:41:01.905Z,1650919261.905 [DataOverHttps](INFO): SBD MOMSN=16661000
2022-04-25T20:41:05.245Z,1650919265.245 [NAL9602](INFO): Not Powering down - fast GPS
2022-04-25T20:41:23.996Z,1650919283.996 [DataOverHttps](INFO): Sending 1178 bytes from file Logs/20220425T203431/Express0001.lzma
2022-04-25T20:41:24.997Z,1650919284.997 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Express0001.lzma.bak
2022-04-25T20:41:24.997Z,1650919284.997 [DataOverHttps](INFO): SBD MOMSN=16661010
2022-04-25T20:41:42.415Z,1650919302.415 [DataOverHttps](INFO): Sending 329 bytes from file Logs/20220425T203431/Express0005.lzma
2022-04-25T20:41:43.417Z,1650919303.417 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Express0005.lzma.bak
2022-04-25T20:41:43.417Z,1650919303.417 [DataOverHttps](INFO): SBD MOMSN=16661043
2022-04-25T20:41:46.125Z,1650919306.125 [Default:CheckIn:Read_Iridium] Stopped
2022-04-25T20:41:46.125Z,1650919306.125 [Default:CheckIn:C.Wait] Running Loop=1
2022-04-25T20:41:46.125Z,1650919306.125 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-04-25T20:44:43.484Z,1650919483.484 [Power24vConverter](INFO): Powering down.
2022-04-25T20:46:46.709Z,1650919606.709 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-04-25T20:46:46.709Z,1650919606.709 [Default:CheckIn:C.Wait] Stopped
2022-04-25T20:46:46.709Z,1650919606.709 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-04-25T20:46:46.709Z,1650919606.709 [Default:CheckIn:D] Running Loop=1
2022-04-25T20:46:47.178Z,1650919607.178 [Default:CheckIn:D] Stopped
2022-04-25T20:46:47.178Z,1650919607.178 [Default:CheckIn:E] Running Loop=1
2022-04-25T20:46:47.568Z,1650919607.568 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 8.286778 min 
2022-04-25T20:46:47.568Z,1650919607.568 [Default:CheckIn:E] Stopped
2022-04-25T20:46:47.568Z,1650919607.568 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-04-25T20:46:47.568Z,1650919607.568 [Default:CheckIn] Stopped
2022-04-25T20:46:47.568Z,1650919607.568 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-04-25T20:46:47.569Z,1650919607.569 [Default:CheckIn](INFO): Running loop #2
2022-04-25T20:46:47.569Z,1650919607.569 [Default:CheckIn] Running Loop=2
2022-04-25T20:46:47.569Z,1650919607.569 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-04-25T20:46:47.569Z,1650919607.569 [Default:CheckIn:Read_GPS] Running Loop=1
2022-04-25T20:46:49.535Z,1650919609.535 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204649.00,A,3648.17702,N,12147.28467,W,0.214,358.37,250422,,,A*7B
2022-04-25T20:46:49.537Z,1650919609.537 [NAL9602](INFO): GPS fix at 20220425T204649: (36.802950, -121.788078)
2022-04-25T20:46:49.548Z,1650919609.548 [Default:CheckIn:Read_GPS] Stopped
2022-04-25T20:46:49.548Z,1650919609.548 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-04-25T20:47:00.602Z,1650919620.602 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220425T203431/Courier0007.lzma
2022-04-25T20:47:01.605Z,1650919621.605 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Courier0007.lzma.bak
2022-04-25T20:47:01.605Z,1650919621.605 [DataOverHttps](INFO): SBD MOMSN=16661059
2022-04-25T20:47:18.815Z,1650919638.815 [DataOverHttps](INFO): Sending 170 bytes from file Logs/20220425T203431/Express0008.lzma
2022-04-25T20:47:19.817Z,1650919639.817 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Express0008.lzma.bak
2022-04-25T20:47:19.817Z,1650919639.817 [DataOverHttps](INFO): SBD MOMSN=16661062
2022-04-25T20:47:20.272Z,1650919640.272 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-04-25T20:47:20.351Z,1650919640.351 [NAL9602](ERROR): received: 
+CSQ:0

OK47, 2, 0, 0, 0

OK
2022-04-25T20:47:22.725Z,1650919642.725 [Default:CheckIn:Read_Iridium] Stopped
2022-04-25T20:47:22.725Z,1650919642.725 [Default:CheckIn:C.Wait] Running Loop=1
2022-04-25T20:47:22.725Z,1650919642.725 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-04-25T20:47:48.999Z,1650919668.999 [NAL9602](INFO): SBD MO Status=2, MOMSN=7647, MT Status=2, MTMSN=0
2022-04-25T20:47:48.999Z,1650919668.999 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-25T20:51:51.877Z,1650919911.877 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-04-25T20:52:22.581Z,1650919942.581 [NAL9602](INFO): Not Powering down - fast GPS
2022-04-25T20:52:23.418Z,1650919943.418 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-04-25T20:52:23.418Z,1650919943.418 [Default:CheckIn:C.Wait] Stopped
2022-04-25T20:52:23.418Z,1650919943.418 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-04-25T20:52:23.418Z,1650919943.418 [Default:CheckIn:D] Running Loop=1
2022-04-25T20:52:23.801Z,1650919943.801 [Default:CheckIn:D] Stopped
2022-04-25T20:52:23.801Z,1650919943.801 [Default:CheckIn:E] Running Loop=1
2022-04-25T20:52:24.214Z,1650919944.214 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 13.897169 min 
2022-04-25T20:52:24.214Z,1650919944.214 [Default:CheckIn:E] Stopped
2022-04-25T20:52:24.214Z,1650919944.214 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-04-25T20:52:24.214Z,1650919944.214 [Default:CheckIn] Stopped
2022-04-25T20:52:24.214Z,1650919944.214 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-04-25T20:52:24.214Z,1650919944.214 [Default:CheckIn](INFO): Running loop #3
2022-04-25T20:52:24.214Z,1650919944.214 [Default:CheckIn] Running Loop=3
2022-04-25T20:52:24.215Z,1650919944.215 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-04-25T20:52:24.215Z,1650919944.215 [Default:CheckIn:Read_GPS] Running Loop=1
2022-04-25T20:52:26.228Z,1650919946.228 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205225.00,A,3648.18322,N,12147.29268,W,0.680,0.00,250422,,,A*76
2022-04-25T20:52:26.231Z,1650919946.231 [NAL9602](INFO): GPS fix at 20220425T205225: (36.803054, -121.788211)
2022-04-25T20:52:26.241Z,1650919946.241 [Default:CheckIn:Read_GPS] Stopped
2022-04-25T20:52:26.241Z,1650919946.241 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-04-25T20:52:33.900Z,1650919953.900 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220425T203431/Courier0010.lzma
2022-04-25T20:52:34.902Z,1650919954.902 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Courier0010.lzma.bak
2022-04-25T20:52:34.903Z,1650919954.903 [DataOverHttps](INFO): SBD MOMSN=16661065
2022-04-25T20:52:52.044Z,1650919972.044 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20220425T203431/Express0011.lzma
2022-04-25T20:52:53.046Z,1650919973.046 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Express0011.lzma.bak
2022-04-25T20:52:53.047Z,1650919973.047 [DataOverHttps](INFO): SBD MOMSN=16661068
2022-04-25T20:52:55.773Z,1650919975.773 [Default:CheckIn:Read_Iridium] Stopped
2022-04-25T20:52:55.773Z,1650919975.773 [Default:CheckIn:C.Wait] Running Loop=1
2022-04-25T20:52:55.773Z,1650919975.773 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-04-25T20:52:56.922Z,1650919976.922 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-04-25T20:52:56.997Z,1650919976.997 [NAL9602](ERROR): received: 
+CSQ:0

OK47, 2, 0, 0, 0

OK
2022-04-25T20:56:49.688Z,1650920209.688 [NAL9602](INFO): SBD MO Status=2, MOMSN=7647, MT Status=2, MTMSN=0
2022-04-25T20:56:49.688Z,1650920209.688 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-25T20:57:38.164Z,1650920258.164 [NAL9602](INFO): SBD MO Status=2, MOMSN=7647, MT Status=2, MTMSN=0
2022-04-25T20:57:38.164Z,1650920258.164 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-25T20:57:38.560Z,1650920258.560 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-04-25T20:57:56.351Z,1650920276.351 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-04-25T20:57:56.351Z,1650920276.351 [Default:CheckIn:C.Wait] Stopped
2022-04-25T20:57:56.351Z,1650920276.351 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-04-25T20:57:56.351Z,1650920276.351 [Default:CheckIn:D] Running Loop=1
2022-04-25T20:57:56.749Z,1650920276.749 [Default:CheckIn:D] Stopped
2022-04-25T20:57:56.749Z,1650920276.749 [Default:CheckIn:E] Running Loop=1
2022-04-25T20:57:57.164Z,1650920277.164 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 19.446303 min 
2022-04-25T20:57:57.165Z,1650920277.165 [Default:CheckIn:E] Stopped
2022-04-25T20:57:57.165Z,1650920277.165 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-04-25T20:57:57.165Z,1650920277.165 [Default:CheckIn] Stopped
2022-04-25T20:57:57.165Z,1650920277.165 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-04-25T20:57:57.165Z,1650920277.165 [Default:CheckIn](INFO): Running loop #4
2022-04-25T20:57:57.165Z,1650920277.165 [Default:CheckIn] Running Loop=4
2022-04-25T20:57:57.165Z,1650920277.165 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-04-25T20:57:57.165Z,1650920277.165 [Default:CheckIn:Read_GPS] Running Loop=1
2022-04-25T20:57:59.172Z,1650920279.172 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205758.00,A,3648.16984,N,12147.28538,W,0.117,320.98,250422,,,A*7B
2022-04-25T20:57:59.174Z,1650920279.174 [NAL9602](INFO): GPS fix at 20220425T205758: (36.802831, -121.788090)
2022-04-25T20:57:59.200Z,1650920279.200 [Default:CheckIn:Read_GPS] Stopped
2022-04-25T20:57:59.200Z,1650920279.200 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-04-25T20:58:07.424Z,1650920287.424 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220425T203431/Courier0013.lzma
2022-04-25T20:58:08.426Z,1650920288.426 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Courier0013.lzma.bak
2022-04-25T20:58:08.427Z,1650920288.427 [DataOverHttps](INFO): SBD MOMSN=16661072
2022-04-25T20:58:25.920Z,1650920305.920 [DataOverHttps](INFO): Sending 224 bytes from file Logs/20220425T203431/Express0014.lzma
2022-04-25T20:58:26.922Z,1650920306.922 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Express0014.lzma.bak
2022-04-25T20:58:26.922Z,1650920306.922 [DataOverHttps](INFO): SBD MOMSN=16661075
2022-04-25T20:58:29.828Z,1650920309.828 [Default:CheckIn:Read_Iridium] Stopped
2022-04-25T20:58:29.828Z,1650920309.828 [Default:CheckIn:C.Wait] Running Loop=1
2022-04-25T20:58:29.829Z,1650920309.829 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-04-25T20:58:31.017Z,1650920311.017 [NAL9602](INFO): Not Powering down - fast GPS
2022-04-25T21:03:30.433Z,1650920610.433 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-04-25T21:03:30.433Z,1650920610.433 [Default:CheckIn:C.Wait] Stopped
2022-04-25T21:03:30.433Z,1650920610.433 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-04-25T21:03:30.433Z,1650920610.433 [Default:CheckIn:D] Running Loop=1
2022-04-25T21:03:30.843Z,1650920610.843 [Default:CheckIn:D] Stopped
2022-04-25T21:03:30.843Z,1650920610.843 [Default:CheckIn:E] Running Loop=1
2022-04-25T21:03:31.253Z,1650920611.253 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 25.014535 min 
2022-04-25T21:03:31.253Z,1650920611.253 [Default:CheckIn:E] Stopped
2022-04-25T21:03:31.253Z,1650920611.253 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-04-25T21:03:31.253Z,1650920611.253 [Default:CheckIn] Stopped
2022-04-25T21:03:31.253Z,1650920611.253 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-04-25T21:03:31.253Z,1650920611.253 [Default:CheckIn](INFO): Running loop #5
2022-04-25T21:03:31.253Z,1650920611.253 [Default:CheckIn] Running Loop=5
2022-04-25T21:03:31.254Z,1650920611.254 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-04-25T21:03:31.254Z,1650920611.254 [Default:CheckIn:Read_GPS] Running Loop=1
2022-04-25T21:03:33.253Z,1650920613.253 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210332.00,A,3648.17259,N,12147.28764,W,0.505,320.98,250422,,,A*71
2022-04-25T21:03:33.255Z,1650920613.255 [NAL9602](INFO): GPS fix at 20220425T210332: (36.802876, -121.788127)
2022-04-25T21:03:33.290Z,1650920613.290 [Default:CheckIn:Read_GPS] Stopped
2022-04-25T21:03:33.290Z,1650920613.290 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-04-25T21:03:41.343Z,1650920621.343 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220425T203431/Courier0016.lzma
2022-04-25T21:03:42.346Z,1650920622.346 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Courier0016.lzma.bak
2022-04-25T21:03:42.346Z,1650920622.346 [DataOverHttps](INFO): SBD MOMSN=16661079
2022-04-25T21:03:59.487Z,1650920639.487 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20220425T203431/Express0017.lzma
2022-04-25T21:04:00.794Z,1650920640.794 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Express0017.lzma.bak
2022-04-25T21:04:00.795Z,1650920640.795 [DataOverHttps](INFO): SBD MOMSN=16661082
2022-04-25T21:04:03.196Z,1650920643.196 [Default:CheckIn:Read_Iridium] Stopped
2022-04-25T21:04:03.196Z,1650920643.196 [Default:CheckIn:C.Wait] Running Loop=1
2022-04-25T21:04:03.197Z,1650920643.197 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-04-25T21:05:25.194Z,1650920725.194 [NAL9602](INFO): SBD MO Status=2, MOMSN=7647, MT Status=2, MTMSN=0
2022-04-25T21:05:25.195Z,1650920725.195 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-25T21:06:51.251Z,1650920811.251 [NAL9602](INFO): SBD MO Status=2, MOMSN=7647, MT Status=2, MTMSN=0
2022-04-25T21:06:51.251Z,1650920811.251 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-25T21:08:35.073Z,1650920915.073 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-04-25T21:09:03.767Z,1650920943.767 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-04-25T21:09:03.767Z,1650920943.767 [Default:CheckIn:C.Wait] Stopped
2022-04-25T21:09:03.767Z,1650920943.767 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-04-25T21:09:03.767Z,1650920943.767 [Default:CheckIn:D] Running Loop=1
2022-04-25T21:09:04.191Z,1650920944.191 [Default:CheckIn:D] Stopped
2022-04-25T21:09:04.191Z,1650920944.191 [Default:CheckIn:E] Running Loop=1
2022-04-25T21:09:04.593Z,1650920944.593 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 30.570335 min 
2022-04-25T21:09:04.593Z,1650920944.593 [Default:CheckIn:E] Stopped
2022-04-25T21:09:04.593Z,1650920944.593 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-04-25T21:09:04.593Z,1650920944.593 [Default:CheckIn] Stopped
2022-04-25T21:09:04.593Z,1650920944.593 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-04-25T21:09:04.593Z,1650920944.593 [Default:CheckIn](INFO): Running loop #6
2022-04-25T21:09:04.593Z,1650920944.593 [Default:CheckIn] Running Loop=6
2022-04-25T21:09:04.593Z,1650920944.593 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-04-25T21:09:04.594Z,1650920944.594 [Default:CheckIn:Read_GPS] Running Loop=1
2022-04-25T21:09:06.587Z,1650920946.587 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210906.00,A,3648.16764,N,12147.27498,W,0.739,0.00,250422,,,A*74
2022-04-25T21:09:06.590Z,1650920946.590 [NAL9602](INFO): GPS fix at 20220425T210906: (36.802794, -121.787916)
2022-04-25T21:09:06.609Z,1650920946.609 [Default:CheckIn:Read_GPS] Stopped
2022-04-25T21:09:06.609Z,1650920946.609 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-04-25T21:09:15.695Z,1650920955.695 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220425T203431/Courier0019.lzma
2022-04-25T21:09:16.698Z,1650920956.698 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Courier0019.lzma.bak
2022-04-25T21:09:16.698Z,1650920956.698 [DataOverHttps](INFO): SBD MOMSN=16661085
2022-04-25T21:09:33.800Z,1650920973.800 [DataOverHttps](INFO): Sending 227 bytes from file Logs/20220425T203431/Express0020.lzma
2022-04-25T21:09:34.802Z,1650920974.802 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Express0020.lzma.bak
2022-04-25T21:09:34.802Z,1650920974.802 [DataOverHttps](INFO): SBD MOMSN=16661088
2022-04-25T21:09:37.748Z,1650920977.748 [Default:CheckIn:Read_Iridium] Stopped
2022-04-25T21:09:37.749Z,1650920977.749 [Default:CheckIn:C.Wait] Running Loop=1
2022-04-25T21:09:37.749Z,1650920977.749 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-04-25T21:09:39.313Z,1650920979.313 [NAL9602](INFO): Not Powering down - fast GPS
2022-04-25T21:14:38.296Z,1650921278.296 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-04-25T21:14:38.296Z,1650921278.296 [Default:CheckIn:C.Wait] Stopped
2022-04-25T21:14:38.297Z,1650921278.297 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-04-25T21:14:38.297Z,1650921278.297 [Default:CheckIn:D] Running Loop=1
2022-04-25T21:14:38.701Z,1650921278.701 [Default:CheckIn:D] Stopped
2022-04-25T21:14:38.701Z,1650921278.701 [Default:CheckIn:E] Running Loop=1
2022-04-25T21:14:39.111Z,1650921279.111 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 36.145492 min 
2022-04-25T21:14:39.111Z,1650921279.111 [Default:CheckIn:E] Stopped
2022-04-25T21:14:39.111Z,1650921279.111 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-04-25T21:14:39.111Z,1650921279.111 [Default:CheckIn] Stopped
2022-04-25T21:14:39.111Z,1650921279.111 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-04-25T21:14:39.111Z,1650921279.111 [Default:CheckIn](INFO): Running loop #7
2022-04-25T21:14:39.111Z,1650921279.111 [Default:CheckIn] Running Loop=7
2022-04-25T21:14:39.111Z,1650921279.111 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-04-25T21:14:39.112Z,1650921279.112 [Default:CheckIn:Read_GPS] Running Loop=1
2022-04-25T21:14:41.119Z,1650921281.119 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211440.00,A,3648.17183,N,12147.27811,W,0.525,0.00,250422,,,A*76
2022-04-25T21:14:41.121Z,1650921281.121 [NAL9602](INFO): GPS fix at 20220425T211440: (36.802864, -121.787969)
2022-04-25T21:14:41.148Z,1650921281.148 [Default:CheckIn:Read_GPS] Stopped
2022-04-25T21:14:41.148Z,1650921281.148 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-04-25T21:14:48.779Z,1650921288.779 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220425T203431/Courier0022.lzma
2022-04-25T21:14:49.782Z,1650921289.782 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Courier0022.lzma.bak
2022-04-25T21:14:49.782Z,1650921289.782 [DataOverHttps](INFO): SBD MOMSN=16661092
2022-04-25T21:15:10.224Z,1650921310.224 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20220425T203431/Express0023.lzma
2022-04-25T21:15:11.226Z,1650921311.226 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Express0023.lzma.bak
2022-04-25T21:15:11.226Z,1650921311.226 [DataOverHttps](INFO): SBD MOMSN=16661095
2022-04-25T21:15:11.859Z,1650921311.859 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-04-25T21:15:11.944Z,1650921311.944 [NAL9602](ERROR): received: 
+CSQ:0

OK47, 2, 0, 0, 0

OK
2022-04-25T21:15:14.728Z,1650921314.728 [Default:CheckIn:Read_Iridium] Stopped
2022-04-25T21:15:14.728Z,1650921314.728 [Default:CheckIn:C.Wait] Running Loop=1
2022-04-25T21:15:14.728Z,1650921314.728 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-04-25T21:15:48.627Z,1650921348.627 [NAL9602](INFO): SBD MO Status=2, MOMSN=7647, MT Status=2, MTMSN=0
2022-04-25T21:15:48.627Z,1650921348.627 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-25T21:16:04.383Z,1650921364.383 [NAL9602](INFO): SBD MO Status=2, MOMSN=7647, MT Status=2, MTMSN=0
2022-04-25T21:16:04.383Z,1650921364.383 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-25T21:17:57.911Z,1650921477.911 [NAL9602](INFO): SBD MO Status=0, MOMSN=7647, MT Status=0, MTMSN=0
2022-04-25T21:17:57.911Z,1650921477.911 [NAL9602](INFO): No messages in MT queue
2022-04-25T21:18:28.613Z,1650921508.613 [NAL9602](INFO): Not Powering down - fast GPS
2022-04-25T21:20:15.310Z,1650921615.310 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-04-25T21:20:15.310Z,1650921615.310 [Default:CheckIn:C.Wait] Stopped
2022-04-25T21:20:15.311Z,1650921615.311 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-04-25T21:20:15.311Z,1650921615.311 [Default:CheckIn:D] Running Loop=1
2022-04-25T21:20:15.711Z,1650921615.711 [Default:CheckIn:D] Stopped
2022-04-25T21:20:15.711Z,1650921615.711 [Default:CheckIn:E] Running Loop=1
2022-04-25T21:20:16.127Z,1650921616.127 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 41.762325 min 
2022-04-25T21:20:16.127Z,1650921616.127 [Default:CheckIn:E] Stopped
2022-04-25T21:20:16.127Z,1650921616.127 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-04-25T21:20:16.127Z,1650921616.127 [Default:CheckIn] Stopped
2022-04-25T21:20:16.127Z,1650921616.127 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-04-25T21:20:16.128Z,1650921616.128 [Default:CheckIn](INFO): Running loop #8
2022-04-25T21:20:16.128Z,1650921616.128 [Default:CheckIn] Running Loop=8
2022-04-25T21:20:16.128Z,1650921616.128 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-04-25T21:20:16.128Z,1650921616.128 [Default:CheckIn:Read_GPS] Running Loop=1
2022-04-25T21:20:18.126Z,1650921618.126 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212018.00,A,3648.17239,N,12147.28261,W,0.136,158.70,250422,,,A*71
2022-04-25T21:20:18.128Z,1650921618.128 [NAL9602](INFO): GPS fix at 20220425T212018: (36.802873, -121.788044)
2022-04-25T21:20:18.138Z,1650921618.138 [Default:CheckIn:Read_GPS] Stopped
2022-04-25T21:20:18.139Z,1650921618.139 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-04-25T21:20:26.175Z,1650921626.175 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220425T203431/Courier0025.lzma
2022-04-25T21:20:27.178Z,1650921627.178 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Courier0025.lzma.bak
2022-04-25T21:20:27.178Z,1650921627.178 [DataOverHttps](INFO): SBD MOMSN=16661113
2022-04-25T21:20:44.419Z,1650921644.419 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20220425T203431/Express0026.lzma
2022-04-25T21:20:45.422Z,1650921645.422 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Express0026.lzma.bak
2022-04-25T21:20:45.422Z,1650921645.422 [DataOverHttps](INFO): SBD MOMSN=16661116
2022-04-25T21:20:48.088Z,1650921648.088 [Default:CheckIn:Read_Iridium] Stopped
2022-04-25T21:20:48.088Z,1650921648.088 [Default:CheckIn:C.Wait] Running Loop=1
2022-04-25T21:20:48.089Z,1650921648.089 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-04-25T21:24:10.103Z,1650921850.103 [NAL9602](INFO): SBD MO Status=2, MOMSN=7648, MT Status=2, MTMSN=0
2022-04-25T21:24:10.103Z,1650921850.103 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-25T21:24:49.291Z,1650921889.291 [NAL9602](INFO): SBD MO Status=2, MOMSN=7648, MT Status=2, MTMSN=0
2022-04-25T21:24:49.292Z,1650921889.292 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-25T21:25:03.835Z,1650921903.835 [NAL9602](INFO): SBD MO Status=2, MOMSN=7648, MT Status=2, MTMSN=0
2022-04-25T21:25:03.835Z,1650921903.835 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-25T21:25:28.493Z,1650921928.493 [NAL9602](INFO): SBD MO Status=2, MOMSN=7648, MT Status=2, MTMSN=0
2022-04-25T21:25:28.493Z,1650921928.493 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-25T21:25:28.902Z,1650921928.902 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-04-25T21:25:48.707Z,1650921948.707 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-04-25T21:25:48.707Z,1650921948.707 [Default:CheckIn:C.Wait] Stopped
2022-04-25T21:25:48.707Z,1650921948.707 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-04-25T21:25:48.707Z,1650921948.707 [Default:CheckIn:D] Running Loop=1
2022-04-25T21:25:49.112Z,1650921949.112 [Default:CheckIn:D] Stopped
2022-04-25T21:25:49.112Z,1650921949.112 [Default:CheckIn:E] Running Loop=1
2022-04-25T21:25:49.524Z,1650921949.524 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 47.319014 min 
2022-04-25T21:25:49.524Z,1650921949.524 [Default:CheckIn:E] Stopped
2022-04-25T21:25:49.524Z,1650921949.524 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-04-25T21:25:49.524Z,1650921949.524 [Default:CheckIn] Stopped
2022-04-25T21:25:49.524Z,1650921949.524 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-04-25T21:25:49.524Z,1650921949.524 [Default:CheckIn](INFO): Running loop #9
2022-04-25T21:25:49.524Z,1650921949.524 [Default:CheckIn] Running Loop=9
2022-04-25T21:25:49.525Z,1650921949.525 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-04-25T21:25:49.525Z,1650921949.525 [Default:CheckIn:Read_GPS] Running Loop=1
2022-04-25T21:25:51.527Z,1650921951.527 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212551.00,A,3648.17356,N,12147.28474,W,0.933,144.46,250422,,,A*76
2022-04-25T21:25:51.530Z,1650921951.530 [NAL9602](INFO): GPS fix at 20220425T212551: (36.802893, -121.788079)
2022-04-25T21:25:51.576Z,1650921951.576 [Default:CheckIn:Read_GPS] Stopped
2022-04-25T21:25:51.576Z,1650921951.576 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-04-25T21:25:59.216Z,1650921959.216 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220425T203431/Courier0028.lzma
2022-04-25T21:26:00.218Z,1650921960.218 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Courier0028.lzma.bak
2022-04-25T21:26:00.218Z,1650921960.218 [DataOverHttps](INFO): SBD MOMSN=16661119
2022-04-25T21:26:17.320Z,1650921977.320 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20220425T203431/Express0029.lzma
2022-04-25T21:26:18.322Z,1650921978.322 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Express0029.lzma.bak
2022-04-25T21:26:18.322Z,1650921978.322 [DataOverHttps](INFO): SBD MOMSN=16661122
2022-04-25T21:26:21.050Z,1650921981.050 [Default:CheckIn:Read_Iridium] Stopped
2022-04-25T21:26:21.050Z,1650921981.050 [Default:CheckIn:C.Wait] Running Loop=1
2022-04-25T21:26:21.050Z,1650921981.050 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-04-25T21:26:24.245Z,1650921984.245 [NAL9602](INFO): Not Powering down - fast GPS
2022-04-25T21:31:21.643Z,1650922281.643 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-04-25T21:31:21.643Z,1650922281.643 [Default:CheckIn:C.Wait] Stopped
2022-04-25T21:31:21.644Z,1650922281.644 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-04-25T21:31:21.644Z,1650922281.644 [Default:CheckIn:D] Running Loop=1
2022-04-25T21:31:22.057Z,1650922282.057 [Default:CheckIn:D] Stopped
2022-04-25T21:31:22.057Z,1650922282.057 [Default:CheckIn:E] Running Loop=1
2022-04-25T21:31:22.446Z,1650922282.446 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 52.868095 min 
2022-04-25T21:31:22.446Z,1650922282.446 [Default:CheckIn:E] Stopped
2022-04-25T21:31:22.446Z,1650922282.446 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-04-25T21:31:22.446Z,1650922282.446 [Default:CheckIn] Stopped
2022-04-25T21:31:22.446Z,1650922282.446 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-04-25T21:31:22.446Z,1650922282.446 [Default:CheckIn](INFO): Running loop #10
2022-04-25T21:31:22.447Z,1650922282.447 [Default:CheckIn] Running Loop=10
2022-04-25T21:31:22.447Z,1650922282.447 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-04-25T21:31:22.447Z,1650922282.447 [Default:CheckIn:Read_GPS] Running Loop=1
2022-04-25T21:31:24.460Z,1650922284.460 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213124.00,A,3648.17210,N,12147.27809,W,0.505,144.46,250422,,,A*72
2022-04-25T21:31:24.462Z,1650922284.462 [NAL9602](INFO): GPS fix at 20220425T213124: (36.802868, -121.787968)
2022-04-25T21:31:24.472Z,1650922284.472 [Default:CheckIn:Read_GPS] Stopped
2022-04-25T21:31:24.472Z,1650922284.472 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-04-25T21:31:33.260Z,1650922293.260 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220425T203431/Courier0031.lzma
2022-04-25T21:31:34.263Z,1650922294.263 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Courier0031.lzma.bak
2022-04-25T21:31:34.263Z,1650922294.263 [DataOverHttps](INFO): SBD MOMSN=16661126
2022-04-25T21:31:51.745Z,1650922311.745 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20220425T203431/Express0032.lzma
2022-04-25T21:31:52.747Z,1650922312.747 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Express0032.lzma.bak
2022-04-25T21:31:52.747Z,1650922312.747 [DataOverHttps](INFO): SBD MOMSN=16661129
2022-04-25T21:31:55.442Z,1650922315.442 [Default:CheckIn:Read_Iridium] Stopped
2022-04-25T21:31:55.442Z,1650922315.442 [Default:CheckIn:C.Wait] Running Loop=1
2022-04-25T21:31:55.442Z,1650922315.442 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-04-25T21:33:27.516Z,1650922407.516 [NAL9602](INFO): SBD MO Status=2, MOMSN=7648, MT Status=2, MTMSN=0
2022-04-25T21:33:27.516Z,1650922407.516 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-25T21:34:30.023Z,1650922470.023 [CommandExec](IMPORTANT): got command maintain sensor AHRS_M2.platform_pitch_angle 7 degree
2022-04-25T21:34:30.026Z,1650922470.026 [ComponentRegistry](DEBUG): SyncComponent "Maintain_AHRS_M2.platform_pitch_angle" handled in the control thread.
2022-04-25T21:34:30.203Z,1650922470.203 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,PAR_Licor,Depth_Keller,PAR_Licor,Maintain_AHRS_M2.platform_pitch_angle,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,VerticalHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2022-04-25T21:34:34.479Z,1650922474.479 [DataOverHttps](IMPORTANT): SBD MTMSN=20220425T213433
2022-04-25T21:34:41.721Z,1650922481.721 [DataOverHttps](INFO): Received command: load Engineering/sci2_quickGPS.xml;set sci2_quickGPS.NeedGPSTime 5 min;set sci2_quickGPS.Lat1 36.797 degree;set sci2_quickGPS.Lon1 -121.9 degree;set sci2_quickGPS.Speed 0.15 m/s;set sci2_quickGPS.MinOffshore 0.0000001 km;run
2022-04-25T21:34:41.770Z,1650922481.770 [CommandExec](IMPORTANT): got command load ./Missions/Engineering/sci2_quickGPS.xml
2022-04-25T21:34:41.770Z,1650922481.770 [MissionManager](INFO): Loading Mission from file: ./Missions/Engineering/sci2_quickGPS.xml
2022-04-25T21:34:41.964Z,1650922481.964 [MissionManager](INFO): DefineArg sci2_quickGPS.MissionTimeout = 2.000000 h
2022-04-25T21:34:41.967Z,1650922481.967 [MissionManager](INFO): DefineArg sci2_quickGPS.NeedCommsTime = 60.000000 min
2022-04-25T21:34:41.970Z,1650922481.970 [MissionManager](INFO): DefineArg sci2_quickGPS.NeedGPSTime = 20.000000 min
2022-04-25T21:34:41.972Z,1650922481.972 [MissionManager](INFO): DefineArg sci2_quickGPS.Repeat = 1.000000 count
2022-04-25T21:34:41.975Z,1650922481.975 [MissionManager](INFO): DefineArg sci2_quickGPS.Lat1 = nan arcdeg
2022-04-25T21:34:41.978Z,1650922481.978 [MissionManager](INFO): DefineArg sci2_quickGPS.Lon1 = nan arcdeg
2022-04-25T21:34:41.980Z,1650922481.980 [MissionManager](INFO): DefineArg sci2_quickGPS.Lat2 = nan arcdeg
2022-04-25T21:34:41.983Z,1650922481.983 [MissionManager](INFO): DefineArg sci2_quickGPS.Lon2 = nan arcdeg
2022-04-25T21:34:41.986Z,1650922481.986 [MissionManager](INFO): DefineArg sci2_quickGPS.Lat3 = nan arcdeg
2022-04-25T21:34:41.989Z,1650922481.989 [MissionManager](INFO): DefineArg sci2_quickGPS.Lon3 = nan arcdeg
2022-04-25T21:34:41.991Z,1650922481.991 [MissionManager](INFO): DefineArg sci2_quickGPS.Lat4 = nan arcdeg
2022-04-25T21:34:41.994Z,1650922481.994 [MissionManager](INFO): DefineArg sci2_quickGPS.Lon4 = nan arcdeg
2022-04-25T21:34:41.997Z,1650922481.997 [MissionManager](INFO): DefineArg sci2_quickGPS.Lat5 = nan arcdeg
2022-04-25T21:34:41.000Z,1650922482.000 [MissionManager](INFO): DefineArg sci2_quickGPS.Lon5 = nan arcdeg
2022-04-25T21:34:42.002Z,1650922482.002 [MissionManager](INFO): DefineArg sci2_quickGPS.Lat6 = nan arcdeg
2022-04-25T21:34:42.006Z,1650922482.006 [MissionManager](INFO): DefineArg sci2_quickGPS.Lon6 = nan arcdeg
2022-04-25T21:34:42.008Z,1650922482.008 [MissionManager](INFO): DefineArg sci2_quickGPS.Lat7 = nan arcdeg
2022-04-25T21:34:42.011Z,1650922482.011 [MissionManager](INFO): DefineArg sci2_quickGPS.Lon7 = nan arcdeg
2022-04-25T21:34:42.058Z,1650922482.058 [MissionManager](INFO): DefineArg sci2_quickGPS.Speed = 1.000000 m/s
2022-04-25T21:34:42.061Z,1650922482.061 [MissionManager](INFO): DefineArg sci2_quickGPS.CaptureRadius = nan m
2022-04-25T21:34:42.064Z,1650922482.064 [MissionManager](INFO): DefineArg sci2_quickGPS.YoYoMinDepth = 2.000000 m
2022-04-25T21:34:42.067Z,1650922482.067 [MissionManager](INFO): DefineArg sci2_quickGPS.YoYoMaxDepth = 100.000000 m
2022-04-25T21:34:42.086Z,1650922482.086 [MissionManager](INFO): DefineArg sci2_quickGPS.YoYoMinAltitude = 9.000000 m
2022-04-25T21:34:42.090Z,1650922482.090 [MissionManager](INFO): DefineArg sci2_quickGPS.YoYoUpPitch = 20.000000 arcdeg
2022-04-25T21:34:42.093Z,1650922482.093 [MissionManager](INFO): DefineArg sci2_quickGPS.YoYoDownPitch = -20.000000 arcdeg
2022-04-25T21:34:42.097Z,1650922482.097 [MissionManager](INFO): DefineArg sci2_quickGPS.BuoyancyNeutral = 255.152618 cc
2022-04-25T21:34:42.100Z,1650922482.100 [MissionManager](INFO): DefineArg sci2_quickGPS.MassDefault = 0.810873 cm
2022-04-25T21:34:42.128Z,1650922482.128 [MissionManager](INFO): DefineArg sci2_quickGPS.MinAltitude = 5.000000 m
2022-04-25T21:34:42.131Z,1650922482.131 [MissionManager](INFO): DefineArg sci2_quickGPS.MaxDepth = 205.000000 m
2022-04-25T21:34:42.133Z,1650922482.133 [MissionManager](INFO): DefineArg sci2_quickGPS.MinOffshore = 2.000000 km
2022-04-25T21:34:42.134Z,1650922482.134 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/Science.xml
2022-04-25T21:34:42.915Z,1650922482.915 [MissionManager](INFO): DefineArg sci2_quickGPS:Science.PeakDetectChlActive = 0 bool
2022-04-25T21:34:42.918Z,1650922482.918 [MissionManager](INFO): DefineArg sci2_quickGPS:Science.TimeWindowPeakReport = nan min
2022-04-25T21:34:42.920Z,1650922482.920 [MissionManager](INFO): DefineArg sci2_quickGPS:Science.HighestChlPeakReportActive = 0 bool
2022-04-25T21:34:42.935Z,1650922482.935 [MissionManager](INFO): DefineArg sci2_quickGPS:Science.HighestSaltPeakReportActive = 0 bool
2022-04-25T21:34:42.938Z,1650922482.938 [MissionManager](INFO): DefineArg sci2_quickGPS:Science.HighestOilPeakReportActive = 0 bool
2022-04-25T21:34:42.940Z,1650922482.940 [MissionManager](INFO): DefineArg sci2_quickGPS:Science.PatchTracking = 0 bool
2022-04-25T21:34:42.943Z,1650922482.943 [MissionManager](INFO): DefineArg sci2_quickGPS:Science.DetectTrough = 0 bool
2022-04-25T21:34:42.955Z,1650922482.955 [MissionManager](INFO): DefineArg sci2_quickGPS:Science.FilterWidthHorizontal = 3.000000 count
2022-04-25T21:34:42.958Z,1650922482.958 [MissionManager](INFO): DefineArg sci2_quickGPS:Science.NumProfilesSlidingwindow = 100.000000 count
2022-04-25T21:34:42.961Z,1650922482.961 [MissionManager](INFO): DefineArg sci2_quickGPS:Science.OffPeakFractionHorizontal = 80.000000 %
2022-04-25T21:34:42.963Z,1650922482.963 [MissionManager](INFO): DefineArg sci2_quickGPS:Science.PeakDetectNO3Active = 0 bool
2022-04-25T21:34:42.993Z,1650922482.993 [MissionManager](INFO): DefineArg sci2_quickGPS:Science.PeakDetectOilActive = 0 bool
2022-04-25T21:34:42.995Z,1650922482.995 [MissionManager](INFO): DefineArg sci2_quickGPS:Science.PeakDetectFDOMActive = 0 bool
2022-04-25T21:34:42.998Z,1650922482.998 [MissionManager](INFO): DefineArg sci2_quickGPS:Science.PeakDetectSalinityActive = 0 bool
2022-04-25T21:34:43.001Z,1650922483.001 [MissionManager](INFO): DefineArg sci2_quickGPS:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2022-04-25T21:34:43.035Z,1650922483.035 [MissionManager](INFO): DefineArg sci2_quickGPS:Science.EnabledAanderaaO2 = 0 bool
2022-04-25T21:34:43.038Z,1650922483.038 [MissionManager](INFO): DefineArg sci2_quickGPS:Science.EnabledNeilBrown = 0 bool
2022-04-25T21:34:43.082Z,1650922483.082 [MissionManager](INFO): DefineArg sci2_quickGPS:Science.EnabledSeabird = 0 bool
2022-04-25T21:34:43.088Z,1650922483.088 [MissionManager](INFO): DefineArg sci2_quickGPS:Science.EnabledWetLabsBB2FL = 1 bool
2022-04-25T21:34:43.120Z,1650922483.120 [MissionManager](INFO): DefineArg sci2_quickGPS:Science.EnabledWetLabsSeaOWL_UV_A = 0 bool
2022-04-25T21:34:43.123Z,1650922483.123 [MissionManager](INFO): DefineArg sci2_quickGPS:Science.EnabledWetLabsUBAT = 0 bool
2022-04-25T21:34:43.160Z,1650922483.160 [MissionManager](INFO): DefineArg sci2_quickGPS:Science.LowPassWindowLength = 20.000000 count
2022-04-25T21:34:43.163Z,1650922483.163 [MissionManager](INFO): DefineArg sci2_quickGPS:Science.MedianFilterLen = 5.000000 count
2022-04-25T21:34:43.166Z,1650922483.166 [MissionManager](INFO): DefineArg sci2_quickGPS:Science.PeakShallowBound = nan m
2022-04-25T21:34:43.198Z,1650922483.198 [MissionManager](INFO): DefineArg sci2_quickGPS:Science.PeakDeepBound = nan m
2022-04-25T21:34:43.201Z,1650922483.201 [MissionManager](INFO): DefineArg sci2_quickGPS:Science.DepChangeThreshForAttitudeFlip = 2.000000 m
2022-04-25T21:34:43.204Z,1650922483.204 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PeakChl = 0.000000 ug/l
2022-04-25T21:34:43.207Z,1650922483.207 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PeakChlDepth = 0.000000 m
2022-04-25T21:34:43.233Z,1650922483.233 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PeakChlTemperature = 0.000000 degC
2022-04-25T21:34:43.236Z,1650922483.236 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PeakChlLatitude = nan arcdeg
2022-04-25T21:34:43.239Z,1650922483.239 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PeakChlLongitude = nan arcdeg
2022-04-25T21:34:43.259Z,1650922483.259 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PeakNO3 = 0.000000 umol/l
2022-04-25T21:34:43.262Z,1650922483.262 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PeakNO3Depth = 0.000000 m
2022-04-25T21:34:43.265Z,1650922483.265 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PeakNO3Latitude = nan arcdeg
2022-04-25T21:34:43.268Z,1650922483.268 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PeakNO3Longitude = nan arcdeg
2022-04-25T21:34:43.308Z,1650922483.308 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PeakOil = 0.000000 kg/m3
2022-04-25T21:34:43.311Z,1650922483.311 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PeakOilDepth = 0.000000 m
2022-04-25T21:34:43.314Z,1650922483.314 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PeakOilLatitude = nan arcdeg
2022-04-25T21:34:43.351Z,1650922483.351 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PeakOilLongitude = nan arcdeg
2022-04-25T21:34:43.354Z,1650922483.354 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PeakFDOM = 0.000000 ppb
2022-04-25T21:34:43.357Z,1650922483.357 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PeakFDOMDepth = 0.000000 m
2022-04-25T21:34:43.360Z,1650922483.360 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PeakFDOMTemperature = nan degC
2022-04-25T21:34:43.371Z,1650922483.371 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PeakFDOMLatitude = nan arcdeg
2022-04-25T21:34:43.374Z,1650922483.374 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PeakFDOMLongitude = nan arcdeg
2022-04-25T21:34:43.389Z,1650922483.389 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PatchFDOMDistance = nan m
2022-04-25T21:34:43.392Z,1650922483.392 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PeakSalt = 0.000000 psu
2022-04-25T21:34:43.395Z,1650922483.395 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PeakSaltDepth = 0.000000 m
2022-04-25T21:34:43.399Z,1650922483.399 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PeakSaltTemperature = 0.000000 degC
2022-04-25T21:34:43.414Z,1650922483.414 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PeakSaltLatitude = nan arcdeg
2022-04-25T21:34:43.417Z,1650922483.417 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PeakSaltLongitude = nan arcdeg
2022-04-25T21:34:43.420Z,1650922483.420 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PatchChl = 0.000000 ug/l
2022-04-25T21:34:43.423Z,1650922483.423 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PatchChlDepth = 0.000000 m
2022-04-25T21:34:43.434Z,1650922483.434 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PatchChlLatitude = nan arcdeg
2022-04-25T21:34:43.437Z,1650922483.437 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PatchChlLongitude = nan arcdeg
2022-04-25T21:34:43.440Z,1650922483.440 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PatchChlDistance = nan m
2022-04-25T21:34:43.443Z,1650922483.443 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PatchSalt = 0.000000 psu
2022-04-25T21:34:43.495Z,1650922483.495 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PatchSaltDepth = 0.000000 m
2022-04-25T21:34:43.506Z,1650922483.506 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PatchSaltLatitude = nan arcdeg
2022-04-25T21:34:43.524Z,1650922483.524 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PatchSaltLongitude = nan arcdeg
2022-04-25T21:34:43.535Z,1650922483.535 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PatchSaltDistance = nan m
2022-04-25T21:34:43.538Z,1650922483.538 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PatchOil = 0.000000 psu
2022-04-25T21:34:43.541Z,1650922483.541 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PatchOilDepth = 0.000000 m
2022-04-25T21:34:43.556Z,1650922483.556 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PatchOilLatitude = nan arcdeg
2022-04-25T21:34:43.563Z,1650922483.563 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PatchOilLongitude = nan arcdeg
2022-04-25T21:34:43.568Z,1650922483.568 [MissionManager](INFO): DefineOutput sci2_quickGPS:Science.PatchOilDistance = nan m
2022-04-25T21:34:43.702Z,1650922483.702 [sci2_quickGPS:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-04-25T21:34:43.736Z,1650922483.736 [sci2_quickGPS:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2022-04-25T21:34:43.809Z,1650922483.809 [sci2_quickGPS:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-04-25T21:34:43.828Z,1650922483.828 [sci2_quickGPS:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-04-25T21:34:43.887Z,1650922483.887 [sci2_quickGPS:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2022-04-25T21:34:43.944Z,1650922483.944 [sci2_quickGPS:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-04-25T21:34:43.990Z,1650922483.990 [sci2_quickGPS:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-04-25T21:34:44.050Z,1650922484.050 [sci2_quickGPS:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2022-04-25T21:34:44.078Z,1650922484.078 [MissionManager](INFO): RedefineArg sci2_quickGPS:Science.PeakDetectChlActive = value:1 bool
2022-04-25T21:34:44.078Z,1650922484.078 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/NeedComms.xml
2022-04-25T21:34:44.221Z,1650922484.221 [MissionManager](INFO): DefineArg sci2_quickGPS:NeedComms.DiveInterval = 3.000000 h
2022-04-25T21:34:44.224Z,1650922484.224 [MissionManager](INFO): DefineArg sci2_quickGPS:NeedComms.WaitForPitchUp = 10.000000 min
2022-04-25T21:34:44.227Z,1650922484.227 [MissionManager](INFO): DefineArg sci2_quickGPS:NeedComms.SurfacePitch = 20.000000 arcdeg
2022-04-25T21:34:44.252Z,1650922484.252 [MissionManager](INFO): DefineArg sci2_quickGPS:NeedComms.SurfaceDepthRate = nan m/s
2022-04-25T21:34:44.273Z,1650922484.273 [MissionManager](INFO): DefineArg sci2_quickGPS:NeedComms.SurfaceSpeed = 1.000000 m/s
2022-04-25T21:34:44.277Z,1650922484.277 [MissionManager](INFO): DefineArg sci2_quickGPS:NeedComms.GPSTimeout = 7.000000 min
2022-04-25T21:34:44.336Z,1650922484.336 [MissionManager](INFO): DefineArg sci2_quickGPS:NeedComms.CommsTimeout = 30.000000 min
2022-04-25T21:34:44.344Z,1650922484.344 [sci2_quickGPS:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2022-04-25T21:34:44.414Z,1650922484.414 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/SurfaceGPS.xml
2022-04-25T21:34:44.468Z,1650922484.468 [MissionManager](INFO): DefineArg sci2_quickGPS:QuickFix.HalfTimeout = 30.000000 s
2022-04-25T21:34:44.483Z,1650922484.483 [MissionManager](INFO): DefineArg sci2_quickGPS:QuickFix.SurfacePitch = 20.000000 arcdeg
2022-04-25T21:34:44.492Z,1650922484.492 [MissionManager](INFO): DefineArg sci2_quickGPS:QuickFix.SurfaceSpeed = 1.000000 m/s
2022-04-25T21:34:44.499Z,1650922484.499 [sci2_quickGPS:QuickFix:A.GoToSurface](DEBUG): Construct GoToSurface.
2022-04-25T21:34:44.517Z,1650922484.517 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/StandardEnvelopes.xml
2022-04-25T21:34:44.563Z,1650922484.563 [MissionManager](INFO): DefineArg sci2_quickGPS:StandardEnvelopes.MinAltitude = 5.000000 m
2022-04-25T21:34:44.578Z,1650922484.578 [MissionManager](INFO): DefineArg sci2_quickGPS:StandardEnvelopes.MaxDepth = 200.000000 m
2022-04-25T21:34:44.581Z,1650922484.581 [MissionManager](INFO): DefineArg sci2_quickGPS:StandardEnvelopes.MinOffshore = 2000.000000 m
2022-04-25T21:34:44.582Z,1650922484.582 [sci2_quickGPS:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2022-04-25T21:34:44.617Z,1650922484.617 [sci2_quickGPS:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2022-04-25T21:34:44.656Z,1650922484.656 [sci2_quickGPS:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2022-04-25T21:34:44.724Z,1650922484.724 [sci2_quickGPS:J.Pitch](DEBUG): Construct.
2022-04-25T21:34:44.757Z,1650922484.757 [sci2_quickGPS:K.Buoyancy](DEBUG): Construct Buoyancy.
2022-04-25T21:34:44.764Z,1650922484.764 [sci2_quickGPS:L.SetSpeed](DEBUG): Construct.
2022-04-25T21:34:44.793Z,1650922484.793 [sci2_quickGPS:M.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2022-04-25T21:34:44.812Z,1650922484.812 [sci2_quickGPS:N.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2022-04-25T21:34:44.842Z,1650922484.842 [sci2_quickGPS:P.YoYo](DEBUG): Construct YoYo.
2022-04-25T21:34:44.896Z,1650922484.896 [sci2_quickGPS:Lap:Wpt1:A.Waypoint](DEBUG): Construct Waypoint.
2022-04-25T21:34:44.920Z,1650922484.920 [sci2_quickGPS:Lap:Wpt2:A.Waypoint](DEBUG): Construct Waypoint.
2022-04-25T21:34:44.944Z,1650922484.944 [sci2_quickGPS:Lap:Wpt3:A.Waypoint](DEBUG): Construct Waypoint.
2022-04-25T21:34:44.958Z,1650922484.958 [sci2_quickGPS:Lap:Wpt4:A.Waypoint](DEBUG): Construct Waypoint.
2022-04-25T21:34:44.973Z,1650922484.973 [sci2_quickGPS:Lap:Wpt5:A.Waypoint](DEBUG): Construct Waypoint.
2022-04-25T21:34:44.981Z,1650922484.981 [sci2_quickGPS:Lap:Wpt6:A.Waypoint](DEBUG): Construct Waypoint.
2022-04-25T21:34:44.996Z,1650922484.996 [sci2_quickGPS:Lap:Wpt7:A.Waypoint](DEBUG): Construct Waypoint.
2022-04-25T21:34:45.112Z,1650922485.112 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<!-- ====================
     Generated by TethysL
     ==================== -->
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Control="Tethys/Control"
         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/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="sci2_quickGPS">

    <Description>
        Vehicle yo-yo's to the specified waypoints, with science turned on.
    </Description>

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

    <DefineArg Name="NeedCommsTime"><Description>
        How often to surface for commumications
    </Description><Units:minute/><Value>60</Value></DefineArg>

    <DefineArg Name="NeedGPSTime"><Description>
        After this time elapses AND the vehicle is pitched up, grab a fix
        underway
    </Description><Units:minute/><Value>20</Value></DefineArg>

    <DefineArg Name="Repeat"><Description>
        Number of times the vehicle should try to cycle through waypoints..
    </Description><Units:count/><Value>1</Value></DefineArg>

    <DefineArg Name="Lat1"><Description>
        Latitude of waypoint 1. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon1"><Description>
        Longitude of waypoint 1. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat2"><Description>
        Latitude of waypoint 2. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon2"><Description>
        Longitude of waypoint 2. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat3"><Description>
        Latitude of waypoint 3. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon3"><Description>
        Longitude of waypoint 3. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat4"><Description>
        Latitude of waypoint 4. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon4"><Description>
        Longitude of waypoint 4. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat5"><Description>
        Latitude of waypoint 5. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon5"><Description>
        Longitude of waypoint 5. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat6"><Description>
        Latitude of waypoint 6. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon6"><Description>
        Longitude of waypoint 6. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat7"><Description>
        Latitude of waypoint 7. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon7"><Description>
        Longitude of waypoint 7. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Speed"><Description>
        Speed while performing the YoYo behavior.
    </Description><Units:meter_per_second/><Value>1</Value></DefineArg>

    <DefineArg Name="CaptureRadius"><Description>
        Speed while performing the YoYo behavior.
    </Description><Units:meter/><Value>NaN</Value></DefineArg>

    <DefineArg Name="YoYoMinDepth"><Description>
        Minimum depth while performing the YoYo behavior.
    </Description><Units:meter/><Value>2</Value></DefineArg>

    <DefineArg Name="YoYoMaxDepth"><Description>
        Maximum depth while performing the YoYo behavior.
    </Description><Units:meter/><Value>100</Value></DefineArg>

    <DefineArg Name="YoYoMinAltitude"><Description>
        Minimum altitude while performing the YoYo behavior (for
        bottom-terminated YoYos).
    </Description><Units:meter/><Value>9</Value></DefineArg>

    <DefineArg Name="YoYoUpPitch"><Description>
        Vehicle up pitch while performing the YoYo behavior.
    </Description><Units:degree/><Value>20</Value></DefineArg>

    <DefineArg Name="YoYoDownPitch"><Description>
        Vehicle down pitch while performing the YoYo behavior.
    </Description><Units:degree/><Value>-20</Value></DefineArg>

    <DefineArg Name="BuoyancyNeutral"><Description>
        Buoyancy bladder position while performing the YoYo behavior. Defaults
        to buoyancyNeutral setting in the Config/Control.cfg file. Set to NaN cc
        for active buoyancy
    </Description><Control:VerticalControl.buoyancyNeutral/></DefineArg>

    <DefineArg Name="MassDefault"><Description>
        Static setting for mass during the mission. Set to NaN mm for active
        mass position
    </Description><Control:VerticalControl.massDefault/></DefineArg>

    <DefineArg Name="MinAltitude"><Description>
        Minimum height above the sea floor for the entire mission.
    </Description><Units:meter/><Value>5</Value></DefineArg>

    <DefineArg Name="MaxDepth"><Description>
        Maximum depth for the entire mission.
    </Description><Units:meter/><Value>205</Value></DefineArg>

    <DefineArg Name="MinOffshore"><Description>
        Minimum offshore distance for the entire mission.
    </Description><Units:kilometer/><Value>2</Value></DefineArg>

    <Timeout Duration="MissionTimeout"/>

    <Insert Filename="Insert/Science.xml">
        <Description>
            Most missions will run the science sensors. If you don't place this
            aggregate above NeedComms, science instruments get turned off on the
            last upcast and while floating on the surface.
        </Description>
        <RedefineArg Name="PeakDetectChlActive"><True/></RedefineArg>
    </Insert>

    <Insert Filename="Insert/NeedComms.xml" Id="NeedComms"/>

    <Assign><Sequence/><Arg Name="NeedComms:DiveInterval"/><Arg Name="NeedCommsTime"/></Assign>

    <Insert Filename="Insert/SurfaceGPS.xml" Id="QuickFix"/>

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

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MinAltitude"/><Arg Name="MinAltitude"/></Assign>

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MaxDepth"/><Arg Name="MaxDepth"/></Assign>

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MinOffshore"/><Arg Name="MinOffshore"/></Assign>

    <Call Id="StartingMission" RefId="NeedComms"/>

    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Arg Name="MassDefault"/></Setting>
    </Guidance:Pitch>

    <Guidance:Buoyancy>
        <Parallel/>
        <Setting><Guidance:Buoyancy.position/><Arg Name="BuoyancyNeutral"/></Setting>
    </Guidance:Buoyancy>

    <Guidance:SetSpeed>
        <Parallel/>
        <Setting><Guidance:SetSpeed.speed/><Arg Name="Speed"/></Setting>
    </Guidance:SetSpeed>

    <Guidance:DepthEnvelope>
        <Description>
            Another depth envelope for the YoYo behavior. This envelope should
            fall within the limits of the standard safety envelopes in
            Insert/StandardEnvelopes.xml in order to avoid commanding high pitch
            angles for depth-terminated YoYos.
        </Description>
        <Parallel/>
        <Setting><Guidance:DepthEnvelope.minDepth/><Arg Name="YoYoMinDepth"/></Setting>
        <Setting><Guidance:DepthEnvelope.maxDepth/><Arg Name="YoYoMaxDepth"/></Setting>
        <Setting><Guidance:DepthEnvelope.downPitch/><Arg Name="YoYoDownPitch"/></Setting>
        <Setting><Guidance:DepthEnvelope.upPitch/><Arg Name="YoYoUpPitch"/></Setting>
    </Guidance:DepthEnvelope>

    <Guidance:AltitudeEnvelope>
        <Description>
            Another altitude envelope for the YoYo behavior. This envelope
            should fall within the limits of the standard safety envelopes in
            Insert/StandardEnvelopes.xml in order to avoid commanding high pitch
            angles for bottom-terminated YoYos.
        </Description>
        <Parallel/>
        <Setting><Guidance:AltitudeEnvelope.minAltitude/><Arg Name="YoYoMinAltitude"/></Setting>
        <Setting><Guidance:AltitudeEnvelope.upPitch/><Arg Name="YoYoUpPitch"/></Setting>
    </Guidance:AltitudeEnvelope>

    <Aggregate Id="NeedGPS">

        <When>
            <Universal:platform_pitch_angle/>
            <Gt><Units:degree/><Value>5</Value></Gt>
            <And><Elapsed><Universal:time_fix/></Elapsed><Gt><Arg Name="NeedGPSTime"/></Gt></And>
        </When>

        <Syslog Severity="Info">Quick GPS - last time_fix was: <Universal:time_fix/><Units:epoch_second/></Syslog>

        <Call Id="NeedGPS" RefId="QuickFix"/>

    </Aggregate>

    <Guidance:YoYo>
        <Parallel/>
        <Setting><Guidance:YoYo.downPitch/><Arg Name="YoYoDownPitch"/></Setting>
        <Setting><Guidance:YoYo.upPitch/><Arg Name="YoYoUpPitch"/></Setting>
    </Guidance:YoYo>


<!-- Here we explicitly call NeedComms because the insert is triggered on time_fix which 
    gets updated every time there's a good GPS fix. We want to make sure to send data back on 
    a regular interval to shore too. The NeedComms insert should probably be changed to reflect 
    comms or GPS
    -->

    <Aggregate Id="NeedCommunications">

        <When>
            <Elapsed><Universal:platform_communications/></Elapsed>
            <Gt><Arg Name="NeedCommsTime"/></Gt>
        </When>

        <Syslog Severity="Info">Surfacing For Communications</Syslog>

        <Call Id="NeedCommunications" RefId="NeedComms"/>

    </Aggregate>

    <Aggregate Id="Lap">

        <Sequence Repeat="Repeat"/>

        <Aggregate Id="Wpt1">

            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat1"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon1"/></Setting>
                <Setting><Guidance:Waypoint.captureRadius/><Arg Name="CaptureRadius"/></Setting>
            </Guidance:Waypoint>

        </Aggregate>

        <Aggregate Id="Wpt2">

            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat2"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon2"/></Setting>
            </Guidance:Waypoint>

        </Aggregate>

        <Aggregate Id="Wpt3">

            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat3"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon3"/></Setting>
            </Guidance:Waypoint>

        </Aggregate>

        <Aggregate Id="Wpt4">

            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat4"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon4"/></Setting>
            </Guidance:Waypoint>

        </Aggregate>

        <Aggregate Id="Wpt5">

            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat5"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon5"/></Setting>
            </Guidance:Waypoint>

        </Aggregate>

        <Aggregate Id="Wpt6">

            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat6"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon6"/></Setting>
            </Guidance:Waypoint>

        </Aggregate>

        <Aggregate Id="Wpt7">

            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat7"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon7"/></Setting>
            </Guidance:Waypoint>

        </Aggregate>

    </Aggregate>

</Mission>


2022-04-25T21:34:45.112Z,1650922485.112 [CommandExec](IMPORTANT): Loaded ./Missions/Engineering/sci2_quickGPS.xml
2022-04-25T21:34:53.828Z,1650922493.828 [CommandExec](IMPORTANT): got command set sci2_quickGPS.NeedGPSTime 5 minute
2022-04-25T21:34:53.829Z,1650922493.829 [CommandExec](IMPORTANT): got command set sci2_quickGPS.Lat1 36.797 degree
2022-04-25T21:34:53.829Z,1650922493.829 [CommandExec](IMPORTANT): got command set sci2_quickGPS.Lon1 -121.9 degree
2022-04-25T21:34:53.830Z,1650922493.830 [CommandExec](IMPORTANT): got command set sci2_quickGPS.Speed 0.15 meter_per_second
2022-04-25T21:34:53.831Z,1650922493.831 [CommandExec](IMPORTANT): got command set sci2_quickGPS.MinOffshore 0.0000001 kilometer
2022-04-25T21:34:53.831Z,1650922493.831 [CommandExec](IMPORTANT): got command run
2022-04-25T21:34:53.883Z,1650922493.883 [CommandExec](IMPORTANT): Running 
2022-04-25T21:34:53.978Z,1650922493.978 [Default] Stopped
2022-04-25T21:34:53.978Z,1650922493.978 [Default](DEBUG): Aggregate::uninitialize Default
2022-04-25T21:34:53.978Z,1650922493.978 [Default:B.GoToSurface] Stopped
2022-04-25T21:34:53.978Z,1650922493.978 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-04-25T21:34:53.978Z,1650922493.978 [Default:CheckIn] Stopped
2022-04-25T21:34:53.978Z,1650922493.978 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-04-25T21:34:53.979Z,1650922493.979 [Default:CheckIn:C.Wait] Stopped
2022-04-25T21:34:53.979Z,1650922493.979 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-04-25T21:34:53.979Z,1650922493.979 [MissionManager](IMPORTANT): Started mission sci2_quickGPS
2022-04-25T21:34:53.979Z,1650922493.979 [sci2_quickGPS] Running Loop=1
2022-04-25T21:34:53.979Z,1650922493.979 [sci2_quickGPS](DEBUG): Aggregate::initialize sci2_quickGPS
2022-04-25T21:34:53.979Z,1650922493.979 [sci2_quickGPS:Science] Running Loop=1
2022-04-25T21:34:53.979Z,1650922493.979 [sci2_quickGPS:Science](DEBUG): Aggregate::initialize sci2_quickGPS:Science
2022-04-25T21:34:53.979Z,1650922493.979 [sci2_quickGPS:Science:A] Running Loop=1
2022-04-25T21:34:53.979Z,1650922493.979 [sci2_quickGPS:Science:B] Running Loop=1
2022-04-25T21:34:53.980Z,1650922493.980 [sci2_quickGPS:Science:C] Running Loop=1
2022-04-25T21:34:53.980Z,1650922493.980 [sci2_quickGPS:Science:D] Running Loop=1
2022-04-25T21:34:53.980Z,1650922493.980 [sci2_quickGPS:Science:E] Running Loop=1
2022-04-25T21:34:53.980Z,1650922493.980 [sci2_quickGPS:Science:F] Running Loop=1
2022-04-25T21:34:53.980Z,1650922493.980 [sci2_quickGPS:Science:Read_Oil] Running Loop=1
2022-04-25T21:34:53.980Z,1650922493.980 [sci2_quickGPS:Science:PeakDetectChl] Running Loop=1
2022-04-25T21:34:53.980Z,1650922493.980 [sci2_quickGPS:Science:PeakDetectChl](DEBUG): Aggregate::initialize sci2_quickGPS:Science:PeakDetectChl
2022-04-25T21:34:53.980Z,1650922493.980 [sci2_quickGPS:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2022-04-25T21:34:53.980Z,1650922493.980 [sci2_quickGPS:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-04-25T21:34:53.982Z,1650922493.982 [sci2_quickGPS:Science:HighestChlPeakReport] Running Loop=1
2022-04-25T21:34:53.982Z,1650922493.982 [sci2_quickGPS:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize sci2_quickGPS:Science:HighestChlPeakReport
2022-04-25T21:34:53.983Z,1650922493.983 [sci2_quickGPS:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2022-04-25T21:34:53.983Z,1650922493.983 [sci2_quickGPS:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2022-04-25T21:34:53.983Z,1650922493.983 [sci2_quickGPS:Science:PeakDetectNO3] Running Loop=1
2022-04-25T21:34:53.983Z,1650922493.983 [sci2_quickGPS:Science:PeakDetectNO3](DEBUG): Aggregate::initialize sci2_quickGPS:Science:PeakDetectNO3
2022-04-25T21:34:53.983Z,1650922493.983 [sci2_quickGPS:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2022-04-25T21:34:53.983Z,1650922493.983 [sci2_quickGPS:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-04-25T21:34:53.986Z,1650922493.986 [sci2_quickGPS:Science:PeakDetectOil] Running Loop=1
2022-04-25T21:34:53.986Z,1650922493.986 [sci2_quickGPS:Science:PeakDetectOil](DEBUG): Aggregate::initialize sci2_quickGPS:Science:PeakDetectOil
2022-04-25T21:34:53.986Z,1650922493.986 [sci2_quickGPS:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2022-04-25T21:34:53.987Z,1650922493.987 [sci2_quickGPS:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-04-25T21:34:53.988Z,1650922493.988 [sci2_quickGPS:Science:HighestOilPeakReport] Running Loop=1
2022-04-25T21:34:53.989Z,1650922493.989 [sci2_quickGPS:Science:HighestOilPeakReport](DEBUG): Aggregate::initialize sci2_quickGPS:Science:HighestOilPeakReport
2022-04-25T21:34:53.989Z,1650922493.989 [sci2_quickGPS:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Running Loop=1
2022-04-25T21:34:53.989Z,1650922493.989 [sci2_quickGPS:Science:HighestOilPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2022-04-25T21:34:53.989Z,1650922493.989 [sci2_quickGPS:Science:PeakDetectFDOM] Running Loop=1
2022-04-25T21:34:53.989Z,1650922493.989 [sci2_quickGPS:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize sci2_quickGPS:Science:PeakDetectFDOM
2022-04-25T21:34:53.990Z,1650922493.990 [sci2_quickGPS:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1
2022-04-25T21:34:53.990Z,1650922493.990 [sci2_quickGPS:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-04-25T21:34:53.992Z,1650922493.992 [sci2_quickGPS:Science:PeakDetectSalinity] Running Loop=1
2022-04-25T21:34:53.992Z,1650922493.992 [sci2_quickGPS:Science:PeakDetectSalinity](DEBUG): Aggregate::initialize sci2_quickGPS:Science:PeakDetectSalinity
2022-04-25T21:34:53.992Z,1650922493.992 [sci2_quickGPS:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Running Loop=1
2022-04-25T21:34:53.992Z,1650922493.992 [sci2_quickGPS:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-04-25T21:34:53.994Z,1650922493.994 [sci2_quickGPS:Science:HighestSaltPeakReport] Running Loop=1
2022-04-25T21:34:53.994Z,1650922493.994 [sci2_quickGPS:Science:HighestSaltPeakReport](DEBUG): Aggregate::initialize sci2_quickGPS:Science:HighestSaltPeakReport
2022-04-25T21:34:53.994Z,1650922493.994 [sci2_quickGPS:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Running Loop=1
2022-04-25T21:34:53.994Z,1650922493.994 [sci2_quickGPS:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2022-04-25T21:34:53.994Z,1650922493.994 [sci2_quickGPS:Science:OceanCurrent] Running Loop=1
2022-04-25T21:34:53.994Z,1650922493.994 [sci2_quickGPS:Science:OceanCurrent](DEBUG): Aggregate::initialize sci2_quickGPS:Science:OceanCurrent
2022-04-25T21:34:53.995Z,1650922493.995 [sci2_quickGPS:Science:OceanCurrent:A.] Running Loop=1
2022-04-25T21:34:53.995Z,1650922493.995 [sci2_quickGPS:Science:OceanCurrent:A.](INFO): Initializing CurrentEstimator.
2022-04-25T21:34:53.995Z,1650922493.995 [sci2_quickGPS:StandardEnvelopes] Running Loop=1
2022-04-25T21:34:53.995Z,1650922493.995 [sci2_quickGPS:StandardEnvelopes](DEBUG): Aggregate::initialize sci2_quickGPS:StandardEnvelopes
2022-04-25T21:34:53.995Z,1650922493.995 [sci2_quickGPS:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2022-04-25T21:34:53.995Z,1650922493.995 [sci2_quickGPS:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2022-04-25T21:34:53.995Z,1650922493.995 [sci2_quickGPS:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2022-04-25T21:34:53.995Z,1650922493.995 [sci2_quickGPS:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2022-04-25T21:34:53.996Z,1650922493.996 [sci2_quickGPS:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2022-04-25T21:34:53.996Z,1650922493.996 [sci2_quickGPS:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2022-04-25T21:34:53.996Z,1650922493.996 [sci2_quickGPS:J.Pitch] Running Loop=1
2022-04-25T21:34:53.996Z,1650922493.996 [sci2_quickGPS:J.Pitch](DEBUG): Initialize.
2022-04-25T21:34:53.996Z,1650922493.996 [sci2_quickGPS:K.Buoyancy] Running Loop=1
2022-04-25T21:34:53.996Z,1650922493.996 [sci2_quickGPS:K.Buoyancy](DEBUG): Initialize Buoyancy Component.
2022-04-25T21:34:53.996Z,1650922493.996 [sci2_quickGPS:L.SetSpeed] Running Loop=1
2022-04-25T21:34:53.996Z,1650922493.996 [sci2_quickGPS:L.SetSpeed](DEBUG): Initialize.
2022-04-25T21:34:53.997Z,1650922493.997 [sci2_quickGPS:M.DepthEnvelope] Running Loop=1
2022-04-25T21:34:53.997Z,1650922493.997 [sci2_quickGPS:M.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2022-04-25T21:34:54.025Z,1650922494.025 [sci2_quickGPS:N.AltitudeEnvelope] Running Loop=1
2022-04-25T21:34:54.025Z,1650922494.025 [sci2_quickGPS:N.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2022-04-25T21:34:54.025Z,1650922494.025 [sci2_quickGPS:P.YoYo] Running Loop=1
2022-04-25T21:34:54.025Z,1650922494.025 [sci2_quickGPS:P.YoYo](DEBUG): Initialize YoYoComponent.
2022-04-25T21:34:54.026Z,1650922494.026 [sci2_quickGPS:C] Running Loop=1
2022-04-25T21:34:54.027Z,1650922494.027 [sci2_quickGPS:P.YoYo] Running Loop=1
2022-04-25T21:34:54.027Z,1650922494.027 [sci2_quickGPS:N.AltitudeEnvelope] Running Loop=1
2022-04-25T21:34:54.028Z,1650922494.028 [sci2_quickGPS:M.DepthEnvelope] Running Loop=1
2022-04-25T21:34:54.029Z,1650922494.029 [sci2_quickGPS:L.SetSpeed] Running Loop=1
2022-04-25T21:34:54.029Z,1650922494.029 [sci2_quickGPS:K.Buoyancy] Running Loop=1
2022-04-25T21:34:54.030Z,1650922494.030 [sci2_quickGPS:J.Pitch] Running Loop=1
2022-04-25T21:34:54.030Z,1650922494.030 [sci2_quickGPS:StandardEnvelopes] Running Loop=1
2022-04-25T21:34:54.030Z,1650922494.030 [sci2_quickGPS:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2022-04-25T21:34:54.051Z,1650922494.051 [sci2_quickGPS:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2022-04-25T21:34:54.052Z,1650922494.052 [sci2_quickGPS:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2022-04-25T21:34:54.052Z,1650922494.052 [sci2_quickGPS:C] Stopped
2022-04-25T21:34:54.052Z,1650922494.052 [sci2_quickGPS:QuickFix] Running Loop=1
2022-04-25T21:34:54.052Z,1650922494.052 [sci2_quickGPS:QuickFix](DEBUG): Aggregate::initialize sci2_quickGPS:QuickFix
2022-04-25T21:34:54.053Z,1650922494.053 [sci2_quickGPS:QuickFix:A.GoToSurface] Running Loop=1
2022-04-25T21:34:54.053Z,1650922494.053 [sci2_quickGPS:QuickFix:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-04-25T21:34:54.053Z,1650922494.053 [sci2_quickGPS:QuickFix:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-04-25T21:34:54.053Z,1650922494.053 [sci2_quickGPS:QuickFix:A.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2022-04-25T21:34:54.054Z,1650922494.054 [sci2_quickGPS:QuickFix:A.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2022-04-25T21:34:54.054Z,1650922494.054 [sci2_quickGPS:QuickFix:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-04-25T21:34:54.054Z,1650922494.054 [sci2_quickGPS:QuickFix:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-04-25T21:34:54.055Z,1650922494.055 [sci2_quickGPS:Science] Running Loop=1
2022-04-25T21:34:54.056Z,1650922494.056 [sci2_quickGPS:Science:HighestSaltPeakReport] Stopped
2022-04-25T21:34:54.056Z,1650922494.056 [sci2_quickGPS:Science:HighestSaltPeakReport](DEBUG): Aggregate::uninitialize sci2_quickGPS:Science:HighestSaltPeakReport
2022-04-25T21:34:54.056Z,1650922494.056 [sci2_quickGPS:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Stopped
2022-04-25T21:34:54.056Z,1650922494.056 [sci2_quickGPS:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2022-04-25T21:34:54.056Z,1650922494.056 [sci2_quickGPS:Science:PeakDetectSalinity] Stopped
2022-04-25T21:34:54.056Z,1650922494.056 [sci2_quickGPS:Science:PeakDetectSalinity](DEBUG): Aggregate::uninitialize sci2_quickGPS:Science:PeakDetectSalinity
2022-04-25T21:34:54.056Z,1650922494.056 [sci2_quickGPS:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Stopped
2022-04-25T21:34:54.056Z,1650922494.056 [sci2_quickGPS:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-04-25T21:34:54.056Z,1650922494.056 [sci2_quickGPS:Science:PeakDetectFDOM] Stopped
2022-04-25T21:34:54.056Z,1650922494.056 [sci2_quickGPS:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize sci2_quickGPS:Science:PeakDetectFDOM
2022-04-25T21:34:54.057Z,1650922494.057 [sci2_quickGPS:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped
2022-04-25T21:34:54.057Z,1650922494.057 [sci2_quickGPS:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-04-25T21:34:54.057Z,1650922494.057 [sci2_quickGPS:Science:HighestOilPeakReport] Stopped
2022-04-25T21:34:54.057Z,1650922494.057 [sci2_quickGPS:Science:HighestOilPeakReport](DEBUG): Aggregate::uninitialize sci2_quickGPS:Science:HighestOilPeakReport
2022-04-25T21:34:54.057Z,1650922494.057 [sci2_quickGPS:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Stopped
2022-04-25T21:34:54.057Z,1650922494.057 [sci2_quickGPS:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2022-04-25T21:34:54.057Z,1650922494.057 [sci2_quickGPS:Science:PeakDetectOil] Stopped
2022-04-25T21:34:54.057Z,1650922494.057 [sci2_quickGPS:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize sci2_quickGPS:Science:PeakDetectOil
2022-04-25T21:34:54.057Z,1650922494.057 [sci2_quickGPS:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2022-04-25T21:34:54.057Z,1650922494.057 [sci2_quickGPS:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-04-25T21:34:54.057Z,1650922494.057 [sci2_quickGPS:Science:PeakDetectNO3] Stopped
2022-04-25T21:34:54.058Z,1650922494.058 [sci2_quickGPS:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize sci2_quickGPS:Science:PeakDetectNO3
2022-04-25T21:34:54.058Z,1650922494.058 [sci2_quickGPS:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2022-04-25T21:34:54.058Z,1650922494.058 [sci2_quickGPS:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-04-25T21:34:54.058Z,1650922494.058 [sci2_quickGPS:Science:HighestChlPeakReport] Stopped
2022-04-25T21:34:54.058Z,1650922494.058 [sci2_quickGPS:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize sci2_quickGPS:Science:HighestChlPeakReport
2022-04-25T21:34:54.058Z,1650922494.058 [sci2_quickGPS:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2022-04-25T21:34:54.058Z,1650922494.058 [sci2_quickGPS:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2022-04-25T21:34:54.058Z,1650922494.058 [sci2_quickGPS:Science:PeakDetectChl] Running Loop=1
2022-04-25T21:34:54.058Z,1650922494.058 [sci2_quickGPS:Science:OceanCurrent:A.] Running Loop=1
2022-04-25T21:34:54.059Z,1650922494.059 [sci2_quickGPS:Science:Read_Oil] Stopped
2022-04-25T21:34:54.059Z,1650922494.059 [sci2_quickGPS:Science:F] Stopped
2022-04-25T21:34:54.059Z,1650922494.059 [sci2_quickGPS:Science:E] Running Loop=1
2022-04-25T21:34:54.059Z,1650922494.059 [sci2_quickGPS:Science:E](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2022-04-25T21:34:54.060Z,1650922494.060 [sci2_quickGPS:Science:D] Stopped
2022-04-25T21:34:54.060Z,1650922494.060 [sci2_quickGPS:Science:C] Stopped
2022-04-25T21:34:54.060Z,1650922494.060 [sci2_quickGPS:Science:B] Stopped
2022-04-25T21:34:54.060Z,1650922494.060 [sci2_quickGPS:Science:A] Stopped
2022-04-25T21:34:54.377Z,1650922494.377 [WetLabsBB2FL](INFO): Powering up
2022-04-25T21:34:54.432Z,1650922494.432 [sci2_quickGPS:QuickFix:GetFix] Running Loop=1
2022-04-25T21:34:54.433Z,1650922494.433 [sci2_quickGPS:QuickFix:GetFix](DEBUG): Aggregate::initialize sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:34:54.437Z,1650922494.437 [sci2_quickGPS:QuickFix:GetFix:A] Running Loop=1
2022-04-25T21:34:54.825Z,1650922494.825 [sci2_quickGPS:QuickFix:GetFix:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2022-04-25T21:34:55.593Z,1650922495.593 [sci2_quickGPS:N.AltitudeEnvelope](ERROR): Altitude Measurement is not Active.
2022-04-25T21:34:55.603Z,1650922495.603 [sci2_quickGPS:StandardEnvelopes:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active.
2022-04-25T21:35:14.168Z,1650922514.168 [NAL9602](INFO): SBD MO Status=2, MOMSN=7648, MT Status=2, MTMSN=0
2022-04-25T21:35:14.168Z,1650922514.168 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-25T21:35:24.706Z,1650922524.706 [sci2_quickGPS:QuickFix:GetFix:A](INFO): Timed out from 2022-04-25T21:34:54.4Z
2022-04-25T21:35:24.706Z,1650922524.706 [sci2_quickGPS:QuickFix:GetFix:A] Stopped
2022-04-25T21:35:24.706Z,1650922524.706 [sci2_quickGPS:QuickFix:GetFix](INFO): Completed sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:35:24.706Z,1650922524.706 [sci2_quickGPS:QuickFix:GetFix] Stopped
2022-04-25T21:35:24.706Z,1650922524.706 [sci2_quickGPS:QuickFix:GetFix](DEBUG): Aggregate::uninitialize sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:35:24.707Z,1650922524.707 [sci2_quickGPS:QuickFix:GetFix](INFO): Running loop #2
2022-04-25T21:35:24.707Z,1650922524.707 [sci2_quickGPS:QuickFix:GetFix] Running Loop=2
2022-04-25T21:35:24.707Z,1650922524.707 [sci2_quickGPS:QuickFix:GetFix](DEBUG): Aggregate::initialize sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:35:24.707Z,1650922524.707 [sci2_quickGPS:QuickFix:GetFix:A] Running Loop=1
2022-04-25T21:35:55.006Z,1650922555.006 [sci2_quickGPS:QuickFix:GetFix:A](INFO): Timed out from 2022-04-25T21:35:24.7Z
2022-04-25T21:35:55.006Z,1650922555.006 [sci2_quickGPS:QuickFix:GetFix:A] Stopped
2022-04-25T21:35:55.006Z,1650922555.006 [sci2_quickGPS:QuickFix:GetFix](INFO): Completed sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:35:55.006Z,1650922555.006 [sci2_quickGPS:QuickFix:GetFix] Stopped
2022-04-25T21:35:55.007Z,1650922555.007 [sci2_quickGPS:QuickFix:GetFix](DEBUG): Aggregate::uninitialize sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:35:55.007Z,1650922555.007 [sci2_quickGPS:QuickFix](INFO): Completed sci2_quickGPS:QuickFix
2022-04-25T21:35:55.007Z,1650922555.007 [sci2_quickGPS:QuickFix] Stopped
2022-04-25T21:35:55.008Z,1650922555.008 [sci2_quickGPS:QuickFix](DEBUG): Aggregate::uninitialize sci2_quickGPS:QuickFix
2022-04-25T21:35:55.008Z,1650922555.008 [sci2_quickGPS:QuickFix:A.GoToSurface] Stopped
2022-04-25T21:35:55.008Z,1650922555.008 [sci2_quickGPS:QuickFix:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-04-25T21:35:55.008Z,1650922555.008 [sci2_quickGPS:F] Running Loop=1
2022-04-25T21:35:55.395Z,1650922555.395 [sci2_quickGPS:F] Stopped
2022-04-25T21:35:55.395Z,1650922555.395 [sci2_quickGPS:G] Running Loop=1
2022-04-25T21:35:55.799Z,1650922555.799 [sci2_quickGPS:G] Stopped
2022-04-25T21:35:55.799Z,1650922555.799 [sci2_quickGPS:H] Running Loop=1
2022-04-25T21:35:56.222Z,1650922556.222 [sci2_quickGPS:H] Stopped
2022-04-25T21:35:56.222Z,1650922556.222 [sci2_quickGPS:StartingMission] Running Loop=1
2022-04-25T21:35:56.222Z,1650922556.222 [sci2_quickGPS:StartingMission](DEBUG): Aggregate::initialize sci2_quickGPS:StartingMission
2022-04-25T21:35:56.624Z,1650922556.624 [sci2_quickGPS:NeedComms] Running Loop=1
2022-04-25T21:35:56.624Z,1650922556.624 [sci2_quickGPS:NeedComms](DEBUG): Aggregate::initialize sci2_quickGPS:NeedComms
2022-04-25T21:35:56.624Z,1650922556.624 [sci2_quickGPS:NeedComms:B.GoToSurface] Running Loop=1
2022-04-25T21:35:56.624Z,1650922556.624 [sci2_quickGPS:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-04-25T21:35:56.624Z,1650922556.624 [sci2_quickGPS:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2022-04-25T21:35:56.625Z,1650922556.625 [sci2_quickGPS:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2022-04-25T21:35:56.625Z,1650922556.625 [sci2_quickGPS:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2022-04-25T21:35:56.626Z,1650922556.626 [sci2_quickGPS:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-04-25T21:35:56.626Z,1650922556.626 [sci2_quickGPS:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-04-25T21:35:56.626Z,1650922556.626 [sci2_quickGPS:NeedComms:A] Running Loop=1
2022-04-25T21:35:56.627Z,1650922556.627 [sci2_quickGPS:NeedComms:A](INFO): last time_fix was: 1650922284.000000 second since 1970/01/01T00:00:00Z 
2022-04-25T21:35:56.627Z,1650922556.627 [sci2_quickGPS:NeedComms:A] Stopped
2022-04-25T21:35:57.014Z,1650922557.014 [sci2_quickGPS:NeedComms:C] Running Loop=1
2022-04-25T21:35:57.429Z,1650922557.429 [sci2_quickGPS:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix
2022-04-25T21:36:24.487Z,1650922584.487 [sci2_quickGPS:NeedGPS] Running Loop=1
2022-04-25T21:36:24.487Z,1650922584.487 [sci2_quickGPS:NeedGPS](DEBUG): Aggregate::initialize sci2_quickGPS:NeedGPS
2022-04-25T21:36:24.488Z,1650922584.488 [sci2_quickGPS:NeedGPS:A] Running Loop=1
2022-04-25T21:36:24.489Z,1650922584.489 [sci2_quickGPS:NeedGPS:A](INFO): Quick GPS - last time_fix was: 1650922284.000000 second since 1970/01/01T00:00:00Z 
2022-04-25T21:36:24.489Z,1650922584.489 [sci2_quickGPS:NeedGPS:A] Stopped
2022-04-25T21:36:24.493Z,1650922584.493 [sci2_quickGPS:NeedGPS:NeedGPS] Running Loop=1
2022-04-25T21:36:24.494Z,1650922584.494 [sci2_quickGPS:NeedGPS:NeedGPS](DEBUG): Aggregate::initialize sci2_quickGPS:NeedGPS:NeedGPS
2022-04-25T21:36:24.868Z,1650922584.868 [NAL9602](INFO): SBD MO Status=0, MOMSN=7648, MT Status=0, MTMSN=0
2022-04-25T21:36:24.868Z,1650922584.868 [NAL9602](INFO): No messages in MT queue
2022-04-25T21:36:24.918Z,1650922584.918 [sci2_quickGPS:QuickFix] Running Loop=1
2022-04-25T21:36:24.918Z,1650922584.918 [sci2_quickGPS:QuickFix](DEBUG): Aggregate::initialize sci2_quickGPS:QuickFix
2022-04-25T21:36:24.918Z,1650922584.918 [sci2_quickGPS:QuickFix:A.GoToSurface] Running Loop=1
2022-04-25T21:36:24.918Z,1650922584.918 [sci2_quickGPS:QuickFix:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-04-25T21:36:24.918Z,1650922584.918 [sci2_quickGPS:QuickFix:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-04-25T21:36:24.919Z,1650922584.919 [sci2_quickGPS:QuickFix:A.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2022-04-25T21:36:24.919Z,1650922584.919 [sci2_quickGPS:QuickFix:A.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2022-04-25T21:36:24.919Z,1650922584.919 [sci2_quickGPS:QuickFix:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-04-25T21:36:24.920Z,1650922584.920 [sci2_quickGPS:QuickFix:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-04-25T21:36:24.920Z,1650922584.920 [sci2_quickGPS:QuickFix:GetFix] Running Loop=1
2022-04-25T21:36:24.921Z,1650922584.921 [sci2_quickGPS:QuickFix:GetFix](DEBUG): Aggregate::initialize sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:36:24.921Z,1650922584.921 [sci2_quickGPS:QuickFix:GetFix:A] Running Loop=1
2022-04-25T21:36:26.088Z,1650922586.088 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213625.00,A,3648.17165,N,12147.27809,W,0.233,144.46,250422,,,A*77
2022-04-25T21:36:26.091Z,1650922586.091 [NAL9602](INFO): GPS fix at 20220425T213625: (36.802861, -121.787968)
2022-04-25T21:36:26.167Z,1650922586.167 [sci2_quickGPS:QuickFix:GetFix:A] Stopped
2022-04-25T21:36:26.167Z,1650922586.167 [sci2_quickGPS:QuickFix:GetFix](INFO): Completed sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:36:26.167Z,1650922586.167 [sci2_quickGPS:QuickFix:GetFix] Stopped
2022-04-25T21:36:26.167Z,1650922586.167 [sci2_quickGPS:QuickFix:GetFix](DEBUG): Aggregate::uninitialize sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:36:26.167Z,1650922586.167 [sci2_quickGPS:QuickFix:GetFix](INFO): Running loop #2
2022-04-25T21:36:26.168Z,1650922586.168 [sci2_quickGPS:QuickFix:GetFix] Running Loop=2
2022-04-25T21:36:26.168Z,1650922586.168 [sci2_quickGPS:QuickFix:GetFix](DEBUG): Aggregate::initialize sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:36:26.168Z,1650922586.168 [sci2_quickGPS:QuickFix:GetFix:A] Running Loop=1
2022-04-25T21:36:26.169Z,1650922586.169 [sci2_quickGPS:NeedComms:C] Stopped
2022-04-25T21:36:26.177Z,1650922586.177 [sci2_quickGPS:NeedComms:D] Running Loop=1
2022-04-25T21:36:26.524Z,1650922586.524 [sci2_quickGPS:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-04-25T21:36:28.496Z,1650922588.496 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220425T203431/Courier0034.lzma
2022-04-25T21:36:28.657Z,1650922588.657 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213628.00,A,3648.17189,N,12147.27796,W,0.175,144.46,250422,,,A*70
2022-04-25T21:36:28.659Z,1650922588.659 [NAL9602](INFO): GPS fix at 20220425T213628: (36.802865, -121.787966)
2022-04-25T21:36:28.676Z,1650922588.676 [sci2_quickGPS:QuickFix:GetFix:A] Stopped
2022-04-25T21:36:28.676Z,1650922588.676 [sci2_quickGPS:QuickFix:GetFix](INFO): Completed sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:36:28.677Z,1650922588.677 [sci2_quickGPS:QuickFix:GetFix] Stopped
2022-04-25T21:36:28.677Z,1650922588.677 [sci2_quickGPS:QuickFix:GetFix](DEBUG): Aggregate::uninitialize sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:36:28.678Z,1650922588.678 [sci2_quickGPS:QuickFix](INFO): Completed sci2_quickGPS:QuickFix
2022-04-25T21:36:28.678Z,1650922588.678 [sci2_quickGPS:QuickFix] Stopped
2022-04-25T21:36:28.678Z,1650922588.678 [sci2_quickGPS:QuickFix](DEBUG): Aggregate::uninitialize sci2_quickGPS:QuickFix
2022-04-25T21:36:28.678Z,1650922588.678 [sci2_quickGPS:QuickFix:A.GoToSurface] Stopped
2022-04-25T21:36:28.678Z,1650922588.678 [sci2_quickGPS:QuickFix:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-04-25T21:36:29.101Z,1650922589.101 [sci2_quickGPS:NeedGPS:NeedGPS](INFO): Completed sci2_quickGPS:NeedGPS:NeedGPS
2022-04-25T21:36:29.101Z,1650922589.101 [sci2_quickGPS:NeedGPS:NeedGPS] Stopped
2022-04-25T21:36:29.101Z,1650922589.101 [sci2_quickGPS:NeedGPS:NeedGPS](DEBUG): Aggregate::uninitialize sci2_quickGPS:NeedGPS:NeedGPS
2022-04-25T21:36:29.101Z,1650922589.101 [sci2_quickGPS:NeedGPS](INFO): Completed sci2_quickGPS:NeedGPS
2022-04-25T21:36:29.101Z,1650922589.101 [sci2_quickGPS:NeedGPS] Stopped
2022-04-25T21:36:29.101Z,1650922589.101 [sci2_quickGPS:NeedGPS](DEBUG): Aggregate::uninitialize sci2_quickGPS:NeedGPS
2022-04-25T21:36:29.503Z,1650922589.503 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Courier0034.lzma.bak
2022-04-25T21:36:29.503Z,1650922589.503 [DataOverHttps](INFO): SBD MOMSN=16661134
2022-04-25T21:36:47.286Z,1650922607.286 [DataOverHttps](INFO): Sending 587 bytes from file Logs/20220425T203431/Express0035.lzma
2022-04-25T21:36:48.287Z,1650922608.287 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Express0035.lzma.bak
2022-04-25T21:36:48.287Z,1650922608.287 [DataOverHttps](INFO): SBD MOMSN=16661137
2022-04-25T21:37:00.976Z,1650922620.976 [NAL9602](INFO): Not Powering down - fast GPS
2022-04-25T21:37:09.864Z,1650922629.864 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220425T203431/Express0038.lzma
2022-04-25T21:37:10.867Z,1650922630.867 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Express0038.lzma.bak
2022-04-25T21:37:10.867Z,1650922630.867 [DataOverHttps](INFO): SBD MOMSN=16661152
2022-04-25T21:37:15.217Z,1650922635.217 [sci2_quickGPS:NeedComms:D] Stopped
2022-04-25T21:37:15.225Z,1650922635.225 [sci2_quickGPS:NeedComms:E] Running Loop=1
2022-04-25T21:37:15.657Z,1650922635.657 [sci2_quickGPS:NeedComms:E](DEBUG): Initialize ReadDataComponent to sense time_fix
2022-04-25T21:37:17.208Z,1650922637.208 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213716.00,A,3648.17062,N,12147.27959,W,0.194,144.46,250422,,,A*7A
2022-04-25T21:37:17.211Z,1650922637.211 [NAL9602](INFO): GPS fix at 20220425T213716: (36.802844, -121.787993)
2022-04-25T21:37:17.251Z,1650922637.251 [sci2_quickGPS:NeedComms:E] Stopped
2022-04-25T21:37:17.252Z,1650922637.252 [sci2_quickGPS:NeedComms](INFO): Completed sci2_quickGPS:NeedComms
2022-04-25T21:37:17.252Z,1650922637.252 [sci2_quickGPS:NeedComms] Stopped
2022-04-25T21:37:17.252Z,1650922637.252 [sci2_quickGPS:NeedComms](DEBUG): Aggregate::uninitialize sci2_quickGPS:NeedComms
2022-04-25T21:37:17.252Z,1650922637.252 [sci2_quickGPS:NeedComms:B.GoToSurface] Stopped
2022-04-25T21:37:17.252Z,1650922637.252 [sci2_quickGPS:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-04-25T21:37:17.657Z,1650922637.657 [sci2_quickGPS:StartingMission](INFO): Completed sci2_quickGPS:StartingMission
2022-04-25T21:37:17.657Z,1650922637.657 [sci2_quickGPS:StartingMission] Stopped
2022-04-25T21:37:17.658Z,1650922637.658 [sci2_quickGPS:StartingMission](DEBUG): Aggregate::uninitialize sci2_quickGPS:StartingMission
2022-04-25T21:37:17.658Z,1650922637.658 [sci2_quickGPS:Lap] Running Loop=1
2022-04-25T21:37:17.658Z,1650922637.658 [sci2_quickGPS:Lap](DEBUG): Aggregate::initialize sci2_quickGPS:Lap
2022-04-25T21:37:17.658Z,1650922637.658 [sci2_quickGPS:Lap:Wpt1] Running Loop=1
2022-04-25T21:37:17.658Z,1650922637.658 [sci2_quickGPS:Lap:Wpt1](DEBUG): Aggregate::initialize sci2_quickGPS:Lap:Wpt1
2022-04-25T21:37:17.658Z,1650922637.658 [sci2_quickGPS:Lap:Wpt1:A.Waypoint] Running Loop=1
2022-04-25T21:37:17.658Z,1650922637.658 [sci2_quickGPS:Lap:Wpt1:A.Waypoint](DEBUG): Initialize WaypointComponent.
2022-04-25T21:37:38.209Z,1650922658.209 [NAL9602](INFO): SBD MO Status=2, MOMSN=7649, MT Status=2, MTMSN=0
2022-04-25T21:37:38.210Z,1650922658.210 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-25T21:38:10.462Z,1650922690.462 [CommandExec](IMPORTANT): got command report mod VerticalControl.verticalMode
2022-04-25T21:38:10.722Z,1650922690.722 [Reporter](INFO): VerticalControl.verticalMode 5 enum
2022-04-25T21:38:16.035Z,1650922696.035 [CommandExec](IMPORTANT): got command report mod SpeedControl.speedCmd
2022-04-25T21:38:16.367Z,1650922696.367 [Reporter](INFO): SpeedControl.speedCmd 0.150000 m/s
2022-04-25T21:38:27.197Z,1650922707.197 [CommandExec](IMPORTANT): got command maintain sensor Depth_Keller.depth 5 meter
2022-04-25T21:38:27.207Z,1650922707.207 [ComponentRegistry](DEBUG): SyncComponent "Maintain_Depth_Keller.depth" handled in the control thread.
2022-04-25T21:38:27.307Z,1650922707.307 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,PAR_Licor,Depth_Keller,PAR_Licor,Maintain_AHRS_M2.platform_pitch_angle,Maintain_Depth_Keller.depth,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,VerticalHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2022-04-25T21:38:27.530Z,1650922707.530 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 0.15 m/s, pitch -20.00 deg, mass-position 8.11 mm (1 active estimators).
2022-04-25T21:38:49.646Z,1650922729.646 [CommandExec](IMPORTANT): got command maintain sensor Depth_Keller.depth 0 meter
2022-04-25T21:39:27.696Z,1650922767.696 [NAL9602](INFO): SBD MO Status=2, MOMSN=7649, MT Status=2, MTMSN=0
2022-04-25T21:39:27.696Z,1650922767.696 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-25T21:41:13.943Z,1650922873.943 [RudderServo](FAULT): Rudder uart error: serial timeout
2022-04-25T21:41:13.943Z,1650922873.943 [RudderServo] Communications Fault, FailCount= 1
2022-04-25T21:41:13.943Z,1650922873.943 [RudderServo](ERROR): Communications Fault
2022-04-25T21:41:14.026Z,1650922874.026 [CBIT](ERROR): Communications Fault in component: RudderServo
2022-04-25T21:41:14.108Z,1650922874.108 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-04-25T21:41:14.109Z,1650922874.109 [RudderServo](INFO): Powering down
2022-04-25T21:41:14.898Z,1650922874.898 [RudderServo](DEBUG): Initializing EZServoServo.
2022-04-25T21:41:15.024Z,1650922875.024 [RudderServo](DEBUG): Initializing RudderServo.
2022-04-25T21:41:15.102Z,1650922875.102 [CBIT](INFO): Clearing failed state for component RudderServo
2022-04-25T21:41:15.102Z,1650922875.102 [RudderServo] No Fault, FailCount= 1
2022-04-25T21:42:06.000Z,1650922927.000 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-04-25T21:42:17.489Z,1650922937.489 [sci2_quickGPS:NeedGPS] Running Loop=1
2022-04-25T21:42:17.490Z,1650922937.490 [sci2_quickGPS:NeedGPS](DEBUG): Aggregate::initialize sci2_quickGPS:NeedGPS
2022-04-25T21:42:17.490Z,1650922937.490 [sci2_quickGPS:NeedGPS:A] Running Loop=1
2022-04-25T21:42:17.490Z,1650922937.490 [sci2_quickGPS:NeedGPS:A](INFO): Quick GPS - last time_fix was: 1650922636.000000 second since 1970/01/01T00:00:00Z 
2022-04-25T21:42:17.491Z,1650922937.491 [sci2_quickGPS:NeedGPS:A] Stopped
2022-04-25T21:42:17.491Z,1650922937.491 [sci2_quickGPS:NeedGPS:NeedGPS] Running Loop=1
2022-04-25T21:42:17.491Z,1650922937.491 [sci2_quickGPS:NeedGPS:NeedGPS](DEBUG): Aggregate::initialize sci2_quickGPS:NeedGPS:NeedGPS
2022-04-25T21:42:17.889Z,1650922937.889 [sci2_quickGPS:QuickFix] Running Loop=1
2022-04-25T21:42:17.890Z,1650922937.889 [sci2_quickGPS:QuickFix](DEBUG): Aggregate::initialize sci2_quickGPS:QuickFix
2022-04-25T21:42:17.890Z,1650922937.890 [sci2_quickGPS:QuickFix:A.GoToSurface] Running Loop=1
2022-04-25T21:42:17.890Z,1650922937.890 [sci2_quickGPS:QuickFix:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-04-25T21:42:17.890Z,1650922937.890 [sci2_quickGPS:QuickFix:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-04-25T21:42:17.907Z,1650922937.907 [sci2_quickGPS:QuickFix:A.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2022-04-25T21:42:17.907Z,1650922937.907 [sci2_quickGPS:QuickFix:A.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2022-04-25T21:42:17.907Z,1650922937.907 [sci2_quickGPS:QuickFix:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-04-25T21:42:17.908Z,1650922937.908 [sci2_quickGPS:QuickFix:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-04-25T21:42:17.909Z,1650922937.909 [sci2_quickGPS:QuickFix:GetFix] Running Loop=1
2022-04-25T21:42:17.909Z,1650922937.909 [sci2_quickGPS:QuickFix:GetFix](DEBUG): Aggregate::initialize sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:42:17.909Z,1650922937.909 [sci2_quickGPS:QuickFix:GetFix:A] Running Loop=1
2022-04-25T21:42:18.062Z,1650922938.062 [Reporter](INFO): VerticalControl.verticalMode 8 enum
2022-04-25T21:42:18.063Z,1650922938.063 [Reporter](INFO): SpeedControl.speedCmd 0.000000 m/s
2022-04-25T21:42:19.902Z,1650922939.902 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-04-25T21:42:19.904Z,1650922939.904 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-04-25T21:42:24.746Z,1650922944.746 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214224.00,A,3648.16817,N,12147.28090,W,0.058,141.58,250422,,,A*7A
2022-04-25T21:42:24.749Z,1650922944.749 [NAL9602](INFO): GPS fix at 20220425T214224: (36.802803, -121.788015)
2022-04-25T21:42:24.764Z,1650922944.764 [sci2_quickGPS:QuickFix:GetFix:A] Stopped
2022-04-25T21:42:24.764Z,1650922944.764 [sci2_quickGPS:QuickFix:GetFix](INFO): Completed sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:42:24.764Z,1650922944.764 [sci2_quickGPS:QuickFix:GetFix] Stopped
2022-04-25T21:42:24.765Z,1650922944.765 [sci2_quickGPS:QuickFix:GetFix](DEBUG): Aggregate::uninitialize sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:42:24.765Z,1650922944.765 [sci2_quickGPS:QuickFix:GetFix](INFO): Running loop #2
2022-04-25T21:42:24.765Z,1650922944.765 [sci2_quickGPS:QuickFix:GetFix] Running Loop=2
2022-04-25T21:42:24.765Z,1650922944.765 [sci2_quickGPS:QuickFix:GetFix](DEBUG): Aggregate::initialize sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:42:24.765Z,1650922944.765 [sci2_quickGPS:QuickFix:GetFix:A] Running Loop=1
2022-04-25T21:42:27.976Z,1650922947.976 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214227.00,A,3648.16862,N,12147.28009,W,0.369,141.58,250422,,,A*7A
2022-04-25T21:42:27.978Z,1650922947.978 [NAL9602](INFO): GPS fix at 20220425T214227: (36.802810, -121.788002)
2022-04-25T21:42:27.994Z,1650922947.994 [sci2_quickGPS:QuickFix:GetFix:A] Stopped
2022-04-25T21:42:27.994Z,1650922947.994 [sci2_quickGPS:QuickFix:GetFix](INFO): Completed sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:42:27.995Z,1650922947.995 [sci2_quickGPS:QuickFix:GetFix] Stopped
2022-04-25T21:42:27.995Z,1650922947.995 [sci2_quickGPS:QuickFix:GetFix](DEBUG): Aggregate::uninitialize sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:42:27.995Z,1650922947.995 [sci2_quickGPS:QuickFix](INFO): Completed sci2_quickGPS:QuickFix
2022-04-25T21:42:27.996Z,1650922947.996 [sci2_quickGPS:QuickFix] Stopped
2022-04-25T21:42:27.996Z,1650922947.996 [sci2_quickGPS:QuickFix](DEBUG): Aggregate::uninitialize sci2_quickGPS:QuickFix
2022-04-25T21:42:27.996Z,1650922947.996 [sci2_quickGPS:QuickFix:A.GoToSurface] Stopped
2022-04-25T21:42:27.996Z,1650922947.996 [sci2_quickGPS:QuickFix:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-04-25T21:42:28.413Z,1650922948.413 [sci2_quickGPS:NeedGPS:NeedGPS](INFO): Completed sci2_quickGPS:NeedGPS:NeedGPS
2022-04-25T21:42:28.413Z,1650922948.413 [sci2_quickGPS:NeedGPS:NeedGPS] Stopped
2022-04-25T21:42:28.414Z,1650922948.414 [sci2_quickGPS:NeedGPS:NeedGPS](DEBUG): Aggregate::uninitialize sci2_quickGPS:NeedGPS:NeedGPS
2022-04-25T21:42:28.414Z,1650922948.414 [sci2_quickGPS:NeedGPS](INFO): Completed sci2_quickGPS:NeedGPS
2022-04-25T21:42:28.414Z,1650922948.414 [sci2_quickGPS:NeedGPS] Stopped
2022-04-25T21:42:28.414Z,1650922948.414 [sci2_quickGPS:NeedGPS](DEBUG): Aggregate::uninitialize sci2_quickGPS:NeedGPS
2022-04-25T21:42:28.590Z,1650922948.590 [Reporter](INFO): VerticalControl.verticalMode 3 enum
2022-04-25T21:42:28.591Z,1650922948.591 [Reporter](INFO): SpeedControl.speedCmd 0.150000 m/s
2022-04-25T21:42:28.968Z,1650922948.968 [Reporter](INFO): VerticalControl.verticalMode 5 enum
2022-04-25T21:42:33.265Z,1650922953.265 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-04-25T21:42:34.231Z,1650922954.231 [ThrusterHE](ERROR): Zero Speed Commanded.
2022-04-25T21:42:46.996Z,1650922966.996 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-04-25T21:43:00.308Z,1650922980.308 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-04-25T21:43:00.315Z,1650922980.315 [NAL9602](INFO): Not Powering down - fast GPS
2022-04-25T21:43:14.053Z,1650922994.053 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-04-25T21:43:27.373Z,1650923007.373 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-04-25T21:43:40.706Z,1650923020.706 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-04-25T21:43:54.093Z,1650923034.093 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-04-25T21:44:07.830Z,1650923047.830 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-04-25T21:44:21.167Z,1650923061.167 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2022-04-25T21:44:34.436Z,1650923074.436 [BPC1](INFO): Calculating totals. Valid battery stick count: 33. Valid reserve battery stick count: 4.
2022-04-25T21:44:34.439Z,1650923074.439 [BPC1](INFO): Received data from all battery sticks.
2022-04-25T21:47:28.235Z,1650923248.235 [sci2_quickGPS:NeedGPS] Running Loop=1
2022-04-25T21:47:28.235Z,1650923248.235 [sci2_quickGPS:NeedGPS](DEBUG): Aggregate::initialize sci2_quickGPS:NeedGPS
2022-04-25T21:47:28.236Z,1650923248.236 [sci2_quickGPS:NeedGPS:A] Running Loop=1
2022-04-25T21:47:28.236Z,1650923248.236 [sci2_quickGPS:NeedGPS:A](INFO): Quick GPS - last time_fix was: 1650922947.000000 second since 1970/01/01T00:00:00Z 
2022-04-25T21:47:28.236Z,1650923248.236 [sci2_quickGPS:NeedGPS:A] Stopped
2022-04-25T21:47:28.237Z,1650923248.237 [sci2_quickGPS:NeedGPS:NeedGPS] Running Loop=1
2022-04-25T21:47:28.237Z,1650923248.237 [sci2_quickGPS:NeedGPS:NeedGPS](DEBUG): Aggregate::initialize sci2_quickGPS:NeedGPS:NeedGPS
2022-04-25T21:47:28.630Z,1650923248.630 [sci2_quickGPS:QuickFix] Running Loop=1
2022-04-25T21:47:28.630Z,1650923248.630 [sci2_quickGPS:QuickFix](DEBUG): Aggregate::initialize sci2_quickGPS:QuickFix
2022-04-25T21:47:28.630Z,1650923248.630 [sci2_quickGPS:QuickFix:A.GoToSurface] Running Loop=1
2022-04-25T21:47:28.630Z,1650923248.630 [sci2_quickGPS:QuickFix:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-04-25T21:47:28.631Z,1650923248.631 [sci2_quickGPS:QuickFix:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-04-25T21:47:28.631Z,1650923248.631 [sci2_quickGPS:QuickFix:A.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2022-04-25T21:47:28.631Z,1650923248.631 [sci2_quickGPS:QuickFix:A.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2022-04-25T21:47:28.632Z,1650923248.632 [sci2_quickGPS:QuickFix:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-04-25T21:47:28.632Z,1650923248.632 [sci2_quickGPS:QuickFix:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-04-25T21:47:28.633Z,1650923248.633 [sci2_quickGPS:QuickFix:GetFix] Running Loop=1
2022-04-25T21:47:28.633Z,1650923248.633 [sci2_quickGPS:QuickFix:GetFix](DEBUG): Aggregate::initialize sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:47:28.633Z,1650923248.633 [sci2_quickGPS:QuickFix:GetFix:A] Running Loop=1
2022-04-25T21:47:28.663Z,1650923248.663 [Reporter](INFO): VerticalControl.verticalMode 8 enum
2022-04-25T21:47:28.664Z,1650923248.664 [Reporter](INFO): SpeedControl.speedCmd 0.000000 m/s
2022-04-25T21:47:30.641Z,1650923250.641 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214730.00,A,3648.17174,N,12147.27841,W,0.078,141.58,250422,,,A*7E
2022-04-25T21:47:30.644Z,1650923250.644 [NAL9602](INFO): GPS fix at 20220425T214730: (36.802862, -121.787974)
2022-04-25T21:47:30.680Z,1650923250.680 [sci2_quickGPS:QuickFix:GetFix:A] Stopped
2022-04-25T21:47:30.680Z,1650923250.680 [sci2_quickGPS:QuickFix:GetFix](INFO): Completed sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:47:30.681Z,1650923250.681 [sci2_quickGPS:QuickFix:GetFix] Stopped
2022-04-25T21:47:30.681Z,1650923250.681 [sci2_quickGPS:QuickFix:GetFix](DEBUG): Aggregate::uninitialize sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:47:30.681Z,1650923250.681 [sci2_quickGPS:QuickFix:GetFix](INFO): Running loop #2
2022-04-25T21:47:30.681Z,1650923250.681 [sci2_quickGPS:QuickFix:GetFix] Running Loop=2
2022-04-25T21:47:30.681Z,1650923250.681 [sci2_quickGPS:QuickFix:GetFix](DEBUG): Aggregate::initialize sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:47:30.681Z,1650923250.681 [sci2_quickGPS:QuickFix:GetFix:A] Running Loop=1
2022-04-25T21:48:00.954Z,1650923280.954 [sci2_quickGPS:QuickFix:GetFix:A](INFO): Timed out from 2022-04-25T21:47:30.7Z
2022-04-25T21:48:00.955Z,1650923280.955 [sci2_quickGPS:QuickFix:GetFix:A] Stopped
2022-04-25T21:48:00.955Z,1650923280.955 [sci2_quickGPS:QuickFix:GetFix](INFO): Completed sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:48:00.955Z,1650923280.955 [sci2_quickGPS:QuickFix:GetFix] Stopped
2022-04-25T21:48:00.955Z,1650923280.955 [sci2_quickGPS:QuickFix:GetFix](DEBUG): Aggregate::uninitialize sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:48:00.956Z,1650923280.956 [sci2_quickGPS:QuickFix](INFO): Completed sci2_quickGPS:QuickFix
2022-04-25T21:48:00.956Z,1650923280.956 [sci2_quickGPS:QuickFix] Stopped
2022-04-25T21:48:00.956Z,1650923280.956 [sci2_quickGPS:QuickFix](DEBUG): Aggregate::uninitialize sci2_quickGPS:QuickFix
2022-04-25T21:48:00.956Z,1650923280.956 [sci2_quickGPS:QuickFix:A.GoToSurface] Stopped
2022-04-25T21:48:00.956Z,1650923280.956 [sci2_quickGPS:QuickFix:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-04-25T21:48:01.340Z,1650923281.340 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-04-25T21:48:01.414Z,1650923281.414 [NAL9602](ERROR): received: 
+CSQ:0

OK49, 2, 0, 0, 0

OK
2022-04-25T21:48:01.434Z,1650923281.434 [sci2_quickGPS:NeedGPS:NeedGPS](INFO): Completed sci2_quickGPS:NeedGPS:NeedGPS
2022-04-25T21:48:01.434Z,1650923281.434 [sci2_quickGPS:NeedGPS:NeedGPS] Stopped
2022-04-25T21:48:01.434Z,1650923281.434 [sci2_quickGPS:NeedGPS:NeedGPS](DEBUG): Aggregate::uninitialize sci2_quickGPS:NeedGPS:NeedGPS
2022-04-25T21:48:01.434Z,1650923281.434 [sci2_quickGPS:NeedGPS](INFO): Completed sci2_quickGPS:NeedGPS
2022-04-25T21:48:01.434Z,1650923281.434 [sci2_quickGPS:NeedGPS] Stopped
2022-04-25T21:48:01.435Z,1650923281.435 [sci2_quickGPS:NeedGPS](DEBUG): Aggregate::uninitialize sci2_quickGPS:NeedGPS
2022-04-25T21:48:01.508Z,1650923281.508 [Reporter](INFO): VerticalControl.verticalMode 3 enum
2022-04-25T21:48:01.510Z,1650923281.510 [Reporter](INFO): SpeedControl.speedCmd 0.150000 m/s
2022-04-25T21:48:01.856Z,1650923281.856 [Reporter](INFO): VerticalControl.verticalMode 5 enum
2022-04-25T21:48:07.132Z,1650923287.132 [ThrusterHE](ERROR): Zero Speed Commanded.
2022-04-25T21:48:14.267Z,1650923294.267 [NAL9602](INFO): SBD MO Status=0, MOMSN=7649, MT Status=0, MTMSN=0
2022-04-25T21:48:14.267Z,1650923294.267 [NAL9602](INFO): No messages in MT queue
2022-04-25T21:48:44.977Z,1650923324.977 [NAL9602](INFO): Not Powering down - fast GPS
2022-04-25T21:52:30.895Z,1650923550.895 [sci2_quickGPS:NeedGPS] Running Loop=1
2022-04-25T21:52:30.895Z,1650923550.895 [sci2_quickGPS:NeedGPS](DEBUG): Aggregate::initialize sci2_quickGPS:NeedGPS
2022-04-25T21:52:30.896Z,1650923550.896 [sci2_quickGPS:NeedGPS:A] Running Loop=1
2022-04-25T21:52:30.896Z,1650923550.896 [sci2_quickGPS:NeedGPS:A](INFO): Quick GPS - last time_fix was: 1650923250.000000 second since 1970/01/01T00:00:00Z 
2022-04-25T21:52:30.896Z,1650923550.896 [sci2_quickGPS:NeedGPS:A] Stopped
2022-04-25T21:52:30.896Z,1650923550.896 [sci2_quickGPS:NeedGPS:NeedGPS] Running Loop=1
2022-04-25T21:52:30.897Z,1650923550.897 [sci2_quickGPS:NeedGPS:NeedGPS](DEBUG): Aggregate::initialize sci2_quickGPS:NeedGPS:NeedGPS
2022-04-25T21:52:31.302Z,1650923551.302 [sci2_quickGPS:QuickFix] Running Loop=1
2022-04-25T21:52:31.302Z,1650923551.302 [sci2_quickGPS:QuickFix](DEBUG): Aggregate::initialize sci2_quickGPS:QuickFix
2022-04-25T21:52:31.302Z,1650923551.302 [sci2_quickGPS:QuickFix:A.GoToSurface] Running Loop=1
2022-04-25T21:52:31.302Z,1650923551.302 [sci2_quickGPS:QuickFix:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-04-25T21:52:31.303Z,1650923551.303 [sci2_quickGPS:QuickFix:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-04-25T21:52:31.303Z,1650923551.303 [sci2_quickGPS:QuickFix:A.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2022-04-25T21:52:31.303Z,1650923551.303 [sci2_quickGPS:QuickFix:A.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2022-04-25T21:52:31.304Z,1650923551.304 [sci2_quickGPS:QuickFix:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-04-25T21:52:31.304Z,1650923551.304 [sci2_quickGPS:QuickFix:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-04-25T21:52:31.305Z,1650923551.305 [sci2_quickGPS:QuickFix:GetFix] Running Loop=1
2022-04-25T21:52:31.305Z,1650923551.305 [sci2_quickGPS:QuickFix:GetFix](DEBUG): Aggregate::initialize sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:52:31.305Z,1650923551.305 [sci2_quickGPS:QuickFix:GetFix:A] Running Loop=1
2022-04-25T21:52:31.388Z,1650923551.388 [Reporter](INFO): VerticalControl.verticalMode 8 enum
2022-04-25T21:52:31.388Z,1650923551.388 [Reporter](INFO): SpeedControl.speedCmd 0.000000 m/s
2022-04-25T21:52:33.309Z,1650923553.309 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215232.00,A,3648.17279,N,12147.28266,W,0.389,141.58,250422,,,A*7B
2022-04-25T21:52:33.312Z,1650923553.312 [NAL9602](INFO): GPS fix at 20220425T215232: (36.802880, -121.788044)
2022-04-25T21:52:33.355Z,1650923553.355 [sci2_quickGPS:QuickFix:GetFix:A] Stopped
2022-04-25T21:52:33.355Z,1650923553.355 [sci2_quickGPS:QuickFix:GetFix](INFO): Completed sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:52:33.355Z,1650923553.355 [sci2_quickGPS:QuickFix:GetFix] Stopped
2022-04-25T21:52:33.355Z,1650923553.355 [sci2_quickGPS:QuickFix:GetFix](DEBUG): Aggregate::uninitialize sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:52:33.355Z,1650923553.355 [sci2_quickGPS:QuickFix:GetFix](INFO): Running loop #2
2022-04-25T21:52:33.356Z,1650923553.356 [sci2_quickGPS:QuickFix:GetFix] Running Loop=2
2022-04-25T21:52:33.356Z,1650923553.356 [sci2_quickGPS:QuickFix:GetFix](DEBUG): Aggregate::initialize sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:52:33.356Z,1650923553.356 [sci2_quickGPS:QuickFix:GetFix:A] Running Loop=1
2022-04-25T21:53:03.632Z,1650923583.632 [sci2_quickGPS:QuickFix:GetFix:A](INFO): Timed out from 2022-04-25T21:52:33.4Z
2022-04-25T21:53:03.632Z,1650923583.632 [sci2_quickGPS:QuickFix:GetFix:A] Stopped
2022-04-25T21:53:03.633Z,1650923583.633 [sci2_quickGPS:QuickFix:GetFix](INFO): Completed sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:53:03.633Z,1650923583.633 [sci2_quickGPS:QuickFix:GetFix] Stopped
2022-04-25T21:53:03.633Z,1650923583.633 [sci2_quickGPS:QuickFix:GetFix](DEBUG): Aggregate::uninitialize sci2_quickGPS:QuickFix:GetFix
2022-04-25T21:53:03.644Z,1650923583.644 [sci2_quickGPS:QuickFix](INFO): Completed sci2_quickGPS:QuickFix
2022-04-25T21:53:03.644Z,1650923583.644 [sci2_quickGPS:QuickFix] Stopped
2022-04-25T21:53:03.644Z,1650923583.644 [sci2_quickGPS:QuickFix](DEBUG): Aggregate::uninitialize sci2_quickGPS:QuickFix
2022-04-25T21:53:03.644Z,1650923583.644 [sci2_quickGPS:QuickFix:A.GoToSurface] Stopped
2022-04-25T21:53:03.644Z,1650923583.644 [sci2_quickGPS:QuickFix:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-04-25T21:53:04.048Z,1650923584.048 [sci2_quickGPS:NeedGPS:NeedGPS](INFO): Completed sci2_quickGPS:NeedGPS:NeedGPS
2022-04-25T21:53:04.048Z,1650923584.048 [sci2_quickGPS:NeedGPS:NeedGPS] Stopped
2022-04-25T21:53:04.048Z,1650923584.048 [sci2_quickGPS:NeedGPS:NeedGPS](DEBUG): Aggregate::uninitialize sci2_quickGPS:NeedGPS:NeedGPS
2022-04-25T21:53:04.048Z,1650923584.048 [sci2_quickGPS:NeedGPS](INFO): Completed sci2_quickGPS:NeedGPS
2022-04-25T21:53:04.048Z,1650923584.048 [sci2_quickGPS:NeedGPS] Stopped
2022-04-25T21:53:04.048Z,1650923584.048 [sci2_quickGPS:NeedGPS](DEBUG): Aggregate::uninitialize sci2_quickGPS:NeedGPS
2022-04-25T21:53:04.181Z,1650923584.181 [Reporter](INFO): VerticalControl.verticalMode 3 enum
2022-04-25T21:53:04.182Z,1650923584.182 [Reporter](INFO): SpeedControl.speedCmd 0.150000 m/s
2022-04-25T21:53:04.528Z,1650923584.528 [Reporter](INFO): VerticalControl.verticalMode 5 enum
2022-04-25T21:53:09.824Z,1650923589.824 [ThrusterHE](ERROR): Zero Speed Commanded.
2022-04-25T21:54:05.819Z,1650923645.819 [NAL9602](INFO): SBD MO Status=2, MOMSN=7650, MT Status=2, MTMSN=0
2022-04-25T21:54:05.820Z,1650923645.820 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-25T21:54:49.452Z,1650923689.452 [NAL9602](INFO): SBD MO Status=0, MOMSN=7650, MT Status=0, MTMSN=0
2022-04-25T21:54:49.452Z,1650923689.452 [NAL9602](INFO): No messages in MT queue
2022-04-25T21:55:20.156Z,1650923720.156 [NAL9602](INFO): Not Powering down - fast GPS
2022-04-25T21:56:10.331Z,1650923770.331 [CommandExec](IMPORTANT): got command stop
2022-04-25T21:56:10.331Z,1650923770.331 [CommandExec](IMPORTANT): Scheduling is paused
2022-04-25T21:56:10.331Z,1650923770.331 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2022-04-25T21:56:10.670Z,1650923770.670 [MissionManager](INFO): MissionManager is completed.
2022-04-25T21:56:10.671Z,1650923770.671 [MissionManager](INFO): Uninitializing Mission sci2_quickGPS
2022-04-25T21:56:10.671Z,1650923770.671 [sci2_quickGPS] Stopped
2022-04-25T21:56:10.671Z,1650923770.671 [sci2_quickGPS](DEBUG): Aggregate::uninitialize sci2_quickGPS
2022-04-25T21:56:10.671Z,1650923770.671 [sci2_quickGPS:Science] Stopped
2022-04-25T21:56:10.671Z,1650923770.671 [sci2_quickGPS:Science](DEBUG): Aggregate::uninitialize sci2_quickGPS:Science
2022-04-25T21:56:10.671Z,1650923770.671 [sci2_quickGPS:Science:E] Stopped
2022-04-25T21:56:10.671Z,1650923770.671 [sci2_quickGPS:Science:OceanCurrent] Stopped
2022-04-25T21:56:10.671Z,1650923770.671 [sci2_quickGPS:Science:OceanCurrent](DEBUG): Aggregate::uninitialize sci2_quickGPS:Science:OceanCurrent
2022-04-25T21:56:10.671Z,1650923770.671 [sci2_quickGPS:Science:OceanCurrent:A.] Stopped
2022-04-25T21:56:10.671Z,1650923770.671 [sci2_quickGPS:Science:PeakDetectChl] Stopped
2022-04-25T21:56:10.671Z,1650923770.671 [sci2_quickGPS:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize sci2_quickGPS:Science:PeakDetectChl
2022-04-25T21:56:10.672Z,1650923770.672 [sci2_quickGPS:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2022-04-25T21:56:10.672Z,1650923770.672 [sci2_quickGPS:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-04-25T21:56:10.672Z,1650923770.672 [sci2_quickGPS:StandardEnvelopes] Stopped
2022-04-25T21:56:10.672Z,1650923770.672 [sci2_quickGPS:StandardEnvelopes](DEBUG): Aggregate::uninitialize sci2_quickGPS:StandardEnvelopes
2022-04-25T21:56:10.672Z,1650923770.672 [sci2_quickGPS:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2022-04-25T21:56:10.672Z,1650923770.672 [sci2_quickGPS:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2022-04-25T21:56:10.672Z,1650923770.672 [sci2_quickGPS:StandardEnvelopes:B.DepthEnvelope] Stopped
2022-04-25T21:56:10.672Z,1650923770.672 [sci2_quickGPS:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2022-04-25T21:56:10.672Z,1650923770.672 [sci2_quickGPS:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2022-04-25T21:56:10.672Z,1650923770.672 [sci2_quickGPS:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2022-04-25T21:56:10.672Z,1650923770.672 [sci2_quickGPS:J.Pitch] Stopped
2022-04-25T21:56:10.672Z,1650923770.672 [sci2_quickGPS:K.Buoyancy] Stopped
2022-04-25T21:56:10.672Z,1650923770.672 [sci2_quickGPS:K.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2022-04-25T21:56:10.673Z,1650923770.673 [sci2_quickGPS:L.SetSpeed] Stopped
2022-04-25T21:56:10.673Z,1650923770.673 [sci2_quickGPS:L.SetSpeed](DEBUG): Uninitialize.
2022-04-25T21:56:10.673Z,1650923770.673 [sci2_quickGPS:M.DepthEnvelope] Stopped
2022-04-25T21:56:10.673Z,1650923770.673 [sci2_quickGPS:M.DepthEnvelope](DEBUG): Uninitialize.
2022-04-25T21:56:10.673Z,1650923770.673 [sci2_quickGPS:N.AltitudeEnvelope] Stopped
2022-04-25T21:56:10.673Z,1650923770.673 [sci2_quickGPS:N.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2022-04-25T21:56:10.673Z,1650923770.673 [sci2_quickGPS:P.YoYo] Stopped
2022-04-25T21:56:10.673Z,1650923770.673 [sci2_quickGPS:P.YoYo](DEBUG): Uninitialize YoYoComponent.
2022-04-25T21:56:10.673Z,1650923770.673 [sci2_quickGPS:Lap] Stopped
2022-04-25T21:56:10.673Z,1650923770.673 [sci2_quickGPS:Lap](DEBUG): Aggregate::uninitialize sci2_quickGPS:Lap
2022-04-25T21:56:10.673Z,1650923770.673 [sci2_quickGPS:Lap:Wpt1] Stopped
2022-04-25T21:56:10.673Z,1650923770.673 [sci2_quickGPS:Lap:Wpt1](DEBUG): Aggregate::uninitialize sci2_quickGPS:Lap:Wpt1
2022-04-25T21:56:10.673Z,1650923770.673 [sci2_quickGPS:Lap:Wpt1:A.Waypoint] Stopped
2022-04-25T21:56:10.674Z,1650923770.674 [sci2_quickGPS:Lap:Wpt1:A.Waypoint](DEBUG): Uninitialize WaypointComponent.
2022-04-25T21:56:10.830Z,1650923770.830 [WetLabsBB2FL](INFO): Powering down
2022-04-25T21:56:11.076Z,1650923771.076 [MissionManager](IMPORTANT): Started mission Default
2022-04-25T21:56:11.076Z,1650923771.076 [Default] Running Loop=1
2022-04-25T21:56:11.076Z,1650923771.076 [Default](DEBUG): Aggregate::initialize Default
2022-04-25T21:56:11.076Z,1650923771.076 [Default:B.GoToSurface] Running Loop=1
2022-04-25T21:56:11.076Z,1650923771.076 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-04-25T21:56:11.077Z,1650923771.077 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-04-25T21:56:11.077Z,1650923771.077 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-04-25T21:56:11.077Z,1650923771.077 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-04-25T21:56:11.078Z,1650923771.078 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-04-25T21:56:11.078Z,1650923771.078 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-04-25T21:56:11.095Z,1650923771.095 [Default:A.Wait] Running Loop=1
2022-04-25T21:56:11.095Z,1650923771.095 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-04-25T21:56:11.199Z,1650923771.199 [Reporter](INFO): VerticalControl.verticalMode 8 enum
2022-04-25T21:56:11.200Z,1650923771.200 [Reporter](INFO): SpeedControl.speedCmd 0.000000 m/s
2022-04-25T21:56:24.402Z,1650923784.402 [Default:A.Wait](INFO): Done Waiting.
2022-04-25T21:56:24.402Z,1650923784.402 [Default:A.Wait] Stopped
2022-04-25T21:56:24.402Z,1650923784.402 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-04-25T21:56:24.846Z,1650923784.846 [Default:CheckIn] Running Loop=1
2022-04-25T21:56:24.846Z,1650923784.846 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-04-25T21:56:24.858Z,1650923784.858 [Default:CheckIn:Read_GPS] Running Loop=1
2022-04-25T21:56:26.827Z,1650923786.827 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215626.00,A,3648.16456,N,12147.28296,W,0.739,0.00,250422,,,A*79
2022-04-25T21:56:26.829Z,1650923786.829 [NAL9602](INFO): GPS fix at 20220425T215626: (36.802743, -121.788049)
2022-04-25T21:56:26.848Z,1650923786.848 [Default:CheckIn:Read_GPS] Stopped
2022-04-25T21:56:26.848Z,1650923786.848 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-04-25T21:56:28.979Z,1650923788.979 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20220425T203431/Courier0040.lzma
2022-04-25T21:56:30.008Z,1650923790.008 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Courier0040.lzma.bak
2022-04-25T21:56:30.008Z,1650923790.008 [DataOverHttps](INFO): SBD MOMSN=16661171
2022-04-25T21:56:48.819Z,1650923808.819 [DataOverHttps](INFO): Sending 393 bytes from file Logs/20220425T203431/Express0041.lzma
2022-04-25T21:56:49.821Z,1650923809.821 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Express0041.lzma.bak
2022-04-25T21:56:49.821Z,1650923809.821 [DataOverHttps](INFO): SBD MOMSN=16661174
2022-04-25T21:56:52.716Z,1650923812.716 [Default:CheckIn:Read_Iridium] Stopped
2022-04-25T21:56:52.716Z,1650923812.716 [Default:CheckIn:C.Wait] Running Loop=1
2022-04-25T21:56:52.716Z,1650923812.716 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-04-25T22:01:29.079Z,1650924089.079 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-04-25T22:01:53.337Z,1650924113.337 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-04-25T22:01:53.337Z,1650924113.337 [Default:CheckIn:C.Wait] Stopped
2022-04-25T22:01:53.337Z,1650924113.337 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-04-25T22:01:53.338Z,1650924113.338 [Default:CheckIn:D] Running Loop=1
2022-04-25T22:01:53.728Z,1650924113.728 [Default:CheckIn:D] Stopped
2022-04-25T22:01:53.728Z,1650924113.728 [Default:CheckIn:E] Running Loop=1
2022-04-25T22:01:54.138Z,1650924114.138 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.710864 min 
2022-04-25T22:01:54.138Z,1650924114.138 [Default:CheckIn:E] Stopped
2022-04-25T22:01:54.138Z,1650924114.138 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-04-25T22:01:54.138Z,1650924114.138 [Default:CheckIn] Stopped
2022-04-25T22:01:54.139Z,1650924114.139 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-04-25T22:01:54.139Z,1650924114.139 [Default:CheckIn](INFO): Running loop #2
2022-04-25T22:01:54.139Z,1650924114.139 [Default:CheckIn] Running Loop=2
2022-04-25T22:01:54.139Z,1650924114.139 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-04-25T22:01:54.139Z,1650924114.139 [Default:CheckIn:Read_GPS] Running Loop=1
2022-04-25T22:01:56.145Z,1650924116.145 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220156.00,A,3648.17019,N,12147.27984,W,0.058,145.42,250422,,,A*70
2022-04-25T22:01:56.148Z,1650924116.148 [NAL9602](INFO): GPS fix at 20220425T220156: (36.802836, -121.787997)
2022-04-25T22:01:56.159Z,1650924116.159 [Default:CheckIn:Read_GPS] Stopped
2022-04-25T22:01:56.160Z,1650924116.160 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-04-25T22:02:03.734Z,1650924123.734 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220425T203431/Courier0043.lzma
2022-04-25T22:02:04.736Z,1650924124.736 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Courier0043.lzma.bak
2022-04-25T22:02:04.737Z,1650924124.737 [DataOverHttps](INFO): SBD MOMSN=16661186
2022-04-25T22:02:21.938Z,1650924141.938 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20220425T203431/Express0044.lzma
2022-04-25T22:02:22.940Z,1650924142.940 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Express0044.lzma.bak
2022-04-25T22:02:22.940Z,1650924142.940 [DataOverHttps](INFO): SBD MOMSN=16661189
2022-04-25T22:02:25.660Z,1650924145.660 [Default:CheckIn:Read_Iridium] Stopped
2022-04-25T22:02:25.660Z,1650924145.660 [Default:CheckIn:C.Wait] Running Loop=1
2022-04-25T22:02:25.661Z,1650924145.661 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-04-25T22:02:28.871Z,1650924148.871 [NAL9602](INFO): Not Powering down - fast GPS
2022-04-25T22:07:26.410Z,1650924446.410 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-04-25T22:07:26.410Z,1650924446.410 [Default:CheckIn:C.Wait] Stopped
2022-04-25T22:07:26.410Z,1650924446.410 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-04-25T22:07:26.411Z,1650924446.411 [Default:CheckIn:D] Running Loop=1
2022-04-25T22:07:26.800Z,1650924446.800 [Default:CheckIn:D] Stopped
2022-04-25T22:07:26.800Z,1650924446.800 [Default:CheckIn:E] Running Loop=1
2022-04-25T22:07:27.210Z,1650924447.210 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.262063 min 
2022-04-25T22:07:27.211Z,1650924447.211 [Default:CheckIn:E] Stopped
2022-04-25T22:07:27.211Z,1650924447.211 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-04-25T22:07:27.211Z,1650924447.211 [Default:CheckIn] Stopped
2022-04-25T22:07:27.211Z,1650924447.211 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-04-25T22:07:27.211Z,1650924447.211 [Default:CheckIn](INFO): Running loop #3
2022-04-25T22:07:27.211Z,1650924447.211 [Default:CheckIn] Running Loop=3
2022-04-25T22:07:27.211Z,1650924447.211 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-04-25T22:07:27.211Z,1650924447.211 [Default:CheckIn:Read_GPS] Running Loop=1
2022-04-25T22:07:29.221Z,1650924449.221 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220728.00,A,3648.17221,N,12147.27803,W,0.253,145.42,250422,,,A*71
2022-04-25T22:07:29.224Z,1650924449.224 [NAL9602](INFO): GPS fix at 20220425T220728: (36.802870, -121.787967)
2022-04-25T22:07:29.235Z,1650924449.235 [Default:CheckIn:Read_GPS] Stopped
2022-04-25T22:07:29.235Z,1650924449.235 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-04-25T22:07:36.971Z,1650924456.971 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220425T203431/Courier0046.lzma
2022-04-25T22:07:37.972Z,1650924457.972 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Courier0046.lzma.bak
2022-04-25T22:07:37.972Z,1650924457.972 [DataOverHttps](INFO): SBD MOMSN=16661193
2022-04-25T22:07:55.202Z,1650924475.202 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20220425T203431/Express0047.lzma
2022-04-25T22:07:56.204Z,1650924476.204 [DataOverHttps](INFO): Moved sent file to Logs/20220425T203431/Express0047.lzma.bak
2022-04-25T22:07:56.205Z,1650924476.205 [DataOverHttps](INFO): SBD MOMSN=16661196
2022-04-25T22:07:59.146Z,1650924479.146 [Default:CheckIn:Read_Iridium] Stopped
2022-04-25T22:07:59.147Z,1650924479.147 [Default:CheckIn:C.Wait] Running Loop=1
2022-04-25T22:07:59.147Z,1650924479.147 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-04-25T22:07:59.927Z,1650924479.927 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-04-25T22:08:00.007Z,1650924480.007 [NAL9602](ERROR): received: 
+CSQ:0

OK50, 0, 0, 0, 0

OK
2022-04-25T22:11:27.629Z,1650924687.629 [NAL9602](INFO): SBD MO Status=2, MOMSN=7651, MT Status=2, MTMSN=0
2022-04-25T22:11:27.629Z,1650924687.629 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-25T22:12:31.048Z,1650924751.048 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-04-25T22:12:59.754Z,1650924779.754 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-04-25T22:12:59.754Z,1650924779.754 [Default:CheckIn:C.Wait] Stopped
2022-04-25T22:12:59.754Z,1650924779.754 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-04-25T22:12:59.755Z,1650924779.755 [Default:CheckIn:D] Running Loop=1
2022-04-25T22:13:00.146Z,1650924780.146 [Default:CheckIn:D] Stopped
2022-04-25T22:13:00.146Z,1650924780.146 [Default:CheckIn:E] Running Loop=1
2022-04-25T22:13:00.556Z,1650924780.556 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 16.817834 min 
2022-04-25T22:13:00.556Z,1650924780.556 [Default:CheckIn:E] Stopped
2022-04-25T22:13:00.556Z,1650924780.556 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-04-25T22:13:00.557Z,1650924780.557 [Default:CheckIn] Stopped
2022-04-25T22:13:00.557Z,1650924780.557 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-04-25T22:13:00.557Z,1650924780.557 [Default:CheckIn](INFO): Running loop #4
2022-04-25T22:13:00.557Z,1650924780.557 [Default:CheckIn] Running Loop=4
2022-04-25T22:13:00.557Z,1650924780.557 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-04-25T22:13:00.557Z,1650924780.557 [Default:CheckIn:Read_GPS] Running Loop=1
2022-04-25T22:13:02.562Z,1650924782.562 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221301.00,A,3648.17481,N,12147.28313,W,0.525,168.22,250422,,,A*79
2022-04-25T22:13:02.564Z,1650924782.564 [NAL9602](INFO): GPS fix at 20220425T221301: (36.802914, -121.788052)
2022-04-25T22:13:02.575Z,1650924782.575 [Default:CheckIn:Read_GPS] Stopped
2022-04-25T22:13:02.575Z,1650924782.575 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-04-25T22:13:08.089Z,1650924788.089 [CommandExec](IMPORTANT): got command quit
2022-04-25T22:13:09.093Z,1650924789.093 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-25T22:13:09.093Z,1650924789.093 [CommandExec](INFO): Uninitializing the command executive.
2022-04-25T22:13:09.093Z,1650924789.093 [CommandExec](INFO): Uninitializing the command scheduler.
2022-04-25T22:13:09.093Z,1650924789.093 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-04-25T22:13:09.252Z,1650924789.252 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2022-04-25T22:13:09.252Z,1650924789.252 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2022-04-25T22:13:09.253Z,1650924789.253 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-04-25T22:13:09.253Z,1650924789.253 [NavChartDb](INFO): Join timeout helper Thread ID is 5323
2022-04-25T22:13:09.533Z,1650924789.533 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-25T22:13:09.533Z,1650924789.533 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-04-25T22:13:09.542Z,1650924789.542 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2022-04-25T22:13:09.542Z,1650924789.542 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-04-25T22:13:09.542Z,1650924789.542 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 5324
2022-04-25T22:13:09.841Z,1650924789.841 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-25T22:13:09.841Z,1650924789.841 [WetLabsBB2FL](INFO): Powering down
2022-04-25T22:13:09.842Z,1650924789.842 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-04-25T22:13:09.857Z,1650924789.857 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2022-04-25T22:13:09.857Z,1650924789.857 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-04-25T22:13:09.857Z,1650924789.857 [Radio_Surface](INFO): Join timeout helper Thread ID is 5325
2022-04-25T22:13:10.005Z,1650924790.005 [Radio_Surface](INFO): Powering down
2022-04-25T22:13:10.006Z,1650924790.006 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-25T22:13:10.006Z,1650924790.006 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-04-25T22:13:10.016Z,1650924790.016 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2022-04-25T22:13:10.017Z,1650924790.017 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-04-25T22:13:10.017Z,1650924790.017 [Onboard](INFO): Join timeout helper Thread ID is 5326
2022-04-25T22:13:10.232Z,1650924790.232 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220425T203431/Courier0049.lzma
2022-04-25T22:13:10.717Z,1650924790.717 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-25T22:13:10.717Z,1650924790.717 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-04-25T22:13:10.720Z,1650924790.720 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2022-04-25T22:13:10.721Z,1650924790.721 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-04-25T22:13:10.721Z,1650924790.721 [DataOverHttps](INFO): Join timeout helper Thread ID is 5327
2022-04-25T22:13:11.233Z,1650924791.233 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-25T22:13:11.236Z,1650924791.236 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-04-25T22:13:11.245Z,1650924791.245 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2022-04-25T22:13:11.245Z,1650924791.245 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-04-25T22:13:11.246Z,1650924791.246 [BackseatComponent](INFO): Join timeout helper Thread ID is 5328
2022-04-25T22:13:11.361Z,1650924791.361 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-25T22:13:11.361Z,1650924791.361 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-04-25T22:13:11.365Z,1650924791.365 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2022-04-25T22:13:11.365Z,1650924791.365 [logger ThreadHandler](INFO): Thread cancelled.
2022-04-25T22:13:11.366Z,1650924791.366 [logger](INFO): Join timeout helper Thread ID is 5329
2022-04-25T22:13:11.409Z,1650924791.409 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-25T22:13:11.409Z,1650924791.409 [logger ThreadHandler](INFO): Thread cancelled.
2022-04-25T22:13:11.425Z,1650924791.425 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2022-04-25T22:13:11.425Z,1650924791.425 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-04-25T22:13:11.426Z,1650924791.426 [CommandLine](INFO): Join timeout helper Thread ID is 5330
2022-04-25T22:13:11.477Z,1650924791.477 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-25T22:13:11.477Z,1650924791.477 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-04-25T22:13:11.497Z,1650924791.497 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2022-04-25T22:13:11.497Z,1650924791.497 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-04-25T22:13:11.498Z,1650924791.498 [CommandExec](INFO): Join timeout helper Thread ID is 5331
2022-04-25T22:13:11.499Z,1650924791.499 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2022-04-25T22:13:11.499Z,1650924791.499 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-04-25T22:13:11.499Z,1650924791.499 [controlThread](INFO): Join timeout helper Thread ID is 5332
2022-04-25T22:13:11.837Z,1650924791.837 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-25T22:13:11.837Z,1650924791.837 [controlThread](DEBUG): Uninitializing ControlThread
2022-04-25T22:13:11.837Z,1650924791.837 [AHRS_M2](INFO): Powering down
2022-04-25T22:13:11.909Z,1650924791.909 [NAL9602](INFO): Powering down
2022-04-25T22:13:11.911Z,1650924791.911 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2022-04-25T22:13:11.912Z,1650924791.912 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2022-04-25T22:13:11.913Z,1650924791.913 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2022-04-25T22:13:11.914Z,1650924791.914 [MissionManager](INFO): Uninitializing Mission Default
2022-04-25T22:13:11.914Z,1650924791.914 [Default] Stopped
2022-04-25T22:13:11.914Z,1650924791.914 [Default](DEBUG): Aggregate::uninitialize Default
2022-04-25T22:13:11.914Z,1650924791.914 [Default:B.GoToSurface] Stopped
2022-04-25T22:13:11.914Z,1650924791.914 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-04-25T22:13:11.914Z,1650924791.914 [Default:CheckIn] Stopped
2022-04-25T22:13:11.914Z,1650924791.914 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-04-25T22:13:11.914Z,1650924791.914 [Default:CheckIn:Read_Iridium] Stopped
2022-04-25T22:13:11.917Z,1650924791.917 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2022-04-25T22:13:11.917Z,1650924791.917 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2022-04-25T22:13:11.918Z,1650924791.918 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2022-04-25T22:13:11.918Z,1650924791.918 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2022-04-25T22:13:11.918Z,1650924791.918 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2022-04-25T22:13:11.918Z,1650924791.918 [BuoyancyServo](INFO): Powering down
2022-04-25T22:13:11.933Z,1650924791.933 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2022-04-25T22:13:11.933Z,1650924791.933 [ElevatorServo](INFO): Powering down
2022-04-25T22:13:11.933Z,1650924791.933 [MassServo](DEBUG): Uninitialize Mass Servo.
2022-04-25T22:13:11.934Z,1650924791.934 [MassServo](INFO): Powering down
2022-04-25T22:13:11.934Z,1650924791.934 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-04-25T22:13:11.935Z,1650924791.935 [RudderServo](INFO): Powering down
2022-04-25T22:13:11.935Z,1650924791.935 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2022-04-25T22:13:11.935Z,1650924791.935 [ThrusterHE](INFO): Powering down
2022-04-25T22:13:11.936Z,1650924791.936 [SBIT](DEBUG): Uninitialize SBIT Component.
2022-04-25T22:13:11.937Z,1650924791.937 [IBIT](DEBUG): Uninitialize IBIT Component.
2022-04-25T22:13:11.937Z,1650924791.937 [CBIT](DEBUG): Uninitialize CBIT Component.
2022-04-25T22:13:11.937Z,1650924791.937 [CBIT](DEBUG): Powering off loads.
2022-04-25T22:13:11.948Z,1650924791.948 [CBIT](DEBUG): Disabling WDT.
2022-04-25T22:13:11.960Z,1650924791.960 [CBIT](DEBUG): Opening all GF detection circuits.
2022-04-25T22:13:11.961Z,1650924791.961 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-04-25T22:13:12.017Z,1650924792.017 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-04-25T22:13:12.020Z,1650924792.020 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-04-25T22:13:12.026Z,1650924792.026 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-04-25T22:13:12.070Z,1650924792.070 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-04-25T22:13:12.105Z,1650924792.105 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-04-25T22:13:12.137Z,1650924792.137 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-04-25T22:13:12.214Z,1650924792.214 [logger ThreadHandler](INFO): Thread cancelled.