2022-10-07T01:46:33.194Z,1665107193.194 [Supervisor](DEBUG): Initializing supervisor.
2022-10-07T01:46:33.198Z,1665107193.198 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2022-10-07T01:46:33.198Z,1665107193.198 [SyncHandler](INFO): Protected caller Thread ID is 830
2022-10-07T01:46:33.199Z,1665107193.199 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2022-10-07T01:46:33.200Z,1665107193.200 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2022-10-07T01:46:33.200Z,1665107193.200 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 831
2022-10-07T01:46:33.204Z,1665107193.204 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2022-10-07T01:46:33.221Z,1665107193.221 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2022-10-07T01:46:33.222Z,1665107193.222 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2022-10-07T01:46:33.222Z,1665107193.222 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 832
2022-10-07T01:46:33.227Z,1665107193.227 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2022-10-07T01:46:33.228Z,1665107193.228 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2022-10-07T01:46:33.228Z,1665107193.228 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 833
2022-10-07T01:46:33.230Z,1665107193.230 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2022-10-07T01:46:33.231Z,1665107193.231 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2022-10-07T01:46:33.231Z,1665107193.231 [logger ThreadHandler](INFO): Protected caller Thread ID is 834
2022-10-07T01:46:33.235Z,1665107193.235 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2022-10-07T01:46:33.235Z,1665107193.235 [Supervisor](INFO): Looking for Config files in directory: Config/
2022-10-07T01:46:33.241Z,1665107193.241 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2022-10-07T01:46:33.335Z,1665107193.335 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2022-10-07T01:46:33.337Z,1665107193.337 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2022-10-07T01:46:33.547Z,1665107193.547 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2022-10-07T01:46:33.547Z,1665107193.547 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2022-10-07T01:46:33.795Z,1665107193.795 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2022-10-07T01:46:33.796Z,1665107193.796 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2022-10-07T01:46:33.902Z,1665107193.902 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2022-10-07T01:46:33.903Z,1665107193.903 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2022-10-07T01:46:34.545Z,1665107194.545 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2022-10-07T01:46:34.546Z,1665107194.546 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2022-10-07T01:46:34.987Z,1665107194.987 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2022-10-07T01:46:34.987Z,1665107194.987 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2022-10-07T01:46:35.476Z,1665107195.476 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2022-10-07T01:46:35.477Z,1665107195.477 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2022-10-07T01:46:35.839Z,1665107195.839 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2022-10-07T01:46:35.841Z,1665107195.841 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2022-10-07T01:46:36.164Z,1665107196.164 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2022-10-07T01:46:36.165Z,1665107196.165 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2022-10-07T01:46:36.516Z,1665107196.516 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2022-10-07T01:46:36.517Z,1665107196.517 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2022-10-07T01:46:37.230Z,1665107197.230 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2022-10-07T01:46:37.230Z,1665107197.230 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2022-10-07T01:46:37.366Z,1665107197.366 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2022-10-07T01:46:37.367Z,1665107197.367 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2022-10-07T01:46:37.447Z,1665107197.447 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2022-10-07T01:46:37.526Z,1665107197.526 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2022-10-07T01:46:37.704Z,1665107197.704 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2022-10-07T01:46:37.706Z,1665107197.706 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2022-10-07T01:46:37.917Z,1665107197.917 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2022-10-07T01:46:37.919Z,1665107197.919 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2022-10-07T01:46:37.922Z,1665107197.922 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2022-10-07T01:46:38.007Z,1665107198.007 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2022-10-07T01:46:38.266Z,1665107198.266 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2022-10-07T01:46:38.267Z,1665107198.267 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2022-10-07T01:46:38.366Z,1665107198.366 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2022-10-07T01:46:38.523Z,1665107198.523 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2022-10-07T01:46:38.700Z,1665107198.700 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2022-10-07T01:46:38.785Z,1665107198.785 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2022-10-07T01:46:38.892Z,1665107198.892 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2022-10-07T01:46:38.996Z,1665107198.996 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2022-10-07T01:46:39.151Z,1665107199.151 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2022-10-07T01:46:39.252Z,1665107199.252 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2022-10-07T01:46:39.350Z,1665107199.350 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2022-10-07T01:46:39.377Z,1665107199.377 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2022-10-07T01:46:39.587Z,1665107199.587 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2022-10-07T01:46:39.587Z,1665107199.587 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2022-10-07T01:46:39.758Z,1665107199.758 [BuoyancyServo] Loaded
2022-10-07T01:46:39.759Z,1665107199.759 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2022-10-07T01:46:39.779Z,1665107199.779 [ElevatorServo] Loaded
2022-10-07T01:46:39.780Z,1665107199.780 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2022-10-07T01:46:39.799Z,1665107199.799 [MassServo] Loaded
2022-10-07T01:46:39.799Z,1665107199.799 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2022-10-07T01:46:39.819Z,1665107199.819 [RudderServo] Loaded
2022-10-07T01:46:39.819Z,1665107199.819 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2022-10-07T01:46:39.834Z,1665107199.834 [ThrusterHE] Loaded
2022-10-07T01:46:39.834Z,1665107199.834 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2022-10-07T01:46:39.835Z,1665107199.835 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2022-10-07T01:46:39.837Z,1665107199.837 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2022-10-07T01:46:40.001Z,1665107200.001 [SBIT](DEBUG): Construct Startup Built In Test.
2022-10-07T01:46:40.016Z,1665107200.016 [SBIT] Loaded
2022-10-07T01:46:40.016Z,1665107200.016 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2022-10-07T01:46:40.019Z,1665107200.019 [IBIT](DEBUG): Construct Initiated Built In Test.
2022-10-07T01:46:40.040Z,1665107200.040 [IBIT] Loaded
2022-10-07T01:46:40.040Z,1665107200.040 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2022-10-07T01:46:40.045Z,1665107200.045 [CBIT](DEBUG): Construct Continuous Built In Test.
2022-10-07T01:46:40.255Z,1665107200.255 [CBIT] Loaded
2022-10-07T01:46:40.255Z,1665107200.255 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2022-10-07T01:46:40.255Z,1665107200.255 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2022-10-07T01:46:40.256Z,1665107200.256 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2022-10-07T01:46:40.468Z,1665107200.468 [CTD_Seabird] Loaded
2022-10-07T01:46:40.469Z,1665107200.469 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2022-10-07T01:46:40.470Z,1665107200.470 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406664E0
2022-10-07T01:46:40.470Z,1665107200.470 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 916
2022-10-07T01:46:40.501Z,1665107200.501 [ESPComponent] Loaded
2022-10-07T01:46:40.502Z,1665107200.502 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2022-10-07T01:46:40.520Z,1665107200.520 [PAR_Licor] Loaded
2022-10-07T01:46:40.521Z,1665107200.521 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2022-10-07T01:46:40.550Z,1665107200.550 [WetLabsBB2FL] Loaded
2022-10-07T01:46:40.551Z,1665107200.551 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2022-10-07T01:46:40.552Z,1665107200.552 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406964E0
2022-10-07T01:46:40.552Z,1665107200.552 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 917
2022-10-07T01:46:40.553Z,1665107200.553 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2022-10-07T01:46:40.553Z,1665107200.553 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2022-10-07T01:46:40.624Z,1665107200.624 [DepthRateCalculator] Loaded
2022-10-07T01:46:40.624Z,1665107200.624 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2022-10-07T01:46:40.629Z,1665107200.629 [PitchRateCalculator] Loaded
2022-10-07T01:46:40.630Z,1665107200.630 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2022-10-07T01:46:40.639Z,1665107200.639 [SpeedCalculator] Loaded
2022-10-07T01:46:40.640Z,1665107200.640 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2022-10-07T01:46:40.644Z,1665107200.644 [YawRateCalculator] Loaded
2022-10-07T01:46:40.644Z,1665107200.644 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2022-10-07T01:46:40.664Z,1665107200.664 [ElevatorOffsetCalculator] Loaded
2022-10-07T01:46:40.664Z,1665107200.664 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2022-10-07T01:46:40.680Z,1665107200.680 [ShortestDistanceToPolygonSidesCalculator] Loaded
2022-10-07T01:46:40.680Z,1665107200.680 [ComponentRegistry](DEBUG): SyncComponent "ShortestDistanceToPolygonSidesCalculator" handled in the control thread.
2022-10-07T01:46:40.680Z,1665107200.680 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2022-10-07T01:46:40.681Z,1665107200.681 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2022-10-07T01:46:40.798Z,1665107200.798 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2022-10-07T01:46:40.799Z,1665107200.799 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2022-10-07T01:46:40.841Z,1665107200.841 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2022-10-07T01:46:40.841Z,1665107200.841 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2022-10-07T01:46:40.976Z,1665107200.976 [DeadReckonUsingMultipleVelocitySources] Loaded
2022-10-07T01:46:40.976Z,1665107200.976 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2022-10-07T01:46:40.990Z,1665107200.990 [NavChart] Loaded
2022-10-07T01:46:40.990Z,1665107200.990 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2022-10-07T01:46:40.995Z,1665107200.995 [UniversalFixResidualReporter] Loaded
2022-10-07T01:46:40.996Z,1665107200.996 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2022-10-07T01:46:40.996Z,1665107200.996 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2022-10-07T01:46:40.997Z,1665107200.997 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2022-10-07T01:46:41.752Z,1665107201.752 [AHRS_M2] Loaded
2022-10-07T01:46:41.752Z,1665107201.752 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2022-10-07T01:46:42.050Z,1665107202.050 [BackseatComponent] Loaded
2022-10-07T01:46:42.050Z,1665107202.050 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2022-10-07T01:46:42.051Z,1665107202.051 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A144E0
2022-10-07T01:46:42.052Z,1665107202.052 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 918
2022-10-07T01:46:42.055Z,1665107202.055 [LcmUniversalReporter] Loaded
2022-10-07T01:46:42.055Z,1665107202.055 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2022-10-07T01:46:42.366Z,1665107202.366 [DataOverHttps] Loaded
2022-10-07T01:46:42.367Z,1665107202.367 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2022-10-07T01:46:42.368Z,1665107202.368 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40A444E0
2022-10-07T01:46:42.368Z,1665107202.368 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 919
2022-10-07T01:46:42.388Z,1665107202.388 [Depth_Keller] Loaded
2022-10-07T01:46:42.388Z,1665107202.388 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2022-10-07T01:46:42.425Z,1665107202.425 [DVL_micro] Loaded
2022-10-07T01:46:42.426Z,1665107202.426 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2022-10-07T01:46:42.488Z,1665107202.488 [NAL9602] Loaded
2022-10-07T01:46:42.488Z,1665107202.488 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2022-10-07T01:46:42.514Z,1665107202.514 [Onboard] Loaded
2022-10-07T01:46:42.514Z,1665107202.514 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2022-10-07T01:46:42.515Z,1665107202.515 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40A744E0
2022-10-07T01:46:42.516Z,1665107202.516 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 920
2022-10-07T01:46:42.527Z,1665107202.527 [Power24vConverter] Loaded
2022-10-07T01:46:42.528Z,1665107202.528 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2022-10-07T01:46:42.541Z,1665107202.541 [Radio_Surface] Loaded
2022-10-07T01:46:42.541Z,1665107202.541 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2022-10-07T01:46:42.542Z,1665107202.542 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40AA44E0
2022-10-07T01:46:42.542Z,1665107202.542 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 921
2022-10-07T01:46:42.633Z,1665107202.633 [DAT] Loaded
2022-10-07T01:46:42.633Z,1665107202.633 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2022-10-07T01:46:42.634Z,1665107202.634 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40AD44E0
2022-10-07T01:46:42.634Z,1665107202.634 [DAT ThreadHandler](INFO): Protected caller Thread ID is 922
2022-10-07T01:46:42.635Z,1665107202.635 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2022-10-07T01:46:42.636Z,1665107202.636 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2022-10-07T01:46:42.718Z,1665107202.718 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2022-10-07T01:46:42.718Z,1665107202.718 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2022-10-07T01:46:42.784Z,1665107202.784 [VerticalControl](DEBUG): Construct VerticalControl.
2022-10-07T01:46:42.834Z,1665107202.834 [VerticalControl] Loaded
2022-10-07T01:46:42.834Z,1665107202.834 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2022-10-07T01:46:42.837Z,1665107202.837 [HorizontalControl](DEBUG): Construct HorizontalControl.
2022-10-07T01:46:42.873Z,1665107202.873 [HorizontalControl] Loaded
2022-10-07T01:46:42.874Z,1665107202.874 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2022-10-07T01:46:42.876Z,1665107202.876 [SpeedControl](DEBUG): Construct SpeedControl.
2022-10-07T01:46:42.878Z,1665107202.878 [SpeedControl] Loaded
2022-10-07T01:46:42.878Z,1665107202.878 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2022-10-07T01:46:42.881Z,1665107202.881 [LoopControl](DEBUG): Construct LoopControl.
2022-10-07T01:46:42.881Z,1665107202.881 [LoopControl] Loaded
2022-10-07T01:46:42.882Z,1665107202.882 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2022-10-07T01:46:42.882Z,1665107202.882 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2022-10-07T01:46:42.883Z,1665107202.883 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2022-10-07T01:46:42.898Z,1665107202.898 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2022-10-07T01:46:42.899Z,1665107202.899 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2022-10-07T01:46:43.253Z,1665107203.253 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2022-10-07T01:46:43.259Z,1665107203.259 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2022-10-07T01:46:43.262Z,1665107203.262 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2022-10-07T01:46:43.273Z,1665107203.273 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2022-10-07T01:46:43.274Z,1665107203.274 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BCE4E0
2022-10-07T01:46:43.275Z,1665107203.275 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 923
2022-10-07T01:46:43.279Z,1665107203.279 [Supervisor](INFO): Main Thread ID is 825
2022-10-07T01:46:43.279Z,1665107203.279 [Supervisor](DEBUG): Running supervisor.
2022-10-07T01:46:43.280Z,1665107203.280 [CommandExec ThreadHandler](INFO): Handler Thread ID is 924
2022-10-07T01:46:43.280Z,1665107203.280 [CommandExec](INFO): Initializing the command executive.
2022-10-07T01:46:43.282Z,1665107203.282 [CommandLine ThreadHandler](INFO): Handler Thread ID is 925
2022-10-07T01:46:43.284Z,1665107203.284 [controlThread ThreadHandler](INFO): Handler Thread ID is 926
2022-10-07T01:46:43.284Z,1665107203.284 [controlThread](DEBUG): Initializing ControlThread
2022-10-07T01:46:43.286Z,1665107203.286 [SBIT](INFO): Initialize SBIT Component.
2022-10-07T01:46:43.287Z,1665107203.287 [SBIT](IMPORTANT): git: 2022-09-08-11-gedf6df38b
2022-10-07T01:46:43.287Z,1665107203.287 [SBIT](INFO): git hash: edf6df38bc8d0b722d0abacdffe647c9d44a259d
2022-10-07T01:46:43.287Z,1665107203.287 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2022-10-07T01:46:43.288Z,1665107203.288 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2022-10-07T01:46:43.289Z,1665107203.289 [SBIT](INFO): Beginning SBIT in 20.000000 seconds.
2022-10-07T01:46:43.290Z,1665107203.290 [IBIT](INFO): Initialize IBIT Component.
2022-10-07T01:46:43.291Z,1665107203.291 [CBIT](DEBUG): Initialize CBIT Component.
2022-10-07T01:46:43.292Z,1665107203.292 [logger ThreadHandler](INFO): Handler Thread ID is 927
2022-10-07T01:46:43.305Z,1665107203.305 [CBIT](DEBUG): Initialized mux pins.
2022-10-07T01:46:43.305Z,1665107203.305 [CBIT](DEBUG): Initializing the watchdog timer.
2022-10-07T01:46:43.317Z,1665107203.317 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 928
2022-10-07T01:46:43.318Z,1665107203.318 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2022-10-07T01:46:43.323Z,1665107203.323 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 930
2022-10-07T01:46:43.325Z,1665107203.325 [WetLabsBB2FL](INFO): Powering up
2022-10-07T01:46:43.327Z,1665107203.327 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 932
2022-10-07T01:46:43.329Z,1665107203.329 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2022-10-07T01:46:43.330Z,1665107203.330 [CBIT](DEBUG): Initializing heartbeat.
2022-10-07T01:46:43.343Z,1665107203.343 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 933
2022-10-07T01:46:43.344Z,1665107203.344 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2022-10-07T01:46:43.357Z,1665107203.357 [Onboard ThreadHandler](INFO): Handler Thread ID is 934
2022-10-07T01:46:43.375Z,1665107203.375 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 935
2022-10-07T01:46:43.397Z,1665107203.397 [DAT ThreadHandler](INFO): Handler Thread ID is 936
2022-10-07T01:46:43.401Z,1665107203.401 [CBIT](DEBUG): Deactivating GF circuits.
2022-10-07T01:46:43.401Z,1665107203.401 [CBIT](DEBUG): Deactivating emergency mode.
2022-10-07T01:46:43.402Z,1665107203.402 [DAT](INFO): Powering up
2022-10-07T01:46:43.402Z,1665107203.402 [DAT](DEBUG): Initializing DAT.
2022-10-07T01:46:43.405Z,1665107203.405 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 938
2022-10-07T01:46:43.414Z,1665107203.414 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2022-10-07T01:46:43.414Z,1665107203.414 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2022-10-07T01:46:43.414Z,1665107203.414 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2022-10-07T01:46:43.414Z,1665107203.414 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2022-10-07T01:46:43.414Z,1665107203.414 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2022-10-07T01:46:43.415Z,1665107203.415 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2022-10-07T01:46:43.415Z,1665107203.415 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2022-10-07T01:46:43.415Z,1665107203.415 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2022-10-07T01:46:43.415Z,1665107203.415 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA69M.000
2022-10-07T01:46:43.415Z,1665107203.415 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA69M.000
2022-10-07T01:46:43.437Z,1665107203.437 [CBIT](DEBUG): Backplane powered.
2022-10-07T01:46:43.441Z,1665107203.441 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2022-10-07T01:46:43.442Z,1665107203.442 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2022-10-07T01:46:43.442Z,1665107203.442 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2022-10-07T01:46:43.442Z,1665107203.442 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2022-10-07T01:46:43.443Z,1665107203.443 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2022-10-07T01:46:43.443Z,1665107203.443 [ShortestDistanceToPolygonSidesCalculator](DEBUG): Initializing.
2022-10-07T01:46:43.445Z,1665107203.445 [NavChart](DEBUG): Initialize NavChart Navigation.
2022-10-07T01:46:43.445Z,1665107203.445 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2022-10-07T01:46:43.458Z,1665107203.458 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2022-10-07T01:46:43.460Z,1665107203.460 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2022-10-07T01:46:43.460Z,1665107203.460 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2022-10-07T01:46:43.469Z,1665107203.469 [LoopControl](DEBUG): Initialize LoopControlComponent.
2022-10-07T01:46:43.470Z,1665107203.470 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2022-10-07T01:46:43.514Z,1665107203.514 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2022-10-07T01:46:43.553Z,1665107203.553 [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-10-07T01:46:43.554Z,1665107203.554 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2022-10-07T01:46:43.637Z,1665107203.637 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2022-10-07T01:46:43.639Z,1665107203.639 [Default:A.Wait](DEBUG): Construct Wait.
2022-10-07T01:46:43.654Z,1665107203.654 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2022-10-07T01:46:43.686Z,1665107203.686 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2022-10-07T01:46:43.688Z,1665107203.688 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2022-10-07T01:46:43.710Z,1665107203.710 [Default:E.Execute](DEBUG): Construct Execute.
2022-10-07T01:46:43.713Z,1665107203.713 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2022-10-07T01:46:43.737Z,1665107203.737 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,Depth_Keller,DVL_micro,NAL9602,Power24vConverter,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,ShortestDistanceToPolygonSidesCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2022-10-07T01:46:43.757Z,1665107203.757 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2022-10-07T01:46:43.781Z,1665107203.781 [Radio_Surface](INFO): Powering up
2022-10-07T01:46:44.018Z,1665107204.018 [Power24vConverter](INFO): Powering up.
2022-10-07T01:46:44.051Z,1665107204.051 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2022-10-07T01:46:44.057Z,1665107204.057 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2022-10-07T01:46:44.058Z,1665107204.058 [ElevatorServo](DEBUG): Initializing EZServoServo.
2022-10-07T01:46:44.065Z,1665107204.065 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2022-10-07T01:46:44.066Z,1665107204.066 [MassServo](DEBUG): Initializing EZServoServo.
2022-10-07T01:46:44.073Z,1665107204.073 [MassServo](DEBUG): Initializing MassServo.
2022-10-07T01:46:44.074Z,1665107204.074 [RudderServo](DEBUG): Initializing EZServoServo.
2022-10-07T01:46:44.081Z,1665107204.081 [RudderServo](DEBUG): Initializing RudderServo.
2022-10-07T01:46:44.082Z,1665107204.082 [ThrusterHE](DEBUG): Initializing EZServoServo.
2022-10-07T01:46:44.089Z,1665107204.089 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2022-10-07T01:46:45.433Z,1665107205.433 [WetLabsBB2FL](INFO): Powering down
2022-10-07T01:46:49.662Z,1665107209.662 [ThrusterHE](ERROR): Zero Speed Commanded.
2022-10-07T01:46:50.350Z,1665107210.350 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2022-10-07T01:46:57.771Z,1665107217.771 [DAT](INFO): commRate: 1200
2022-10-07T01:46:59.837Z,1665107219.837 [DAT](INFO): entering command mode
2022-10-07T01:47:00.038Z,1665107220.038 [DAT](INFO): setting verbose to 3
2022-10-07T01:47:00.291Z,1665107220.291 [DAT](INFO): set verbose to 3
2022-10-07T01:47:00.291Z,1665107220.291 [DAT](INFO): setting DatVerbose to 27440
2022-10-07T01:47:00.543Z,1665107220.543 [DAT](INFO): set DatVerbose to 27440
2022-10-07T01:47:00.543Z,1665107220.543 [DAT](INFO): setting transmit power to 8
2022-10-07T01:47:00.795Z,1665107220.795 [DAT](INFO): set transmit power to 8
2022-10-07T01:47:00.795Z,1665107220.795 [DAT](INFO): setting local address to 4
2022-10-07T01:47:01.046Z,1665107221.046 [DAT](INFO): set local address to 4
2022-10-07T01:47:01.047Z,1665107221.047 [DAT](INFO): Setting time to: 1:47:1 And date to:10/7/2022
2022-10-07T01:47:01.299Z,1665107221.299 [DAT](INFO): Local DAT time set to Fri Oct 7, 2022  01:47:01  

2022-10-07T01:47:03.997Z,1665107223.997 [SBIT](IMPORTANT): Beginning Startup BIT
2022-10-07T01:47:04.006Z,1665107224.006 [CBIT](IMPORTANT): Beginning ground fault scan
2022-10-07T01:47:12.851Z,1665107232.851 [NAL9602](INFO): Powering up NAL9602
2022-10-07T01:47:14.915Z,1665107234.915 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.053494
CHAN A1 (24V): 0.058058
CHAN A2 (12V): -0.013338
CHAN A3 (5V): -0.028226
CHAN B0 (3.3V): -0.017884
CHAN B1 (3.15aV): -0.011600
CHAN B2 (3.15bV): -0.007511
CHAN B3 (GND): -0.018320
OPEN: 0.005152
Full Scale: +/- 1 mA
2022-10-07T01:47:23.752Z,1665107243.752 [NAL9602](INFO): NAL9602 initialized
2022-10-07T01:47:58.115Z,1665107278.115 [SBIT](IMPORTANT): SBIT PASSED
2022-10-07T01:47:58.115Z,1665107278.115 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2022-10-07T01:47:58.116Z,1665107278.116 [SBIT](IMPORTANT): BPC1.loadAtStartup=0 bool;

2022-10-07T01:47:58.116Z,1665107278.116 [SBIT](IMPORTANT): DAT.loadAtStartup=1 bool;

2022-10-07T01:47:58.116Z,1665107278.116 [SBIT](IMPORTANT): DAT.sbdAddress=-1 enum;

2022-10-07T01:47:58.116Z,1665107278.116 [SBIT](IMPORTANT): Depth_Keller.offset=-0.41 decibar;

2022-10-07T01:47:58.116Z,1665107278.116 [SBIT](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2022-10-07T01:47:58.116Z,1665107278.116 [SBIT](IMPORTANT): ElevatorServo.offsetAngle=1 degree;

2022-10-07T01:47:58.116Z,1665107278.116 [SBIT](IMPORTANT): Express linearApproximation CBIT.ampHoursUsed 5.0 ampere_hour;

2022-10-07T01:47:58.117Z,1665107278.117 [SBIT](IMPORTANT): Express linearApproximation NAL9602.sigQuality 1.000000 count;

2022-10-07T01:47:58.117Z,1665107278.117 [SBIT](IMPORTANT): Express none WetLabsBB2FL.BackscatteringCoeff470nm;

2022-10-07T01:47:58.117Z,1665107278.117 [SBIT](IMPORTANT): Express none WetLabsBB2FL.BackscatteringCoeff650nm;

2022-10-07T01:47:58.117Z,1665107278.117 [SBIT](IMPORTANT): RudderServo.offsetAngle=0 degree;

2022-10-07T01:47:58.117Z,1665107278.117 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.latVertex1=34.45 degree;

2022-10-07T01:47:58.117Z,1665107278.117 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.latVertex2=34.4 degree;

2022-10-07T01:47:58.118Z,1665107278.118 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.latVertex3=34.13 degree;

2022-10-07T01:47:58.118Z,1665107278.118 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.latVertex4=34.29 degree;

2022-10-07T01:47:58.118Z,1665107278.118 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.latVertex5=nan degree;

2022-10-07T01:47:58.118Z,1665107278.118 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.loadAtStartup=1 bool;

2022-10-07T01:47:58.118Z,1665107278.118 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.lonVertex1=-120.09 degree;

2022-10-07T01:47:58.118Z,1665107278.118 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.lonVertex2=-119.28 degree;

2022-10-07T01:47:58.118Z,1665107278.118 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.lonVertex3=-119.28 degree;

2022-10-07T01:47:58.118Z,1665107278.118 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.lonVertex4=-120.11 degree;

2022-10-07T01:47:58.118Z,1665107278.118 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.lonVertex5=nan degree;

2022-10-07T01:47:58.119Z,1665107278.119 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=90 cubic_centimeter;

2022-10-07T01:47:58.119Z,1665107278.119 [SBIT](IMPORTANT): VerticalControl.massDefault=0 centimeter;

2022-10-07T01:47:58.119Z,1665107278.119 [SBIT](IMPORTANT): VerticalControl.massPositionLimitAft=-37 millimeter;

2022-10-07T01:47:58.507Z,1665107278.507 [MissionManager](IMPORTANT): Started mission Startup
2022-10-07T01:47:58.507Z,1665107278.507 [Startup] Running Loop=1
2022-10-07T01:47:58.507Z,1665107278.507 [Startup](DEBUG): Aggregate::initialize Startup
2022-10-07T01:47:58.508Z,1665107278.508 [Startup:A.GoToSurface] Running Loop=1
2022-10-07T01:47:58.508Z,1665107278.508 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-10-07T01:47:58.508Z,1665107278.508 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-10-07T01:47:58.509Z,1665107278.509 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-10-07T01:47:58.509Z,1665107278.509 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-10-07T01:47:58.510Z,1665107278.510 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-10-07T01:47:58.510Z,1665107278.510 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-10-07T01:47:58.511Z,1665107278.511 [Startup:StartupSatComms] Running Loop=1
2022-10-07T01:47:58.511Z,1665107278.511 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2022-10-07T01:47:58.511Z,1665107278.511 [Startup:StartupSatComms:A] Running Loop=1
2022-10-07T01:47:58.911Z,1665107278.911 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2022-10-07T01:48:58.719Z,1665107338.719 [Startup:StartupSatComms:A](INFO): Timed out from 2022-10-07T01:47:58.5Z
2022-10-07T01:48:58.719Z,1665107338.719 [Startup:StartupSatComms:A] Stopped
2022-10-07T01:48:58.719Z,1665107338.719 [Startup:StartupSatComms:B] Running Loop=1
2022-10-07T01:48:59.103Z,1665107339.103 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-10-07T01:49:23.268Z,1665107363.268 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004941
2022-10-07T01:49:43.576Z,1665107383.576 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2022-10-07T01:49:43.576Z,1665107383.576 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-10-07T01:49:43.620Z,1665107383.620 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-10-07T01:49:44.030Z,1665107384.030 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-10-07T01:49:44.030Z,1665107384.030 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2022-10-07T01:49:47.184Z,1665107387.184 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2022-10-07T01:49:47.184Z,1665107387.184 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000,+21.4,0000.0,1489.0,000
2022-10-07T01:49:49.265Z,1665107389.265 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20221007T013741/Courier0004.lzma
2022-10-07T01:49:50.267Z,1665107390.267 [DataOverHttps](INFO): Moved sent file to Logs/20221007T013741/Courier0004.lzma.bak
2022-10-07T01:49:50.267Z,1665107390.267 [DataOverHttps](INFO): SBD MOMSN=17237431
2022-10-07T01:49:58.919Z,1665107398.919 [Startup:StartupSatComms:B](INFO): Timed out from 2022-10-07T01:48:58.7Z
2022-10-07T01:49:58.919Z,1665107398.919 [Startup:StartupSatComms:B] Stopped
2022-10-07T01:49:58.919Z,1665107398.919 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2022-10-07T01:49:58.919Z,1665107398.919 [Startup:StartupSatComms] Stopped
2022-10-07T01:49:58.919Z,1665107398.919 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2022-10-07T01:49:58.920Z,1665107398.920 [Startup](INFO): Completed Startup
2022-10-07T01:49:58.920Z,1665107398.920 [MissionManager](INFO): Startup is completed.
2022-10-07T01:49:58.920Z,1665107398.920 [MissionManager](INFO): Uninitializing Mission Startup
2022-10-07T01:49:58.920Z,1665107398.920 [Startup] Stopped
2022-10-07T01:49:58.921Z,1665107398.921 [Startup](DEBUG): Aggregate::uninitialize Startup
2022-10-07T01:49:58.921Z,1665107398.921 [Startup:A.GoToSurface] Stopped
2022-10-07T01:49:58.925Z,1665107398.925 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-10-07T01:49:59.406Z,1665107399.406 [MissionManager](IMPORTANT): Started mission Default
2022-10-07T01:49:59.406Z,1665107399.406 [Default] Running Loop=1
2022-10-07T01:49:59.406Z,1665107399.406 [Default](DEBUG): Aggregate::initialize Default
2022-10-07T01:49:59.406Z,1665107399.406 [Default:B.GoToSurface] Running Loop=1
2022-10-07T01:49:59.406Z,1665107399.406 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-10-07T01:49:59.407Z,1665107399.407 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-10-07T01:49:59.407Z,1665107399.407 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-10-07T01:49:59.407Z,1665107399.407 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-10-07T01:49:59.408Z,1665107399.408 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-10-07T01:49:59.408Z,1665107399.408 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-10-07T01:49:59.408Z,1665107399.408 [Default:A.Wait] Running Loop=1
2022-10-07T01:49:59.408Z,1665107399.408 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-10-07T01:50:10.925Z,1665107410.925 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20221007T014633/Courier0000.lzma
2022-10-07T01:50:11.927Z,1665107411.927 [DataOverHttps](INFO): Moved sent file to Logs/20221007T014633/Courier0000.lzma.bak
2022-10-07T01:50:11.927Z,1665107411.927 [DataOverHttps](INFO): SBD MOMSN=17237433
2022-10-07T01:50:12.640Z,1665107412.640 [Default:A.Wait](INFO): Done Waiting.
2022-10-07T01:50:12.640Z,1665107412.640 [Default:A.Wait] Stopped
2022-10-07T01:50:12.640Z,1665107412.640 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-10-07T01:50:13.036Z,1665107413.036 [Default:CheckIn] Running Loop=1
2022-10-07T01:50:13.036Z,1665107413.036 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-10-07T01:50:13.036Z,1665107413.036 [Default:CheckIn:Read_GPS] Running Loop=1
2022-10-07T01:50:13.450Z,1665107413.450 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2022-10-07T01:50:45.752Z,1665107445.752 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2022-10-07T01:50:45.753Z,1665107445.753 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+21.4,00000,000
2022-10-07T01:52:26.759Z,1665107546.759 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-10-07T01:52:44.550Z,1665107564.550 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2022-10-07T01:52:44.550Z,1665107564.550 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-10-07T01:52:44.560Z,1665107564.560 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-10-07T01:52:44.983Z,1665107564.983 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-10-07T01:52:44.983Z,1665107564.983 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2022-10-07T01:55:13.242Z,1665107713.242 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-10-07T01:50:13.0Z
2022-10-07T01:55:13.243Z,1665107713.243 [Default:CheckIn:Read_GPS] Stopped
2022-10-07T01:55:13.243Z,1665107713.243 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-10-07T01:55:13.636Z,1665107713.636 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-10-07T01:55:20.561Z,1665107720.561 [DVL_micro](ERROR): Failed to parse:
:WI,-00113,-00017,-00395,+00000,A
2022-10-07T01:55:20.720Z,1665107720.720 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20221007T014633/Courier0004.lzma
2022-10-07T01:55:21.727Z,1665107721.727 [DataOverHttps](INFO): Moved sent file to Logs/20221007T014633/Courier0004.lzma.bak
2022-10-07T01:55:21.727Z,1665107721.727 [DataOverHttps](INFO): SBD MOMSN=17237436
2022-10-07T01:55:45.602Z,1665107745.602 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2022-10-07T01:55:45.602Z,1665107745.602 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-10-07T01:55:45.613Z,1665107745.613 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-10-07T01:55:46.032Z,1665107746.032 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-10-07T01:55:46.033Z,1665107746.033 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2022-10-07T01:55:46.342Z,1665107746.342 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20221007T005613/Express0011.lzma
2022-10-07T01:55:47.343Z,1665107747.343 [DataOverHttps](INFO): Moved sent file to Logs/20221007T005613/Express0011.lzma.bak
2022-10-07T01:55:47.343Z,1665107747.343 [DataOverHttps](INFO): SBD MOMSN=17237438
2022-10-07T01:55:58.929Z,1665107758.929 [DVL_micro](ERROR): only read 3 of 4 data items
2022-10-07T01:55:58.929Z,1665107758.929 [DVL_micro](ERROR): Failed to parse:
:RD,+99999.99,+9999.99,+9999.99
2022-10-07T01:56:11.108Z,1665107771.108 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20221007T005613/Express0014.lzma
2022-10-07T01:56:12.107Z,1665107772.107 [DataOverHttps](INFO): Moved sent file to Logs/20221007T005613/Express0014.lzma.bak
2022-10-07T01:56:12.107Z,1665107772.107 [DataOverHttps](INFO): SBD MOMSN=17237440
2022-10-07T01:56:24.379Z,1665107784.379 [DVL_micro](ERROR): Failed to parse:00000000000,35.0,+21.5,0000.0,1489.0,000
2022-10-07T01:56:43.486Z,1665107803.486 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20221007T005613/Express0017.lzma
2022-10-07T01:56:44.487Z,1665107804.487 [DataOverHttps](INFO): Moved sent file to Logs/20221007T005613/Express0017.lzma.bak
2022-10-07T01:56:44.487Z,1665107804.487 [DataOverHttps](INFO): SBD MOMSN=17237447
2022-10-07T01:57:08.127Z,1665107828.127 [DataOverHttps](INFO): Sending 842 bytes from file Logs/20221007T013741/Express0001.lzma
2022-10-07T01:57:09.127Z,1665107829.127 [DataOverHttps](INFO): Moved sent file to Logs/20221007T013741/Express0001.lzma.bak
2022-10-07T01:57:09.127Z,1665107829.127 [DataOverHttps](INFO): SBD MOMSN=17237449
2022-10-07T01:57:20.157Z,1665107840.157 [DVL_micro](ERROR): only read 3 of 4 data items
2022-10-07T01:57:20.157Z,1665107840.157 [DVL_micro](ERROR): Failed to parse:
:BI,-0009,-00363,+00000,I
2022-10-07T01:57:25.828Z,1665107845.828 [NAL9602](FAULT): GPS failed to acquire within timeout.
2022-10-07T01:57:25.828Z,1665107845.828 [NAL9602] Data Fault, FailCount= 1
2022-10-07T01:57:25.828Z,1665107845.828 [NAL9602](ERROR): Data Fault
2022-10-07T01:57:25.924Z,1665107845.924 [CBIT](ERROR): Data Fault in component: NAL9602
2022-10-07T01:57:26.212Z,1665107846.212 [NAL9602](INFO): Powering down
2022-10-07T01:57:27.084Z,1665107847.084 [CBIT](INFO): Clearing failed state for component NAL9602
2022-10-07T01:57:27.084Z,1665107847.084 [NAL9602] No Fault, FailCount= 1
2022-10-07T01:57:36.968Z,1665107856.968 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20221007T013741/Express0005.lzma
2022-10-07T01:57:37.987Z,1665107857.987 [DataOverHttps](INFO): Moved sent file to Logs/20221007T013741/Express0005.lzma.bak
2022-10-07T01:57:37.987Z,1665107857.987 [DataOverHttps](INFO): SBD MOMSN=17237469
2022-10-07T01:57:56.496Z,1665107876.496 [NAL9602](INFO): Powering up NAL9602
2022-10-07T01:58:01.504Z,1665107881.504 [DataOverHttps](INFO): Sending 1068 bytes from file Logs/20221007T014633/Express0001.lzma
2022-10-07T01:58:02.503Z,1665107882.503 [DataOverHttps](INFO): Moved sent file to Logs/20221007T014633/Express0001.lzma.bak
2022-10-07T01:58:02.503Z,1665107882.503 [DataOverHttps](INFO): SBD MOMSN=17237471
2022-10-07T01:58:07.407Z,1665107887.407 [NAL9602](INFO): NAL9602 initialized
2022-10-07T01:58:28.837Z,1665107908.837 [DVL_micro](ERROR): only read 2 of 4 data items
2022-10-07T01:58:28.837Z,1665107908.837 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.999,+9999..99
2022-10-07T01:58:42.974Z,1665107922.974 [DataOverHttps](INFO): Sending 195 bytes from file Logs/20221007T014633/Express0005.lzma
2022-10-07T01:58:43.975Z,1665107923.975 [DataOverHttps](INFO): Moved sent file to Logs/20221007T014633/Express0005.lzma.bak
2022-10-07T01:58:43.975Z,1665107923.975 [DataOverHttps](INFO): SBD MOMSN=17237507
2022-10-07T01:58:46.659Z,1665107926.659 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2022-10-07T01:58:46.659Z,1665107926.659 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-10-07T01:58:46.710Z,1665107926.710 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-10-07T01:58:47.049Z,1665107927.049 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-10-07T01:58:47.049Z,1665107927.049 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2022-10-07T01:58:52.679Z,1665107932.679 [Default:CheckIn:Read_Iridium] Stopped
2022-10-07T01:58:52.679Z,1665107932.679 [Default:CheckIn:C.Wait] Running Loop=1
2022-10-07T01:58:52.679Z,1665107932.679 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-10-07T02:00:33.660Z,1665108033.660 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00
2022-10-07T02:00:49.024Z,1665108049.024 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00
2022-10-07T02:01:47.642Z,1665108107.642 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2022-10-07T02:01:47.642Z,1665108107.642 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-10-07T02:01:47.653Z,1665108107.653 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-10-07T02:01:48.031Z,1665108108.031 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-10-07T02:01:48.031Z,1665108108.031 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2022-10-07T02:01:55.280Z,1665108115.280 [DVL_micro](ERROR): only read 3 of 4 data items
2022-10-07T02:01:55.280Z,1665108115.280 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.999,+9999.99
2022-10-07T02:03:31.838Z,1665108211.838 [DVL_micro](ERROR): only read 3 of 4 data items
2022-10-07T02:03:31.838Z,1665108211.838 [DVL_micro](ERROR): Failed to parse:
:BI,+00113,00399,+00000,I
2022-10-07T02:03:53.244Z,1665108233.244 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-10-07T02:03:53.244Z,1665108233.244 [Default:CheckIn:C.Wait] Stopped
2022-10-07T02:03:53.244Z,1665108233.244 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-10-07T02:03:53.244Z,1665108233.244 [Default:CheckIn:D] Running Loop=1
2022-10-07T02:03:53.658Z,1665108233.658 [Default:CheckIn:D] Stopped
2022-10-07T02:03:53.658Z,1665108233.658 [Default:CheckIn:E] Running Loop=1
2022-10-07T02:03:54.051Z,1665108234.051 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 13.904202 min 
2022-10-07T02:03:54.051Z,1665108234.051 [Default:CheckIn:E] Stopped
2022-10-07T02:03:54.051Z,1665108234.051 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-10-07T02:03:54.051Z,1665108234.051 [Default:CheckIn] Stopped
2022-10-07T02:03:54.051Z,1665108234.051 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-10-07T02:03:54.051Z,1665108234.051 [Default:CheckIn](INFO): Running loop #2
2022-10-07T02:03:54.052Z,1665108234.052 [Default:CheckIn] Running Loop=2
2022-10-07T02:03:54.052Z,1665108234.052 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-10-07T02:03:54.052Z,1665108234.052 [Default:CheckIn:Read_GPS] Running Loop=1
2022-10-07T02:04:48.597Z,1665108288.597 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2022-10-07T02:04:48.597Z,1665108288.597 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-10-07T02:04:48.616Z,1665108288.616 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-10-07T02:04:49.027Z,1665108289.027 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-10-07T02:04:49.028Z,1665108289.028 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2022-10-07T02:07:49.594Z,1665108469.594 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2022-10-07T02:07:49.594Z,1665108469.594 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-10-07T02:07:49.621Z,1665108469.621 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-10-07T02:07:50.023Z,1665108470.023 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-10-07T02:07:50.023Z,1665108470.023 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2022-10-07T02:08:09.372Z,1665108489.372 [NAL9602](FAULT): GPS failed to acquire within timeout.
2022-10-07T02:08:09.372Z,1665108489.372 [NAL9602] Data Fault, FailCount= 2
2022-10-07T02:08:09.372Z,1665108489.372 [NAL9602](ERROR): Data Fault
2022-10-07T02:08:09.388Z,1665108489.388 [CBIT](ERROR): Data Fault in component: NAL9602
2022-10-07T02:08:09.792Z,1665108489.792 [NAL9602](INFO): Powering down
2022-10-07T02:08:10.598Z,1665108490.598 [CBIT](INFO): Clearing failed state for component NAL9602
2022-10-07T02:08:10.598Z,1665108490.598 [NAL9602] No Fault, FailCount= 2
2022-10-07T02:08:40.091Z,1665108520.091 [NAL9602](INFO): Powering up NAL9602
2022-10-07T02:08:50.983Z,1665108530.983 [NAL9602](INFO): NAL9602 initialized
2022-10-07T02:08:54.252Z,1665108534.252 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-10-07T02:03:54.1Z
2022-10-07T02:08:54.252Z,1665108534.252 [Default:CheckIn:Read_GPS] Stopped
2022-10-07T02:08:54.252Z,1665108534.252 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-10-07T02:09:05.057Z,1665108545.057 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20221007T014633/Courier0007.lzma
2022-10-07T02:09:06.059Z,1665108546.059 [DataOverHttps](INFO): Moved sent file to Logs/20221007T014633/Courier0007.lzma.bak
2022-10-07T02:09:06.059Z,1665108546.059 [DataOverHttps](INFO): SBD MOMSN=17237511
2022-10-07T02:09:13.223Z,1665108553.223 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2022-10-07T02:09:13.225Z,1665108553.225 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+21.5,0000.0,1489.0I+00024,-00355,+00000,A
2022-10-07T02:09:28.861Z,1665108568.861 [DataOverHttps](INFO): Sending 305 bytes from file Logs/20221007T014633/Express0008.lzma
2022-10-07T02:09:29.863Z,1665108569.863 [DataOverHttps](INFO): Moved sent file to Logs/20221007T014633/Express0008.lzma.bak
2022-10-07T02:09:29.863Z,1665108569.863 [DataOverHttps](INFO): SBD MOMSN=17237513
2022-10-07T02:09:38.715Z,1665108578.715 [Default:CheckIn:Read_Iridium] Stopped
2022-10-07T02:09:38.715Z,1665108578.715 [Default:CheckIn:C.Wait] Running Loop=1
2022-10-07T02:09:38.716Z,1665108578.716 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-10-07T02:10:18.087Z,1665108618.087 [CommandExec](IMPORTANT): got command maintain sensor NAL9602.latitude_fix 36.8 degree
2022-10-07T02:10:18.099Z,1665108618.099 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.latitude_fix" handled in the control thread.
2022-10-07T02:10:18.100Z,1665108618.100 [CommandExec](IMPORTANT): got command maintain sensor NAL9602.longitude_fix -121.9 degree
2022-10-07T02:10:18.164Z,1665108618.164 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.longitude_fix" handled in the control thread.
2022-10-07T02:10:18.321Z,1665108618.321 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,Depth_Keller,DVL_micro,NAL9602,Power24vConverter,PAR_Licor,Depth_Keller,Maintain_NAL9602.latitude_fix,Maintain_NAL9602.longitude_fix,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,ShortestDistanceToPolygonSidesCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2022-10-07T02:10:32.608Z,1665108632.608 [CommandExec](IMPORTANT): got command set NAL9602.time_fix 1665108618 second
2022-10-07T02:10:35.162Z,1665108635.162 [CommandExec](IMPORTANT): got command get latitude
2022-10-07T02:10:35.163Z,1665108635.163 [CommandExec](IMPORTANT): latitude 36.799999 arcdeg
2022-10-07T02:10:39.288Z,1665108639.288 [CommandExec](IMPORTANT): got command get longitude
2022-10-07T02:10:39.325Z,1665108639.325 [CommandExec](IMPORTANT): longitude -121.900002 arcdeg
2022-10-07T02:10:50.185Z,1665108650.185 [NAL9602](INFO): Not Powering down - fast GPS
2022-10-07T02:11:10.251Z,1665108670.251 [DataOverHttps](IMPORTANT): SBD MTMSN=20221007T021107
2022-10-07T02:11:21.835Z,1665108681.835 [DataOverHttps](INFO): Received command: load Maintenance/sample_lab.xml;set sample_lab.CartridgeType -6 count;run
2022-10-07T02:11:21.879Z,1665108681.879 [CommandExec](IMPORTANT): got command load ./Missions/Maintenance/sample_lab.xml
2022-10-07T02:11:21.880Z,1665108681.880 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/sample_lab.xml
2022-10-07T02:11:21.922Z,1665108681.922 [MissionManager](INFO): DefineArg sample_lab.MissionTimeout = 90.000000 min
2022-10-07T02:11:21.925Z,1665108681.925 [MissionManager](INFO): DefineArg sample_lab.CartridgeType = -4.000000 count
2022-10-07T02:11:21.928Z,1665108681.928 [MissionManager](INFO): DefineArg sample_lab.NumberOfSamples = 1.000000 count
2022-10-07T02:11:21.930Z,1665108681.930 [sample_lab:A.AbortSample](DEBUG): Construct.
2022-10-07T02:11:21.934Z,1665108681.934 [sample_lab:SampleRepeater:B.ESPCartridgeSelect](DEBUG): Construct.
2022-10-07T02:11:21.939Z,1665108681.939 [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:Sample="Tethys/Sample"
         xmlns:Science="Tethys/Science"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Sample http://okeanids.mbari.org/tethys/Xml/Sample.xsd
                             Tethys/Science http://okeanids.mbari.org/tethys/Xml/Science.xsd"
       Id="sample_lab">

    <Description>
        This mission is designed to run in the lab only and triggers an ESP
        sample with specified type.
    </Description>

    <DefineArg Name="MissionTimeout"><Description>
        How long to let the mission run.
    </Description><Units:minute/><Value>90</Value></DefineArg>

    <DefineArg Name="CartridgeType"><Description>
        Specifies ESP cartridge type code (defaults to archiveHiBiomass_bac: -4)
    </Description><Units:count/><Value>-4</Value></DefineArg>

    <DefineArg Name="NumberOfSamples"><Description>
        Number of samples to take.
    </Description><Units:count/><Value>1</Value></DefineArg>

    <Timeout Duration="MissionTimeout"/>

    <Sample:AbortSample>
        <Parallel/>
    </Sample:AbortSample>

    <Aggregate Id="SampleRepeater">

        <Sequence Repeat="NumberOfSamples"/>

        <Syslog Severity="Important">Sampling ESP cartridge type <Arg Name="CartridgeType"/><Units:count/></Syslog>

        <Science:ESPCartridgeSelect>
            <Sequence/>
            <Timeout Duration="P1M"/>
            <Setting><Science:ESPCartridgeSelect.cartridgeType/><Arg Name="CartridgeType"/></Setting>
        </Science:ESPCartridgeSelect>

        <ReadDatum Id="TriggerESP">
            <Science:ESPComponent.sampling/>
        </ReadDatum>

        <ReadDatum Id="WaitForESP">
            <Science:ESPComponent.sample_number/>
        </ReadDatum>

    </Aggregate>

</Mission>


2022-10-07T02:11:21.940Z,1665108681.940 [CommandExec](IMPORTANT): Loaded ./Missions/Maintenance/sample_lab.xml
2022-10-07T02:11:23.585Z,1665108683.585 [CommandExec](IMPORTANT): got command set sample_lab.CartridgeType -6 count
2022-10-07T02:11:23.586Z,1665108683.586 [CommandExec](IMPORTANT): got command run
2022-10-07T02:11:23.593Z,1665108683.593 [CommandExec](IMPORTANT): Running 
2022-10-07T02:11:23.728Z,1665108683.728 [Default] Stopped
2022-10-07T02:11:23.728Z,1665108683.728 [Default](DEBUG): Aggregate::uninitialize Default
2022-10-07T02:11:23.728Z,1665108683.728 [Default:B.GoToSurface] Stopped
2022-10-07T02:11:23.729Z,1665108683.729 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-10-07T02:11:23.729Z,1665108683.729 [Default:CheckIn] Stopped
2022-10-07T02:11:23.729Z,1665108683.729 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-10-07T02:11:23.729Z,1665108683.729 [Default:CheckIn:C.Wait] Stopped
2022-10-07T02:11:23.729Z,1665108683.729 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-10-07T02:11:23.729Z,1665108683.729 [MissionManager](IMPORTANT): Started mission sample_lab
2022-10-07T02:11:23.730Z,1665108683.730 [sample_lab] Running Loop=1
2022-10-07T02:11:23.730Z,1665108683.730 [sample_lab](DEBUG): Aggregate::initialize sample_lab
2022-10-07T02:11:23.730Z,1665108683.730 [sample_lab:A.AbortSample] Running Loop=1
2022-10-07T02:11:23.730Z,1665108683.730 [sample_lab:A.AbortSample](INFO): Initializing AbortSample.
2022-10-07T02:11:23.730Z,1665108683.730 [sample_lab:SampleRepeater] Running Loop=1
2022-10-07T02:11:23.730Z,1665108683.730 [sample_lab:SampleRepeater](DEBUG): Aggregate::initialize sample_lab:SampleRepeater
2022-10-07T02:11:23.730Z,1665108683.730 [sample_lab:SampleRepeater:A] Running Loop=1
2022-10-07T02:11:23.731Z,1665108683.731 [sample_lab:SampleRepeater:A](IMPORTANT): Sampling ESP cartridge type -6.000000 count 
2022-10-07T02:11:23.731Z,1665108683.731 [sample_lab:SampleRepeater:A] Stopped
2022-10-07T02:11:23.731Z,1665108683.731 [sample_lab:SampleRepeater:B.ESPCartridgeSelect] Running Loop=1
2022-10-07T02:11:23.731Z,1665108683.731 [sample_lab:SampleRepeater:B.ESPCartridgeSelect](INFO): Initializing ESPCartridgeSelect.
2022-10-07T02:11:23.732Z,1665108683.732 [sample_lab:A.AbortSample] Running Loop=1
2022-10-07T02:11:24.121Z,1665108684.121 [sample_lab:SampleRepeater:B.ESPCartridgeSelect](INFO): Issuing request for ESP cartridge type: -6.
2022-10-07T02:11:24.122Z,1665108684.122 [sample_lab:SampleRepeater:B.ESPCartridgeSelect] Stopped
2022-10-07T02:11:24.122Z,1665108684.122 [sample_lab:SampleRepeater:B.ESPCartridgeSelect](INFO): Uninitializing ESPCartridgeSelect.
2022-10-07T02:11:24.122Z,1665108684.122 [sample_lab:SampleRepeater:TriggerESP] Running Loop=1
2022-10-07T02:11:24.529Z,1665108684.529 [sample_lab:SampleRepeater:TriggerESP](DEBUG): Initialize ReadDataComponent to sense ESPComponent.sampling
2022-10-07T02:11:25.303Z,1665108685.303 [ESPComponent](IMPORTANT): Setting regex for ESP Log summary: 'Selecting Cartridge|Sampled|Error|Underpressure|Overpressure|Fail|Retry|Cmd::|Sampler::|summary:'
2022-10-07T02:11:25.362Z,1665108685.362 [ESPComponent](INFO): compiled regex: "Selecting Cartridge|Sampled|Error|Underpressure|Overpressure|Fail|Retry|Cmd::|Sampler::|summary:"
2022-10-07T02:11:25.362Z,1665108685.362 [ESPComponent](DEBUG): (612) Will wait for 10.0000 before power-up/connection sequence
2022-10-07T02:11:35.402Z,1665108695.402 [ESPComponent](DEBUG): (612) Done with wait. Will continue with general power-up/connection sequence
2022-10-07T02:11:35.407Z,1665108695.407 [ESPComponent](INFO): powering up ESP
2022-10-07T02:11:35.425Z,1665108695.425 [ESPComponent](INFO): powering up ESP secondary power supply
2022-10-07T02:11:35.442Z,1665108695.442 [ESPComponent](IMPORTANT): Starting PPPD with command:/sbin/pppd xonxoff asyncmap A0000 /dev/ttyTX1 linkname esp noauth local lock 115200 10.89.5.2:10.89.5.3 persist maxfail 0 holdoff 10 lcp-echo-interval 60 lcp-echo-failure 3 proxyarp ktune deflate 12 ms-dns 8.8.8.8
2022-10-07T02:11:35.778Z,1665108695.778 [ESPComponent](IMPORTANT): Waiting for ESP to connect (timeout=150.0000)
2022-10-07T02:11:36.718Z,1665108696.718 [ESPComponent](INFO): console:

2022-10-07T02:11:37.123Z,1665108697.123 [ESPComponent](INFO): console:NAND:  256 MiB
2022-10-07T02:11:37.528Z,1665108697.528 [ESPComponent](INFO): console:
BOOTMODE: SPI
2022-10-07T02:11:37.930Z,1665108697.930 [ESPComponent](INFO): console:
reading SPI NOR..Done
2022-10-07T02:11:38.347Z,1665108698.347 [ESPComponent](INFO): console:

2022-10-07T02:11:38.738Z,1665108698.738 [ESPComponent](INFO): console:

2022-10-07T02:11:39.143Z,1665108699.143 [ESPComponent](INFO): console:
U-Boot 2009.11-mbariD (Jun 28 2020 - 19:44:45)
2022-10-07T02:11:39.547Z,1665108699.547 [ESPComponent](INFO): console:

2022-10-07T02:11:39.951Z,1665108699.951 [ESPComponent](INFO): console:
MBARI LPC31xx ESP 3G
2022-10-07T02:11:40.355Z,1665108700.355 [ESPComponent](INFO): console:
flash params are already written into flash
2022-10-07T02:11:40.763Z,1665108700.763 [ESPComponent](INFO): console:
DRAM:  64 MB
2022-10-07T02:11:41.167Z,1665108701.167 [ESPComponent](INFO): console:
In:    serial
2022-10-07T02:11:41.570Z,1665108701.570 [ESPComponent](INFO): console:
Out:   serial
2022-10-07T02:11:41.972Z,1665108701.972 [ESPComponent](INFO): console:
Err:   serial
2022-10-07T02:11:42.374Z,1665108702.374 [ESPComponent](INFO): console:
Net:   ks8851_mll
2022-10-07T02:11:42.779Z,1665108702.779 [ESPComponent](INFO): console:
Hit <ctrl-C> to stop autoboot:  1  0 
2022-10-07T02:11:43.184Z,1665108703.184 [ESPComponent](INFO): console:
4096 KiB S25FL032P at 0:0 is now current device
2022-10-07T02:11:43.587Z,1665108703.587 [ESPComponent](INFO): console:
Loading kernel from SPI flash...done
2022-10-07T02:11:43.992Z,1665108703.992 [ESPComponent](INFO): console:
## Booting kernel from Legacy Image at 31000000 ...
2022-10-07T02:11:44.395Z,1665108704.395 [ESPComponent](INFO): console:
   Image Name:   Linux-3.18.140-lpc31-mbari4
2022-10-07T02:11:44.800Z,1665108704.800 [ESPComponent](INFO): console:
   Image Type:   ARM Linux Kernel Image (uncompressed)
2022-10-07T02:11:45.203Z,1665108705.203 [ESPComponent](INFO): console:
   Data Size:    2336344 Bytes =  2.2 MB
2022-10-07T02:11:45.607Z,1665108705.607 [ESPComponent](INFO): console:
   Load Address: 30008000
2022-10-07T02:11:46.011Z,1665108706.011 [ESPComponent](INFO): console:
   Entry Point:  30008000
2022-10-07T02:11:46.415Z,1665108706.415 [ESPComponent](INFO): console:
   Verifying Checksum ... OK
2022-10-07T02:11:46.819Z,1665108706.819 [ESPComponent](INFO): console:
   Loading Kernel . OK
2022-10-07T02:11:47.223Z,1665108707.223 [ESPComponent](INFO): console:
OK
2022-10-07T02:11:47.626Z,1665108707.626 [ESPComponent](INFO): console:

2022-10-07T02:11:48.031Z,1665108708.031 [ESPComponent](INFO): console:
Starting kernel ...
2022-10-07T02:11:48.434Z,1665108708.434 [ESPComponent](INFO): console:

2022-10-07T02:11:48.839Z,1665108708.839 [ESPComponent](INFO): console:
Uncompressing Linux... Booting kernel...
2022-10-07T02:11:49.255Z,1665108709.255 [ESPComponent](INFO): console:
[    0.03] MBARI ESP 3G
2022-10-07T02:11:49.647Z,1665108709.647 [ESPComponent](INFO): console:

2022-10-07T02:11:50.051Z,1665108710.051 [ESPComponent](INFO): console:INIT: version 2.85 booting
2022-10-07T02:11:50.454Z,1665108710.454 [ESPComponent](INFO): console:

2022-10-07T02:11:50.860Z,1665108710.860 [ESPComponent](INFO): console:MBARI ESP Embedded Linux    http://www.mbari.org   mailto:brent@mbari.org
2022-10-07T02:11:51.262Z,1665108711.262 [ESPComponent](INFO): console:
ESPmv1
2022-10-07T02:11:51.667Z,1665108711.667 [ESPComponent](INFO): console:

2022-10-07T02:11:52.070Z,1665108712.070 [ESPComponent](INFO): console:INIT: Entering runlevel: 3
2022-10-07T02:11:52.474Z,1665108712.474 [ESPComponent](INFO): console:

2022-10-07T02:11:52.879Z,1665108712.879 [ESPComponent](INFO): console:Loading kernel modules
2022-10-07T02:11:53.283Z,1665108713.283 [ESPComponent](INFO): console:
Mounting filesystems and adding swapfiles listed in /etc/fstab
2022-10-07T02:11:53.686Z,1665108713.686 [ESPComponent](INFO): console:
Starting device events handler
2022-10-07T02:11:54.161Z,1665108714.161 [ESPComponent](INFO): console:

2022-10-07T02:11:57.323Z,1665108717.323 [ESPComponent](INFO): console:Set system clock to:  Thu Oct  6 19:11:55 PDT 2022
2022-10-07T02:11:57.727Z,1665108717.727 [ESPComponent](INFO): console:
Starting syslogd klogd...
2022-10-07T02:11:58.131Z,1665108718.131 [ESPComponent](INFO): console:
stopped syslogd (pid 689)
2022-10-07T02:11:58.534Z,1665108718.534 [ESPComponent](INFO): console:
Bringing up lo ...
2022-10-07T02:11:58.939Z,1665108718.939 [ESPComponent](INFO): console:
lo IP=127.0.0.1
2022-10-07T02:11:59.343Z,1665108719.343 [ESPComponent](INFO): console:
Packet forwarding enabled
2022-10-07T02:11:59.747Z,1665108719.747 [ESPComponent](INFO): console:
Bringing up wg2shore ...
2022-10-07T02:12:00.221Z,1665108720.221 [ESPComponent](INFO): console:

2022-10-07T02:12:00.555Z,1665108720.555 [ESPComponent](INFO): console:[#] ip link add wg2shore type wireguard
2022-10-07T02:12:01.029Z,1665108721.029 [ESPComponent](INFO): console:

2022-10-07T02:12:02.171Z,1665108722.171 [ESPComponent](INFO): console:[#] wg setconf wg2shore /dev/fd/63
2022-10-07T02:12:02.575Z,1665108722.575 [ESPComponent](INFO): console:
[#] ip -4 add 192.168.5.31 dev wg2shore
2022-10-07T02:12:02.979Z,1665108722.979 [ESPComponent](INFO): console:
[#] ip link set mtu 1420 up dev wg2shore
2022-10-07T02:12:03.383Z,1665108723.383 [ESPComponent](INFO): console:
[#] ip -4 route add 192.168.4.0/23 dev wg2shore
2022-10-07T02:12:03.787Z,1665108723.787 [ESPComponent](INFO): console:
Bringing up platform ...
2022-10-07T02:12:04.190Z,1665108724.190 [ESPComponent](INFO): console:
Starting netplugd...
2022-10-07T02:12:04.595Z,1665108724.595 [ESPComponent](INFO): console:
Starting portmap...
2022-10-07T02:12:04.000Z,1665108725.000 [ESPComponent](INFO): console:
Network unavailable:  Local time is Thu Oct  6 19:12:02 PDT 2022
2022-10-07T02:12:05.402Z,1665108725.402 [ESPComponent](INFO): console:
Starting chronyd...
2022-10-07T02:12:05.806Z,1665108725.806 [ESPComponent](INFO): console:
Starting thttpd...
2022-10-07T02:12:06.211Z,1665108726.211 [ESPComponent](INFO): console:
Starting dnsmasq...
2022-10-07T02:12:06.685Z,1665108726.685 [ESPComponent](INFO): console:

2022-10-07T02:12:08.230Z,1665108728.230 [ESPComponent](INFO): console:Bringing up wired ...
2022-10-07T02:12:08.636Z,1665108728.636 [ESPComponent](INFO): console:

2022-10-07T02:12:09.038Z,1665108729.038 [ESPComponent](INFO): console:

2022-10-07T02:12:09.443Z,1665108729.443 [ESPComponent](INFO): console:MBARI ESP Embedded Linux 2.75a -- 4/28/22 brent@mbari.org
2022-10-07T02:12:09.846Z,1665108729.846 [ESPComponent](INFO): console:

2022-10-07T02:12:10.252Z,1665108730.252 [ESPComponent](INFO): console:ESPmv1 login: Determining IP configuration for wired ...udhcpc (v1.11.2) started
2022-10-07T02:12:10.654Z,1665108730.654 [ESPComponent](INFO): console:
Sending discover...
2022-10-07T02:12:11.129Z,1665108731.129 [ESPComponent](INFO): console:

2022-10-07T02:12:12.272Z,1665108732.272 [ESPComponent](INFO): console:Sending discover...
2022-10-07T02:12:12.745Z,1665108732.745 [ESPComponent](INFO): console:

2022-10-07T02:12:15.502Z,1665108735.502 [ESPComponent](INFO): console:Sending discover...
2022-10-07T02:12:15.969Z,1665108735.969 [ESPComponent](INFO): console:

2022-10-07T02:12:18.331Z,1665108738.331 [ESPComponent](INFO): console:No lease, forking to background
2022-10-07T02:12:18.795Z,1665108738.795 [ESPComponent](INFO): console:

2022-10-07T02:12:19.138Z,1665108739.138 [ESPComponent](INFO): console:Bringing up direct ...
2022-10-07T02:12:19.605Z,1665108739.605 [ESPComponent](INFO): console:

2022-10-07T02:12:19.947Z,1665108739.947 [ESPComponent](INFO): console:direct IP=10.10.10.10
2022-10-07T02:12:20.421Z,1665108740.421 [ESPComponent](INFO): console:

2022-10-07T02:12:36.915Z,1665108756.915 [ESPComponent](IMPORTANT): ESP has connected as client
2022-10-07T02:12:37.840Z,1665108757.840 [ESPComponent](IMPORTANT): [sample #1] Setting cartridge argument to -6
2022-10-07T02:12:37.841Z,1665108757.841 [ESPComponent](IMPORTANT): [sample #1] ESP sampling sequence starting. Sampling state: S_WAITING_INITIAL_PROMPT
2022-10-07T02:12:37.842Z,1665108757.842 [ESPComponent](DEBUG): Writing samplingActive=1, sampleNumber=1
2022-10-07T02:12:37.865Z,1665108757.865 [sample_lab:SampleRepeater:TriggerESP] Stopped
2022-10-07T02:12:37.866Z,1665108757.866 [sample_lab:SampleRepeater:WaitForESP] Running Loop=1
2022-10-07T02:12:38.162Z,1665108758.162 [sample_lab:SampleRepeater:WaitForESP](DEBUG): Initialize ReadDataComponent to sense ESPComponent.sample_number
2022-10-07T02:12:38.939Z,1665108758.939 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PREPARING_SHOW_LOG
2022-10-07T02:12:39.344Z,1665108759.344 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PREPARING_SHOW_STATUS
2022-10-07T02:12:40.954Z,1665108760.954 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_LOADING_CARTRIDGE
2022-10-07T02:12:49.869Z,1665108769.869 [DVL_micro](ERROR): only read 3 of 4 data items
2022-10-07T02:12:49.869Z,1665108769.869 [DVL_micro](ERROR): Failed to parse:
:BI,-00028,+00050,-00353I
2022-10-07T02:13:02.307Z,1665108782.307 [CommandExec](IMPORTANT): got command set NAL9602.time_fix 1665108769 second
2022-10-07T02:13:15.296Z,1665108795.296 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_WAITING_FOR_PRIMING (@59,archive_bac)
2022-10-07T02:13:17.316Z,1665108797.316 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PRIMING (@100.0)
2022-10-07T02:13:17.720Z,1665108797.720 [ESPComponent](IMPORTANT): Filtering timeoutMinutes=92.070000 issuedCmd_=Cmd.startFiltering
2022-10-07T02:13:18.123Z,1665108798.123 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_WAITING_FOR_FILTERING (@100.0)
2022-10-07T02:13:20.566Z,1665108800.566 [DVL_micro](ERROR): only read 2 of 4 data items
2022-10-07T02:13:20.566Z,1665108800.566 [DVL_micro](ERROR): Failed to parse:
:BI,+00045,-002999.99
2022-10-07T02:15:36.695Z,1665108936.695 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_FILTERING (@0.0)
2022-10-07T02:15:37.099Z,1665108937.099 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_WAITING_FOR_PAUSED (@0.0)
2022-10-07T02:15:56.124Z,1665108956.124 [CommandExec](IMPORTANT): got command set NAL9602.time_fix 1665108937 second
2022-10-07T02:24:25.558Z,1665109465.558 [DVL_micro](ERROR): only read 3 of 4 data items
2022-10-07T02:24:25.558Z,1665109465.558 [DVL_micro](ERROR): Failed to parse:
:BI,+00053,+00004,-00279,+00BD,+00000000.0000.00,+.00,9999.0
2022-10-07T02:26:48.165Z,1665109608.165 [DVL_micro](ERROR): Failed to parse:
:WI,+00140,-00157,-00272,+00000,A
2022-10-07T02:27:26.539Z,1665109646.539 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2022-10-07T02:27:26.540Z,1665109646.540 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+22.0,0000.0,1.99
2022-10-07T02:29:08.352Z,1665109748.352 [DVL_micro](ERROR): Failed to parse:30+00000,A
2022-10-07T02:33:45.906Z,1665110025.906 [DVL_micro](ERROR): only read 0 of 4 data items
2022-10-07T02:33:45.907Z,1665110025.907 [DVL_micro](ERROR): Failed to parse:
:RD,,+9999.99,+9

2022-10-07T02:36:44.472Z,1665110204.472 [DVL_micro](ERROR): Failed to parse:
:WI,-00077,-00010,-00213,+00000,A
2022-10-07T02:43:47.079Z,1665110627.079 [DVL_micro](ERROR): only read 0 of 4 data items
2022-10-07T02:43:47.079Z,1665110627.079 [DVL_micro](ERROR): Failed to parse:
:RD9,+9999.99,+9999.99,+9999.99
2022-10-07T02:46:35.169Z,1665110795.169 [DVL_micro](ERROR): DVL BIT error. See manual. Result code: 1
2022-10-07T02:46:35.172Z,1665110795.172 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00
2022-10-07T02:47:51.902Z,1665110871.902 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2022-10-07T02:47:51.902Z,1665110871.902 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+22.4,0000.0,14
2022-10-07T02:48:17.019Z,1665110897.019 [CommandExec](IMPORTANT): got command show stack
2022-10-07T02:48:17.021Z,1665110897.021 [CommandExec](IMPORTANT): Behavior Stack:

2022-10-07T02:48:17.021Z,1665110897.021 [sample_lab](IMPORTANT): Priority 0: sample_lab:A.AbortSample
2022-10-07T02:48:17.022Z,1665110897.022 [sample_lab:SampleRepeater](IMPORTANT): Priority 1: sample_lab:SampleRepeater:WaitForESP
2022-10-07T02:49:36.515Z,1665110976.515 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PAUSED (@1000.0)
2022-10-07T02:49:36.516Z,1665110976.516 [ESPComponent](DEBUG): Writing sampleVolume=1000.000000
2022-10-07T02:49:36.919Z,1665110976.919 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PROCESSING (@1000.0)
2022-10-07T02:49:38.939Z,1665110978.939 [ESPComponent](IMPORTANT): Processing timeoutMinutes=30.000000 issuedCmd_=Cmd.startProcessing
2022-10-07T02:49:39.343Z,1665110979.343 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_WAITING_FOR_PROCESSED (@59,archive_bac)
2022-10-07T02:52:19.348Z,1665111139.348 [DVL_micro](ERROR): Failed to parse:
88,+00006,-00133,+00000,I
2022-10-07T02:52:39.548Z,1665111159.548 [DVL_micro](ERROR): only read 3 of 4 data items
2022-10-07T02:52:39.549Z,1665111159.549 [DVL_micro](ERROR): Failed to parse:
:BI,+00008,+00137,-0012,I
2022-10-07T02:54:01.166Z,1665111241.166 [DVL_micro](ERROR): Failed to parse:
:SA,-03.70,+05.50,166.0
2022-10-07T02:55:37.743Z,1665111337.743 [DVL_micro](ERROR): Failed to parse:
:SA,-03.74,+05.41,166.1
2022-10-07T02:57:17.101Z,1665111437.101 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2022-10-07T02:57:17.101Z,1665111437.101 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000,+22.5,0000.0,1489.0,000
2022-10-07T03:01:30.534Z,1665111690.534 [CommandExec](IMPORTANT): got command show stack
2022-10-07T03:01:30.534Z,1665111690.534 [CommandExec](IMPORTANT): Behavior Stack:

2022-10-07T03:01:30.535Z,1665111690.535 [sample_lab](IMPORTANT): Priority 0: sample_lab:A.AbortSample
2022-10-07T03:01:30.535Z,1665111690.535 [sample_lab:SampleRepeater](IMPORTANT): Priority 1: sample_lab:SampleRepeater:WaitForESP
2022-10-07T03:01:42.915Z,1665111702.915 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_STOPPING (@59,archive_bac)
2022-10-07T03:01:52.613Z,1665111712.613 [ESPComponent](IMPORTANT): Syncing ESP logs with command: rsync -azPq --timeout=60 esp@esp:'/var/log/esp/real /var/log/esp/real.out /var/log/esp/real.slot /var/log/esp/*.spr*' /LRAUV/ESPlogs &
2022-10-07T03:01:52.654Z,1665111712.654 [ESPComponent](INFO): closing pipe.
2022-10-07T03:01:53.015Z,1665111713.015 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_STOPPED
2022-10-07T03:02:53.632Z,1665111773.632 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2022-10-07T03:02:53.633Z,1665111773.633 [DVL_micro](ERROR): Failed to parse:
:TS,000000005.0,+22.6,0000.0,1489.0,000
2022-10-07T03:04:05.148Z,1665111845.148 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2022-10-07T03:04:05.148Z,1665111845.148 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,.6,0000.0,1489.0,000
2022-10-07T03:05:39.275Z,1665111939.275 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2022-10-07T03:05:39.275Z,1665111939.275 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+22.,1489.0,000
2022-10-07T03:06:52.782Z,1665112012.782 [ESPComponent](IMPORTANT): [sample #1] ESP sampling sequence completed normally.
2022-10-07T03:06:52.782Z,1665112012.782 [ESPComponent](DEBUG): Writing samplingActive=1, sampleNumber=1
2022-10-07T03:06:52.807Z,1665112012.807 [sample_lab:SampleRepeater:WaitForESP] Stopped
2022-10-07T03:06:52.807Z,1665112012.807 [sample_lab:SampleRepeater](INFO): Completed sample_lab:SampleRepeater
2022-10-07T03:06:52.808Z,1665112012.808 [sample_lab:SampleRepeater] Stopped
2022-10-07T03:06:52.808Z,1665112012.808 [sample_lab:SampleRepeater](DEBUG): Aggregate::uninitialize sample_lab:SampleRepeater
2022-10-07T03:06:52.808Z,1665112012.808 [sample_lab](INFO): Completed sample_lab
2022-10-07T03:06:52.808Z,1665112012.808 [MissionManager](INFO): sample_lab is completed.
2022-10-07T03:06:52.808Z,1665112012.808 [MissionManager](INFO): Uninitializing Mission sample_lab
2022-10-07T03:06:52.808Z,1665112012.808 [sample_lab] Stopped
2022-10-07T03:06:52.808Z,1665112012.808 [sample_lab](DEBUG): Aggregate::uninitialize sample_lab
2022-10-07T03:06:52.808Z,1665112012.808 [sample_lab:A.AbortSample] Stopped
2022-10-07T03:06:52.808Z,1665112012.808 [sample_lab:A.AbortSample](INFO): Uninitializing AbortSample.
2022-10-07T03:06:53.187Z,1665112013.187 [ESPComponent](IMPORTANT): [sample #1] ESP log summary report (2 messages):
@19:12:49.74 Selecting Cartridge 59
@19:49:33.35 Sampled  1000.0ml

2022-10-07T03:06:53.188Z,1665112013.188 [ESPComponent](INFO): powering down ESP
2022-10-07T03:06:53.189Z,1665112013.189 [ESPComponent](INFO): powering down ESP secondary power supply
2022-10-07T03:06:53.409Z,1665112013.409 [MissionManager](IMPORTANT): Started mission Default
2022-10-07T03:06:53.409Z,1665112013.409 [Default] Running Loop=1
2022-10-07T03:06:53.409Z,1665112013.409 [Default](DEBUG): Aggregate::initialize Default
2022-10-07T03:06:53.409Z,1665112013.409 [Default:B.GoToSurface] Running Loop=1
2022-10-07T03:06:53.410Z,1665112013.410 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-10-07T03:06:53.410Z,1665112013.410 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-10-07T03:06:53.410Z,1665112013.410 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-10-07T03:06:53.410Z,1665112013.411 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-10-07T03:06:53.411Z,1665112013.411 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-10-07T03:06:53.411Z,1665112013.411 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-10-07T03:06:53.412Z,1665112013.412 [Default:A.Wait] Running Loop=1
2022-10-07T03:06:53.412Z,1665112013.412 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-10-07T03:06:53.590Z,1665112013.590 [ESPComponent](FAULT): LCB 2 fault: LCB Watchdog Reset. Invalid Command. Hardware Overcurrent Shutdown.
2022-10-07T03:06:53.590Z,1665112013.590 [ESPComponent] Hardware Fault, FailCount= 1
2022-10-07T03:06:53.590Z,1665112013.590 [ESPComponent](ERROR): Hardware Fault
2022-10-07T03:06:53.668Z,1665112013.668 [CBIT](ERROR): Hardware Fault in component: ESPComponent
2022-10-07T03:06:54.030Z,1665112014.030 [CBIT](INFO): Clearing failed state for component ESPComponent
2022-10-07T03:06:54.030Z,1665112014.030 [ESPComponent] No Fault, FailCount= 1
2022-10-07T03:06:54.802Z,1665112014.802 [ESPComponent](INFO): powering down ESP
2022-10-07T03:06:54.802Z,1665112014.802 [ESPComponent](INFO): powering down ESP secondary power supply
2022-10-07T03:07:06.546Z,1665112026.546 [Default:A.Wait](INFO): Done Waiting.
2022-10-07T03:07:06.546Z,1665112026.546 [Default:A.Wait] Stopped
2022-10-07T03:07:06.546Z,1665112026.546 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-10-07T03:07:06.951Z,1665112026.951 [Default:CheckIn] Running Loop=1
2022-10-07T03:07:06.952Z,1665112026.952 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-10-07T03:07:06.952Z,1665112026.952 [Default:CheckIn:Read_GPS] Running Loop=1
2022-10-07T03:07:08.568Z,1665112028.568 [NAL9602](FAULT): GPS failed to acquire within timeout.
2022-10-07T03:07:08.568Z,1665112028.568 [NAL9602] Data Fault, FailCount= 3
2022-10-07T03:07:08.568Z,1665112028.568 [NAL9602](ERROR): Data Fault
2022-10-07T03:07:08.616Z,1665112028.616 [CBIT](ERROR): Data Fault in component: NAL9602
2022-10-07T03:07:08.962Z,1665112028.962 [NAL9602](INFO): Powering down
2022-10-07T03:07:09.799Z,1665112029.799 [CBIT](INFO): Clearing failed state for component NAL9602
2022-10-07T03:07:09.800Z,1665112029.800 [NAL9602] No Fault, FailCount= 3
2022-10-07T03:07:39.257Z,1665112059.257 [NAL9602](INFO): Powering up NAL9602
2022-10-07T03:07:50.169Z,1665112070.169 [NAL9602](INFO): NAL9602 initialized
2022-10-07T03:10:24.170Z,1665112224.170 [CommandExec](IMPORTANT): got command show stack
2022-10-07T03:10:24.170Z,1665112224.170 [CommandExec](IMPORTANT): Behavior Stack:

2022-10-07T03:10:24.171Z,1665112224.171 [Default](IMPORTANT): Priority 0: Default:B.GoToSurface
2022-10-07T03:10:24.171Z,1665112224.171 [Default:CheckIn](IMPORTANT): Priority 1: Default:CheckIn:Read_GPS
2022-10-07T03:10:36.166Z,1665112236.166 [CommandExec](IMPORTANT): got command quit
2022-10-07T03:10:37.173Z,1665112237.173 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2022-10-07T03:10:37.174Z,1665112237.174 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-07T03:10:37.174Z,1665112237.174 [CommandExec](INFO): Uninitializing the command executive.
2022-10-07T03:10:37.174Z,1665112237.174 [CommandExec](INFO): Uninitializing the command scheduler.
2022-10-07T03:10:37.174Z,1665112237.174 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:37.329Z,1665112237.329 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2022-10-07T03:10:37.329Z,1665112237.329 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2022-10-07T03:10:37.330Z,1665112237.330 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:37.330Z,1665112237.330 [NavChartDb](INFO): Join timeout helper Thread ID is 1194
2022-10-07T03:10:37.577Z,1665112237.577 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-07T03:10:37.578Z,1665112237.578 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:37.597Z,1665112237.597 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler
2022-10-07T03:10:37.597Z,1665112237.597 [DAT ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:37.598Z,1665112237.598 [DAT](INFO): Join timeout helper Thread ID is 1195
2022-10-07T03:10:37.605Z,1665112237.605 [DAT](INFO): Powering down
2022-10-07T03:10:37.678Z,1665112237.678 [DAT ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-07T03:10:37.678Z,1665112237.678 [DAT](INFO): Powering down
2022-10-07T03:10:37.679Z,1665112237.679 [DAT ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:37.680Z,1665112237.680 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2022-10-07T03:10:37.681Z,1665112237.681 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:37.681Z,1665112237.681 [Radio_Surface](INFO): Join timeout helper Thread ID is 1196
2022-10-07T03:10:37.978Z,1665112237.978 [Radio_Surface](INFO): Powering down
2022-10-07T03:10:37.979Z,1665112237.979 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-07T03:10:37.979Z,1665112237.979 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:37.985Z,1665112237.985 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2022-10-07T03:10:37.985Z,1665112237.985 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:37.986Z,1665112237.986 [Onboard](INFO): Join timeout helper Thread ID is 1197
2022-10-07T03:10:38.585Z,1665112238.585 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2022-10-07T03:10:42.673Z,1665112242.673 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-07T03:10:42.673Z,1665112242.673 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:42.681Z,1665112242.681 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2022-10-07T03:10:42.681Z,1665112242.681 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:42.682Z,1665112242.682 [DataOverHttps](INFO): Join timeout helper Thread ID is 1198
2022-10-07T03:10:43.605Z,1665112243.605 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-07T03:10:43.605Z,1665112243.605 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:43.618Z,1665112243.618 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2022-10-07T03:10:43.618Z,1665112243.618 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:43.618Z,1665112243.618 [BackseatComponent](INFO): Join timeout helper Thread ID is 1199
2022-10-07T03:10:43.757Z,1665112243.757 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-07T03:10:43.757Z,1665112243.757 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:43.774Z,1665112243.774 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2022-10-07T03:10:43.774Z,1665112243.774 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:43.774Z,1665112243.774 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1200
2022-10-07T03:10:44.169Z,1665112244.169 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-07T03:10:44.169Z,1665112244.169 [WetLabsBB2FL](INFO): Powering down
2022-10-07T03:10:44.170Z,1665112244.170 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:44.182Z,1665112244.182 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2022-10-07T03:10:44.182Z,1665112244.182 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:44.182Z,1665112244.182 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1201
2022-10-07T03:10:44.413Z,1665112244.413 [CTD_Seabird](INFO): Powering down
2022-10-07T03:10:44.426Z,1665112244.426 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-07T03:10:44.426Z,1665112244.426 [CTD_Seabird](INFO): Powering down
2022-10-07T03:10:44.437Z,1665112244.437 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:44.450Z,1665112244.450 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2022-10-07T03:10:44.450Z,1665112244.450 [logger ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:44.450Z,1665112244.450 [logger](INFO): Join timeout helper Thread ID is 1202
2022-10-07T03:10:44.453Z,1665112244.453 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-07T03:10:44.454Z,1665112244.454 [logger ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:44.470Z,1665112244.470 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2022-10-07T03:10:44.470Z,1665112244.470 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:44.470Z,1665112244.470 [CommandLine](INFO): Join timeout helper Thread ID is 1203
2022-10-07T03:10:44.477Z,1665112244.477 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-07T03:10:44.477Z,1665112244.477 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:44.490Z,1665112244.490 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2022-10-07T03:10:44.490Z,1665112244.490 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:44.490Z,1665112244.490 [CommandExec](INFO): Join timeout helper Thread ID is 1204
2022-10-07T03:10:44.491Z,1665112244.491 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2022-10-07T03:10:44.492Z,1665112244.492 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:44.492Z,1665112244.492 [controlThread](INFO): Join timeout helper Thread ID is 1205
2022-10-07T03:10:44.673Z,1665112244.673 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2022-10-07T03:10:44.673Z,1665112244.673 [controlThread](DEBUG): Uninitializing ControlThread
2022-10-07T03:10:44.675Z,1665112244.675 [AHRS_M2](INFO): Powering down
2022-10-07T03:10:44.817Z,1665112244.817 [DVL_micro](INFO): Powering down
2022-10-07T03:10:44.818Z,1665112244.818 [NAL9602](INFO): Powering down
2022-10-07T03:10:44.820Z,1665112244.820 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2022-10-07T03:10:44.821Z,1665112244.821 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2022-10-07T03:10:44.822Z,1665112244.822 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2022-10-07T03:10:44.822Z,1665112244.822 [MissionManager](INFO): Uninitializing Mission Default
2022-10-07T03:10:44.822Z,1665112244.822 [Default] Stopped
2022-10-07T03:10:44.822Z,1665112244.822 [Default](DEBUG): Aggregate::uninitialize Default
2022-10-07T03:10:44.822Z,1665112244.822 [Default:B.GoToSurface] Stopped
2022-10-07T03:10:44.822Z,1665112244.822 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-10-07T03:10:44.823Z,1665112244.823 [Default:CheckIn] Stopped
2022-10-07T03:10:44.823Z,1665112244.823 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-10-07T03:10:44.823Z,1665112244.823 [Default:CheckIn:Read_GPS] Stopped
2022-10-07T03:10:44.826Z,1665112244.826 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2022-10-07T03:10:44.826Z,1665112244.826 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2022-10-07T03:10:44.826Z,1665112244.826 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2022-10-07T03:10:44.827Z,1665112244.827 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2022-10-07T03:10:44.827Z,1665112244.827 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2022-10-07T03:10:44.827Z,1665112244.827 [BuoyancyServo](INFO): Powering down
2022-10-07T03:10:44.842Z,1665112244.842 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2022-10-07T03:10:44.842Z,1665112244.842 [ElevatorServo](INFO): Powering down
2022-10-07T03:10:44.843Z,1665112244.843 [MassServo](DEBUG): Uninitialize Mass Servo.
2022-10-07T03:10:44.843Z,1665112244.843 [MassServo](INFO): Powering down
2022-10-07T03:10:44.844Z,1665112244.844 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-10-07T03:10:44.844Z,1665112244.844 [RudderServo](INFO): Powering down
2022-10-07T03:10:44.846Z,1665112244.846 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2022-10-07T03:10:44.846Z,1665112244.846 [ThrusterHE](INFO): Powering down
2022-10-07T03:10:44.847Z,1665112244.847 [SBIT](DEBUG): Uninitialize SBIT Component.
2022-10-07T03:10:44.847Z,1665112244.847 [IBIT](DEBUG): Uninitialize IBIT Component.
2022-10-07T03:10:44.848Z,1665112244.848 [CBIT](DEBUG): Uninitialize CBIT Component.
2022-10-07T03:10:44.848Z,1665112244.848 [CBIT](DEBUG): Powering off loads.
2022-10-07T03:10:44.861Z,1665112244.861 [CBIT](DEBUG): Disabling WDT.
2022-10-07T03:10:44.873Z,1665112244.873 [CBIT](DEBUG): Opening all GF detection circuits.
2022-10-07T03:10:44.874Z,1665112244.874 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:45.004Z,1665112245.004 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:45.650Z,1665112245.650 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:45.922Z,1665112245.922 [DAT ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:45.927Z,1665112245.927 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:45.934Z,1665112245.934 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:45.957Z,1665112245.957 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:45.974Z,1665112245.974 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:46.217Z,1665112246.217 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-10-07T03:10:46.375Z,1665112246.375 [logger ThreadHandler](INFO): Thread cancelled.