2021-12-14T18:02:54.112Z,1639504974.112 [Supervisor](DEBUG): Initializing supervisor.
2021-12-14T18:02:54.117Z,1639504974.117 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2021-12-14T18:02:54.118Z,1639504974.118 [SyncHandler](INFO): Protected caller Thread ID is 2690
2021-12-14T18:02:54.118Z,1639504974.118 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2021-12-14T18:02:54.119Z,1639504974.119 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2021-12-14T18:02:54.120Z,1639504974.120 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2691
2021-12-14T18:02:54.124Z,1639504974.124 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2021-12-14T18:02:54.142Z,1639504974.142 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2021-12-14T18:02:54.143Z,1639504974.143 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2021-12-14T18:02:54.144Z,1639504974.144 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 2692
2021-12-14T18:02:54.148Z,1639504974.148 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2021-12-14T18:02:54.149Z,1639504974.149 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2021-12-14T18:02:54.149Z,1639504974.149 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2693
2021-12-14T18:02:54.151Z,1639504974.151 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2021-12-14T18:02:54.152Z,1639504974.152 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2021-12-14T18:02:54.153Z,1639504974.153 [logger ThreadHandler](INFO): Protected caller Thread ID is 2694
2021-12-14T18:02:54.156Z,1639504974.156 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2021-12-14T18:02:54.157Z,1639504974.157 [Supervisor](INFO): Looking for Config files in directory: Config/
2021-12-14T18:02:54.158Z,1639504974.158 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2021-12-14T18:02:54.659Z,1639504974.659 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2021-12-14T18:02:54.660Z,1639504974.660 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2021-12-14T18:02:54.879Z,1639504974.879 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2021-12-14T18:02:54.879Z,1639504974.879 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2021-12-14T18:02:55.075Z,1639504975.075 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2021-12-14T18:02:55.075Z,1639504975.075 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2021-12-14T18:02:55.188Z,1639504975.188 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2021-12-14T18:02:55.188Z,1639504975.188 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2021-12-14T18:02:55.555Z,1639504975.555 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2021-12-14T18:02:55.555Z,1639504975.555 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2021-12-14T18:02:55.886Z,1639504975.886 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2021-12-14T18:02:55.886Z,1639504975.886 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2021-12-14T18:02:55.988Z,1639504975.988 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2021-12-14T18:02:55.989Z,1639504975.989 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2021-12-14T18:02:56.144Z,1639504976.144 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2021-12-14T18:02:56.145Z,1639504976.145 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2021-12-14T18:02:56.673Z,1639504976.673 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2021-12-14T18:02:56.674Z,1639504976.674 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2021-12-14T18:02:57.048Z,1639504977.048 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2021-12-14T18:02:57.049Z,1639504977.049 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2021-12-14T18:02:57.471Z,1639504977.471 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2021-12-14T18:02:57.994Z,1639504977.994 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2021-12-14T18:02:57.995Z,1639504977.995 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2021-12-14T18:02:58.127Z,1639504978.127 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2021-12-14T18:02:58.127Z,1639504978.127 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2021-12-14T18:02:58.808Z,1639504978.808 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2021-12-14T18:02:58.809Z,1639504978.809 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2021-12-14T18:02:58.894Z,1639504978.894 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2021-12-14T18:02:59.143Z,1639504979.143 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2021-12-14T18:02:59.145Z,1639504979.145 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/
2021-12-14T18:02:59.146Z,1639504979.146 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/vehicle.cfg
2021-12-14T18:02:59.323Z,1639504979.323 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/logger.cfg
2021-12-14T18:02:59.422Z,1639504979.422 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Servo.cfg
2021-12-14T18:02:59.539Z,1639504979.539 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Control.cfg
2021-12-14T18:02:59.644Z,1639504979.644 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/secure.cfg
2021-12-14T18:02:59.733Z,1639504979.733 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Simulator.cfg
2021-12-14T18:02:59.824Z,1639504979.824 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Science.cfg
2021-12-14T18:02:59.944Z,1639504979.944 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/BIT.cfg
2021-12-14T18:03:00.049Z,1639504980.049 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Sensor.cfg
2021-12-14T18:03:00.205Z,1639504980.205 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Battery.cfg
2021-12-14T18:03:00.465Z,1639504980.465 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2021-12-14T18:03:00.466Z,1639504980.466 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Navigation.cfg
2021-12-14T18:03:00.566Z,1639504980.566 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/root/
2021-12-14T18:03:00.567Z,1639504980.567 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2021-12-14T18:03:00.579Z,1639504980.579 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2021-12-14T18:03:00.945Z,1639504980.945 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2021-12-14T18:03:00.945Z,1639504980.945 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2021-12-14T18:03:01.042Z,1639504981.042 [DeadReckonUsingMultipleVelocitySources] Loaded
2021-12-14T18:03:01.042Z,1639504981.042 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2021-12-14T18:03:01.075Z,1639504981.075 [DeadReckonUsingSpeedCalculator] Loaded
2021-12-14T18:03:01.075Z,1639504981.075 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2021-12-14T18:03:01.087Z,1639504981.087 [NavChart] Loaded
2021-12-14T18:03:01.088Z,1639504981.088 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2021-12-14T18:03:01.093Z,1639504981.093 [UniversalFixResidualReporter] Loaded
2021-12-14T18:03:01.093Z,1639504981.093 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2021-12-14T18:03:01.094Z,1639504981.094 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2021-12-14T18:03:01.095Z,1639504981.095 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2021-12-14T18:03:01.110Z,1639504981.110 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2021-12-14T18:03:01.111Z,1639504981.111 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2021-12-14T18:03:01.348Z,1639504981.348 [CTD_Seabird] Loaded
2021-12-14T18:03:01.348Z,1639504981.348 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2021-12-14T18:03:01.349Z,1639504981.349 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406504E0
2021-12-14T18:03:01.349Z,1639504981.349 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 2776
2021-12-14T18:03:01.368Z,1639504981.368 [PAR_Licor] Loaded
2021-12-14T18:03:01.369Z,1639504981.369 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2021-12-14T18:03:01.399Z,1639504981.399 [WetLabsBB2FL] Loaded
2021-12-14T18:03:01.399Z,1639504981.399 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2021-12-14T18:03:01.400Z,1639504981.400 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406804E0
2021-12-14T18:03:01.401Z,1639504981.401 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 2777
2021-12-14T18:03:01.401Z,1639504981.401 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2021-12-14T18:03:01.402Z,1639504981.402 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2021-12-14T18:03:01.470Z,1639504981.470 [VerticalControl](DEBUG): Construct VerticalControl.
2021-12-14T18:03:01.529Z,1639504981.529 [VerticalControl] Loaded
2021-12-14T18:03:01.529Z,1639504981.529 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2021-12-14T18:03:01.532Z,1639504981.532 [HorizontalControl](DEBUG): Construct HorizontalControl.
2021-12-14T18:03:01.569Z,1639504981.569 [HorizontalControl] Loaded
2021-12-14T18:03:01.569Z,1639504981.569 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2021-12-14T18:03:01.572Z,1639504981.572 [SpeedControl](DEBUG): Construct SpeedControl.
2021-12-14T18:03:01.575Z,1639504981.575 [SpeedControl] Loaded
2021-12-14T18:03:01.575Z,1639504981.575 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2021-12-14T18:03:01.578Z,1639504981.578 [LoopControl](DEBUG): Construct LoopControl.
2021-12-14T18:03:01.578Z,1639504981.578 [LoopControl] Loaded
2021-12-14T18:03:01.578Z,1639504981.578 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2021-12-14T18:03:01.579Z,1639504981.579 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2021-12-14T18:03:01.579Z,1639504981.579 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2021-12-14T18:03:01.638Z,1639504981.638 [DepthRateCalculator] Loaded
2021-12-14T18:03:01.638Z,1639504981.638 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2021-12-14T18:03:01.643Z,1639504981.643 [PitchRateCalculator] Loaded
2021-12-14T18:03:01.643Z,1639504981.643 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2021-12-14T18:03:01.652Z,1639504981.652 [SpeedCalculator] Loaded
2021-12-14T18:03:01.652Z,1639504981.652 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2021-12-14T18:03:01.665Z,1639504981.665 [TempGradientCalculator] Loaded
2021-12-14T18:03:01.665Z,1639504981.665 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2021-12-14T18:03:01.670Z,1639504981.670 [YawRateCalculator] Loaded
2021-12-14T18:03:01.670Z,1639504981.670 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2021-12-14T18:03:01.687Z,1639504981.687 [ElevatorOffsetCalculator] Loaded
2021-12-14T18:03:01.687Z,1639504981.687 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2021-12-14T18:03:01.687Z,1639504981.687 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2021-12-14T18:03:01.688Z,1639504981.688 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2021-12-14T18:03:01.801Z,1639504981.801 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2021-12-14T18:03:01.801Z,1639504981.801 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2021-12-14T18:03:01.881Z,1639504981.881 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2021-12-14T18:03:01.882Z,1639504981.882 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2021-12-14T18:03:02.033Z,1639504982.033 [BuoyancyServo] Loaded
2021-12-14T18:03:02.033Z,1639504982.033 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2021-12-14T18:03:02.052Z,1639504982.052 [ElevatorServo] Loaded
2021-12-14T18:03:02.052Z,1639504982.052 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2021-12-14T18:03:02.071Z,1639504982.071 [MassServo] Loaded
2021-12-14T18:03:02.071Z,1639504982.071 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2021-12-14T18:03:02.088Z,1639504982.088 [RudderServo] Loaded
2021-12-14T18:03:02.089Z,1639504982.089 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2021-12-14T18:03:02.103Z,1639504982.103 [ThrusterHE] Loaded
2021-12-14T18:03:02.103Z,1639504982.103 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2021-12-14T18:03:02.103Z,1639504982.103 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2021-12-14T18:03:02.104Z,1639504982.104 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2021-12-14T18:03:02.589Z,1639504982.589 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2021-12-14T18:03:02.590Z,1639504982.590 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2021-12-14T18:03:03.204Z,1639504983.204 [AHRS_M2] Loaded
2021-12-14T18:03:03.205Z,1639504983.204 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2021-12-14T18:03:03.243Z,1639504983.243 [BackseatComponent] Loaded
2021-12-14T18:03:03.243Z,1639504983.243 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2021-12-14T18:03:03.244Z,1639504983.244 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A544E0
2021-12-14T18:03:03.245Z,1639504983.245 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 2778
2021-12-14T18:03:03.247Z,1639504983.247 [LcmUniversalReporter] Loaded
2021-12-14T18:03:03.248Z,1639504983.248 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2021-12-14T18:03:04.031Z,1639504984.031 [BPC1] Loaded
2021-12-14T18:03:04.031Z,1639504984.031 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2021-12-14T18:03:04.051Z,1639504984.051 [Depth_Keller] Loaded
2021-12-14T18:03:04.051Z,1639504984.051 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2021-12-14T18:03:04.055Z,1639504984.055 [DropWeight] Loaded
2021-12-14T18:03:04.056Z,1639504984.056 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2021-12-14T18:03:04.114Z,1639504984.114 [NAL9602] Loaded
2021-12-14T18:03:04.115Z,1639504984.115 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2021-12-14T18:03:04.143Z,1639504984.143 [Onboard] Loaded
2021-12-14T18:03:04.143Z,1639504984.143 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2021-12-14T18:03:04.144Z,1639504984.144 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40A844E0
2021-12-14T18:03:04.145Z,1639504984.145 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 2779
2021-12-14T18:03:04.156Z,1639504984.156 [Power24vConverter] Loaded
2021-12-14T18:03:04.156Z,1639504984.156 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2021-12-14T18:03:04.170Z,1639504984.170 [Radio_Surface] Loaded
2021-12-14T18:03:04.171Z,1639504984.171 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2021-12-14T18:03:04.172Z,1639504984.172 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40AB44E0
2021-12-14T18:03:04.172Z,1639504984.172 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2780
2021-12-14T18:03:04.253Z,1639504984.253 [DAT] Loaded
2021-12-14T18:03:04.253Z,1639504984.253 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2021-12-14T18:03:04.255Z,1639504984.255 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40AE44E0
2021-12-14T18:03:04.255Z,1639504984.255 [DAT ThreadHandler](INFO): Protected caller Thread ID is 2781
2021-12-14T18:03:04.255Z,1639504984.255 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2021-12-14T18:03:04.256Z,1639504984.256 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2021-12-14T18:03:04.422Z,1639504984.422 [SBIT](DEBUG): Construct Startup Built In Test.
2021-12-14T18:03:04.431Z,1639504984.431 [SBIT] Loaded
2021-12-14T18:03:04.432Z,1639504984.432 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2021-12-14T18:03:04.434Z,1639504984.434 [IBIT](DEBUG): Construct Initiated Built In Test.
2021-12-14T18:03:04.447Z,1639504984.447 [IBIT] Loaded
2021-12-14T18:03:04.447Z,1639504984.447 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2021-12-14T18:03:04.453Z,1639504984.453 [CBIT](DEBUG): Construct Continuous Built In Test.
2021-12-14T18:03:04.553Z,1639504984.553 [CBIT] Loaded
2021-12-14T18:03:04.553Z,1639504984.553 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2021-12-14T18:03:04.554Z,1639504984.554 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2021-12-14T18:03:04.554Z,1639504984.554 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2021-12-14T18:03:04.596Z,1639504984.596 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2021-12-14T18:03:04.602Z,1639504984.602 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2021-12-14T18:03:04.605Z,1639504984.605 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2021-12-14T18:03:04.615Z,1639504984.615 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2021-12-14T18:03:04.616Z,1639504984.616 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B6F4E0
2021-12-14T18:03:04.617Z,1639504984.617 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2782
2021-12-14T18:03:04.621Z,1639504984.621 [Supervisor](INFO): Main Thread ID is 2344
2021-12-14T18:03:04.621Z,1639504984.621 [Supervisor](DEBUG): Running supervisor.
2021-12-14T18:03:04.622Z,1639504984.622 [CommandExec ThreadHandler](INFO): Handler Thread ID is 2783
2021-12-14T18:03:04.623Z,1639504984.623 [CommandExec](INFO): Initializing the command executive.
2021-12-14T18:03:04.624Z,1639504984.624 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2784
2021-12-14T18:03:04.627Z,1639504984.627 [controlThread ThreadHandler](INFO): Handler Thread ID is 2785
2021-12-14T18:03:04.628Z,1639504984.628 [controlThread](DEBUG): Initializing ControlThread
2021-12-14T18:03:04.629Z,1639504984.629 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2021-12-14T18:03:04.630Z,1639504984.630 [NavChart](DEBUG): Initialize NavChart Navigation.
2021-12-14T18:03:04.630Z,1639504984.630 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2021-12-14T18:03:04.634Z,1639504984.634 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2021-12-14T18:03:04.636Z,1639504984.636 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2021-12-14T18:03:04.637Z,1639504984.637 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2021-12-14T18:03:04.638Z,1639504984.638 [LoopControl](DEBUG): Initialize LoopControlComponent.
2021-12-14T18:03:04.638Z,1639504984.638 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2021-12-14T18:03:04.639Z,1639504984.639 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2021-12-14T18:03:04.639Z,1639504984.639 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2021-12-14T18:03:04.639Z,1639504984.639 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2021-12-14T18:03:04.640Z,1639504984.640 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2021-12-14T18:03:04.640Z,1639504984.640 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2021-12-14T18:03:04.648Z,1639504984.648 [SBIT](INFO): Initialize SBIT Component.
2021-12-14T18:03:04.648Z,1639504984.648 [SBIT](IMPORTANT): git: 2021-11-29_Tethys-67-g74230a6a0
2021-12-14T18:03:04.648Z,1639504984.648 [SBIT](INFO): git hash: 74230a6a060d1e4ee808cf6f97b40bbb4518e3be
2021-12-14T18:03:04.649Z,1639504984.649 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2021-12-14T18:03:04.650Z,1639504984.650 [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
2021-12-14T18:03:04.651Z,1639504984.651 [SBIT](INFO): Beginning SBIT in 40.000000 seconds.
2021-12-14T18:03:04.652Z,1639504984.652 [IBIT](INFO): Initialize IBIT Component.
2021-12-14T18:03:04.653Z,1639504984.653 [CBIT](DEBUG): Initialize CBIT Component.
2021-12-14T18:03:04.654Z,1639504984.654 [logger ThreadHandler](INFO): Handler Thread ID is 2786
2021-12-14T18:03:04.666Z,1639504984.666 [CBIT](DEBUG): Initialized mux pins.
2021-12-14T18:03:04.666Z,1639504984.666 [CBIT](DEBUG): Initializing the watchdog timer.
2021-12-14T18:03:04.675Z,1639504984.675 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 2787
2021-12-14T18:03:04.676Z,1639504984.676 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2021-12-14T18:03:04.680Z,1639504984.680 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 2789
2021-12-14T18:03:04.682Z,1639504984.682 [WetLabsBB2FL](INFO): Powering up
2021-12-14T18:03:04.684Z,1639504984.684 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 2791
2021-12-14T18:03:04.690Z,1639504984.690 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2021-12-14T18:03:04.691Z,1639504984.691 [CBIT](DEBUG): Initializing heartbeat.
2021-12-14T18:03:04.692Z,1639504984.692 [Onboard ThreadHandler](INFO): Handler Thread ID is 2792
2021-12-14T18:03:04.711Z,1639504984.711 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2793
2021-12-14T18:03:04.722Z,1639504984.722 [DAT ThreadHandler](INFO): Handler Thread ID is 2794
2021-12-14T18:03:04.724Z,1639504984.724 [DAT](INFO): Powering up
2021-12-14T18:03:04.724Z,1639504984.724 [DAT](DEBUG): Initializing DAT.
2021-12-14T18:03:04.727Z,1639504984.727 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2796
2021-12-14T18:03:04.732Z,1639504984.732 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2021-12-14T18:03:04.733Z,1639504984.733 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2021-12-14T18:03:04.733Z,1639504984.733 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2021-12-14T18:03:04.733Z,1639504984.733 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2021-12-14T18:03:04.733Z,1639504984.733 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2021-12-14T18:03:04.734Z,1639504984.734 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2021-12-14T18:03:04.734Z,1639504984.734 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2021-12-14T18:03:04.734Z,1639504984.734 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2021-12-14T18:03:04.734Z,1639504984.734 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2021-12-14T18:03:04.735Z,1639504984.735 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2021-12-14T18:03:04.735Z,1639504984.735 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2021-12-14T18:03:04.735Z,1639504984.735 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2021-12-14T18:03:04.735Z,1639504984.735 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2021-12-14T18:03:04.735Z,1639504984.735 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2021-12-14T18:03:04.735Z,1639504984.735 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2021-12-14T18:03:04.736Z,1639504984.736 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2021-12-14T18:03:04.762Z,1639504984.762 [CBIT](DEBUG): Deactivating GF circuits.
2021-12-14T18:03:04.762Z,1639504984.762 [CBIT](DEBUG): Deactivating emergency mode.
2021-12-14T18:03:04.798Z,1639504984.798 [CBIT](DEBUG): Backplane powered.
2021-12-14T18:03:04.799Z,1639504984.799 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2021-12-14T18:03:04.826Z,1639504984.826 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2021-12-14T18:03:04.882Z,1639504984.882 [MissionManager](DEBUG):
2021-12-14T18:03:04.883Z,1639504984.883 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2021-12-14T18:03:04.964Z,1639504984.964 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2021-12-14T18:03:04.965Z,1639504984.965 [Default:A.Wait](DEBUG): Construct Wait.
2021-12-14T18:03:04.968Z,1639504984.968 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-12-14T18:03:05.011Z,1639504985.011 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-12-14T18:03:05.013Z,1639504985.013 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-12-14T18:03:05.027Z,1639504985.027 [Default:E.Execute](DEBUG): Construct Execute.
2021-12-14T18:03:05.031Z,1639504985.031 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2021-12-14T18:03:05.058Z,1639504985.058 [controlThread](DEBUG): Component order: CycleStarter,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2021-12-14T18:03:05.091Z,1639504985.091 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2021-12-14T18:03:05.114Z,1639504985.114 [Radio_Surface](INFO): Powering up
2021-12-14T18:03:05.152Z,1639504985.152 [Power24vConverter](INFO): Powering up.
2021-12-14T18:03:05.186Z,1639504985.186 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2021-12-14T18:03:05.195Z,1639504985.195 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2021-12-14T18:03:05.196Z,1639504985.196 [ElevatorServo](DEBUG): Initializing EZServoServo.
2021-12-14T18:03:05.202Z,1639504985.202 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2021-12-14T18:03:05.203Z,1639504985.203 [MassServo](DEBUG): Initializing EZServoServo.
2021-12-14T18:03:05.210Z,1639504985.210 [MassServo](DEBUG): Initializing MassServo.
2021-12-14T18:03:05.211Z,1639504985.211 [RudderServo](DEBUG): Initializing EZServoServo.
2021-12-14T18:03:05.218Z,1639504985.218 [RudderServo](DEBUG): Initializing RudderServo.
2021-12-14T18:03:05.219Z,1639504985.219 [ThrusterHE](DEBUG): Initializing EZServoServo.
2021-12-14T18:03:05.227Z,1639504985.227 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2021-12-14T18:03:05.500Z,1639504985.500 [DropWeight](CRITICAL): DROP WEIGHT MISSING.
2021-12-14T18:03:05.500Z,1639504985.500 [DropWeight] Hardware Fault, FailCount= 1
2021-12-14T18:03:05.500Z,1639504985.500 [DropWeight](ERROR): Hardware Fault
2021-12-14T18:03:05.532Z,1639504985.532 [CommandExec](FAULT): Scheduling is paused
2021-12-14T18:03:05.532Z,1639504985.532 [CBIT](INFO): Critical error at 20211214T180305
2021-12-14T18:03:05.533Z,1639504985.533 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2021-12-14T18:03:05.535Z,1639504985.535 [CBIT](ERROR): Hardware Fault in component: DropWeight
2021-12-14T18:03:05.536Z,1639504985.536 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2021-12-14T18:03:05.964Z,1639504985.964 [CBIT](INFO): Critical error at 20211214T180305
2021-12-14T18:03:07.294Z,1639504987.294 [WetLabsBB2FL](INFO): Powering down
2021-12-14T18:03:11.707Z,1639504991.707 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2021-12-14T18:03:16.315Z,1639504996.315 [DAT](INFO): DAT read:
2021-12-14T18:03:16.316Z,1639504996.316 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series
2021-12-14T18:03:17.827Z,1639504997.827 [DAT](INFO): DAT read: MF Frequency Band
2021-12-14T18:03:17.828Z,1639504997.828 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0
2021-12-14T18:03:17.829Z,1639504997.829 [DAT](INFO): DAT read: Dec 14 2021 18:02:44
2021-12-14T18:03:18.835Z,1639504998.835 [DAT](INFO): DAT read: Features enabled [Bearing]
2021-12-14T18:03:18.836Z,1639504998.836 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP
2021-12-14T18:03:18.837Z,1639504998.837 [DAT](INFO): commRate: 800
2021-12-14T18:03:20.851Z,1639505000.851 [DAT](INFO): entering command mode
2021-12-14T18:03:21.103Z,1639505001.103 [DAT](INFO): DAT read:
2021-12-14T18:03:21.103Z,1639505001.103 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:21.354Z,1639505001.354 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:21.606Z,1639505001.606 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:21.859Z,1639505001.859 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:22.111Z,1639505002.111 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:22.362Z,1639505002.362 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:22.615Z,1639505002.615 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:22.866Z,1639505002.866 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:23.118Z,1639505003.118 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:23.371Z,1639505003.371 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:23.622Z,1639505003.622 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:23.874Z,1639505003.874 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:24.127Z,1639505004.127 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:24.378Z,1639505004.378 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:24.631Z,1639505004.631 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:24.882Z,1639505004.882 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:25.134Z,1639505005.134 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:25.387Z,1639505005.387 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:25.638Z,1639505005.638 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:25.890Z,1639505005.890 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:26.142Z,1639505006.142 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:26.394Z,1639505006.394 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:26.646Z,1639505006.646 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:26.899Z,1639505006.899 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:27.150Z,1639505007.150 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:27.402Z,1639505007.402 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:27.654Z,1639505007.654 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:27.907Z,1639505007.907 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:28.167Z,1639505008.167 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:28.418Z,1639505008.418 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:28.670Z,1639505008.670 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:28.922Z,1639505008.922 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:29.174Z,1639505009.174 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:29.426Z,1639505009.426 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:29.678Z,1639505009.678 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:29.930Z,1639505009.930 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:30.182Z,1639505010.182 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:30.434Z,1639505010.434 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:30.687Z,1639505010.687 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:30.938Z,1639505010.938 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:31.191Z,1639505011.191 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:31.442Z,1639505011.442 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:31.694Z,1639505011.694 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:31.946Z,1639505011.946 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:32.199Z,1639505012.199 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:32.450Z,1639505012.450 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:32.705Z,1639505012.705 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:32.955Z,1639505012.955 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:33.207Z,1639505013.207 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:33.458Z,1639505013.458 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:33.710Z,1639505013.710 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:33.962Z,1639505013.962 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:34.167Z,1639505014.167 [NAL9602](INFO): Powering up NAL9602
2021-12-14T18:03:34.214Z,1639505014.214 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:34.466Z,1639505014.466 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:34.719Z,1639505014.719 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:34.970Z,1639505014.970 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:35.222Z,1639505015.222 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:35.475Z,1639505015.475 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:35.726Z,1639505015.726 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:35.978Z,1639505015.978 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T18:03:35.979Z,1639505015.979 [DAT](FAULT): failed to enter command mode
2021-12-14T18:03:36.230Z,1639505016.230 [DAT](INFO): entering command mode
2021-12-14T18:03:36.483Z,1639505016.483 [DAT](INFO): DAT read: user:1>
2021-12-14T18:03:36.484Z,1639505016.484 [DAT](INFO): DAT read: Command '+++' not found
2021-12-14T18:03:36.484Z,1639505016.484 [DAT](INFO): DAT read: Error
2021-12-14T18:03:36.484Z,1639505016.484 [DAT](INFO): setting verbose to 3
2021-12-14T18:03:36.735Z,1639505016.735 [DAT](INFO): DAT read: user:2>
2021-12-14T18:03:36.736Z,1639505016.736 [DAT](INFO): DAT read: Verbose | 3
2021-12-14T18:03:36.736Z,1639505016.736 [DAT](INFO): set verbose to 3
2021-12-14T18:03:36.736Z,1639505016.736 [DAT](INFO): setting DatVerbose to 27440
2021-12-14T18:03:36.987Z,1639505016.987 [DAT](INFO): DAT read: user:3>
2021-12-14T18:03:36.988Z,1639505016.988 [DAT](INFO): DAT read: DatVerbose | 27440
2021-12-14T18:03:36.988Z,1639505016.988 [DAT](INFO): set DatVerbose to 27440
2021-12-14T18:03:36.988Z,1639505016.988 [DAT](INFO): setting transmit power to 8
2021-12-14T18:03:37.239Z,1639505017.239 [DAT](INFO): DAT read: user:4>
2021-12-14T18:03:37.240Z,1639505017.240 [DAT](INFO): DAT read: TxPower | 8 (Max)
2021-12-14T18:03:37.240Z,1639505017.240 [DAT](INFO): set transmit power to 8
2021-12-14T18:03:37.240Z,1639505017.240 [DAT](INFO): setting local address to 10
2021-12-14T18:03:37.493Z,1639505017.493 [DAT](INFO): DAT read: user:5>
2021-12-14T18:03:37.494Z,1639505017.494 [DAT](INFO): DAT read: LocalAddr | 10
2021-12-14T18:03:37.494Z,1639505017.494 [DAT](INFO): set local address to 10
2021-12-14T18:03:45.076Z,1639505025.076 [NAL9602](INFO): NAL9602 initialized
2021-12-14T18:03:45.117Z,1639505025.117 [SBIT](IMPORTANT): Beginning Startup BIT
2021-12-14T18:03:45.121Z,1639505025.121 [CBIT](IMPORTANT): Beginning ground fault scan
2021-12-14T18:03:56.077Z,1639505036.077 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.006128
CHAN A1 (24V): 0.001866
CHAN A2 (12V): -0.004548
CHAN A3 (5V): -0.002425
CHAN B0 (3.3V): -0.000751
CHAN B1 (3.15aV): -0.001879
CHAN B2 (3.15bV): -0.001485
CHAN B3 (GND): -0.000872
OPEN: 0.004776
Full Scale: +/- 1 mA
2021-12-14T18:04:34.421Z,1639505074.421 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-12-14T18:04:39.233Z,1639505079.233 [SBIT](IMPORTANT): SBIT PASSED
2021-12-14T18:04:39.233Z,1639505079.233 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2021-12-14T18:04:39.234Z,1639505079.234 [SBIT](IMPORTANT): BackseatComponent.needs24v=1 bool;
2021-12-14T18:04:39.234Z,1639505079.234 [SBIT](IMPORTANT): BuoyancyServo.fastPumpCoefficient=6 none;
2021-12-14T18:04:39.234Z,1639505079.234 [SBIT](IMPORTANT): CBIT.gf24Offset=149 microampere;
2021-12-14T18:04:39.234Z,1639505079.234 [SBIT](IMPORTANT): DAT.surfaceThreshold=-2 meter;
2021-12-14T18:04:39.234Z,1639505079.234 [SBIT](IMPORTANT): DAT.verbosity=3 count;
2021-12-14T18:04:39.235Z,1639505079.235 [SBIT](IMPORTANT): DataOverHttps.loadAtStartup=0 bool;
2021-12-14T18:04:39.235Z,1639505079.235 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=5 ampere_hour;
2021-12-14T18:04:39.235Z,1639505079.235 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=11 volt;
2021-12-14T18:04:39.235Z,1639505079.235 [SBIT](IMPORTANT): PowerOnly.loadAtStartup=0 bool;
2021-12-14T18:04:39.235Z,1639505079.235 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=126.383040 cubic_centimeter;
2021-12-14T18:04:39.235Z,1639505079.235 [SBIT](IMPORTANT): VerticalControl.massDefault=-5.157439 millimeter;
2021-12-14T18:04:39.649Z,1639505079.649 [MissionManager](IMPORTANT): Started mission Startup
2021-12-14T18:04:39.650Z,1639505079.650 [Startup] Running Loop=1
2021-12-14T18:04:39.650Z,1639505079.650 [Startup](DEBUG): Aggregate::initialize Startup
2021-12-14T18:04:39.650Z,1639505079.650 [Startup:A.GoToSurface] Running Loop=1
2021-12-14T18:04:39.650Z,1639505079.650 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-12-14T18:04:39.651Z,1639505079.651 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-12-14T18:04:39.651Z,1639505079.651 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-12-14T18:04:39.652Z,1639505079.652 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-12-14T18:04:39.652Z,1639505079.652 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-12-14T18:04:39.652Z,1639505079.652 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-12-14T18:04:39.654Z,1639505079.654 [Startup:StartupSatComms] Running Loop=1
2021-12-14T18:04:39.654Z,1639505079.654 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2021-12-14T18:04:39.654Z,1639505079.654 [Startup:StartupSatComms:A] Running Loop=1
2021-12-14T18:04:40.057Z,1639505080.057 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2021-12-14T18:04:46.949Z,1639505086.949 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-12-14T18:05:39.826Z,1639505139.826 [Startup:StartupSatComms:A](INFO): Timed out from 2021-12-14T18:04:39.7Z
2021-12-14T18:05:39.827Z,1639505139.827 [Startup:StartupSatComms:A] Stopped
2021-12-14T18:05:39.828Z,1639505139.828 [Startup:StartupSatComms:B] Running Loop=1
2021-12-14T18:05:40.231Z,1639505140.231 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-12-14T18:05:41.394Z,1639505141.394 [DAT](INFO): #Outgoing data=1
2021-12-14T18:05:41.394Z,1639505141.394 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-12-14T18:05:41.396Z,1639505141.396 [DAT](INFO): setting remote address to 1
2021-12-14T18:05:41.647Z,1639505141.647 [DAT](INFO): DAT read: user:6>
2021-12-14T18:05:41.648Z,1639505141.648 [DAT](INFO): DAT read: RemoteAddr | 1
2021-12-14T18:05:41.648Z,1639505141.648 [DAT](INFO): set remote address to 1
2021-12-14T18:05:41.648Z,1639505141.648 [DAT](INFO): entering online mode
2021-12-14T18:05:41.899Z,1639505141.899 [DAT](INFO): DAT read: user:7>
2021-12-14T18:05:41.899Z,1639505141.899 [DAT](INFO): DAT read:
2021-12-14T18:05:41.901Z,1639505141.901 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP
2021-12-14T18:05:41.901Z,1639505141.901 [DAT](INFO): commRate: 800
2021-12-14T18:05:41.901Z,1639505141.901 [DAT](INFO): online mode acknowledged
2021-12-14T18:05:41.901Z,1639505141.901 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-12-14T18:05:45.431Z,1639505145.431 [DAT](INFO): DAT read: Forwarding Delay UpTx time:18:05:13.8884
2021-12-14T18:05:45.432Z,1639505145.432 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-12-14T18:05:48.775Z,1639505148.775 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-12-14T18:06:04.895Z,1639505164.895 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2021-12-14T18:06:04.895Z,1639505164.895 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-12-14T18:06:04.896Z,1639505164.896 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2021-12-14T18:06:04.896Z,1639505164.896 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2021-12-14T18:06:04.907Z,1639505164.907 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-12-14T18:06:04.907Z,1639505164.907 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2021-12-14T18:06:05.311Z,1639505165.311 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-12-14T18:06:05.311Z,1639505165.311 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2021-12-14T18:06:05.311Z,1639505165.311 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2021-12-14T18:06:05.311Z,1639505165.311 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2021-12-14T18:06:05.687Z,1639505165.687 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2021-12-14T18:06:18.685Z,1639505178.685 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-12-14T18:06:26.543Z,1639505186.543 [DAT](FAULT): Ack receipt timeout failure.
2021-12-14T18:06:26.543Z,1639505186.543 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2021-12-14T18:06:27.716Z,1639505187.716 [DAT](INFO): #Outgoing data=1
2021-12-14T18:06:27.716Z,1639505187.716 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-12-14T18:06:27.719Z,1639505187.719 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-12-14T18:06:30.995Z,1639505190.995 [DAT](INFO): DAT read: Forwarding Delay UpTx time:18:05:59.6387
2021-12-14T18:06:30.995Z,1639505190.995 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-12-14T18:06:32.995Z,1639505192.995 [CommandExec](IMPORTANT): got command show stack
2021-12-14T18:06:32.995Z,1639505192.995 [CommandExec](IMPORTANT): Behavior Stack:
2021-12-14T18:06:32.996Z,1639505192.996 [Startup](IMPORTANT): Priority 0: Startup:A.GoToSurface
2021-12-14T18:06:32.996Z,1639505192.996 [Startup:StartupSatComms](IMPORTANT): Priority 1: Startup:StartupSatComms:B
2021-12-14T18:06:40.057Z,1639505200.057 [Startup:StartupSatComms:B](INFO): Timed out from 2021-12-14T18:05:39.8Z
2021-12-14T18:06:40.057Z,1639505200.057 [Startup:StartupSatComms:B] Stopped
2021-12-14T18:06:40.057Z,1639505200.057 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2021-12-14T18:06:40.057Z,1639505200.057 [Startup:StartupSatComms] Stopped
2021-12-14T18:06:40.057Z,1639505200.057 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2021-12-14T18:06:40.058Z,1639505200.058 [Startup](INFO): Completed Startup
2021-12-14T18:06:40.059Z,1639505200.059 [MissionManager](INFO): Startup is completed.
2021-12-14T18:06:40.059Z,1639505200.059 [MissionManager](INFO): Uninitializing Mission Startup
2021-12-14T18:06:40.059Z,1639505200.059 [Startup] Stopped
2021-12-14T18:06:40.059Z,1639505200.059 [Startup](DEBUG): Aggregate::uninitialize Startup
2021-12-14T18:06:40.059Z,1639505200.059 [Startup:A.GoToSurface] Stopped
2021-12-14T18:06:40.059Z,1639505200.059 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-12-14T18:06:40.432Z,1639505200.432 [MissionManager](IMPORTANT): Started mission Default
2021-12-14T18:06:40.432Z,1639505200.432 [Default] Running Loop=1
2021-12-14T18:06:40.432Z,1639505200.432 [Default](DEBUG): Aggregate::initialize Default
2021-12-14T18:06:40.433Z,1639505200.433 [Default:B.GoToSurface] Running Loop=1
2021-12-14T18:06:40.433Z,1639505200.433 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-12-14T18:06:40.433Z,1639505200.433 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-12-14T18:06:40.433Z,1639505200.433 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-12-14T18:06:40.434Z,1639505200.434 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-12-14T18:06:40.435Z,1639505200.435 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-12-14T18:06:40.435Z,1639505200.435 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-12-14T18:06:40.435Z,1639505200.435 [Default:A.Wait] Running Loop=1
2021-12-14T18:06:40.435Z,1639505200.435 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-12-14T18:06:46.956Z,1639505206.956 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-12-14T18:06:53.769Z,1639505213.769 [Default:A.Wait](INFO): Done Waiting.
2021-12-14T18:06:53.769Z,1639505213.769 [Default:A.Wait] Stopped
2021-12-14T18:06:53.769Z,1639505213.769 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-12-14T18:06:54.173Z,1639505214.173 [Default:CheckIn] Running Loop=1
2021-12-14T18:06:54.173Z,1639505214.173 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-12-14T18:06:54.173Z,1639505214.173 [Default:CheckIn:Read_GPS] Running Loop=1
2021-12-14T18:06:54.598Z,1639505214.598 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2021-12-14T18:07:12.095Z,1639505232.095 [DAT](FAULT): Ack receipt timeout failure.
2021-12-14T18:07:12.095Z,1639505232.095 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2021-12-14T18:07:12.347Z,1639505232.347 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-12-14T18:07:12.599Z,1639505232.599 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-12-14T18:07:15.875Z,1639505235.875 [DAT](INFO): DAT read: Forwarding Delay UpTx time:18:06:44.5390
2021-12-14T18:07:15.875Z,1639505235.875 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-12-14T18:07:57.047Z,1639505277.047 [DAT](FAULT): Ack receipt timeout failure.
2021-12-14T18:07:57.047Z,1639505277.047 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2021-12-14T18:07:57.299Z,1639505277.299 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-12-14T18:07:57.551Z,1639505277.551 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-12-14T18:08:00.827Z,1639505280.827 [DAT](INFO): DAT read: Forwarding Delay UpTx time:18:07:29.4893
2021-12-14T18:08:00.827Z,1639505280.827 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-12-14T18:08:41.923Z,1639505321.923 [DAT](FAULT): Ack receipt timeout failure.
2021-12-14T18:08:41.923Z,1639505321.923 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2021-12-14T18:08:42.175Z,1639505322.175 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER
2021-12-14T18:08:42.427Z,1639505322.427 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-12-14T18:08:42.679Z,1639505322.679 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-12-14T18:08:45.955Z,1639505325.955 [DAT](INFO): DAT read: Forwarding Delay UpTx time:18:08:14.5896
2021-12-14T18:08:45.956Z,1639505325.956 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-12-14T18:08:48.192Z,1639505328.192 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-12-14T18:09:01.562Z,1639505341.562 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/run_backseat_on_surface.xml
2021-12-14T18:09:01.562Z,1639505341.562 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/run_backseat_on_surface.xml
2021-12-14T18:09:01.627Z,1639505341.627 [MissionManager](INFO): DefineArg run_backseat_on_surface.ElapsedSinceMissionStarted = 0.000000 min
2021-12-14T18:09:01.635Z,1639505341.635 [run_backseat_on_surface:A.BackseatDriver](DEBUG): Construct BackseatDriver.
2021-12-14T18:09:01.663Z,1639505341.663 [run_backseat_on_surface:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-12-14T18:09:01.706Z,1639505341.706 [run_backseat_on_surface:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-12-14T18:09:01.717Z,1639505341.717 [run_backseat_on_surface:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-12-14T18:09:01.732Z,1639505341.732 [run_backseat_on_surface:E.Execute](DEBUG): Construct Execute.
2021-12-14T18:09:01.748Z,1639505341.748 [MissionManager](DEBUG):
0
Burn on
Dropped weight due to communications timeout.
5
run_backseat_on_surface mission has been running for
Restarting logs and run_backseat_on_surface mission.
restart logs
2021-12-14T18:09:01.759Z,1639505341.759 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/run_backseat_on_surface.xml
2021-12-14T18:09:01.935Z,1639505341.935 [Default] Stopped
2021-12-14T18:09:01.935Z,1639505341.935 [Default](DEBUG): Aggregate::uninitialize Default
2021-12-14T18:09:01.935Z,1639505341.935 [Default:B.GoToSurface] Stopped
2021-12-14T18:09:01.935Z,1639505341.935 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-12-14T18:09:01.935Z,1639505341.935 [Default:CheckIn] Stopped
2021-12-14T18:09:01.935Z,1639505341.935 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-12-14T18:09:01.935Z,1639505341.935 [Default:CheckIn:Read_GPS] Stopped
2021-12-14T18:09:01.936Z,1639505341.936 [MissionManager](IMPORTANT): Started mission run_backseat_on_surface
2021-12-14T18:09:01.936Z,1639505341.936 [run_backseat_on_surface] Running Loop=1
2021-12-14T18:09:01.936Z,1639505341.936 [run_backseat_on_surface](DEBUG): Aggregate::initialize run_backseat_on_surface
2021-12-14T18:09:01.936Z,1639505341.936 [run_backseat_on_surface:A.BackseatDriver] Running Loop=1
2021-12-14T18:09:01.936Z,1639505341.936 [run_backseat_on_surface:A.BackseatDriver](DEBUG): Initialize.
2021-12-14T18:09:01.957Z,1639505341.957 [run_backseat_on_surface:B.GoToSurface] Running Loop=1
2021-12-14T18:09:01.957Z,1639505341.957 [run_backseat_on_surface:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-12-14T18:09:01.958Z,1639505341.958 [run_backseat_on_surface:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-12-14T18:09:01.974Z,1639505341.974 [run_backseat_on_surface:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-12-14T18:09:01.974Z,1639505341.974 [run_backseat_on_surface:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-12-14T18:09:01.975Z,1639505341.975 [run_backseat_on_surface:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-12-14T18:09:01.975Z,1639505341.975 [run_backseat_on_surface:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-12-14T18:09:01.976Z,1639505341.976 [run_backseat_on_surface:CheckIn] Running Loop=1
2021-12-14T18:09:01.976Z,1639505341.976 [run_backseat_on_surface:CheckIn](DEBUG): Aggregate::initialize run_backseat_on_surface:CheckIn
2021-12-14T18:09:01.977Z,1639505341.977 [run_backseat_on_surface:CheckIn:Read_GPS] Running Loop=1
2021-12-14T18:09:01.977Z,1639505341.977 [run_backseat_on_surface:A.BackseatDriver] Running Loop=1
2021-12-14T18:09:02.042Z,1639505342.042 [BackseatComponent](INFO): Powering up
2021-12-14T18:09:02.043Z,1639505342.043 [BackseatComponent](INFO): Subscribing to LCM channels.
2021-12-14T18:09:02.349Z,1639505342.349 [run_backseat_on_surface:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2021-12-14T18:09:05.966Z,1639505345.966 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2021-12-14T18:09:05.966Z,1639505345.966 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-12-14T18:09:05.967Z,1639505345.967 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2021-12-14T18:09:05.968Z,1639505345.968 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2021-12-14T18:09:05.999Z,1639505345.999 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-12-14T18:09:05.000Z,1639505346.000 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2021-12-14T18:09:06.435Z,1639505346.435 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-12-14T18:09:06.435Z,1639505346.435 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2021-12-14T18:09:06.435Z,1639505346.435 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2021-12-14T18:09:06.435Z,1639505346.435 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2021-12-14T18:09:06.787Z,1639505346.787 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2021-12-14T18:09:27.054Z,1639505367.054 [DAT](FAULT): Ack receipt timeout failure.
2021-12-14T18:09:27.055Z,1639505367.055 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2021-12-14T18:09:27.306Z,1639505367.306 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER
2021-12-14T18:09:28.230Z,1639505368.230 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-12-14T18:09:35.121Z,1639505375.121 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-12-14T18:09:42.738Z,1639505382.738 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2021-12-14T18:09:42.742Z,1639505382.742 [BPC1](INFO): Received data from all battery sticks.
2021-12-14T18:12:06.999Z,1639505527.000 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2021-12-14T18:12:06.000Z,1639505527.000 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-12-14T18:12:07.001Z,1639505527.001 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3
2021-12-14T18:12:07.001Z,1639505527.001 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2021-12-14T18:12:07.039Z,1639505527.039 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-12-14T18:12:07.040Z,1639505527.040 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2021-12-14T18:12:07.403Z,1639505527.403 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-12-14T18:12:07.403Z,1639505527.403 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2021-12-14T18:12:07.403Z,1639505527.403 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2021-12-14T18:12:07.404Z,1639505527.404 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3
2021-12-14T18:12:07.781Z,1639505527.781 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2021-12-14T18:12:46.867Z,1639505566.867 [CommandExec](IMPORTANT): got command get BackseatComponent.loadControl
2021-12-14T18:12:46.868Z,1639505566.868 [CommandExec](IMPORTANT): BackseatComponent.loadControl /dev/loadC4
2021-12-14T18:13:48.368Z,1639505628.368 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-12-14T18:13:48.368Z,1639505628.368 [NAL9602] Data Fault, FailCount= 1
2021-12-14T18:13:48.368Z,1639505628.368 [NAL9602](ERROR): Data Fault
2021-12-14T18:13:48.408Z,1639505628.408 [CBIT](ERROR): Data Fault in component: NAL9602
2021-12-14T18:13:48.775Z,1639505628.775 [NAL9602](INFO): Powering down
2021-12-14T18:13:49.611Z,1639505629.611 [CBIT](INFO): Clearing failed state for component NAL9602
2021-12-14T18:13:49.611Z,1639505629.611 [NAL9602] No Fault, FailCount= 1
2021-12-14T18:14:02.111Z,1639505642.111 [run_backseat_on_surface:CheckIn:Read_GPS](INFO): Timed out from 2021-12-14T18:09:01.0Z
2021-12-14T18:14:02.112Z,1639505642.112 [run_backseat_on_surface:CheckIn:Read_GPS] Stopped
2021-12-14T18:14:02.112Z,1639505642.112 [run_backseat_on_surface:CheckIn:Read_Iridium] Running Loop=1
2021-12-14T18:14:02.519Z,1639505642.519 [run_backseat_on_surface:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-12-14T18:14:03.658Z,1639505643.658 [DAT](INFO): #Outgoing data=1
2021-12-14T18:14:03.659Z,1639505643.659 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-12-14T18:14:03.660Z,1639505643.660 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-12-14T18:14:06.941Z,1639505646.941 [DAT](INFO): DAT read: Forwarding Delay UpTx time:18:13:35.4924
2021-12-14T18:14:06.941Z,1639505646.941 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-12-14T18:14:17.382Z,1639505657.382 [BackseatComponent](FAULT): Failed to receive device response within the specified timeout.
2021-12-14T18:14:17.382Z,1639505657.382 [BackseatComponent] Communications Fault, FailCount= 1
2021-12-14T18:14:17.382Z,1639505657.382 [BackseatComponent](ERROR): Communications Fault
2021-12-14T18:14:17.483Z,1639505657.483 [CBIT](ERROR): Communications Fault in component: BackseatComponent
2021-12-14T18:14:17.805Z,1639505657.805 [BackseatComponent](INFO): Sent LCM shutdown request.
2021-12-14T18:14:19.076Z,1639505659.076 [NAL9602](INFO): Powering up NAL9602
2021-12-14T18:14:29.980Z,1639505669.980 [NAL9602](INFO): NAL9602 initialized
2021-12-14T18:14:33.158Z,1639505673.158 [BackseatComponent](INFO): Powering down
2021-12-14T18:14:33.562Z,1639505673.562 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2021-12-14T18:14:33.563Z,1639505673.563 [LcmUniversalReporter](INFO): Deactivating messaging.
2021-12-14T18:14:33.966Z,1639505673.966 [BackseatComponent](INFO): Powering up
2021-12-14T18:14:33.967Z,1639505673.967 [BackseatComponent](INFO): Subscribing to LCM channels.
2021-12-14T18:14:34.544Z,1639505674.544 [CBIT](INFO): Clearing failed state for component BackseatComponent
2021-12-14T18:14:34.544Z,1639505674.544 [BackseatComponent] No Fault, FailCount= 1
2021-12-14T18:14:45.843Z,1639505685.843 [CommandExec](IMPORTANT): got command stop
2021-12-14T18:14:45.843Z,1639505685.843 [CommandExec](IMPORTANT): Scheduling is paused
2021-12-14T18:14:45.843Z,1639505685.843 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2021-12-14T18:14:46.074Z,1639505686.074 [MissionManager](INFO): MissionManager is completed.
2021-12-14T18:14:46.074Z,1639505686.074 [MissionManager](INFO): Uninitializing Mission run_backseat_on_surface
2021-12-14T18:14:46.074Z,1639505686.074 [run_backseat_on_surface] Stopped
2021-12-14T18:14:46.075Z,1639505686.075 [run_backseat_on_surface](DEBUG): Aggregate::uninitialize run_backseat_on_surface
2021-12-14T18:14:46.075Z,1639505686.075 [run_backseat_on_surface:A.BackseatDriver] Stopped
2021-12-14T18:14:46.075Z,1639505686.075 [run_backseat_on_surface:A.BackseatDriver](DEBUG): Uninitialize.
2021-12-14T18:14:46.075Z,1639505686.075 [run_backseat_on_surface:B.GoToSurface] Stopped
2021-12-14T18:14:46.075Z,1639505686.075 [run_backseat_on_surface:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-12-14T18:14:46.075Z,1639505686.075 [run_backseat_on_surface:CheckIn] Stopped
2021-12-14T18:14:46.075Z,1639505686.075 [run_backseat_on_surface:CheckIn](DEBUG): Aggregate::uninitialize run_backseat_on_surface:CheckIn
2021-12-14T18:14:46.075Z,1639505686.075 [run_backseat_on_surface:CheckIn:Read_Iridium] Stopped
2021-12-14T18:14:46.524Z,1639505686.524 [MissionManager](IMPORTANT): Started mission Default
2021-12-14T18:14:46.525Z,1639505686.525 [Default] Running Loop=1
2021-12-14T18:14:46.525Z,1639505686.525 [Default](DEBUG): Aggregate::initialize Default
2021-12-14T18:14:46.525Z,1639505686.525 [Default:B.GoToSurface] Running Loop=1
2021-12-14T18:14:46.525Z,1639505686.525 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-12-14T18:14:46.525Z,1639505686.525 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-12-14T18:14:46.526Z,1639505686.526 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-12-14T18:14:46.526Z,1639505686.526 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-12-14T18:14:46.527Z,1639505686.527 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-12-14T18:14:46.527Z,1639505686.527 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-12-14T18:14:46.527Z,1639505686.527 [Default:A.Wait] Running Loop=1
2021-12-14T18:14:46.527Z,1639505686.527 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-12-14T18:14:48.062Z,1639505688.062 [DAT](FAULT): Ack receipt timeout failure.
2021-12-14T18:14:48.063Z,1639505688.063 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2021-12-14T18:14:48.315Z,1639505688.315 [DAT](INFO): Sent 1016 bytes from file Logs/20211210T221713/Courier9023.lzma.parts
2021-12-14T18:14:48.315Z,1639505688.315 [DAT](INFO): Packets left to send: 6
2021-12-14T18:14:48.317Z,1639505688.317 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER
2021-12-14T18:14:51.817Z,1639505691.817 [BackseatComponent](INFO): Sent LCM shutdown request.
2021-12-14T18:14:59.930Z,1639505699.930 [Default:A.Wait](INFO): Done Waiting.
2021-12-14T18:14:59.930Z,1639505699.930 [Default:A.Wait] Stopped
2021-12-14T18:14:59.930Z,1639505699.930 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-12-14T18:15:00.365Z,1639505700.365 [Default:CheckIn] Running Loop=1
2021-12-14T18:15:00.365Z,1639505700.365 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-12-14T18:15:00.365Z,1639505700.365 [Default:CheckIn:Read_GPS] Running Loop=1
2021-12-14T18:15:06.914Z,1639505706.914 [BackseatComponent](INFO): Powering down
2021-12-14T18:15:07.118Z,1639505707.118 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2021-12-14T18:15:07.118Z,1639505707.118 [LcmUniversalReporter](INFO): Deactivating messaging.
2021-12-14T18:15:07.990Z,1639505707.990 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2021-12-14T18:15:07.990Z,1639505707.990 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-12-14T18:15:07.991Z,1639505707.991 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 4
2021-12-14T18:15:07.991Z,1639505707.991 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2021-12-14T18:15:08.003Z,1639505708.003 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-12-14T18:15:08.003Z,1639505708.003 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2021-12-14T18:15:08.415Z,1639505708.415 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-12-14T18:15:08.415Z,1639505708.415 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2021-12-14T18:15:08.415Z,1639505708.415 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2021-12-14T18:15:08.416Z,1639505708.416 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 4
2021-12-14T18:15:08.801Z,1639505708.801 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2021-12-14T18:18:05.776Z,1639505885.776 [CBIT](INFO): Clearing failed state for component DropWeight
2021-12-14T18:18:05.776Z,1639505885.776 [DropWeight] No Fault, FailCount= 1
2021-12-14T18:18:09.010Z,1639505889.010 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2021-12-14T18:18:09.011Z,1639505889.011 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-12-14T18:18:09.012Z,1639505889.012 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 5
2021-12-14T18:18:09.012Z,1639505889.012 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2021-12-14T18:18:09.023Z,1639505889.023 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-12-14T18:18:09.023Z,1639505889.023 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2021-12-14T18:18:09.412Z,1639505889.412 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-12-14T18:18:09.413Z,1639505889.413 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2021-12-14T18:18:09.413Z,1639505889.413 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2021-12-14T18:18:09.413Z,1639505889.413 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 5
2021-12-14T18:18:09.787Z,1639505889.787 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2021-12-14T18:20:00.489Z,1639506000.489 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-14T18:15:00.4Z
2021-12-14T18:20:00.489Z,1639506000.489 [Default:CheckIn:Read_GPS] Stopped
2021-12-14T18:20:00.491Z,1639506000.491 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-12-14T18:20:00.903Z,1639506000.903 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-12-14T18:20:02.043Z,1639506002.043 [DAT](INFO): #Outgoing data=1
2021-12-14T18:20:02.044Z,1639506002.044 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-12-14T18:20:02.046Z,1639506002.046 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-12-14T18:20:05.323Z,1639506005.323 [DAT](INFO): DAT read: Forwarding Delay UpTx time:18:19:33.7965
2021-12-14T18:20:05.323Z,1639506005.323 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-12-14T18:20:46.430Z,1639506046.430 [DAT](FAULT): Ack receipt timeout failure.
2021-12-14T18:20:46.431Z,1639506046.431 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2021-12-14T18:20:46.683Z,1639506046.683 [DAT](INFO): Sent 1016 bytes from file Logs/20211210T221713/Courier9023.lzma.parts
2021-12-14T18:20:46.683Z,1639506046.683 [DAT](INFO): Packets left to send: 5
2021-12-14T18:20:46.685Z,1639506046.685 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER
2021-12-14T18:20:48.468Z,1639506048.468 [DAT](INFO): #Outgoing data=1
2021-12-14T18:20:48.468Z,1639506048.468 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-12-14T18:20:48.470Z,1639506048.470 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-12-14T18:20:51.752Z,1639506051.752 [DAT](INFO): DAT read: Forwarding Delay UpTx time:18:20:20.1971
2021-12-14T18:20:51.752Z,1639506051.752 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-12-14T18:21:10.103Z,1639506070.103 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2021-12-14T18:21:10.103Z,1639506070.103 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-12-14T18:21:10.104Z,1639506070.104 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 6
2021-12-14T18:21:10.104Z,1639506070.104 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2021-12-14T18:21:10.115Z,1639506070.115 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-12-14T18:21:10.116Z,1639506070.116 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2021-12-14T18:21:10.524Z,1639506070.524 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-12-14T18:21:10.524Z,1639506070.524 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2021-12-14T18:21:10.524Z,1639506070.524 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2021-12-14T18:21:10.524Z,1639506070.524 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 6
2021-12-14T18:21:10.950Z,1639506070.950 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2021-12-14T18:21:32.879Z,1639506092.879 [DAT](FAULT): Ack receipt timeout failure.
2021-12-14T18:21:32.879Z,1639506092.879 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2021-12-14T18:21:33.131Z,1639506093.131 [DAT](INFO): Sent 1016 bytes from file Logs/20211210T221713/Courier9023.lzma.parts
2021-12-14T18:21:33.131Z,1639506093.131 [DAT](INFO): Packets left to send: 4
2021-12-14T18:21:33.132Z,1639506093.132 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER
2021-12-14T18:21:35.337Z,1639506095.337 [DAT](INFO): #Outgoing data=1
2021-12-14T18:21:35.337Z,1639506095.337 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-12-14T18:21:35.339Z,1639506095.339 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-12-14T18:21:38.624Z,1639506098.624 [DAT](INFO): DAT read: Forwarding Delay UpTx time:18:21:07.0477
2021-12-14T18:21:38.624Z,1639506098.624 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-12-14T18:22:19.871Z,1639506139.871 [DAT](FAULT): Ack receipt timeout failure.
2021-12-14T18:22:19.871Z,1639506139.871 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2021-12-14T18:22:20.123Z,1639506140.123 [DAT](INFO): Sent 1016 bytes from file Logs/20211210T221713/Courier9023.lzma.parts
2021-12-14T18:22:20.124Z,1639506140.124 [DAT](INFO): Packets left to send: 3
2021-12-14T18:22:20.125Z,1639506140.125 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER
2021-12-14T18:22:21.938Z,1639506141.938 [DAT](INFO): #Outgoing data=1
2021-12-14T18:22:21.959Z,1639506141.959 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-12-14T18:22:21.961Z,1639506141.961 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-12-14T18:22:25.488Z,1639506145.488 [DAT](INFO): DAT read: Forwarding Delay UpTx time:18:21:54.0482
2021-12-14T18:22:25.488Z,1639506145.488 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-12-14T18:23:06.575Z,1639506186.575 [DAT](FAULT): Ack receipt timeout failure.
2021-12-14T18:23:06.575Z,1639506186.575 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2021-12-14T18:23:06.828Z,1639506186.828 [DAT](INFO): Sent 1016 bytes from file Logs/20211210T221713/Courier9023.lzma.parts
2021-12-14T18:23:06.828Z,1639506186.828 [DAT](INFO): Packets left to send: 2
2021-12-14T18:23:06.829Z,1639506186.829 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER
2021-12-14T18:23:08.068Z,1639506188.068 [DAT](INFO): #Outgoing data=1
2021-12-14T18:23:08.068Z,1639506188.068 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-12-14T18:23:08.070Z,1639506188.070 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-12-14T18:23:11.348Z,1639506191.348 [DAT](INFO): DAT read: Forwarding Delay UpTx time:18:22:40.0988
2021-12-14T18:23:11.348Z,1639506191.348 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-12-14T18:23:52.427Z,1639506232.427 [DAT](FAULT): Ack receipt timeout failure.
2021-12-14T18:23:52.427Z,1639506232.427 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2021-12-14T18:23:52.679Z,1639506232.679 [DAT](INFO): Sent 1016 bytes from file Logs/20211210T221713/Courier9023.lzma.parts
2021-12-14T18:23:52.680Z,1639506232.680 [DAT](INFO): Packets left to send: 1
2021-12-14T18:23:52.681Z,1639506232.681 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER
2021-12-14T18:23:53.905Z,1639506233.905 [DAT](INFO): #Outgoing data=1
2021-12-14T18:23:53.906Z,1639506233.906 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-12-14T18:23:53.908Z,1639506233.908 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-12-14T18:23:57.184Z,1639506237.184 [DAT](INFO): DAT read: Forwarding Delay UpTx time:18:23:25.8992
2021-12-14T18:23:57.185Z,1639506237.185 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-12-14T18:24:11.278Z,1639506251.278 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2021-12-14T18:24:11.278Z,1639506251.278 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-12-14T18:24:11.279Z,1639506251.279 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 7
2021-12-14T18:24:11.279Z,1639506251.279 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2021-12-14T18:24:11.290Z,1639506251.290 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-12-14T18:24:11.290Z,1639506251.290 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2021-12-14T18:24:11.404Z,1639506251.404 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-12-14T18:24:11.404Z,1639506251.404 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2021-12-14T18:24:11.405Z,1639506251.405 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2021-12-14T18:24:11.405Z,1639506251.405 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 7
2021-12-14T18:24:11.732Z,1639506251.732 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2021-12-14T18:24:28.199Z,1639506268.199 [DAT](FAULT): Ack receipt timeout failure.
2021-12-14T18:24:28.200Z,1639506268.200 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2021-12-14T18:24:28.451Z,1639506268.451 [DAT](INFO): Sent 672 bytes from file Logs/20211210T221713/Courier9023.lzma.parts
2021-12-14T18:24:28.452Z,1639506268.452 [DAT](INFO): Packets left to send: 0
2021-12-14T18:24:28.454Z,1639506268.454 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER
2021-12-14T18:24:29.908Z,1639506269.908 [DAT](INFO): #Outgoing data=1
2021-12-14T18:24:29.908Z,1639506269.908 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-12-14T18:24:29.910Z,1639506269.910 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-12-14T18:24:31.120Z,1639506271.120 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-12-14T18:24:31.120Z,1639506271.120 [NAL9602] Data Fault, FailCount= 2
2021-12-14T18:24:31.120Z,1639506271.120 [NAL9602](ERROR): Data Fault
2021-12-14T18:24:31.137Z,1639506271.137 [CBIT](ERROR): Data Fault in component: NAL9602
2021-12-14T18:24:31.521Z,1639506271.521 [NAL9602](INFO): Powering down
2021-12-14T18:24:32.342Z,1639506272.342 [CBIT](INFO): Clearing failed state for component NAL9602
2021-12-14T18:24:32.343Z,1639506272.343 [NAL9602] No Fault, FailCount= 2
2021-12-14T18:24:33.188Z,1639506273.188 [DAT](INFO): DAT read: Forwarding Delay UpTx time:18:24:01.9496
2021-12-14T18:24:33.189Z,1639506273.189 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-12-14T18:25:01.817Z,1639506301.817 [NAL9602](INFO): Powering up NAL9602
2021-12-14T18:25:12.725Z,1639506312.725 [NAL9602](INFO): NAL9602 initialized
2021-12-14T18:25:14.283Z,1639506314.283 [DAT](FAULT): Ack receipt timeout failure.
2021-12-14T18:25:14.283Z,1639506314.283 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2021-12-14T18:25:14.536Z,1639506314.536 [DAT](INFO): Sent 1016 bytes from file Logs/20211210T221713/Courier9024.lzma.parts
2021-12-14T18:25:14.536Z,1639506314.536 [DAT](INFO): Packets left to send: 2
2021-12-14T18:25:14.538Z,1639506314.538 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER
2021-12-14T18:25:15.767Z,1639506315.767 [DAT](INFO): #Outgoing data=1
2021-12-14T18:25:15.767Z,1639506315.767 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-12-14T18:25:15.769Z,1639506315.769 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-12-14T18:25:19.044Z,1639506319.044 [DAT](INFO): DAT read: Forwarding Delay UpTx time:18:24:47.8000
2021-12-14T18:25:19.044Z,1639506319.044 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-12-14T18:26:00.155Z,1639506360.155 [DAT](FAULT): Ack receipt timeout failure.
2021-12-14T18:26:00.155Z,1639506360.155 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2021-12-14T18:26:00.407Z,1639506360.407 [DAT](INFO): Sent 1016 bytes from file Logs/20211210T221713/Courier9024.lzma.parts
2021-12-14T18:26:00.408Z,1639506360.408 [DAT](INFO): Packets left to send: 1
2021-12-14T18:26:00.409Z,1639506360.409 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER
2021-12-14T18:26:02.179Z,1639506362.179 [DAT](INFO): #Outgoing data=1
2021-12-14T18:26:02.179Z,1639506362.179 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-12-14T18:26:02.180Z,1639506362.180 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-12-14T18:26:05.456Z,1639506365.456 [DAT](INFO): DAT read: Forwarding Delay UpTx time:18:25:34.1004
2021-12-14T18:26:05.456Z,1639506365.456 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-12-14T18:26:27.703Z,1639506387.703 [DAT](FAULT): Ack receipt timeout failure.
2021-12-14T18:26:27.703Z,1639506387.703 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2021-12-14T18:26:27.952Z,1639506387.952 [DAT](INFO): Sent 386 bytes from file Logs/20211210T221713/Courier9024.lzma.parts
2021-12-14T18:26:27.952Z,1639506387.952 [DAT](INFO): Packets left to send: 0
2021-12-14T18:26:27.954Z,1639506387.954 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER
2021-12-14T18:26:30.628Z,1639506390.628 [DAT](INFO): #Outgoing data=1
2021-12-14T18:26:30.629Z,1639506390.629 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-12-14T18:26:30.632Z,1639506390.632 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-12-14T18:26:33.916Z,1639506393.916 [DAT](INFO): DAT read: Forwarding Delay UpTx time:18:26:02.6009
2021-12-14T18:26:33.916Z,1639506393.916 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-12-14T18:26:48.380Z,1639506408.380 [CommandExec](IMPORTANT): got command restart application
2021-12-14T18:26:49.383Z,1639506409.383 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-14T18:26:49.383Z,1639506409.383 [CommandExec](INFO): Uninitializing the command executive.
2021-12-14T18:26:49.383Z,1639506409.383 [CommandExec](INFO): Uninitializing the command scheduler.
2021-12-14T18:26:49.383Z,1639506409.383 [CommandExec ThreadHandler](INFO): Thread cancelled.
2021-12-14T18:26:49.535Z,1639506409.535 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2021-12-14T18:26:49.535Z,1639506409.535 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2021-12-14T18:26:49.535Z,1639506409.535 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-12-14T18:26:49.536Z,1639506409.536 [NavChartDb](INFO): Join timeout helper Thread ID is 2859
2021-12-14T18:26:49.811Z,1639506409.811 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-14T18:26:49.811Z,1639506409.811 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-12-14T18:26:49.823Z,1639506409.823 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler
2021-12-14T18:26:49.823Z,1639506409.823 [DAT ThreadHandler](INFO): Thread cancelled.
2021-12-14T18:26:49.823Z,1639506409.823 [DAT](INFO): Join timeout helper Thread ID is 2860
2021-12-14T18:26:50.055Z,1639506410.055 [DAT](INFO): Powering down
2021-12-14T18:26:50.123Z,1639506410.123 [DAT ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-14T18:26:50.124Z,1639506410.124 [DAT](INFO): Powering down
2021-12-14T18:26:50.124Z,1639506410.124 [DAT ThreadHandler](INFO): Thread cancelled.
2021-12-14T18:26:50.134Z,1639506410.134 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2021-12-14T18:26:50.134Z,1639506410.134 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-12-14T18:26:50.134Z,1639506410.134 [Radio_Surface](INFO): Join timeout helper Thread ID is 2861
2021-12-14T18:26:50.139Z,1639506410.139 [Radio_Surface](INFO): Powering down
2021-12-14T18:26:50.140Z,1639506410.140 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-14T18:26:50.140Z,1639506410.140 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-12-14T18:26:50.151Z,1639506410.151 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2021-12-14T18:26:50.151Z,1639506410.151 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-12-14T18:26:50.151Z,1639506410.151 [Onboard](INFO): Join timeout helper Thread ID is 2862
2021-12-14T18:26:50.523Z,1639506410.523 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-14T18:26:50.523Z,1639506410.523 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-12-14T18:26:50.531Z,1639506410.531 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2021-12-14T18:26:50.531Z,1639506410.531 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2021-12-14T18:26:50.531Z,1639506410.531 [BackseatComponent](INFO): Join timeout helper Thread ID is 2863
2021-12-14T18:26:50.647Z,1639506410.647 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-14T18:26:50.647Z,1639506410.647 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2021-12-14T18:26:50.664Z,1639506410.664 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2021-12-14T18:26:50.664Z,1639506410.664 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-12-14T18:26:50.664Z,1639506410.664 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 2864
2021-12-14T18:26:50.915Z,1639506410.915 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-14T18:26:50.915Z,1639506410.915 [WetLabsBB2FL](INFO): Powering down
2021-12-14T18:26:50.916Z,1639506410.916 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-12-14T18:26:50.928Z,1639506410.928 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2021-12-14T18:26:50.928Z,1639506410.928 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-12-14T18:26:50.928Z,1639506410.928 [CTD_Seabird](INFO): Join timeout helper Thread ID is 2865
2021-12-14T18:26:51.279Z,1639506411.279 [CTD_Seabird](INFO): Powering down
2021-12-14T18:26:51.295Z,1639506411.295 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-14T18:26:51.295Z,1639506411.295 [CTD_Seabird](INFO): Powering down
2021-12-14T18:26:51.307Z,1639506411.307 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-12-14T18:26:51.308Z,1639506411.308 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2021-12-14T18:26:51.308Z,1639506411.308 [logger ThreadHandler](INFO): Thread cancelled.
2021-12-14T18:26:51.309Z,1639506411.309 [logger](INFO): Join timeout helper Thread ID is 2866
2021-12-14T18:26:51.332Z,1639506411.332 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-14T18:26:51.332Z,1639506411.332 [logger ThreadHandler](INFO): Thread cancelled.
2021-12-14T18:26:51.351Z,1639506411.351 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2021-12-14T18:26:51.352Z,1639506411.352 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-12-14T18:26:51.352Z,1639506411.352 [CommandLine](INFO): Join timeout helper Thread ID is 2867
2021-12-14T18:26:51.447Z,1639506411.447 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-14T18:26:51.447Z,1639506411.447 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-12-14T18:26:51.451Z,1639506411.451 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2021-12-14T18:26:51.452Z,1639506411.452 [CommandExec ThreadHandler](INFO): Thread cancelled.
2021-12-14T18:26:51.452Z,1639506411.452 [CommandExec](INFO): Join timeout helper Thread ID is 2868
2021-12-14T18:26:51.453Z,1639506411.453 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2021-12-14T18:26:51.453Z,1639506411.453 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-12-14T18:26:51.454Z,1639506411.454 [controlThread](INFO): Join timeout helper Thread ID is 2869
2021-12-14T18:26:51.639Z,1639506411.639 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-14T18:26:51.639Z,1639506411.639 [controlThread](DEBUG): Uninitializing ControlThread
2021-12-14T18:26:51.640Z,1639506411.640 [AHRS_M2](INFO): Powering down
2021-12-14T18:26:51.712Z,1639506411.712 [NAL9602](INFO): Powering down
2021-12-14T18:26:51.713Z,1639506411.713 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2021-12-14T18:26:51.714Z,1639506411.714 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2021-12-14T18:26:51.715Z,1639506411.715 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2021-12-14T18:26:51.716Z,1639506411.716 [MissionManager](INFO): Uninitializing Mission Default
2021-12-14T18:26:51.716Z,1639506411.716 [Default] Stopped
2021-12-14T18:26:51.716Z,1639506411.716 [Default](DEBUG): Aggregate::uninitialize Default
2021-12-14T18:26:51.716Z,1639506411.716 [Default:B.GoToSurface] Stopped
2021-12-14T18:26:51.716Z,1639506411.716 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-12-14T18:26:51.716Z,1639506411.716 [Default:CheckIn] Stopped
2021-12-14T18:26:51.716Z,1639506411.716 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-12-14T18:26:51.716Z,1639506411.716 [Default:CheckIn:Read_Iridium] Stopped
2021-12-14T18:26:51.720Z,1639506411.720 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2021-12-14T18:26:51.720Z,1639506411.720 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2021-12-14T18:26:51.720Z,1639506411.720 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2021-12-14T18:26:51.721Z,1639506411.721 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2021-12-14T18:26:51.721Z,1639506411.721 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2021-12-14T18:26:51.721Z,1639506411.721 [BuoyancyServo](INFO): Powering down
2021-12-14T18:26:51.735Z,1639506411.735 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2021-12-14T18:26:51.735Z,1639506411.735 [ElevatorServo](INFO): Powering down
2021-12-14T18:26:51.736Z,1639506411.736 [MassServo](DEBUG): Uninitialize Mass Servo.
2021-12-14T18:26:51.736Z,1639506411.736 [MassServo](INFO): Powering down
2021-12-14T18:26:51.737Z,1639506411.737 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-12-14T18:26:51.737Z,1639506411.737 [RudderServo](INFO): Powering down
2021-12-14T18:26:51.738Z,1639506411.738 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2021-12-14T18:26:51.738Z,1639506411.738 [ThrusterHE](INFO): Powering down
2021-12-14T18:26:51.739Z,1639506411.739 [SBIT](DEBUG): Uninitialize SBIT Component.
2021-12-14T18:26:51.739Z,1639506411.739 [IBIT](DEBUG): Uninitialize IBIT Component.
2021-12-14T18:26:51.740Z,1639506411.740 [CBIT](DEBUG): Uninitialize CBIT Component.
2021-12-14T18:26:51.740Z,1639506411.740 [CBIT](DEBUG): Powering off loads.
2021-12-14T18:26:51.751Z,1639506411.751 [CBIT](DEBUG): Disabling WDT.
2021-12-14T18:26:51.763Z,1639506411.763 [CBIT](DEBUG): Opening all GF detection circuits.
2021-12-14T18:26:51.764Z,1639506411.764 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-12-14T18:26:51.799Z,1639506411.799 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-12-14T18:26:51.803Z,1639506411.803 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-12-14T18:26:51.847Z,1639506411.847 [DAT ThreadHandler](INFO): Thread cancelled.
2021-12-14T18:26:51.851Z,1639506411.851 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-12-14T18:26:51.853Z,1639506411.853 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-12-14T18:26:51.897Z,1639506411.897 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2021-12-14T18:26:51.935Z,1639506411.935 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-12-14T18:26:51.996Z,1639506411.996 [logger ThreadHandler](INFO): Thread cancelled.