2020-05-19T18:05:47.035Z,1589911547.035 [Supervisor](DEBUG): Initializing supervisor.
2020-05-19T18:05:47.038Z,1589911547.038 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-05-19T18:05:47.038Z,1589911547.038 [SyncHandler](INFO): Protected caller Thread ID is 3396
2020-05-19T18:05:47.038Z,1589911547.038 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-05-19T18:05:47.040Z,1589911547.040 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-05-19T18:05:47.040Z,1589911547.040 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 3397
2020-05-19T18:05:47.042Z,1589911547.042 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-05-19T18:05:47.055Z,1589911547.055 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-05-19T18:05:47.056Z,1589911547.056 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-05-19T18:05:47.056Z,1589911547.056 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 3398
2020-05-19T18:05:47.057Z,1589911547.057 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-05-19T18:05:47.058Z,1589911547.058 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-05-19T18:05:47.058Z,1589911547.058 [logger ThreadHandler](INFO): Protected caller Thread ID is 3399
2020-05-19T18:05:47.060Z,1589911547.060 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-05-19T18:05:47.060Z,1589911547.060 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-05-19T18:05:47.062Z,1589911547.062 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-05-19T18:05:47.154Z,1589911547.154 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-05-19T18:05:47.154Z,1589911547.154 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-05-19T18:05:47.356Z,1589911547.356 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-05-19T18:05:47.357Z,1589911547.357 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-05-19T18:05:47.487Z,1589911547.487 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-05-19T18:05:47.488Z,1589911547.488 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-05-19T18:05:48.188Z,1589911548.188 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-05-19T18:05:48.189Z,1589911548.189 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-05-19T18:05:48.630Z,1589911548.630 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-05-19T18:05:48.631Z,1589911548.631 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-05-19T18:05:49.080Z,1589911549.080 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-05-19T18:05:49.081Z,1589911549.081 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-05-19T18:05:49.442Z,1589911549.442 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-05-19T18:05:49.443Z,1589911549.443 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-05-19T18:05:49.753Z,1589911549.753 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-05-19T18:05:49.754Z,1589911549.754 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-05-19T18:05:50.151Z,1589911550.151 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-05-19T18:05:50.152Z,1589911550.152 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-05-19T18:05:50.294Z,1589911550.294 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-05-19T18:05:50.295Z,1589911550.295 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-05-19T18:05:50.398Z,1589911550.398 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-05-19T18:05:50.399Z,1589911550.399 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-05-19T18:05:50.477Z,1589911550.477 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-05-19T18:05:50.576Z,1589911550.576 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-05-19T18:05:50.577Z,1589911550.577 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-05-19T18:05:50.760Z,1589911550.760 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-05-19T18:05:50.760Z,1589911550.760 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-05-19T18:05:50.962Z,1589911550.962 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-05-19T18:05:50.964Z,1589911550.964 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2020-05-19T18:05:50.965Z,1589911550.965 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2020-05-19T18:05:51.046Z,1589911551.046 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2020-05-19T18:05:51.269Z,1589911551.269 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-05-19T18:05:51.269Z,1589911551.269 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2020-05-19T18:05:51.362Z,1589911551.362 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2020-05-19T18:05:51.521Z,1589911551.521 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2020-05-19T18:05:51.718Z,1589911551.718 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2020-05-19T18:05:51.801Z,1589911551.801 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2020-05-19T18:05:51.899Z,1589911551.899 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2020-05-19T18:05:51.989Z,1589911551.989 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2020-05-19T18:05:52.137Z,1589911552.137 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2020-05-19T18:05:52.238Z,1589911552.238 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2020-05-19T18:05:52.335Z,1589911552.335 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2020-05-19T18:05:52.335Z,1589911552.335 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-05-19T18:05:52.347Z,1589911552.347 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-05-19T18:05:52.444Z,1589911552.444 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-05-19T18:05:52.444Z,1589911552.444 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-05-19T18:05:52.573Z,1589911552.573 [BuoyancyServo] Loaded
2020-05-19T18:05:52.573Z,1589911552.573 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-05-19T18:05:52.589Z,1589911552.589 [ElevatorServo] Loaded
2020-05-19T18:05:52.589Z,1589911552.589 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-05-19T18:05:52.604Z,1589911552.604 [MassServo] Loaded
2020-05-19T18:05:52.604Z,1589911552.604 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-05-19T18:05:52.620Z,1589911552.620 [RudderServo] Loaded
2020-05-19T18:05:52.620Z,1589911552.620 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-05-19T18:05:52.634Z,1589911552.634 [ThrusterServo] Loaded
2020-05-19T18:05:52.635Z,1589911552.635 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-05-19T18:05:52.635Z,1589911552.635 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-05-19T18:05:52.636Z,1589911552.636 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-05-19T18:05:52.768Z,1589911552.768 [SBIT](DEBUG): Construct Startup Built In Test.
2020-05-19T18:05:52.797Z,1589911552.797 [SBIT] Loaded
2020-05-19T18:05:52.797Z,1589911552.797 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-05-19T18:05:52.798Z,1589911552.798 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-05-19T18:05:52.828Z,1589911552.828 [IBIT] Loaded
2020-05-19T18:05:52.828Z,1589911552.828 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-05-19T18:05:52.831Z,1589911552.831 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-05-19T18:05:53.222Z,1589911553.222 [CBIT] Loaded
2020-05-19T18:05:53.222Z,1589911553.222 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-05-19T18:05:53.223Z,1589911553.223 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-05-19T18:05:53.223Z,1589911553.223 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-05-19T18:05:53.797Z,1589911553.797 [ESPComponent] Loaded
2020-05-19T18:05:53.797Z,1589911553.797 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2020-05-19T18:05:53.847Z,1589911553.847 [PAR_Licor] Loaded
2020-05-19T18:05:53.847Z,1589911553.847 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-05-19T18:05:53.874Z,1589911553.874 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470
2020-05-19T18:05:53.874Z,1589911553.874 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470
2020-05-19T18:05:53.882Z,1589911553.882 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650
2020-05-19T18:05:53.883Z,1589911553.883 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650
2020-05-19T18:05:53.887Z,1589911553.887 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl
2020-05-19T18:05:53.887Z,1589911553.887 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl
2020-05-19T18:05:53.891Z,1589911553.891 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm
2020-05-19T18:05:53.892Z,1589911553.892 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm
2020-05-19T18:05:53.896Z,1589911553.896 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm
2020-05-19T18:05:53.896Z,1589911553.896 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm
2020-05-19T18:05:53.900Z,1589911553.900 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm
2020-05-19T18:05:53.901Z,1589911553.901 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm
2020-05-19T18:05:53.905Z,1589911553.905 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm
2020-05-19T18:05:53.905Z,1589911553.905 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm
2020-05-19T18:05:53.909Z,1589911553.909 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water
2020-05-19T18:05:53.914Z,1589911553.914 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water
2020-05-19T18:05:53.915Z,1589911553.915 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-05-19T18:05:53.915Z,1589911553.915 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-05-19T18:05:53.919Z,1589911553.919 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-05-19T18:05:53.919Z,1589911553.919 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-05-19T18:05:53.924Z,1589911553.924 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-05-19T18:05:53.924Z,1589911553.924 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-05-19T18:05:53.928Z,1589911553.928 [WetLabsBB2FL] Loaded
2020-05-19T18:05:53.929Z,1589911553.929 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2020-05-19T18:05:53.930Z,1589911553.930 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4066C4E0
2020-05-19T18:05:53.930Z,1589911553.930 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 3479
2020-05-19T18:05:53.931Z,1589911553.931 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-05-19T18:05:53.932Z,1589911553.932 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-05-19T18:05:54.043Z,1589911554.043 [DepthRateCalculator] Loaded
2020-05-19T18:05:54.043Z,1589911554.043 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-05-19T18:05:54.049Z,1589911554.049 [PitchRateCalculator] Loaded
2020-05-19T18:05:54.049Z,1589911554.049 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-05-19T18:05:54.065Z,1589911554.065 [SpeedCalculator] Loaded
2020-05-19T18:05:54.065Z,1589911554.065 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-05-19T18:05:54.086Z,1589911554.086 [TempGradientCalculator] Loaded
2020-05-19T18:05:54.086Z,1589911554.086 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-05-19T18:05:54.092Z,1589911554.092 [YawRateCalculator] Loaded
2020-05-19T18:05:54.092Z,1589911554.092 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-05-19T18:05:54.125Z,1589911554.125 [ElevatorOffsetCalculator] Loaded
2020-05-19T18:05:54.125Z,1589911554.125 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-05-19T18:05:54.126Z,1589911554.126 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-05-19T18:05:54.126Z,1589911554.126 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-05-19T18:05:54.158Z,1589911554.158 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-05-19T18:05:54.158Z,1589911554.158 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-05-19T18:05:54.261Z,1589911554.261 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-05-19T18:05:54.262Z,1589911554.262 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-05-19T18:05:54.283Z,1589911554.283 [NavChart] Loaded
2020-05-19T18:05:54.283Z,1589911554.283 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-05-19T18:05:54.287Z,1589911554.287 [UniversalFixResidualReporter] Loaded
2020-05-19T18:05:54.287Z,1589911554.287 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-05-19T18:05:54.288Z,1589911554.288 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-05-19T18:05:54.288Z,1589911554.288 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-05-19T18:05:54.609Z,1589911554.609 [DataOverHttps] Loaded
2020-05-19T18:05:54.609Z,1589911554.609 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-05-19T18:05:54.610Z,1589911554.610 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409394E0
2020-05-19T18:05:54.611Z,1589911554.611 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 3480
2020-05-19T18:05:54.624Z,1589911554.624 [Depth_Keller] Loaded
2020-05-19T18:05:54.624Z,1589911554.624 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-05-19T18:05:54.629Z,1589911554.629 [DropWeight] Loaded
2020-05-19T18:05:54.629Z,1589911554.629 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-05-19T18:05:54.719Z,1589911554.719 [NAL9602] Loaded
2020-05-19T18:05:54.719Z,1589911554.719 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-05-19T18:05:54.757Z,1589911554.757 [Onboard] Loaded
2020-05-19T18:05:54.758Z,1589911554.758 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2020-05-19T18:05:54.759Z,1589911554.759 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409694E0
2020-05-19T18:05:54.759Z,1589911554.759 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 3481
2020-05-19T18:05:54.762Z,1589911554.762 [Radio_Surface] Loaded
2020-05-19T18:05:54.763Z,1589911554.763 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-05-19T18:05:54.764Z,1589911554.764 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409994E0
2020-05-19T18:05:54.764Z,1589911554.764 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 3482
2020-05-19T18:05:54.893Z,1589911554.893 [DAT] Loaded
2020-05-19T18:05:54.893Z,1589911554.893 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2020-05-19T18:05:56.162Z,1589911556.162 [BPC1] Loaded
2020-05-19T18:05:56.162Z,1589911556.162 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-05-19T18:05:56.162Z,1589911556.162 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-05-19T18:05:56.163Z,1589911556.163 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-05-19T18:05:56.233Z,1589911556.233 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-05-19T18:05:56.233Z,1589911556.233 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-05-19T18:05:56.279Z,1589911556.279 [VerticalControl](DEBUG): Construct VerticalControl.
2020-05-19T18:05:56.363Z,1589911556.363 [VerticalControl] Loaded
2020-05-19T18:05:56.364Z,1589911556.364 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-05-19T18:05:56.364Z,1589911556.364 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-05-19T18:05:56.422Z,1589911556.422 [HorizontalControl] Loaded
2020-05-19T18:05:56.423Z,1589911556.423 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-05-19T18:05:56.423Z,1589911556.423 [SpeedControl](DEBUG): Construct SpeedControl.
2020-05-19T18:05:56.425Z,1589911556.425 [SpeedControl] Loaded
2020-05-19T18:05:56.425Z,1589911556.425 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-05-19T18:05:56.426Z,1589911556.426 [LoopControl](DEBUG): Construct LoopControl.
2020-05-19T18:05:56.427Z,1589911556.427 [LoopControl] Loaded
2020-05-19T18:05:56.427Z,1589911556.427 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-05-19T18:05:56.427Z,1589911556.427 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-05-19T18:05:56.428Z,1589911556.428 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-05-19T18:05:56.441Z,1589911556.441 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-05-19T18:05:56.442Z,1589911556.442 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-05-19T18:05:56.726Z,1589911556.726 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-05-19T18:05:56.730Z,1589911556.730 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-05-19T18:05:56.731Z,1589911556.731 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-05-19T18:05:56.737Z,1589911556.737 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-05-19T18:05:56.738Z,1589911556.738 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40ACC4E0
2020-05-19T18:05:56.739Z,1589911556.739 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 3483
2020-05-19T18:05:56.744Z,1589911556.744 [Supervisor](INFO): Main Thread ID is 3395
2020-05-19T18:05:56.744Z,1589911556.744 [Supervisor](DEBUG): Running supervisor.
2020-05-19T18:05:56.744Z,1589911556.744 [CommandLine ThreadHandler](INFO): Handler Thread ID is 3484
2020-05-19T18:05:56.747Z,1589911556.747 [controlThread ThreadHandler](INFO): Handler Thread ID is 3485
2020-05-19T18:05:56.747Z,1589911556.747 [controlThread](DEBUG): Initializing ControlThread
2020-05-19T18:05:56.749Z,1589911556.749 [SBIT](INFO): Initialize SBIT Component.
2020-05-19T18:05:56.749Z,1589911556.749 [SBIT](IMPORTANT): git: 2020-01-30-35-gb1cf28841
2020-05-19T18:05:56.750Z,1589911556.750 [SBIT](INFO): git hash: b1cf28841e0d8ea373dfd2467fcdbb870873af49
2020-05-19T18:05:56.750Z,1589911556.750 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-05-19T18:05:56.751Z,1589911556.751 [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 Nov 13 12:38:10 PST 2019
2020-05-19T18:05:56.753Z,1589911556.753 [SBIT](INFO): Beginning SBIT in 72.000000 seconds.
2020-05-19T18:05:56.753Z,1589911556.753 [IBIT](INFO): Initialize IBIT Component.
2020-05-19T18:05:56.754Z,1589911556.754 [CBIT](DEBUG): Initialize CBIT Component.
2020-05-19T18:05:56.755Z,1589911556.755 [logger ThreadHandler](INFO): Handler Thread ID is 3486
2020-05-19T18:05:56.767Z,1589911556.767 [CBIT](DEBUG): Initialized mux pins.
2020-05-19T18:05:56.767Z,1589911556.767 [CBIT](DEBUG): Initializing the watchdog timer.
2020-05-19T18:05:56.776Z,1589911556.776 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 3487
2020-05-19T18:05:56.777Z,1589911556.777 [WetLabsBB2FL](INFO): Powering down
2020-05-19T18:05:56.791Z,1589911556.791 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-05-19T18:05:56.791Z,1589911556.791 [CBIT](DEBUG): Initializing heartbeat.
2020-05-19T18:05:56.811Z,1589911556.811 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 3488
2020-05-19T18:05:56.812Z,1589911556.812 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-05-19T18:05:56.828Z,1589911556.828 [Onboard ThreadHandler](INFO): Handler Thread ID is 3489
2020-05-19T18:05:56.840Z,1589911556.840 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 3490
2020-05-19T18:05:56.855Z,1589911556.855 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 3491
2020-05-19T18:05:56.858Z,1589911556.858 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-05-19T18:05:56.858Z,1589911556.858 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-05-19T18:05:56.859Z,1589911556.859 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-05-19T18:05:56.859Z,1589911556.859 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-05-19T18:05:56.859Z,1589911556.859 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-05-19T18:05:56.859Z,1589911556.859 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-05-19T18:05:56.860Z,1589911556.860 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-05-19T18:05:56.860Z,1589911556.860 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-05-19T18:05:56.860Z,1589911556.860 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-05-19T18:05:56.860Z,1589911556.860 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-05-19T18:05:56.860Z,1589911556.860 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-05-19T18:05:56.860Z,1589911556.860 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-05-19T18:05:56.861Z,1589911556.861 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-05-19T18:05:56.861Z,1589911556.861 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-05-19T18:05:56.861Z,1589911556.861 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-05-19T18:05:56.861Z,1589911556.861 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-05-19T18:05:56.863Z,1589911556.863 [CBIT](DEBUG): Deactivating GF circuits.
2020-05-19T18:05:56.863Z,1589911556.863 [CBIT](DEBUG): Deactivating emergency mode.
2020-05-19T18:05:56.899Z,1589911556.899 [CBIT](DEBUG): Backplane powered.
2020-05-19T18:05:56.903Z,1589911556.903 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-05-19T18:05:56.904Z,1589911556.904 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-05-19T18:05:56.904Z,1589911556.904 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-05-19T18:05:56.904Z,1589911556.904 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-05-19T18:05:56.905Z,1589911556.905 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-05-19T18:05:56.905Z,1589911556.905 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-05-19T18:05:56.906Z,1589911556.906 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-05-19T18:05:56.907Z,1589911556.907 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-05-19T18:05:56.913Z,1589911556.913 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-05-19T18:05:56.915Z,1589911556.915 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-05-19T18:05:56.916Z,1589911556.916 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-05-19T18:05:56.916Z,1589911556.916 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-05-19T18:05:56.917Z,1589911556.917 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-05-19T18:05:56.944Z,1589911556.944 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-05-19T18:05:56.980Z,1589911556.980 [MissionManager](DEBUG):
2020-05-19T18:05:56.980Z,1589911556.980 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-05-19T18:05:57.050Z,1589911557.050 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-05-19T18:05:57.075Z,1589911557.075 [Default:A.Wait](DEBUG): Construct Wait.
2020-05-19T18:05:57.077Z,1589911557.077 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-05-19T18:05:57.104Z,1589911557.104 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-05-19T18:05:57.106Z,1589911557.106 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-05-19T18:05:57.128Z,1589911557.128 [Default:E.Execute](DEBUG): Construct Execute.
2020-05-19T18:05:57.146Z,1589911557.146 [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
2020-05-19T18:05:57.155Z,1589911557.155 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,Depth_Keller,DropWeight,NAL9602,DAT,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2020-05-19T18:05:57.170Z,1589911557.170 [Depth_Keller](ERROR): Pressure reading out of range: 1895.684326 decibar
2020-05-19T18:05:57.174Z,1589911557.174 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-05-19T18:05:57.174Z,1589911557.174 [DAT](INFO): Powering up
2020-05-19T18:05:57.174Z,1589911557.174 [DAT](DEBUG): Initializing DAT.
2020-05-19T18:05:57.228Z,1589911557.228 [DepthRateCalculator](ERROR): Depth measurement is not active
2020-05-19T18:05:57.243Z,1589911557.243 [Radio_Surface](INFO): Powering up
2020-05-19T18:05:57.252Z,1589911557.252 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-05-19T18:05:57.312Z,1589911557.312 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-05-19T18:05:57.319Z,1589911557.319 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-05-19T18:05:57.321Z,1589911557.321 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-05-19T18:05:57.332Z,1589911557.332 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-05-19T18:05:57.333Z,1589911557.333 [MassServo](DEBUG): Initializing EZServoServo.
2020-05-19T18:05:57.343Z,1589911557.343 [MassServo](DEBUG): Initializing MassServo.
2020-05-19T18:05:57.344Z,1589911557.344 [RudderServo](DEBUG): Initializing EZServoServo.
2020-05-19T18:05:57.355Z,1589911557.355 [RudderServo](DEBUG): Initializing RudderServo.
2020-05-19T18:05:57.356Z,1589911557.356 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-05-19T18:05:57.369Z,1589911557.369 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-05-19T18:05:57.605Z,1589911557.605 [DropWeight](CRITICAL): DROP WEIGHT MISSING.
2020-05-19T18:05:57.605Z,1589911557.605 [DropWeight] Hardware Fault, FailCount= 1
2020-05-19T18:05:57.605Z,1589911557.605 [DropWeight](ERROR): Hardware Fault
2020-05-19T18:05:57.633Z,1589911557.633 [CommandLine](FAULT): Scheduling is paused
2020-05-19T18:05:57.633Z,1589911557.633 [CBIT](INFO): Critical error at 20200519T180557
2020-05-19T18:05:57.633Z,1589911557.633 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2020-05-19T18:05:57.636Z,1589911557.636 [CBIT](ERROR): Hardware Fault in component: DropWeight
2020-05-19T18:05:57.636Z,1589911557.636 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2020-05-19T18:05:58.291Z,1589911558.291 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2020-05-19T18:05:58.291Z,1589911558.291 [RudderServo](FAULT): Rudder failed to initialize
2020-05-19T18:05:58.291Z,1589911558.291 [RudderServo] Communications Fault, FailCount= 1
2020-05-19T18:05:58.291Z,1589911558.291 [RudderServo](ERROR): Communications Fault
2020-05-19T18:05:58.400Z,1589911558.400 [CBIT](INFO): Critical error at 20200519T180557
2020-05-19T18:05:58.403Z,1589911558.403 [CBIT](ERROR): Communications Fault in component: RudderServo
2020-05-19T18:05:58.604Z,1589911558.604 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-05-19T18:05:58.604Z,1589911558.604 [RudderServo](INFO): Powering down
2020-05-19T18:05:59.243Z,1589911559.243 [RudderServo](DEBUG): Initializing EZServoServo.
2020-05-19T18:05:59.364Z,1589911559.364 [RudderServo](DEBUG): Initializing RudderServo.
2020-05-19T18:05:59.368Z,1589911559.368 [CBIT](INFO): Clearing failed state for component RudderServo
2020-05-19T18:05:59.368Z,1589911559.368 [RudderServo] No Fault, FailCount= 1
2020-05-19T18:06:06.944Z,1589911566.944 [CBIT](CRITICAL): Environmental Failure. Press:0.000000 PSI. Humidity:2296080%. Temp:3785888 C. ABORTING MISSION
2020-05-19T18:06:07.346Z,1589911567.346 [CBIT](INFO): Critical error at 20200519T180606
2020-05-19T18:06:25.076Z,1589911585.076 [NAL9602](INFO): Powering up NAL9602
2020-05-19T18:06:35.991Z,1589911595.991 [NAL9602](INFO): NAL9602 initialized
2020-05-19T18:06:57.402Z,1589911617.402 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: , available:
2020-05-19T18:06:57.402Z,1589911617.402 [DAT] Communications Fault, FailCount= 1
2020-05-19T18:06:57.402Z,1589911617.402 [DAT](ERROR): Communications Fault
2020-05-19T18:06:57.440Z,1589911617.440 [CBIT](ERROR): Communications Fault in component: DAT
2020-05-19T18:06:57.808Z,1589911617.808 [DAT](INFO): Powering down
2020-05-19T18:06:58.647Z,1589911618.647 [CBIT](INFO): Clearing failed state for component DAT
2020-05-19T18:06:58.647Z,1589911618.647 [DAT] No Fault, FailCount= 1
2020-05-19T18:07:01.045Z,1589911621.045 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-05-19T18:07:01.045Z,1589911621.045 [DAT](INFO): Powering up
2020-05-19T18:07:01.045Z,1589911621.045 [DAT](DEBUG): Initializing DAT.
2020-05-19T18:07:01.132Z,1589911621.132 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-05-19T18:07:09.533Z,1589911629.533 [SBIT](IMPORTANT): Beginning Startup BIT
2020-05-19T18:07:09.538Z,1589911629.538 [CBIT](IMPORTANT): Beginning ground fault scan
2020-05-19T18:07:20.680Z,1589911640.680 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.007391
CHAN A1 (24V): -0.000550
CHAN A2 (12V): -0.000050
CHAN A3 (5V): -0.000393
CHAN B0 (3.3V): -0.000737
CHAN B1 (3.15aV): -0.000132
CHAN B2 (3.15bV): 0.000160
CHAN B3 (GND): -0.000148
OPEN: 0.006535
Full Scale Calc: 4.765 mA, -1.589 mA
2020-05-19T18:07:57.164Z,1589911677.164 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2020-05-19T18:07:57.164Z,1589911677.164 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2020-05-19T18:07:57.164Z,1589911677.164 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-05-19T18:07:57.197Z,1589911677.197 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-05-19T18:07:57.596Z,1589911677.596 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-05-19T18:07:57.596Z,1589911677.596 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2020-05-19T18:08:01.187Z,1589911681.187 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: , available:
2020-05-19T18:08:01.187Z,1589911681.187 [DAT] Communications Fault, FailCount= 2
2020-05-19T18:08:01.187Z,1589911681.187 [DAT](ERROR): Communications Fault
2020-05-19T18:08:01.202Z,1589911681.202 [CBIT](ERROR): Communications Fault in component: DAT
2020-05-19T18:08:01.588Z,1589911681.588 [DAT](INFO): Powering down
2020-05-19T18:08:02.445Z,1589911682.445 [CBIT](INFO): Clearing failed state for component DAT
2020-05-19T18:08:02.445Z,1589911682.445 [DAT] No Fault, FailCount= 2
2020-05-19T18:08:03.230Z,1589911683.230 [SBIT](IMPORTANT): SBIT PASSED
2020-05-19T18:08:03.230Z,1589911683.230 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-05-19T18:08:03.231Z,1589911683.231 [SBIT](IMPORTANT): AHRS_M2.loadAtStartup=0 bool;
2020-05-19T18:08:03.231Z,1589911683.231 [SBIT](IMPORTANT): Aanderaa_O2.loadAtStartup=0 bool;
2020-05-19T18:08:03.231Z,1589911683.231 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;
2020-05-19T18:08:03.231Z,1589911683.231 [SBIT](IMPORTANT): BuoyancyServo.checkingTimeout=30 second;
2020-05-19T18:08:03.232Z,1589911683.232 [SBIT](IMPORTANT): CBIT.gf12Offset=61.5 microampere;
2020-05-19T18:08:03.232Z,1589911683.232 [SBIT](IMPORTANT): CBIT.gf24Offset=148.1 microampere;
2020-05-19T18:08:03.232Z,1589911683.232 [SBIT](IMPORTANT): CBIT.gf3_15Offset=-4.3 microampere;
2020-05-19T18:08:03.232Z,1589911683.232 [SBIT](IMPORTANT): CBIT.gf3_3Offset=-2.7 microampere;
2020-05-19T18:08:03.232Z,1589911683.232 [SBIT](IMPORTANT): CBIT.gf5Offset=8.7 microampere;
2020-05-19T18:08:03.232Z,1589911683.232 [SBIT](IMPORTANT): CBIT.gfCommOffset=-27.9 microampere;
2020-05-19T18:08:03.232Z,1589911683.232 [SBIT](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool;
2020-05-19T18:08:03.232Z,1589911683.232 [SBIT](IMPORTANT): DAT.sbdAddress=-1 enum;
2020-05-19T18:08:03.232Z,1589911683.232 [SBIT](IMPORTANT): DVL_micro.loadAtStartup=0 bool;
2020-05-19T18:08:03.233Z,1589911683.233 [SBIT](IMPORTANT): Onboard.simulateHardware=1 bool;
2020-05-19T18:08:03.635Z,1589911683.635 [MissionManager](IMPORTANT): Started mission Startup
2020-05-19T18:08:03.635Z,1589911683.635 [Startup] Running Loop=1
2020-05-19T18:08:03.636Z,1589911683.636 [Startup](DEBUG): Aggregate::initialize Startup
2020-05-19T18:08:03.636Z,1589911683.636 [Startup:A.GoToSurface] Running Loop=1
2020-05-19T18:08:03.636Z,1589911683.636 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-05-19T18:08:03.636Z,1589911683.636 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-05-19T18:08:03.637Z,1589911683.637 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-05-19T18:08:03.637Z,1589911683.637 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-05-19T18:08:03.638Z,1589911683.638 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-05-19T18:08:03.638Z,1589911683.638 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-05-19T18:08:03.640Z,1589911683.640 [Startup:StartupSatComms] Running Loop=1
2020-05-19T18:08:03.640Z,1589911683.640 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-05-19T18:08:03.640Z,1589911683.640 [Startup:StartupSatComms:A] Running Loop=1
2020-05-19T18:08:04.079Z,1589911684.079 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-05-19T18:08:04.816Z,1589911684.816 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-05-19T18:08:04.816Z,1589911684.816 [DAT](INFO): Powering up
2020-05-19T18:08:04.817Z,1589911684.817 [DAT](DEBUG): Initializing DAT.
2020-05-19T18:08:04.843Z,1589911684.843 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-05-19T18:08:39.450Z,1589911719.450 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005237
2020-05-19T18:09:03.811Z,1589911743.811 [Startup:StartupSatComms:A](INFO): Timed out from 2020-05-19T18:08:03.6Z
2020-05-19T18:09:03.812Z,1589911743.812 [Startup:StartupSatComms:A] Stopped
2020-05-19T18:09:03.812Z,1589911743.812 [Startup:StartupSatComms:B] Running Loop=1
2020-05-19T18:09:04.212Z,1589911744.212 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-05-19T18:09:05.017Z,1589911745.017 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: , available:
2020-05-19T18:09:05.017Z,1589911745.017 [DAT] Communications Fault, FailCount= 3
2020-05-19T18:09:05.017Z,1589911745.017 [DAT](ERROR): Communications Fault
2020-05-19T18:09:05.090Z,1589911745.090 [CBIT](ERROR): Communications Fault in component: DAT
2020-05-19T18:09:05.431Z,1589911745.431 [DAT](INFO): Powering down
2020-05-19T18:09:06.260Z,1589911746.260 [CBIT](INFO): Clearing failed state for component DAT
2020-05-19T18:09:06.260Z,1589911746.260 [DAT] No Fault, FailCount= 3
2020-05-19T18:09:08.655Z,1589911748.655 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-05-19T18:09:08.655Z,1589911748.655 [DAT](INFO): Powering up
2020-05-19T18:09:08.656Z,1589911748.656 [DAT](DEBUG): Initializing DAT.
2020-05-19T18:09:08.660Z,1589911748.660 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-05-19T18:09:08.968Z,1589911748.968 [DataOverHttps](INFO): Sending 50 bytes from file Logs/20200519T164053/Courier0025.lzma
2020-05-19T18:09:09.969Z,1589911749.969 [DataOverHttps](INFO): Moved sent file to Logs/20200519T164053/Courier0025.lzma.bak
2020-05-19T18:09:09.969Z,1589911749.969 [DataOverHttps](INFO): SBD MOMSN=12338229
2020-05-19T18:09:25.059Z,1589911765.059 [DataOverHttps](INFO): Sending 217 bytes from file Logs/20200519T180336/Courier0000.lzma
2020-05-19T18:09:26.061Z,1589911766.061 [DataOverHttps](INFO): Moved sent file to Logs/20200519T180336/Courier0000.lzma.bak
2020-05-19T18:09:26.061Z,1589911766.061 [DataOverHttps](INFO): SBD MOMSN=12338231
2020-05-19T18:09:41.243Z,1589911781.243 [DataOverHttps](INFO): Sending 217 bytes from file Logs/20200519T180547/Courier0000.lzma
2020-05-19T18:09:42.245Z,1589911782.245 [DataOverHttps](INFO): Moved sent file to Logs/20200519T180547/Courier0000.lzma.bak
2020-05-19T18:09:42.245Z,1589911782.245 [DataOverHttps](INFO): SBD MOMSN=12338237
2020-05-19T18:09:57.219Z,1589911797.219 [DataOverHttps](INFO): Sending 451 bytes from file Logs/20200519T164053/Express0026.lzma
2020-05-19T18:09:58.221Z,1589911798.221 [DataOverHttps](INFO): Moved sent file to Logs/20200519T164053/Express0026.lzma.bak
2020-05-19T18:09:58.221Z,1589911798.221 [DataOverHttps](INFO): SBD MOMSN=12338243
2020-05-19T18:09:58.360Z,1589911798.360 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2020-05-19T18:09:58.360Z,1589911798.360 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2020-05-19T18:09:58.360Z,1589911798.360 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-05-19T18:09:58.370Z,1589911798.370 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-05-19T18:09:58.779Z,1589911798.779 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-05-19T18:09:58.779Z,1589911798.779 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2020-05-19T18:10:04.039Z,1589911804.039 [Startup:StartupSatComms:B](INFO): Timed out from 2020-05-19T18:09:03.8Z
2020-05-19T18:10:04.040Z,1589911804.040 [Startup:StartupSatComms:B] Stopped
2020-05-19T18:10:04.040Z,1589911804.040 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-05-19T18:10:04.040Z,1589911804.040 [Startup:StartupSatComms] Stopped
2020-05-19T18:10:04.040Z,1589911804.040 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-05-19T18:10:04.041Z,1589911804.041 [Startup](INFO): Completed Startup
2020-05-19T18:10:04.041Z,1589911804.041 [MissionManager](INFO): Startup is completed.
2020-05-19T18:10:04.041Z,1589911804.041 [MissionManager](INFO): Uninitializing Mission Startup
2020-05-19T18:10:04.041Z,1589911804.041 [Startup] Stopped
2020-05-19T18:10:04.041Z,1589911804.041 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-05-19T18:10:04.041Z,1589911804.041 [Startup:A.GoToSurface] Stopped
2020-05-19T18:10:04.041Z,1589911804.041 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-05-19T18:10:04.429Z,1589911804.429 [MissionManager](IMPORTANT): Started mission Default
2020-05-19T18:10:04.429Z,1589911804.429 [Default] Running Loop=1
2020-05-19T18:10:04.429Z,1589911804.429 [Default](DEBUG): Aggregate::initialize Default
2020-05-19T18:10:04.429Z,1589911804.429 [Default:B.GoToSurface] Running Loop=1
2020-05-19T18:10:04.430Z,1589911804.430 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-05-19T18:10:04.430Z,1589911804.430 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-05-19T18:10:04.430Z,1589911804.430 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-05-19T18:10:04.430Z,1589911804.430 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-05-19T18:10:04.431Z,1589911804.431 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-05-19T18:10:04.431Z,1589911804.431 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-05-19T18:10:04.431Z,1589911804.431 [Default:A.Wait] Running Loop=1
2020-05-19T18:10:04.432Z,1589911804.432 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-05-19T18:10:08.860Z,1589911808.860 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: , available:
2020-05-19T18:10:08.860Z,1589911808.860 [DAT] Communications Fault, FailCount= 4
2020-05-19T18:10:08.860Z,1589911808.860 [DAT](ERROR): Communications Fault
2020-05-19T18:10:08.912Z,1589911808.912 [CBIT](ERROR): Communications Fault in component: DAT
2020-05-19T18:10:09.263Z,1589911809.263 [DAT](INFO): Powering down
2020-05-19T18:10:10.082Z,1589911810.082 [CBIT](INFO): Clearing failed state for component DAT
2020-05-19T18:10:10.082Z,1589911810.082 [DAT] No Fault, FailCount= 4
2020-05-19T18:10:12.486Z,1589911812.486 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-05-19T18:10:12.486Z,1589911812.486 [DAT](INFO): Powering up
2020-05-19T18:10:12.486Z,1589911812.486 [DAT](DEBUG): Initializing DAT.
2020-05-19T18:10:12.493Z,1589911812.493 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-05-19T18:10:14.432Z,1589911814.432 [DataOverHttps](INFO): Sending 655 bytes from file Logs/20200519T180336/Express0001.lzma
2020-05-19T18:10:15.433Z,1589911815.433 [DataOverHttps](INFO): Moved sent file to Logs/20200519T180336/Express0001.lzma.bak
2020-05-19T18:10:15.433Z,1589911815.433 [DataOverHttps](INFO): SBD MOMSN=12338258
2020-05-19T18:10:17.744Z,1589911817.744 [Default:A.Wait](INFO): Done Waiting.
2020-05-19T18:10:17.744Z,1589911817.744 [Default:A.Wait] Stopped
2020-05-19T18:10:17.744Z,1589911817.744 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-05-19T18:10:18.150Z,1589911818.150 [Default:CheckIn] Running Loop=1
2020-05-19T18:10:18.150Z,1589911818.150 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-05-19T18:10:18.150Z,1589911818.150 [Default:CheckIn:Read_GPS] Running Loop=1
2020-05-19T18:10:18.565Z,1589911818.565 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-05-19T18:11:12.692Z,1589911872.692 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: , available:
2020-05-19T18:11:12.692Z,1589911872.692 [DAT] Communications Fault, FailCount= 5
2020-05-19T18:11:12.692Z,1589911872.692 [DAT](ERROR): Communications Fault
2020-05-19T18:11:12.761Z,1589911872.761 [CBIT](ERROR): Communications Fault in component: DAT
2020-05-19T18:11:13.092Z,1589911873.092 [DAT](INFO): Powering down
2020-05-19T18:11:13.937Z,1589911873.937 [CBIT](INFO): Clearing failed state for component DAT
2020-05-19T18:11:13.937Z,1589911873.937 [DAT] No Fault, FailCount= 5
2020-05-19T18:11:16.321Z,1589911876.321 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-05-19T18:11:16.321Z,1589911876.321 [DAT](INFO): Powering up
2020-05-19T18:11:16.321Z,1589911876.321 [DAT](DEBUG): Initializing DAT.
2020-05-19T18:11:16.395Z,1589911876.395 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-05-19T18:11:37.329Z,1589911897.329 [CommandLine](IMPORTANT): got command quit
2020-05-19T18:11:38.335Z,1589911898.335 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2020-05-19T18:11:38.335Z,1589911898.335 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-05-19T18:11:38.487Z,1589911898.487 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2020-05-19T18:11:38.487Z,1589911898.487 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-05-19T18:11:38.488Z,1589911898.488 [CommandLine](INFO): Join timeout helper Thread ID is 3533
2020-05-19T18:11:38.489Z,1589911898.489 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2020-05-19T18:11:38.489Z,1589911898.489 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-05-19T18:11:38.489Z,1589911898.489 [NavChartDb](INFO): Join timeout helper Thread ID is 3534
2020-05-19T18:11:38.515Z,1589911898.515 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2020-05-19T18:11:38.516Z,1589911898.516 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-05-19T18:11:38.536Z,1589911898.536 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2020-05-19T18:11:38.536Z,1589911898.536 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-05-19T18:11:38.536Z,1589911898.536 [Radio_Surface](INFO): Join timeout helper Thread ID is 3535
2020-05-19T18:11:38.671Z,1589911898.671 [Radio_Surface](INFO): Powering down
2020-05-19T18:11:38.672Z,1589911898.672 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2020-05-19T18:11:38.672Z,1589911898.672 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-05-19T18:11:38.679Z,1589911898.679 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2020-05-19T18:11:38.679Z,1589911898.679 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-05-19T18:11:38.680Z,1589911898.680 [Onboard](INFO): Join timeout helper Thread ID is 3536
2020-05-19T18:11:39.346Z,1589911899.346 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-05-19T18:11:42.115Z,1589911902.115 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2020-05-19T18:11:42.115Z,1589911902.115 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-05-19T18:11:42.127Z,1589911902.127 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2020-05-19T18:11:42.127Z,1589911902.127 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-05-19T18:11:42.127Z,1589911902.127 [DataOverHttps](INFO): Join timeout helper Thread ID is 3537
2020-05-19T18:11:42.919Z,1589911902.919 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2020-05-19T18:11:42.920Z,1589911902.920 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-05-19T18:11:42.936Z,1589911902.936 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2020-05-19T18:11:42.936Z,1589911902.936 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-05-19T18:11:42.937Z,1589911902.937 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 3538
2020-05-19T18:11:43.071Z,1589911903.071 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2020-05-19T18:11:43.072Z,1589911903.072 [WetLabsBB2FL](INFO): Powering down
2020-05-19T18:11:43.072Z,1589911903.072 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-05-19T18:11:43.076Z,1589911903.076 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2020-05-19T18:11:43.076Z,1589911903.076 [logger ThreadHandler](INFO): Thread cancelled.
2020-05-19T18:11:43.076Z,1589911903.076 [logger](INFO): Join timeout helper Thread ID is 3539
2020-05-19T18:11:43.087Z,1589911903.087 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2020-05-19T18:11:43.087Z,1589911903.087 [logger ThreadHandler](INFO): Thread cancelled.
2020-05-19T18:11:43.096Z,1589911903.096 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2020-05-19T18:11:43.096Z,1589911903.096 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-05-19T18:11:43.096Z,1589911903.096 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2020-05-19T18:11:43.096Z,1589911903.096 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-05-19T18:11:43.097Z,1589911903.097 [controlThread](INFO): Join timeout helper Thread ID is 3540
2020-05-19T18:11:43.371Z,1589911903.371 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2020-05-19T18:11:43.371Z,1589911903.371 [controlThread](DEBUG): Uninitializing ControlThread
2020-05-19T18:11:43.393Z,1589911903.393 [NAL9602](INFO): Powering down
2020-05-19T18:11:43.394Z,1589911903.394 [DAT](INFO): Powering down
2020-05-19T18:11:43.516Z,1589911903.516 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2020-05-19T18:11:43.517Z,1589911903.517 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2020-05-19T18:11:43.518Z,1589911903.518 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2020-05-19T18:11:43.518Z,1589911903.518 [MissionManager](INFO): Uninitializing Mission Default
2020-05-19T18:11:43.518Z,1589911903.518 [Default] Stopped
2020-05-19T18:11:43.518Z,1589911903.518 [Default](DEBUG): Aggregate::uninitialize Default
2020-05-19T18:11:43.519Z,1589911903.519 [Default:B.GoToSurface] Stopped
2020-05-19T18:11:43.519Z,1589911903.519 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-05-19T18:11:43.519Z,1589911903.519 [Default:CheckIn] Stopped
2020-05-19T18:11:43.519Z,1589911903.519 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-05-19T18:11:43.519Z,1589911903.519 [Default:CheckIn:Read_GPS] Stopped
2020-05-19T18:11:43.522Z,1589911903.522 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2020-05-19T18:11:43.522Z,1589911903.522 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2020-05-19T18:11:43.522Z,1589911903.522 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2020-05-19T18:11:43.522Z,1589911903.522 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2020-05-19T18:11:43.523Z,1589911903.523 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2020-05-19T18:11:43.523Z,1589911903.523 [BuoyancyServo](INFO): Powering down
2020-05-19T18:11:43.535Z,1589911903.535 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2020-05-19T18:11:43.535Z,1589911903.535 [ElevatorServo](INFO): Powering down
2020-05-19T18:11:43.536Z,1589911903.536 [MassServo](DEBUG): Uninitialize Mass Servo.
2020-05-19T18:11:43.536Z,1589911903.536 [MassServo](INFO): Powering down
2020-05-19T18:11:43.537Z,1589911903.537 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-05-19T18:11:43.537Z,1589911903.537 [RudderServo](INFO): Powering down
2020-05-19T18:11:43.538Z,1589911903.538 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2020-05-19T18:11:43.538Z,1589911903.538 [ThrusterServo](INFO): Powering down
2020-05-19T18:11:43.539Z,1589911903.539 [SBIT](DEBUG): Uninitialize SBIT Component.
2020-05-19T18:11:43.539Z,1589911903.539 [IBIT](DEBUG): Uninitialize IBIT Component.
2020-05-19T18:11:43.539Z,1589911903.539 [CBIT](DEBUG): Uninitialize CBIT Component.
2020-05-19T18:11:43.539Z,1589911903.539 [CBIT](DEBUG): Powering off loads.
2020-05-19T18:11:43.551Z,1589911903.551 [CBIT](DEBUG): Disabling WDT.
2020-05-19T18:11:43.563Z,1589911903.563 [CBIT](DEBUG): Opening all GF detection circuits.
2020-05-19T18:11:43.563Z,1589911903.563 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-05-19T18:11:43.597Z,1589911903.597 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-05-19T18:11:43.665Z,1589911903.665 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-05-19T18:11:43.666Z,1589911903.666 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-05-19T18:11:43.671Z,1589911903.671 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-05-19T18:11:43.718Z,1589911903.718 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-05-19T18:11:43.776Z,1589911903.776 [logger ThreadHandler](INFO): Thread cancelled.