2023-06-23T13:45:16.898Z,1687527916.898 [Supervisor](DEBUG): Initializing supervisor.
2023-06-23T13:45:16.903Z,1687527916.903 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-06-23T13:45:16.903Z,1687527916.903 [SyncHandler](INFO): Protected caller Thread ID is 831
2023-06-23T13:45:16.904Z,1687527916.904 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-06-23T13:45:16.905Z,1687527916.905 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-06-23T13:45:16.905Z,1687527916.905 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 832
2023-06-23T13:45:16.909Z,1687527916.909 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-06-23T13:45:16.928Z,1687527916.928 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-06-23T13:45:16.929Z,1687527916.929 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-06-23T13:45:16.929Z,1687527916.929 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 833
2023-06-23T13:45:16.933Z,1687527916.933 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-06-23T13:45:16.934Z,1687527916.934 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-06-23T13:45:16.935Z,1687527916.935 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 834
2023-06-23T13:45:16.937Z,1687527916.937 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-06-23T13:45:16.938Z,1687527916.938 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-06-23T13:45:16.938Z,1687527916.938 [logger ThreadHandler](INFO): Protected caller Thread ID is 835
2023-06-23T13:45:16.942Z,1687527916.942 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-06-23T13:45:16.943Z,1687527916.943 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-06-23T13:45:16.948Z,1687527916.948 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-06-23T13:45:17.044Z,1687527917.044 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-06-23T13:45:17.046Z,1687527917.046 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-06-23T13:45:17.259Z,1687527917.259 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-06-23T13:45:17.261Z,1687527917.261 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-06-23T13:45:17.511Z,1687527917.511 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-06-23T13:45:17.513Z,1687527917.513 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-06-23T13:45:17.620Z,1687527917.620 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-06-23T13:45:17.622Z,1687527917.622 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-06-23T13:45:18.329Z,1687527918.329 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-06-23T13:45:18.331Z,1687527918.331 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-06-23T13:45:18.803Z,1687527918.803 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-06-23T13:45:18.803Z,1687527918.803 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-06-23T13:45:19.321Z,1687527919.321 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-06-23T13:45:19.322Z,1687527919.322 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-06-23T13:45:19.732Z,1687527919.732 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-06-23T13:45:19.732Z,1687527919.732 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-06-23T13:45:20.081Z,1687527920.081 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-06-23T13:45:20.408Z,1687527920.408 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-06-23T13:45:20.814Z,1687527920.814 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-06-23T13:45:20.814Z,1687527920.814 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-06-23T13:45:21.031Z,1687527921.031 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-06-23T13:45:21.031Z,1687527921.031 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-06-23T13:45:21.170Z,1687527921.170 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-06-23T13:45:21.170Z,1687527921.170 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-06-23T13:45:21.251Z,1687527921.251 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-06-23T13:45:21.332Z,1687527921.332 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-06-23T13:45:21.511Z,1687527921.511 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-06-23T13:45:21.513Z,1687527921.513 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-06-23T13:45:21.732Z,1687527921.732 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-06-23T13:45:21.734Z,1687527921.734 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2023-06-23T13:45:21.738Z,1687527921.738 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2023-06-23T13:45:21.822Z,1687527921.822 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2023-06-23T13:45:22.082Z,1687527922.082 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-06-23T13:45:22.083Z,1687527922.083 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2023-06-23T13:45:22.181Z,1687527922.181 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2023-06-23T13:45:22.336Z,1687527922.336 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2023-06-23T13:45:22.437Z,1687527922.437 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2023-06-23T13:45:22.521Z,1687527922.521 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2023-06-23T13:45:22.630Z,1687527922.630 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2023-06-23T13:45:22.732Z,1687527922.732 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2023-06-23T13:45:22.885Z,1687527922.885 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2023-06-23T13:45:22.980Z,1687527922.980 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2023-06-23T13:45:23.081Z,1687527923.081 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-06-23T13:45:23.100Z,1687527923.100 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-06-23T13:45:23.285Z,1687527923.285 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-06-23T13:45:23.285Z,1687527923.285 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-06-23T13:45:23.473Z,1687527923.473 [BuoyancyServo] Loaded
2023-06-23T13:45:23.474Z,1687527923.474 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-06-23T13:45:23.495Z,1687527923.495 [ElevatorServo] Loaded
2023-06-23T13:45:23.495Z,1687527923.495 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-06-23T13:45:23.515Z,1687527923.515 [MassServo] Loaded
2023-06-23T13:45:23.516Z,1687527923.516 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-06-23T13:45:23.535Z,1687527923.535 [RudderServo] Loaded
2023-06-23T13:45:23.536Z,1687527923.536 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-06-23T13:45:23.551Z,1687527923.551 [ThrusterHE] Loaded
2023-06-23T13:45:23.552Z,1687527923.552 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2023-06-23T13:45:23.552Z,1687527923.552 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-06-23T13:45:23.553Z,1687527923.553 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-06-23T13:45:23.727Z,1687527923.727 [SBIT](DEBUG): Construct Startup Built In Test.
2023-06-23T13:45:23.743Z,1687527923.743 [SBIT] Loaded
2023-06-23T13:45:23.743Z,1687527923.743 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-06-23T13:45:23.746Z,1687527923.746 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-06-23T13:45:23.767Z,1687527923.767 [IBIT] Loaded
2023-06-23T13:45:23.767Z,1687527923.767 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-06-23T13:45:23.773Z,1687527923.773 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-06-23T13:45:23.994Z,1687527923.994 [CBIT] Loaded
2023-06-23T13:45:23.995Z,1687527923.995 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-06-23T13:45:23.995Z,1687527923.995 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-06-23T13:45:23.996Z,1687527923.996 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-06-23T13:45:24.212Z,1687527924.212 [CTD_Seabird] Loaded
2023-06-23T13:45:24.212Z,1687527924.212 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-06-23T13:45:24.213Z,1687527924.213 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406644E0
2023-06-23T13:45:24.213Z,1687527924.213 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 918
2023-06-23T13:45:24.245Z,1687527924.245 [ESPComponent] Loaded
2023-06-23T13:45:24.246Z,1687527924.246 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2023-06-23T13:45:24.266Z,1687527924.266 [PAR_Licor] Loaded
2023-06-23T13:45:24.266Z,1687527924.266 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-06-23T13:45:24.297Z,1687527924.297 [WetLabsBB2FL] Loaded
2023-06-23T13:45:24.297Z,1687527924.297 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-06-23T13:45:24.298Z,1687527924.298 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406944E0
2023-06-23T13:45:24.298Z,1687527924.298 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 919
2023-06-23T13:45:24.299Z,1687527924.299 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-06-23T13:45:24.300Z,1687527924.300 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-06-23T13:45:24.371Z,1687527924.371 [DepthRateCalculator] Loaded
2023-06-23T13:45:24.371Z,1687527924.371 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-06-23T13:45:24.377Z,1687527924.377 [PitchRateCalculator] Loaded
2023-06-23T13:45:24.377Z,1687527924.377 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-06-23T13:45:24.387Z,1687527924.387 [SpeedCalculator] Loaded
2023-06-23T13:45:24.387Z,1687527924.387 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-06-23T13:45:24.392Z,1687527924.392 [YawRateCalculator] Loaded
2023-06-23T13:45:24.392Z,1687527924.392 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-06-23T13:45:24.412Z,1687527924.412 [ElevatorOffsetCalculator] Loaded
2023-06-23T13:45:24.412Z,1687527924.412 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-06-23T13:45:24.413Z,1687527924.413 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-06-23T13:45:24.413Z,1687527924.413 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-06-23T13:45:24.538Z,1687527924.538 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-06-23T13:45:24.539Z,1687527924.539 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-06-23T13:45:24.583Z,1687527924.583 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-06-23T13:45:24.583Z,1687527924.583 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-06-23T13:45:24.721Z,1687527924.721 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-06-23T13:45:24.722Z,1687527924.722 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-06-23T13:45:24.736Z,1687527924.736 [NavChart] Loaded
2023-06-23T13:45:24.736Z,1687527924.736 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-06-23T13:45:24.742Z,1687527924.742 [UniversalFixResidualReporter] Loaded
2023-06-23T13:45:24.742Z,1687527924.742 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-06-23T13:45:24.743Z,1687527924.743 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-06-23T13:45:24.743Z,1687527924.743 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-06-23T13:45:26.374Z,1687527926.374 [AHRS_M2] Loaded
2023-06-23T13:45:26.375Z,1687527926.375 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-06-23T13:45:26.663Z,1687527926.663 [BackseatComponent] Loaded
2023-06-23T13:45:26.664Z,1687527926.664 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-06-23T13:45:26.666Z,1687527926.666 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A294E0
2023-06-23T13:45:26.666Z,1687527926.666 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 920
2023-06-23T13:45:26.669Z,1687527926.669 [LcmUniversalReporter] Loaded
2023-06-23T13:45:26.669Z,1687527926.669 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-06-23T13:45:27.453Z,1687527927.453 [BPC1] Loaded
2023-06-23T13:45:27.454Z,1687527927.454 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-06-23T13:45:27.600Z,1687527927.600 [DataOverHttps] Loaded
2023-06-23T13:45:27.600Z,1687527927.600 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-06-23T13:45:27.601Z,1687527927.601 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40A594E0
2023-06-23T13:45:27.602Z,1687527927.602 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 921
2023-06-23T13:45:27.622Z,1687527927.622 [Depth_Keller] Loaded
2023-06-23T13:45:27.623Z,1687527927.623 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-06-23T13:45:27.627Z,1687527927.627 [DropWeight] Loaded
2023-06-23T13:45:27.628Z,1687527927.628 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2023-06-23T13:45:27.666Z,1687527927.666 [DVL_micro] Loaded
2023-06-23T13:45:27.666Z,1687527927.666 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2023-06-23T13:45:27.726Z,1687527927.726 [NAL9602] Loaded
2023-06-23T13:45:27.727Z,1687527927.727 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-06-23T13:45:27.754Z,1687527927.754 [Onboard] Loaded
2023-06-23T13:45:27.754Z,1687527927.754 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-06-23T13:45:27.755Z,1687527927.755 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40A894E0
2023-06-23T13:45:27.755Z,1687527927.755 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 922
2023-06-23T13:45:27.767Z,1687527927.767 [Power24vConverter] Loaded
2023-06-23T13:45:27.768Z,1687527927.768 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-06-23T13:45:27.781Z,1687527927.781 [Radio_Surface] Loaded
2023-06-23T13:45:27.781Z,1687527927.781 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-06-23T13:45:27.782Z,1687527927.782 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40AB94E0
2023-06-23T13:45:27.783Z,1687527927.783 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 923
2023-06-23T13:45:27.796Z,1687527927.796 [Sonardyne_Nano] Loaded
2023-06-23T13:45:27.797Z,1687527927.797 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2023-06-23T13:45:27.890Z,1687527927.890 [DAT] Loaded
2023-06-23T13:45:27.890Z,1687527927.890 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2023-06-23T13:45:27.891Z,1687527927.891 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40AE94E0
2023-06-23T13:45:27.892Z,1687527927.892 [DAT ThreadHandler](INFO): Protected caller Thread ID is 924
2023-06-23T13:45:27.893Z,1687527927.893 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-06-23T13:45:27.893Z,1687527927.893 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-06-23T13:45:27.976Z,1687527927.976 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-06-23T13:45:27.976Z,1687527927.976 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-06-23T13:45:28.044Z,1687527928.044 [VerticalControl](DEBUG): Construct VerticalControl.
2023-06-23T13:45:28.095Z,1687527928.095 [VerticalControl] Loaded
2023-06-23T13:45:28.095Z,1687527928.095 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-06-23T13:45:28.098Z,1687527928.098 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-06-23T13:45:28.135Z,1687527928.135 [HorizontalControl] Loaded
2023-06-23T13:45:28.136Z,1687527928.136 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-06-23T13:45:28.138Z,1687527928.138 [SpeedControl](DEBUG): Construct SpeedControl.
2023-06-23T13:45:28.140Z,1687527928.140 [SpeedControl] Loaded
2023-06-23T13:45:28.140Z,1687527928.140 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-06-23T13:45:28.143Z,1687527928.143 [LoopControl](DEBUG): Construct LoopControl.
2023-06-23T13:45:28.143Z,1687527928.143 [LoopControl] Loaded
2023-06-23T13:45:28.144Z,1687527928.144 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-06-23T13:45:28.144Z,1687527928.144 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-06-23T13:45:28.145Z,1687527928.145 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-06-23T13:45:28.161Z,1687527928.161 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-06-23T13:45:28.162Z,1687527928.162 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-06-23T13:45:28.525Z,1687527928.525 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-06-23T13:45:28.532Z,1687527928.532 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-06-23T13:45:28.535Z,1687527928.535 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-06-23T13:45:28.546Z,1687527928.546 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-06-23T13:45:28.547Z,1687527928.547 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BF44E0
2023-06-23T13:45:28.548Z,1687527928.548 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 925
2023-06-23T13:45:28.552Z,1687527928.552 [Supervisor](INFO): Main Thread ID is 824
2023-06-23T13:45:28.553Z,1687527928.553 [Supervisor](DEBUG): Running supervisor.
2023-06-23T13:45:28.553Z,1687527928.553 [CommandExec ThreadHandler](INFO): Handler Thread ID is 926
2023-06-23T13:45:28.554Z,1687527928.554 [CommandExec](INFO): Initializing the command executive.
2023-06-23T13:45:28.555Z,1687527928.555 [CommandLine ThreadHandler](INFO): Handler Thread ID is 927
2023-06-23T13:45:28.557Z,1687527928.557 [controlThread ThreadHandler](INFO): Handler Thread ID is 928
2023-06-23T13:45:28.558Z,1687527928.558 [controlThread](DEBUG): Initializing ControlThread
2023-06-23T13:45:28.560Z,1687527928.560 [SBIT](INFO): Initialize SBIT Component.
2023-06-23T13:45:28.560Z,1687527928.560 [SBIT](IMPORTANT): git: 2023-06-22
2023-06-23T13:45:28.560Z,1687527928.560 [SBIT](INFO): git hash: 6e9037c118cca75fa4ac89fea42f4403cb21b2f0
2023-06-23T13:45:28.561Z,1687527928.561 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-06-23T13:45:28.562Z,1687527928.562 [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
2023-06-23T13:45:28.563Z,1687527928.563 [SBIT](INFO): Beginning SBIT in 109.000000 seconds.
2023-06-23T13:45:28.564Z,1687527928.564 [IBIT](INFO): Initialize IBIT Component.
2023-06-23T13:45:28.564Z,1687527928.564 [CBIT](DEBUG): Initialize CBIT Component.
2023-06-23T13:45:28.565Z,1687527928.565 [logger ThreadHandler](INFO): Handler Thread ID is 929
2023-06-23T13:45:28.576Z,1687527928.576 [CBIT](DEBUG): Initialized mux pins.
2023-06-23T13:45:28.576Z,1687527928.576 [CBIT](DEBUG): Initializing the watchdog timer.
2023-06-23T13:45:28.584Z,1687527928.584 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 930
2023-06-23T13:45:28.585Z,1687527928.585 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-06-23T13:45:28.590Z,1687527928.590 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 932
2023-06-23T13:45:28.592Z,1687527928.592 [WetLabsBB2FL](INFO): Powering up
2023-06-23T13:45:28.594Z,1687527928.594 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 934
2023-06-23T13:45:28.600Z,1687527928.600 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-06-23T13:45:28.600Z,1687527928.600 [CBIT](DEBUG): Initializing heartbeat.
2023-06-23T13:45:28.601Z,1687527928.601 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 935
2023-06-23T13:45:28.602Z,1687527928.602 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-06-23T13:45:28.608Z,1687527928.608 [Onboard ThreadHandler](INFO): Handler Thread ID is 936
2023-06-23T13:45:28.625Z,1687527928.625 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 937
2023-06-23T13:45:28.648Z,1687527928.648 [DAT ThreadHandler](INFO): Handler Thread ID is 938
2023-06-23T13:45:28.649Z,1687527928.649 [DAT](INFO): Powering up
2023-06-23T13:45:28.649Z,1687527928.649 [DAT](DEBUG): Initializing DAT.
2023-06-23T13:45:28.653Z,1687527928.653 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 940
2023-06-23T13:45:28.661Z,1687527928.661 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2MI01M.000
2023-06-23T13:45:28.661Z,1687527928.661 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2MI01M.000
2023-06-23T13:45:28.662Z,1687527928.662 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI89M.000
2023-06-23T13:45:28.662Z,1687527928.662 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI89M.000
2023-06-23T13:45:28.662Z,1687527928.662 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI11M.000
2023-06-23T13:45:28.662Z,1687527928.662 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI11M.000
2023-06-23T13:45:28.662Z,1687527928.662 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5MI07M.000
2023-06-23T13:45:28.662Z,1687527928.662 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5MI07M.000
2023-06-23T13:45:28.663Z,1687527928.663 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5OH07M.000
2023-06-23T13:45:28.663Z,1687527928.663 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5OH07M.000
2023-06-23T13:45:28.663Z,1687527928.663 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5OH31M.000
2023-06-23T13:45:28.663Z,1687527928.663 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5OH31M.000
2023-06-23T13:45:28.672Z,1687527928.672 [CBIT](DEBUG): Deactivating GF circuits.
2023-06-23T13:45:28.672Z,1687527928.672 [CBIT](DEBUG): Deactivating emergency mode.
2023-06-23T13:45:28.712Z,1687527928.712 [CBIT](DEBUG): Backplane powered.
2023-06-23T13:45:28.716Z,1687527928.716 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-06-23T13:45:28.717Z,1687527928.717 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-06-23T13:45:28.717Z,1687527928.717 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-06-23T13:45:28.717Z,1687527928.717 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-06-23T13:45:28.718Z,1687527928.718 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-06-23T13:45:28.719Z,1687527928.719 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-06-23T13:45:28.719Z,1687527928.719 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-06-23T13:45:28.726Z,1687527928.726 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-06-23T13:45:28.728Z,1687527928.728 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-06-23T13:45:28.729Z,1687527928.729 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-06-23T13:45:28.729Z,1687527928.729 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-06-23T13:45:28.730Z,1687527928.730 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-06-23T13:45:28.773Z,1687527928.773 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-06-23T13:45:28.809Z,1687527928.809 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2023-06-23T13:45:28.809Z,1687527928.809 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-06-23T13:45:28.910Z,1687527928.910 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-06-23T13:45:28.911Z,1687527928.911 [Default:A.Wait](DEBUG): Construct Wait.
2023-06-23T13:45:28.913Z,1687527928.913 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-06-23T13:45:28.955Z,1687527928.955 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-06-23T13:45:28.970Z,1687527928.970 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-06-23T13:45:28.992Z,1687527928.992 [Default:E.Execute](DEBUG): Construct Execute.
2023-06-23T13:45:28.995Z,1687527928.995 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2023-06-23T13:45:29.004Z,1687527929.004 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,Sonardyne_Nano,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2023-06-23T13:45:29.022Z,1687527929.022 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-06-23T13:45:29.032Z,1687527929.032 [Radio_Surface](INFO): Powering up
2023-06-23T13:45:29.173Z,1687527929.173 [Depth_Keller](ERROR): Pressure or depth reading out of range: 1895.994385 decibar, 0.000000 m
2023-06-23T13:45:29.181Z,1687527929.181 [Power24vConverter](INFO): Powering up.
2023-06-23T13:45:29.182Z,1687527929.182 [Sonardyne_Nano](INFO): Initializing.
2023-06-23T13:45:29.228Z,1687527929.228 [DepthRateCalculator](ERROR): Depth measurement is not active
2023-06-23T13:45:29.272Z,1687527929.272 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-06-23T13:45:29.280Z,1687527929.280 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-06-23T13:45:29.282Z,1687527929.282 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-06-23T13:45:29.288Z,1687527929.288 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-06-23T13:45:29.289Z,1687527929.289 [MassServo](DEBUG): Initializing EZServoServo.
2023-06-23T13:45:29.296Z,1687527929.296 [MassServo](DEBUG): Initializing MassServo.
2023-06-23T13:45:29.297Z,1687527929.297 [RudderServo](DEBUG): Initializing EZServoServo.
2023-06-23T13:45:29.304Z,1687527929.304 [RudderServo](DEBUG): Initializing RudderServo.
2023-06-23T13:45:29.305Z,1687527929.305 [ThrusterHE](DEBUG): Initializing EZServoServo.
2023-06-23T13:45:29.312Z,1687527929.312 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2023-06-23T13:45:30.700Z,1687527930.700 [WetLabsBB2FL](INFO): Powering down
2023-06-23T13:45:31.442Z,1687527931.442 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2023-06-23T13:45:34.905Z,1687527934.905 [ThrusterHE](ERROR): Zero Speed Commanded.
2023-06-23T13:45:35.616Z,1687527935.616 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2023-06-23T13:45:40.748Z,1687527940.748 [DAT](INFO): DAT read: 

2023-06-23T13:45:40.750Z,1687527940.750 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2023-06-23T13:45:42.261Z,1687527942.261 [DAT](INFO): DAT read: MF Frequency Band

2023-06-23T13:45:42.262Z,1687527942.262 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2023-06-23T13:45:42.263Z,1687527942.263 [DAT](INFO): DAT read: Jun 23 2023 13:45:35 

2023-06-23T13:45:43.521Z,1687527943.521 [DAT](INFO): DAT read: Features enabled [Bearing]

2023-06-23T13:45:43.522Z,1687527943.522 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC

2023-06-23T13:45:43.523Z,1687527943.523 [DAT](INFO): commRate: 1200
2023-06-23T13:45:45.588Z,1687527945.588 [DAT](INFO): entering command mode
2023-06-23T13:45:45.788Z,1687527945.788 [DAT](INFO): DAT read: 

2023-06-23T13:45:45.789Z,1687527945.789 [DAT](INFO): DAT read: user:1>

2023-06-23T13:45:45.789Z,1687527945.789 [DAT](INFO): setting verbose to 3
2023-06-23T13:45:46.041Z,1687527946.041 [DAT](INFO): DAT read: user:1>

2023-06-23T13:45:46.042Z,1687527946.042 [DAT](INFO): DAT read: Verbose         | 3           

2023-06-23T13:45:46.042Z,1687527946.042 [DAT](INFO): set verbose to 3
2023-06-23T13:45:46.043Z,1687527946.043 [DAT](INFO): setting DatVerbose to 27440
2023-06-23T13:45:46.293Z,1687527946.293 [DAT](INFO): DAT read: user:2>

2023-06-23T13:45:46.294Z,1687527946.294 [DAT](INFO): DAT read: DatVerbose      | 27440       

2023-06-23T13:45:46.294Z,1687527946.294 [DAT](INFO): set DatVerbose to 27440
2023-06-23T13:45:46.294Z,1687527946.294 [DAT](INFO): setting transmit power to 8
2023-06-23T13:45:46.545Z,1687527946.545 [DAT](INFO): DAT read: user:3>

2023-06-23T13:45:46.546Z,1687527946.546 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2023-06-23T13:45:46.546Z,1687527946.546 [DAT](INFO): set transmit power to 8
2023-06-23T13:45:46.546Z,1687527946.546 [DAT](INFO): setting local address to 5
2023-06-23T13:45:46.797Z,1687527946.797 [DAT](INFO): DAT read: user:4>

2023-06-23T13:45:46.798Z,1687527946.798 [DAT](INFO): DAT read: LocalAddr       | 5           

2023-06-23T13:45:46.798Z,1687527946.798 [DAT](INFO): set local address to 5
2023-06-23T13:45:46.799Z,1687527946.799 [DAT](INFO): Setting time to: 13:45:46 And date to:6/23/2023
2023-06-23T13:45:47.048Z,1687527947.048 [DAT](INFO): DAT read: user:5>

2023-06-23T13:45:47.049Z,1687527947.049 [DAT](INFO): DAT read: Fri Jun 23, 2023  13:45:46  

2023-06-23T13:45:47.050Z,1687527947.050 [DAT](INFO): Local DAT time set to Fri Jun 23, 2023  13:45:46  

2023-06-23T13:45:58.111Z,1687527958.111 [NAL9602](INFO): Powering up NAL9602
2023-06-23T13:46:01.280Z,1687527961.280 [MassServo](ERROR): getPosition uart error serial timeout
2023-06-23T13:46:01.280Z,1687527961.280 [MassServo](FAULT): Invalid EZ Servo response:""
2023-06-23T13:46:01.280Z,1687527961.280 [MassServo] Communications Fault, FailCount= 1
2023-06-23T13:46:01.280Z,1687527961.280 [MassServo](ERROR): Communications Fault
2023-06-23T13:46:01.285Z,1687527961.285 [CBIT](ERROR): Communications Fault in component: MassServo
2023-06-23T13:46:01.381Z,1687527961.381 [MassServo](DEBUG): Uninitialize Mass Servo.
2023-06-23T13:46:01.382Z,1687527961.382 [MassServo](INFO): Powering down
2023-06-23T13:46:02.167Z,1687527962.167 [MassServo](DEBUG): Initializing EZServoServo.
2023-06-23T13:46:02.285Z,1687527962.285 [MassServo](DEBUG): Initializing MassServo.
2023-06-23T13:46:02.290Z,1687527962.290 [CBIT](INFO): Clearing failed state for component MassServo
2023-06-23T13:46:02.290Z,1687527962.290 [MassServo] No Fault, FailCount= 1
2023-06-23T13:46:09.025Z,1687527969.025 [NAL9602](INFO): NAL9602 initialized
2023-06-23T13:46:32.854Z,1687527992.854 [NAL9602](INFO): SBD MO Status=2, MOMSN=6133, MT Status=2, MTMSN=0
2023-06-23T13:46:32.854Z,1687527992.854 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-06-23T13:46:50.259Z,1687528010.259 [NAL9602](INFO): SBD MO Status=0, MOMSN=6133, MT Status=0, MTMSN=0
2023-06-23T13:46:50.259Z,1687528010.259 [NAL9602](INFO): No messages in MT queue
2023-06-23T13:46:51.442Z,1687528011.442 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,134629.00,A,4313.61521,N,08620.31070,W,4.413,243.24,230623,,,A*7D
2023-06-23T13:46:51.446Z,1687528011.446 [NAL9602](INFO): GPS fix at 20230623T134629: (43.226920, -86.338512)
2023-06-23T13:47:18.126Z,1687528038.126 [SBIT](IMPORTANT): Beginning Startup BIT
2023-06-23T13:47:18.130Z,1687528038.130 [CBIT](IMPORTANT): Beginning ground fault scan
2023-06-23T13:47:23.366Z,1687528043.366 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-23T13:47:24.995Z,1687528044.995 [DVL_micro](ERROR): only read 2 of 4 data items
2023-06-23T13:47:24.995Z,1687528044.995 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+99999.99,+

2023-06-23T13:47:29.069Z,1687528049.069 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.005402
CHAN A1 (24V): 0.001892
CHAN A2 (12V): -0.006658
CHAN A3 (5V): -0.003697
CHAN B0 (3.3V): -0.001113
CHAN B1 (3.15aV): -0.001614
CHAN B2 (3.15bV): -0.001435
CHAN B3 (GND): -0.000421
OPEN: 0.001145
Full Scale: +/- 1 mA
2023-06-23T13:48:12.275Z,1687528092.275 [SBIT](IMPORTANT): SBIT PASSED
2023-06-23T13:48:12.275Z,1687528092.275 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-06-23T13:48:12.276Z,1687528092.276 [SBIT](IMPORTANT): Depth_Keller.offset=-0.25 decibar;

2023-06-23T13:48:12.276Z,1687528092.276 [SBIT](IMPORTANT): DropWeight.loadAtStartup=1 bool;

2023-06-23T13:48:12.276Z,1687528092.276 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=3 minute;

2023-06-23T13:48:12.277Z,1687528092.277 [SBIT](IMPORTANT): ESPComponent.simulateHardware=0 bool;

2023-06-23T13:48:12.277Z,1687528092.277 [SBIT](IMPORTANT): ElevatorServo.offsetAngle=1 degree;

2023-06-23T13:48:12.277Z,1687528092.277 [SBIT](IMPORTANT): Sonardyne_Nano.loadAtStartup=1 bool;

2023-06-23T13:48:12.277Z,1687528092.277 [SBIT](IMPORTANT): StratificationFrontDetector.loadAtStartup=0 bool;

2023-06-23T13:48:12.277Z,1687528092.277 [SBIT](IMPORTANT): StratificationFrontDetector.threshold_VTHI=0.05 celsius;

2023-06-23T13:48:12.277Z,1687528092.277 [SBIT](IMPORTANT): StratificationFrontDetector.verbosity=1 count;

2023-06-23T13:48:12.277Z,1687528092.277 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=171.613872 cubic_centimeter;

2023-06-23T13:48:12.277Z,1687528092.277 [SBIT](IMPORTANT): VerticalControl.massDefault=22.341465 millimeter;

2023-06-23T13:48:12.278Z,1687528092.278 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth3=20 meter;

2023-06-23T13:48:12.278Z,1687528092.278 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth4=30 meter;

2023-06-23T13:48:12.278Z,1687528092.278 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.loadAtStartup=0 bool;

2023-06-23T13:48:12.688Z,1687528092.688 [MissionManager](IMPORTANT): Started mission Startup
2023-06-23T13:48:12.688Z,1687528092.688 [Startup] Running Loop=1
2023-06-23T13:48:12.688Z,1687528092.688 [Startup](DEBUG): Aggregate::initialize Startup
2023-06-23T13:48:12.688Z,1687528092.688 [Startup:A.GoToSurface] Running Loop=1
2023-06-23T13:48:12.688Z,1687528092.688 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-06-23T13:48:12.689Z,1687528092.689 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-06-23T13:48:12.689Z,1687528092.689 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-06-23T13:48:12.690Z,1687528092.690 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-06-23T13:48:12.690Z,1687528092.690 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-06-23T13:48:12.691Z,1687528092.691 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-06-23T13:48:12.696Z,1687528092.696 [Startup:StartupSatComms] Running Loop=1
2023-06-23T13:48:12.696Z,1687528092.696 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-06-23T13:48:12.696Z,1687528092.696 [Startup:StartupSatComms:A] Running Loop=1
2023-06-23T13:48:13.062Z,1687528093.062 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-06-23T13:48:14.667Z,1687528094.667 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,134752.00,A,4313.61525,N,08620.31622,W,0.175,244.63,230623,,,A*70
2023-06-23T13:48:14.670Z,1687528094.670 [NAL9602](INFO): GPS fix at 20230623T134752: (43.226921, -86.338604)
2023-06-23T13:48:14.679Z,1687528094.679 [Startup:StartupSatComms:A] Stopped
2023-06-23T13:48:14.679Z,1687528094.679 [Startup:StartupSatComms:B] Running Loop=1
2023-06-23T13:48:15.140Z,1687528095.140 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-06-23T13:48:34.475Z,1687528114.475 [NAL9602](INFO): SBD MO Status=1, MOMSN=6134, MT Status=0, MTMSN=0
2023-06-23T13:48:34.524Z,1687528114.524 [NAL9602](INFO): Sent 18 bytes from file Logs/20230623T131503/Courier0019.lzma
2023-06-23T13:48:34.524Z,1687528114.524 [NAL9602](INFO): Packets left to send: 0
2023-06-23T13:48:45.202Z,1687528125.202 [NAL9602](INFO): SBD MO Status=1, MOMSN=6135, MT Status=0, MTMSN=0
2023-06-23T13:48:45.260Z,1687528125.260 [NAL9602](INFO): Sent 268 bytes from file Logs/20230623T134516/Courier0000.lzma
2023-06-23T13:48:45.260Z,1687528125.260 [NAL9602](INFO): Packets left to send: 0
2023-06-23T13:48:55.058Z,1687528135.058 [NAL9602](INFO): SBD MO Status=1, MOMSN=6136, MT Status=0, MTMSN=0
2023-06-23T13:48:55.112Z,1687528135.112 [NAL9602](INFO): Sent 18 bytes from file Logs/20230623T131503/Express0020.lzma
2023-06-23T13:48:55.112Z,1687528135.112 [NAL9602](INFO): Packets left to send: 0
2023-06-23T13:49:07.938Z,1687528147.938 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004276
2023-06-23T13:49:08.255Z,1687528148.255 [NAL9602](INFO): SBD MO Status=1, MOMSN=6137, MT Status=0, MTMSN=0
2023-06-23T13:49:08.316Z,1687528148.316 [NAL9602](INFO): Sent 332 bytes from file Logs/20230623T134516/Express0001.lzma
2023-06-23T13:49:08.316Z,1687528148.316 [NAL9602](INFO): Packets left to send: 3
2023-06-23T13:49:08.361Z,1687528148.361 [Startup:StartupSatComms:B] Stopped
2023-06-23T13:49:08.361Z,1687528148.361 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-06-23T13:49:08.361Z,1687528148.361 [Startup:StartupSatComms] Stopped
2023-06-23T13:49:08.361Z,1687528148.361 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-06-23T13:49:08.362Z,1687528148.362 [Startup](INFO): Completed Startup
2023-06-23T13:49:08.362Z,1687528148.362 [MissionManager](INFO): Startup is completed.
2023-06-23T13:49:08.362Z,1687528148.362 [MissionManager](INFO): Uninitializing Mission Startup
2023-06-23T13:49:08.362Z,1687528148.362 [Startup] Stopped
2023-06-23T13:49:08.363Z,1687528148.363 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-06-23T13:49:08.363Z,1687528148.363 [Startup:A.GoToSurface] Stopped
2023-06-23T13:49:08.363Z,1687528148.363 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-06-23T13:49:08.650Z,1687528148.650 [MissionManager](IMPORTANT): Started mission Default
2023-06-23T13:49:08.651Z,1687528148.651 [Default] Running Loop=1
2023-06-23T13:49:08.651Z,1687528148.651 [Default](DEBUG): Aggregate::initialize Default
2023-06-23T13:49:08.651Z,1687528148.651 [Default:B.GoToSurface] Running Loop=1
2023-06-23T13:49:08.651Z,1687528148.651 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-06-23T13:49:08.651Z,1687528148.651 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-06-23T13:49:08.652Z,1687528148.652 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-06-23T13:49:08.652Z,1687528148.652 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-06-23T13:49:08.653Z,1687528148.653 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-06-23T13:49:08.653Z,1687528148.653 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-06-23T13:49:08.653Z,1687528148.653 [Default:A.Wait] Running Loop=1
2023-06-23T13:49:08.653Z,1687528148.653 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-06-23T13:49:21.978Z,1687528161.978 [Default:A.Wait](INFO): Done Waiting.
2023-06-23T13:49:21.979Z,1687528161.979 [Default:A.Wait] Stopped
2023-06-23T13:49:21.979Z,1687528161.979 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-06-23T13:49:22.384Z,1687528162.384 [Default:CheckIn] Running Loop=1
2023-06-23T13:49:22.384Z,1687528162.384 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-23T13:49:22.384Z,1687528162.384 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-23T13:49:22.791Z,1687528162.791 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-06-23T13:49:24.391Z,1687528164.391 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,134902.00,A,4313.61423,N,08620.31094,W,0.039,244.63,230623,,,A*7E
2023-06-23T13:49:24.402Z,1687528164.402 [NAL9602](INFO): GPS fix at 20230623T134902: (43.226904, -86.338516)
2023-06-23T13:49:24.411Z,1687528164.411 [Default:CheckIn:Read_GPS] Stopped
2023-06-23T13:49:24.411Z,1687528164.411 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-23T13:49:24.832Z,1687528164.832 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-06-23T13:49:32.103Z,1687528172.103 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230623T134516/Courier0004.lzma
2023-06-23T13:49:33.106Z,1687528173.106 [DataOverHttps](INFO): Moved sent file to Logs/20230623T134516/Courier0004.lzma.bak
2023-06-23T13:49:33.106Z,1687528173.106 [DataOverHttps](INFO): SBD MOMSN=18420934
2023-06-23T13:49:49.245Z,1687528189.245 [DataOverHttps](INFO): Sending 1020 bytes from file Logs/20230623T134516/Express0001.lzma
2023-06-23T13:49:50.245Z,1687528190.245 [DataOverHttps](INFO): Moved sent file to Logs/20230623T134516/Express0001.lzma.bak
2023-06-23T13:49:50.246Z,1687528190.246 [DataOverHttps](INFO): SBD MOMSN=18420937
2023-06-23T13:49:56.368Z,1687528196.368 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-23T13:50:14.115Z,1687528214.115 [DataOverHttps](INFO): Sending 104 bytes from file Logs/20230623T134516/Express0005.lzma
2023-06-23T13:50:15.118Z,1687528215.118 [DataOverHttps](INFO): Moved sent file to Logs/20230623T134516/Express0005.lzma.bak
2023-06-23T13:50:15.118Z,1687528215.118 [DataOverHttps](INFO): SBD MOMSN=18420964
2023-06-23T13:50:16.813Z,1687528216.813 [Default:CheckIn:Read_Iridium] Stopped
2023-06-23T13:50:16.813Z,1687528216.813 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-23T13:50:16.813Z,1687528216.813 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-23T13:50:38.838Z,1687528238.838 [CommandExec](IMPORTANT): got command configSet Depth_Keller.offset -.3 decibar persist
2023-06-23T13:50:41.989Z,1687528241.989 [CommandExec](IMPORTANT): got command get depth
2023-06-23T13:50:41.989Z,1687528241.989 [CommandExec](IMPORTANT): depth -0.002050 m
2023-06-23T13:50:51.537Z,1687528251.537 [DVL_micro](ERROR): Failed to parse:
0000000000,35.0,+28.5,0000.0,1489.0,000
2023-06-23T13:50:56.915Z,1687528256.915 [CommandExec](IMPORTANT): got command configSet Depth_Keller.offset -.35 decibar persist
2023-06-23T13:50:59.269Z,1687528259.269 [CommandExec](IMPORTANT): got command get depth
2023-06-23T13:50:59.270Z,1687528259.270 [CommandExec](IMPORTANT): depth -0.082150 m
2023-06-23T13:53:25.325Z,1687528405.325 [DVL_micro](ERROR): only read 2 of 4 data items
2023-06-23T13:53:25.325Z,1687528405.325 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,++9999.99
2023-06-23T13:54:05.803Z,1687528445.803 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2023-06-23T13:54:05.806Z,1687528445.806 [BPC1](INFO): Received data from all battery sticks.
2023-06-23T13:54:16.503Z,1687528456.503 [CommandExec](IMPORTANT): got command get Sonardyne_Nano.chargePercent
2023-06-23T13:54:16.504Z,1687528456.504 [CommandExec](IMPORTANT): Sonardyne_Nano.chargePercent 0.000000 %
2023-06-23T13:55:17.365Z,1687528517.365 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-23T13:55:17.365Z,1687528517.365 [Default:CheckIn:C.Wait] Stopped
2023-06-23T13:55:17.365Z,1687528517.365 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-23T13:55:17.365Z,1687528517.365 [Default:CheckIn:D] Running Loop=1
2023-06-23T13:55:17.772Z,1687528517.772 [Default:CheckIn:D] Stopped
2023-06-23T13:55:17.772Z,1687528517.772 [Default:CheckIn:E] Running Loop=1
2023-06-23T13:55:18.169Z,1687528518.169 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.152013 min 
2023-06-23T13:55:18.169Z,1687528518.169 [Default:CheckIn:E] Stopped
2023-06-23T13:55:18.169Z,1687528518.169 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-23T13:55:18.169Z,1687528518.169 [Default:CheckIn] Stopped
2023-06-23T13:55:18.170Z,1687528518.170 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-23T13:55:18.170Z,1687528518.170 [Default:CheckIn](INFO): Running loop #2
2023-06-23T13:55:18.170Z,1687528518.170 [Default:CheckIn] Running Loop=2
2023-06-23T13:55:18.170Z,1687528518.170 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-23T13:55:18.170Z,1687528518.170 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-23T13:55:20.182Z,1687528520.182 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,135501.00,A,4313.61581,N,08620.31838,W,0.019,244.63,230623,,,A*75
2023-06-23T13:55:20.184Z,1687528520.184 [NAL9602](INFO): GPS fix at 20230623T135501: (43.226930, -86.338640)
2023-06-23T13:55:20.194Z,1687528520.194 [Default:CheckIn:Read_GPS] Stopped
2023-06-23T13:55:20.194Z,1687528520.194 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-23T13:55:26.244Z,1687528526.244 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-06-23T13:55:26.245Z,1687528526.245 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+28.8,0000.0,1489.0,,+01267,-00009,+00605,+00000,A
2023-06-23T13:55:27.535Z,1687528527.535 [DataOverHttps](INFO): Sending 201 bytes from file Logs/20230623T134516/Courier0007.lzma
2023-06-23T13:55:28.538Z,1687528528.538 [DataOverHttps](INFO): Moved sent file to Logs/20230623T134516/Courier0007.lzma.bak
2023-06-23T13:55:28.538Z,1687528528.538 [DataOverHttps](INFO): SBD MOMSN=18420984
2023-06-23T13:55:37.958Z,1687528537.958 [NAL9602](INFO): SBD MO Status=0, MOMSN=6138, MT Status=0, MTMSN=0
2023-06-23T13:55:37.958Z,1687528537.958 [NAL9602](INFO): No messages in MT queue
2023-06-23T13:55:44.460Z,1687528544.460 [DataOverHttps](INFO): Sending 327 bytes from file Logs/20230623T134516/Express0008.lzma
2023-06-23T13:55:45.579Z,1687528545.579 [DataOverHttps](INFO): Moved sent file to Logs/20230623T134516/Express0008.lzma.bak
2023-06-23T13:55:45.579Z,1687528545.579 [DataOverHttps](INFO): SBD MOMSN=18420988
2023-06-23T13:55:47.276Z,1687528547.276 [Default:CheckIn:Read_Iridium] Stopped
2023-06-23T13:55:47.276Z,1687528547.276 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-23T13:55:47.276Z,1687528547.276 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-23T13:56:08.698Z,1687528568.698 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-23T13:57:44.475Z,1687528664.475 [DVL_micro](ERROR): only read 3 of 4 data items
2023-06-23T13:57:44.475Z,1687528664.475 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,+9999.99,
2023-06-23T13:57:49.314Z,1687528669.314 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-06-23T13:57:49.314Z,1687528669.314 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000,+28.9,0000.0,1489.0,000
2023-06-23T14:00:48.076Z,1687528848.076 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-23T14:00:48.076Z,1687528848.076 [Default:CheckIn:C.Wait] Stopped
2023-06-23T14:00:48.076Z,1687528848.076 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-23T14:00:48.076Z,1687528848.076 [Default:CheckIn:D] Running Loop=1
2023-06-23T14:00:48.484Z,1687528848.484 [Default:CheckIn:D] Stopped
2023-06-23T14:00:48.484Z,1687528848.484 [Default:CheckIn:E] Running Loop=1
2023-06-23T14:00:48.877Z,1687528848.877 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.663890 min 
2023-06-23T14:00:48.877Z,1687528848.877 [Default:CheckIn:E] Stopped
2023-06-23T14:00:48.877Z,1687528848.877 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-23T14:00:48.878Z,1687528848.878 [Default:CheckIn] Stopped
2023-06-23T14:00:48.878Z,1687528848.878 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-23T14:00:48.878Z,1687528848.878 [Default:CheckIn](INFO): Running loop #3
2023-06-23T14:00:48.878Z,1687528848.878 [Default:CheckIn] Running Loop=3
2023-06-23T14:00:48.878Z,1687528848.878 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-23T14:00:48.878Z,1687528848.878 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-23T14:00:50.887Z,1687528850.887 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,140032.00,A,4313.61035,N,08620.32264,W,0.058,244.63,230623,,,D*78
2023-06-23T14:00:50.898Z,1687528850.898 [NAL9602](INFO): GPS fix at 20230623T140032: (43.226839, -86.338711)
2023-06-23T14:00:50.908Z,1687528850.908 [Default:CheckIn:Read_GPS] Stopped
2023-06-23T14:00:50.908Z,1687528850.908 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-23T14:01:01.487Z,1687528861.487 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230623T134516/Courier0010.lzma
2023-06-23T14:01:02.490Z,1687528862.490 [DataOverHttps](INFO): Moved sent file to Logs/20230623T134516/Courier0010.lzma.bak
2023-06-23T14:01:02.490Z,1687528862.490 [DataOverHttps](INFO): SBD MOMSN=18421034
2023-06-23T14:01:07.099Z,1687528867.099 [NAL9602](INFO): SBD MO Status=0, MOMSN=6139, MT Status=0, MTMSN=0
2023-06-23T14:01:07.099Z,1687528867.099 [NAL9602](INFO): No messages in MT queue
2023-06-23T14:01:18.428Z,1687528878.428 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20230623T134516/Express0011.lzma
2023-06-23T14:01:19.430Z,1687528879.430 [DataOverHttps](INFO): Moved sent file to Logs/20230623T134516/Express0011.lzma.bak
2023-06-23T14:01:19.430Z,1687528879.430 [DataOverHttps](INFO): SBD MOMSN=18421037
2023-06-23T14:01:21.257Z,1687528881.257 [Default:CheckIn:Read_Iridium] Stopped
2023-06-23T14:01:21.257Z,1687528881.257 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-23T14:01:21.257Z,1687528881.257 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-23T14:01:25.697Z,1687528885.697 [DVL_micro](ERROR): only read 3 of 4 data items
2023-06-23T14:01:25.698Z,1687528885.698 [DVL_micro](ERROR): Failed to parse:
:BI,+01385,+00053,+0070,I
2023-06-23T14:01:37.805Z,1687528897.805 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-23T14:02:15.860Z,1687528935.860 [DVL_micro](ERROR): Failed to parse:
:SA,-03.64,+16.64,345.1
2023-06-23T14:02:46.149Z,1687528966.149 [DVL_micro](ERROR): only read 3 of 4 data items
2023-06-23T14:02:46.149Z,1687528966.149 [DVL_micro](ERROR): Failed to parse:
:BI,+0116,+00763,+00000,I
2023-06-23T14:03:31.515Z,1687529011.515 [DVL_micro](ERROR): only read 3 of 4 data items
2023-06-23T14:03:31.515Z,1687529011.515 [DVL_micro](ERROR): Failed to parse:
:BI,+01275,+01309,+01035,+000D,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00
2023-06-23T14:06:21.798Z,1687529181.798 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-23T14:06:21.798Z,1687529181.798 [Default:CheckIn:C.Wait] Stopped
2023-06-23T14:06:21.798Z,1687529181.798 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-23T14:06:21.798Z,1687529181.798 [Default:CheckIn:D] Running Loop=1
2023-06-23T14:06:22.223Z,1687529182.223 [Default:CheckIn:D] Stopped
2023-06-23T14:06:22.223Z,1687529182.223 [Default:CheckIn:E] Running Loop=1
2023-06-23T14:06:22.602Z,1687529182.602 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.226200 min 
2023-06-23T14:06:22.602Z,1687529182.602 [Default:CheckIn:E] Stopped
2023-06-23T14:06:22.602Z,1687529182.602 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-23T14:06:22.602Z,1687529182.602 [Default:CheckIn] Stopped
2023-06-23T14:06:22.603Z,1687529182.603 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-23T14:06:22.603Z,1687529182.603 [Default:CheckIn](INFO): Running loop #4
2023-06-23T14:06:22.603Z,1687529182.603 [Default:CheckIn] Running Loop=4
2023-06-23T14:06:22.603Z,1687529182.603 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-23T14:06:22.603Z,1687529182.603 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-23T14:06:24.621Z,1687529184.621 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,140605.00,A,4313.61751,N,08620.32027,W,0.214,266.88,230623,,,A*70
2023-06-23T14:06:24.623Z,1687529184.623 [NAL9602](INFO): GPS fix at 20230623T140605: (43.226959, -86.338671)
2023-06-23T14:06:24.633Z,1687529184.633 [Default:CheckIn:Read_GPS] Stopped
2023-06-23T14:06:24.633Z,1687529184.633 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-23T14:06:31.483Z,1687529191.483 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230623T134516/Courier0013.lzma
2023-06-23T14:06:32.486Z,1687529192.486 [DataOverHttps](INFO): Moved sent file to Logs/20230623T134516/Courier0013.lzma.bak
2023-06-23T14:06:32.486Z,1687529192.486 [DataOverHttps](INFO): SBD MOMSN=18421048
2023-06-23T14:06:28.990Z,1687529188.990 [DataOverHttps](INFO): Sending 127 bytes from file Logs/20230623T134516/Express0014.lzma
2023-06-23T14:06:29.992Z,1687529189.992 [DataOverHttps](INFO): Moved sent file to Logs/20230623T134516/Express0014.lzma.bak
2023-06-23T14:06:29.992Z,1687529189.992 [DataOverHttps](INFO): SBD MOMSN=18421054
2023-06-23T14:06:35.132Z,1687529195.132 [DVL_micro](ERROR): No DVL communication! Re-initializing
2023-06-23T14:06:35.132Z,1687529195.132 [DVL_micro] Communications Fault, FailCount= 1
2023-06-23T14:06:35.132Z,1687529195.132 [DVL_micro](ERROR): Communications Fault
2023-06-23T14:06:35.176Z,1687529195.176 [NAL9602](INFO): SBD MO Status=0, MOMSN=6140, MT Status=0, MTMSN=0
2023-06-23T14:06:35.177Z,1687529195.177 [NAL9602](INFO): No messages in MT queue
2023-06-23T14:06:35.192Z,1687529195.192 [Default:CheckIn:Read_Iridium] Stopped
2023-06-23T14:06:35.193Z,1687529195.193 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-23T14:06:35.193Z,1687529195.193 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-23T14:06:35.229Z,1687529195.229 [CBIT](ERROR): Communications Fault in component: DVL_micro
2023-06-23T14:06:35.655Z,1687529195.655 [DVL_micro](INFO): Powering down
2023-06-23T14:06:36.477Z,1687529196.477 [CBIT](INFO): Clearing failed state for component DVL_micro
2023-06-23T14:06:36.477Z,1687529196.477 [DVL_micro] No Fault, FailCount= 1
2023-06-23T14:06:41.896Z,1687529201.896 [DataOverHttps](IMPORTANT): SBD MTMSN=20230623T140641
2023-06-23T14:06:50.011Z,1687529210.011 [DataOverHttps](INFO): Received command: restart sys
2023-06-23T14:06:50.052Z,1687529210.052 [CommandExec](IMPORTANT): got command restart system
2023-06-23T14:06:52.115Z,1687529212.115 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2023-06-23T14:06:52.115Z,1687529212.115 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-23T14:06:52.116Z,1687529212.116 [CommandExec](INFO): Uninitializing the command executive.
2023-06-23T14:06:52.116Z,1687529212.116 [CommandExec](INFO): Uninitializing the command scheduler.
2023-06-23T14:06:52.116Z,1687529212.116 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:52.199Z,1687529212.199 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2023-06-23T14:06:52.199Z,1687529212.199 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2023-06-23T14:06:52.199Z,1687529212.199 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:52.200Z,1687529212.200 [NavChartDb](INFO): Join timeout helper Thread ID is 1130
2023-06-23T14:06:52.347Z,1687529212.347 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-23T14:06:52.347Z,1687529212.347 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:52.359Z,1687529212.359 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler
2023-06-23T14:06:52.359Z,1687529212.359 [DAT ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:52.359Z,1687529212.359 [DAT](INFO): Join timeout helper Thread ID is 1131
2023-06-23T14:06:52.571Z,1687529212.571 [DAT](INFO): Powering down
2023-06-23T14:06:52.643Z,1687529212.643 [DAT ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-23T14:06:52.644Z,1687529212.644 [DAT](INFO): Powering down
2023-06-23T14:06:52.645Z,1687529212.645 [DAT ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:52.651Z,1687529212.651 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2023-06-23T14:06:52.651Z,1687529212.651 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:52.651Z,1687529212.651 [Radio_Surface](INFO): Join timeout helper Thread ID is 1132
2023-06-23T14:06:52.799Z,1687529212.799 [Radio_Surface](INFO): Powering down
2023-06-23T14:06:52.800Z,1687529212.800 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-23T14:06:52.800Z,1687529212.800 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:52.803Z,1687529212.803 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2023-06-23T14:06:52.803Z,1687529212.803 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:52.803Z,1687529212.803 [Onboard](INFO): Join timeout helper Thread ID is 1133
2023-06-23T14:06:53.019Z,1687529213.019 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2023-06-23T14:06:54.727Z,1687529214.727 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-23T14:06:54.727Z,1687529214.727 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:54.743Z,1687529214.743 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2023-06-23T14:06:54.743Z,1687529214.743 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:54.743Z,1687529214.743 [DataOverHttps](INFO): Join timeout helper Thread ID is 1134
2023-06-23T14:06:55.027Z,1687529215.027 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-23T14:06:55.027Z,1687529215.027 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:55.040Z,1687529215.040 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2023-06-23T14:06:55.040Z,1687529215.040 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:55.040Z,1687529215.040 [BackseatComponent](INFO): Join timeout helper Thread ID is 1135
2023-06-23T14:06:55.171Z,1687529215.171 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-23T14:06:55.171Z,1687529215.171 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:55.186Z,1687529215.186 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2023-06-23T14:06:55.186Z,1687529215.186 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:55.187Z,1687529215.187 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1136
2023-06-23T14:06:55.651Z,1687529215.651 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-23T14:06:55.651Z,1687529215.651 [WetLabsBB2FL](INFO): Powering down
2023-06-23T14:06:55.652Z,1687529215.652 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:55.663Z,1687529215.663 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2023-06-23T14:06:55.663Z,1687529215.663 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:55.664Z,1687529215.664 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1137
2023-06-23T14:06:56.375Z,1687529216.375 [CTD_Seabird](INFO): Powering down
2023-06-23T14:06:56.387Z,1687529216.387 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-23T14:06:56.387Z,1687529216.387 [CTD_Seabird](INFO): Powering down
2023-06-23T14:06:56.399Z,1687529216.399 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:56.415Z,1687529216.415 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2023-06-23T14:06:56.415Z,1687529216.415 [logger ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:56.416Z,1687529216.416 [logger](INFO): Join timeout helper Thread ID is 1138
2023-06-23T14:06:56.427Z,1687529216.427 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-23T14:06:56.427Z,1687529216.427 [logger ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:56.435Z,1687529216.435 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2023-06-23T14:06:56.435Z,1687529216.435 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:56.436Z,1687529216.436 [CommandLine](INFO): Join timeout helper Thread ID is 1139
2023-06-23T14:06:56.471Z,1687529216.471 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-23T14:06:56.471Z,1687529216.471 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:56.475Z,1687529216.475 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2023-06-23T14:06:56.475Z,1687529216.475 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:56.476Z,1687529216.476 [CommandExec](INFO): Join timeout helper Thread ID is 1140
2023-06-23T14:06:56.477Z,1687529216.477 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2023-06-23T14:06:56.477Z,1687529216.477 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:56.477Z,1687529216.477 [controlThread](INFO): Join timeout helper Thread ID is 1141
2023-06-23T14:06:56.551Z,1687529216.551 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-23T14:06:56.551Z,1687529216.551 [controlThread](DEBUG): Uninitializing ControlThread
2023-06-23T14:06:56.553Z,1687529216.553 [AHRS_M2](INFO): Powering down
2023-06-23T14:06:56.695Z,1687529216.695 [DVL_micro](INFO): Powering down
2023-06-23T14:06:56.696Z,1687529216.696 [NAL9602](INFO): Powering down
2023-06-23T14:06:56.697Z,1687529216.697 [Sonardyne_Nano](INFO): Powering down
2023-06-23T14:06:56.815Z,1687529216.815 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2023-06-23T14:06:56.816Z,1687529216.816 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2023-06-23T14:06:56.817Z,1687529216.817 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2023-06-23T14:06:56.817Z,1687529216.817 [MissionManager](INFO): Uninitializing Mission Default
2023-06-23T14:06:56.817Z,1687529216.817 [Default] Stopped
2023-06-23T14:06:56.817Z,1687529216.817 [Default](DEBUG): Aggregate::uninitialize Default
2023-06-23T14:06:56.817Z,1687529216.817 [Default:B.GoToSurface] Stopped
2023-06-23T14:06:56.818Z,1687529216.818 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-06-23T14:06:56.818Z,1687529216.818 [Default:CheckIn] Stopped
2023-06-23T14:06:56.818Z,1687529216.818 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-23T14:06:56.818Z,1687529216.818 [Default:CheckIn:C.Wait] Stopped
2023-06-23T14:06:56.818Z,1687529216.818 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-23T14:06:56.821Z,1687529216.821 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2023-06-23T14:06:56.821Z,1687529216.821 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2023-06-23T14:06:56.821Z,1687529216.821 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2023-06-23T14:06:56.822Z,1687529216.822 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2023-06-23T14:06:56.822Z,1687529216.822 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2023-06-23T14:06:56.822Z,1687529216.822 [BuoyancyServo](INFO): Powering down
2023-06-23T14:06:56.835Z,1687529216.835 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2023-06-23T14:06:56.835Z,1687529216.835 [ElevatorServo](INFO): Powering down
2023-06-23T14:06:56.836Z,1687529216.836 [MassServo](DEBUG): Uninitialize Mass Servo.
2023-06-23T14:06:56.836Z,1687529216.836 [MassServo](INFO): Powering down
2023-06-23T14:06:56.837Z,1687529216.837 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2023-06-23T14:06:56.837Z,1687529216.837 [RudderServo](INFO): Powering down
2023-06-23T14:06:56.838Z,1687529216.838 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2023-06-23T14:06:56.838Z,1687529216.838 [ThrusterHE](INFO): Powering down
2023-06-23T14:06:56.839Z,1687529216.839 [SBIT](DEBUG): Uninitialize SBIT Component.
2023-06-23T14:06:56.839Z,1687529216.839 [IBIT](DEBUG): Uninitialize IBIT Component.
2023-06-23T14:06:56.840Z,1687529216.840 [CBIT](DEBUG): Uninitialize CBIT Component.
2023-06-23T14:06:56.840Z,1687529216.840 [CBIT](DEBUG): Powering off loads.
2023-06-23T14:06:56.850Z,1687529216.850 [CBIT](DEBUG): Disabling WDT.
2023-06-23T14:06:56.862Z,1687529216.862 [CBIT](DEBUG): Opening all GF detection circuits.
2023-06-23T14:06:56.864Z,1687529216.864 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:56.912Z,1687529216.912 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:56.918Z,1687529216.918 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:56.954Z,1687529216.954 [DAT ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:56.959Z,1687529216.959 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:56.961Z,1687529216.961 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:56.969Z,1687529216.969 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:57.016Z,1687529217.016 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:57.077Z,1687529217.077 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-06-23T14:06:57.125Z,1687529217.125 [logger ThreadHandler](INFO): Thread cancelled.