2023-05-11T23:49:56.793Z,1683848996.793 [Supervisor](DEBUG): Initializing supervisor. 2023-05-11T23:49:56.798Z,1683848996.798 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2023-05-11T23:49:56.798Z,1683848996.798 [SyncHandler](INFO): Protected caller Thread ID is 557 2023-05-11T23:49:56.799Z,1683848996.799 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2023-05-11T23:49:56.799Z,1683848996.799 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2023-05-11T23:49:56.800Z,1683848996.800 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 558 2023-05-11T23:49:56.804Z,1683848996.804 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2023-05-11T23:49:56.821Z,1683848996.821 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2023-05-11T23:49:56.822Z,1683848996.822 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2023-05-11T23:49:56.822Z,1683848996.822 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 559 2023-05-11T23:49:56.826Z,1683848996.826 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2023-05-11T23:49:56.827Z,1683848996.827 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2023-05-11T23:49:56.827Z,1683848996.827 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 560 2023-05-11T23:49:56.829Z,1683848996.829 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2023-05-11T23:49:56.830Z,1683848996.830 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2023-05-11T23:49:56.831Z,1683848996.831 [logger ThreadHandler](INFO): Protected caller Thread ID is 561 2023-05-11T23:49:56.834Z,1683848996.834 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2023-05-11T23:49:56.834Z,1683848996.834 [Supervisor](INFO): Looking for Config files in directory: Config/ 2023-05-11T23:49:56.836Z,1683848996.836 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2023-05-11T23:49:57.152Z,1683848997.152 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2023-05-11T23:49:57.153Z,1683848997.153 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2023-05-11T23:49:57.794Z,1683848997.794 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2023-05-11T23:49:57.795Z,1683848997.795 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2023-05-11T23:49:57.902Z,1683848997.902 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2023-05-11T23:49:57.902Z,1683848997.902 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2023-05-11T23:49:58.440Z,1683848998.440 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2023-05-11T23:49:58.441Z,1683848998.441 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2023-05-11T23:49:58.536Z,1683848998.536 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2023-05-11T23:49:58.537Z,1683848998.537 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2023-05-11T23:49:58.617Z,1683848998.617 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2023-05-11T23:49:58.996Z,1683848998.996 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2023-05-11T23:49:58.996Z,1683848998.996 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2023-05-11T23:49:59.206Z,1683848999.206 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2023-05-11T23:49:59.206Z,1683848999.206 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2023-05-11T23:49:59.349Z,1683848999.349 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2023-05-11T23:49:59.350Z,1683848999.350 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2023-05-11T23:49:59.572Z,1683848999.572 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2023-05-11T23:49:59.572Z,1683848999.572 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2023-05-11T23:50:00.064Z,1683849000.064 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2023-05-11T23:50:00.065Z,1683849000.065 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2023-05-11T23:50:00.419Z,1683849000.419 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2023-05-11T23:50:00.420Z,1683849000.420 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2023-05-11T23:50:00.499Z,1683849000.499 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2023-05-11T23:50:00.677Z,1683849000.677 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2023-05-11T23:50:00.677Z,1683849000.677 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2023-05-11T23:50:00.888Z,1683849000.888 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2023-05-11T23:50:00.889Z,1683849000.889 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2023-05-11T23:50:01.168Z,1683849001.168 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2023-05-11T23:50:01.171Z,1683849001.171 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-brizo/ 2023-05-11T23:50:01.171Z,1683849001.171 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Control.cfg 2023-05-11T23:50:01.278Z,1683849001.278 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Sensor.cfg 2023-05-11T23:50:01.420Z,1683849001.420 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Simulator.cfg 2023-05-11T23:50:01.512Z,1683849001.512 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/secure.cfg 2023-05-11T23:50:01.785Z,1683849001.785 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Servo.cfg 2023-05-11T23:50:02.065Z,1683849002.065 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/vehicle.cfg 2023-05-11T23:50:02.397Z,1683849002.397 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Battery.cfg 2023-05-11T23:50:02.801Z,1683849002.801 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2023-05-11T23:50:02.802Z,1683849002.802 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Science.cfg 2023-05-11T23:50:02.931Z,1683849002.931 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/logger.cfg 2023-05-11T23:50:03.022Z,1683849003.022 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/BIT.cfg 2023-05-11T23:50:03.125Z,1683849003.125 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Navigation.cfg 2023-05-11T23:50:03.225Z,1683849003.225 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-brizo/root/ 2023-05-11T23:50:03.225Z,1683849003.225 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2023-05-11T23:50:03.243Z,1683849003.243 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2023-05-11T23:50:03.339Z,1683849003.339 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2023-05-11T23:50:03.339Z,1683849003.339 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2023-05-11T23:50:03.349Z,1683849003.349 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2023-05-11T23:50:03.350Z,1683849003.350 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2023-05-11T23:50:03.400Z,1683849003.400 [DepthRateCalculator] Loaded 2023-05-11T23:50:03.400Z,1683849003.400 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2023-05-11T23:50:03.405Z,1683849003.405 [PitchRateCalculator] Loaded 2023-05-11T23:50:03.406Z,1683849003.406 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2023-05-11T23:50:03.416Z,1683849003.416 [SpeedCalculator] Loaded 2023-05-11T23:50:03.416Z,1683849003.416 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2023-05-11T23:50:03.431Z,1683849003.431 [VerticalHomogeneityIndexCalculator] Loaded 2023-05-11T23:50:03.431Z,1683849003.431 [ComponentRegistry](DEBUG): SyncComponent "VerticalHomogeneityIndexCalculator" handled in the control thread. 2023-05-11T23:50:03.436Z,1683849003.436 [YawRateCalculator] Loaded 2023-05-11T23:50:03.436Z,1683849003.436 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2023-05-11T23:50:03.456Z,1683849003.456 [ElevatorOffsetCalculator] Loaded 2023-05-11T23:50:03.457Z,1683849003.457 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2023-05-11T23:50:03.457Z,1683849003.457 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2023-05-11T23:50:03.458Z,1683849003.458 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2023-05-11T23:50:03.506Z,1683849003.506 [VerticalControl](DEBUG): Construct VerticalControl. 2023-05-11T23:50:03.560Z,1683849003.560 [VerticalControl] Loaded 2023-05-11T23:50:03.560Z,1683849003.560 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2023-05-11T23:50:03.563Z,1683849003.563 [HorizontalControl](DEBUG): Construct HorizontalControl. 2023-05-11T23:50:03.602Z,1683849003.602 [HorizontalControl] Loaded 2023-05-11T23:50:03.602Z,1683849003.602 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2023-05-11T23:50:03.604Z,1683849003.604 [SpeedControl](DEBUG): Construct SpeedControl. 2023-05-11T23:50:03.607Z,1683849003.607 [SpeedControl] Loaded 2023-05-11T23:50:03.607Z,1683849003.607 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2023-05-11T23:50:03.610Z,1683849003.610 [LoopControl](DEBUG): Construct LoopControl. 2023-05-11T23:50:03.610Z,1683849003.610 [LoopControl] Loaded 2023-05-11T23:50:03.611Z,1683849003.611 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2023-05-11T23:50:03.611Z,1683849003.611 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2023-05-11T23:50:03.612Z,1683849003.612 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2023-05-11T23:50:03.719Z,1683849003.719 [DeadReckonUsingMultipleVelocitySources] Loaded 2023-05-11T23:50:03.719Z,1683849003.719 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2023-05-11T23:50:03.732Z,1683849003.732 [NavChart] Loaded 2023-05-11T23:50:03.732Z,1683849003.732 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2023-05-11T23:50:03.738Z,1683849003.738 [UniversalFixResidualReporter] Loaded 2023-05-11T23:50:03.738Z,1683849003.738 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2023-05-11T23:50:03.738Z,1683849003.738 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2023-05-11T23:50:03.739Z,1683849003.739 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2023-05-11T23:50:03.886Z,1683849003.886 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2023-05-11T23:50:03.887Z,1683849003.887 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2023-05-11T23:50:04.294Z,1683849004.294 [AHRS_M2] Loaded 2023-05-11T23:50:04.294Z,1683849004.294 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2023-05-11T23:50:04.329Z,1683849004.329 [BackseatComponent] Loaded 2023-05-11T23:50:04.329Z,1683849004.329 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2023-05-11T23:50:04.330Z,1683849004.330 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408F64E0 2023-05-11T23:50:04.330Z,1683849004.330 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 644 2023-05-11T23:50:04.333Z,1683849004.333 [LcmUniversalReporter] Loaded 2023-05-11T23:50:04.333Z,1683849004.333 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2023-05-11T23:50:05.143Z,1683849005.143 [BPC1] Loaded 2023-05-11T23:50:05.143Z,1683849005.143 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2023-05-11T23:50:05.216Z,1683849005.216 [DataOverHttps] Loaded 2023-05-11T23:50:05.216Z,1683849005.216 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2023-05-11T23:50:05.217Z,1683849005.217 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409264E0 2023-05-11T23:50:05.218Z,1683849005.218 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 645 2023-05-11T23:50:05.238Z,1683849005.238 [Depth_Keller] Loaded 2023-05-11T23:50:05.238Z,1683849005.238 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2023-05-11T23:50:05.243Z,1683849005.243 [DropWeight] Loaded 2023-05-11T23:50:05.243Z,1683849005.243 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2023-05-11T23:50:05.280Z,1683849005.280 [DVL_micro] Loaded 2023-05-11T23:50:05.280Z,1683849005.280 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2023-05-11T23:50:05.340Z,1683849005.340 [NAL9602] Loaded 2023-05-11T23:50:05.341Z,1683849005.341 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2023-05-11T23:50:05.370Z,1683849005.370 [Onboard] Loaded 2023-05-11T23:50:05.370Z,1683849005.370 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2023-05-11T23:50:05.371Z,1683849005.371 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409564E0 2023-05-11T23:50:05.372Z,1683849005.372 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 646 2023-05-11T23:50:05.383Z,1683849005.383 [Power24vConverter] Loaded 2023-05-11T23:50:05.384Z,1683849005.384 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2023-05-11T23:50:05.397Z,1683849005.397 [Radio_Surface] Loaded 2023-05-11T23:50:05.397Z,1683849005.397 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2023-05-11T23:50:05.398Z,1683849005.398 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409864E0 2023-05-11T23:50:05.399Z,1683849005.399 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 647 2023-05-11T23:50:05.489Z,1683849005.489 [DAT] Loaded 2023-05-11T23:50:05.490Z,1683849005.490 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2023-05-11T23:50:05.491Z,1683849005.491 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 409B64E0 2023-05-11T23:50:05.491Z,1683849005.491 [DAT ThreadHandler](INFO): Protected caller Thread ID is 648 2023-05-11T23:50:05.491Z,1683849005.491 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2023-05-11T23:50:05.492Z,1683849005.492 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2023-05-11T23:50:05.621Z,1683849005.621 [BuoyancyServo] Loaded 2023-05-11T23:50:05.622Z,1683849005.622 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2023-05-11T23:50:05.641Z,1683849005.641 [ElevatorServo] Loaded 2023-05-11T23:50:05.642Z,1683849005.642 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2023-05-11T23:50:05.661Z,1683849005.661 [MassServo] Loaded 2023-05-11T23:50:05.661Z,1683849005.661 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2023-05-11T23:50:05.679Z,1683849005.679 [RudderServo] Loaded 2023-05-11T23:50:05.679Z,1683849005.679 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2023-05-11T23:50:05.694Z,1683849005.694 [ThrusterHE] Loaded 2023-05-11T23:50:05.694Z,1683849005.694 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2023-05-11T23:50:05.694Z,1683849005.694 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2023-05-11T23:50:05.695Z,1683849005.695 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2023-05-11T23:50:05.764Z,1683849005.764 [StratificationFrontDetector](IMPORTANT): thresholdVTHI set to: 0.100000 degC 2023-05-11T23:50:05.764Z,1683849005.764 [StratificationFrontDetector](INFO): (re)initializing 2023-05-11T23:50:05.764Z,1683849005.764 [StratificationFrontDetector] Loaded 2023-05-11T23:50:05.764Z,1683849005.764 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread. 2023-05-11T23:50:05.765Z,1683849005.765 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2023-05-11T23:50:05.766Z,1683849005.766 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2023-05-11T23:50:05.792Z,1683849005.792 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2023-05-11T23:50:05.792Z,1683849005.792 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2023-05-11T23:50:06.091Z,1683849006.091 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2023-05-11T23:50:06.092Z,1683849006.092 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2023-05-11T23:50:06.257Z,1683849006.257 [CTD_Seabird] Loaded 2023-05-11T23:50:06.258Z,1683849006.258 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2023-05-11T23:50:06.259Z,1683849006.259 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B494E0 2023-05-11T23:50:06.259Z,1683849006.259 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 649 2023-05-11T23:50:06.292Z,1683849006.292 [ESPComponent] Loaded 2023-05-11T23:50:06.292Z,1683849006.292 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2023-05-11T23:50:06.312Z,1683849006.312 [PAR_Licor] Loaded 2023-05-11T23:50:06.312Z,1683849006.312 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2023-05-11T23:50:06.342Z,1683849006.342 [WetLabsBB2FL] Loaded 2023-05-11T23:50:06.342Z,1683849006.342 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2023-05-11T23:50:06.343Z,1683849006.343 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B794E0 2023-05-11T23:50:06.344Z,1683849006.344 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 650 2023-05-11T23:50:06.344Z,1683849006.344 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2023-05-11T23:50:06.345Z,1683849006.345 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2023-05-11T23:50:06.483Z,1683849006.483 [SBIT](DEBUG): Construct Startup Built In Test. 2023-05-11T23:50:06.491Z,1683849006.491 [SBIT] Loaded 2023-05-11T23:50:06.492Z,1683849006.492 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2023-05-11T23:50:06.494Z,1683849006.494 [IBIT](DEBUG): Construct Initiated Built In Test. 2023-05-11T23:50:06.507Z,1683849006.507 [IBIT] Loaded 2023-05-11T23:50:06.507Z,1683849006.507 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2023-05-11T23:50:06.513Z,1683849006.513 [CBIT](DEBUG): Construct Continuous Built In Test. 2023-05-11T23:50:06.614Z,1683849006.614 [CBIT] Loaded 2023-05-11T23:50:06.615Z,1683849006.615 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2023-05-11T23:50:06.615Z,1683849006.615 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2023-05-11T23:50:06.671Z,1683849006.671 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2023-05-11T23:50:06.673Z,1683849006.673 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2023-05-11T23:50:06.684Z,1683849006.684 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2023-05-11T23:50:06.685Z,1683849006.685 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BE74E0 2023-05-11T23:50:06.686Z,1683849006.686 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 651 2023-05-11T23:50:06.690Z,1683849006.690 [Supervisor](INFO): Main Thread ID is 556 2023-05-11T23:50:06.690Z,1683849006.690 [Supervisor](DEBUG): Running supervisor. 2023-05-11T23:50:06.691Z,1683849006.691 [CommandExec ThreadHandler](INFO): Handler Thread ID is 652 2023-05-11T23:50:06.691Z,1683849006.691 [CommandExec](INFO): Initializing the command executive. 2023-05-11T23:50:06.693Z,1683849006.693 [CommandLine ThreadHandler](INFO): Handler Thread ID is 653 2023-05-11T23:50:06.695Z,1683849006.695 [controlThread ThreadHandler](INFO): Handler Thread ID is 654 2023-05-11T23:50:06.695Z,1683849006.695 [controlThread](DEBUG): Initializing ControlThread 2023-05-11T23:50:06.696Z,1683849006.696 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2023-05-11T23:50:06.697Z,1683849006.697 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2023-05-11T23:50:06.697Z,1683849006.697 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2023-05-11T23:50:06.698Z,1683849006.698 [VerticalHomogeneityIndexCalculator](DEBUG): (re)initializing 2023-05-11T23:50:06.699Z,1683849006.699 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2023-05-11T23:50:06.699Z,1683849006.699 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2023-05-11T23:50:06.700Z,1683849006.700 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2023-05-11T23:50:06.706Z,1683849006.706 [logger ThreadHandler](INFO): Handler Thread ID is 655 2023-05-11T23:50:06.730Z,1683849006.730 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 656 2023-05-11T23:50:06.732Z,1683849006.732 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 657 2023-05-11T23:50:06.733Z,1683849006.733 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2023-05-11T23:50:06.735Z,1683849006.735 [Onboard ThreadHandler](INFO): Handler Thread ID is 658 2023-05-11T23:50:06.766Z,1683849006.766 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 659 2023-05-11T23:50:06.770Z,1683849006.770 [DAT ThreadHandler](INFO): Handler Thread ID is 660 2023-05-11T23:50:06.771Z,1683849006.771 [DAT](INFO): Powering up 2023-05-11T23:50:06.771Z,1683849006.771 [DAT](DEBUG): Initializing DAT. 2023-05-11T23:50:06.787Z,1683849006.787 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 663 2023-05-11T23:50:06.790Z,1683849006.790 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2023-05-11T23:50:06.791Z,1683849006.791 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2023-05-11T23:50:06.791Z,1683849006.791 [LoopControl](DEBUG): Initialize LoopControlComponent. 2023-05-11T23:50:06.792Z,1683849006.792 [NavChart](DEBUG): Initialize NavChart Navigation. 2023-05-11T23:50:06.793Z,1683849006.793 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2023-05-11T23:50:06.802Z,1683849006.802 [SBIT](INFO): Initialize SBIT Component. 2023-05-11T23:50:06.802Z,1683849006.802 [SBIT](IMPORTANT): git: 2023-05-11 2023-05-11T23:50:06.802Z,1683849006.802 [SBIT](INFO): git hash: 819773fe6d6f007a19954d172147646e14066f04 2023-05-11T23:50:06.803Z,1683849006.803 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2023-05-11T23:50:06.804Z,1683849006.804 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #1 PREEMPT Tue Sep 24 11:12:27 PDT 2019 Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021 2023-05-11T23:50:06.805Z,1683849006.805 [SBIT](INFO): Beginning SBIT in 134.000000 seconds. 2023-05-11T23:50:06.805Z,1683849006.805 [IBIT](INFO): Initialize IBIT Component. 2023-05-11T23:50:06.810Z,1683849006.810 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 665 2023-05-11T23:50:06.812Z,1683849006.812 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2023-05-11T23:50:06.813Z,1683849006.813 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2023-05-11T23:50:06.813Z,1683849006.813 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2023-05-11T23:50:06.813Z,1683849006.813 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2023-05-11T23:50:06.813Z,1683849006.813 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2023-05-11T23:50:06.814Z,1683849006.814 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2023-05-11T23:50:06.814Z,1683849006.814 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2023-05-11T23:50:06.814Z,1683849006.814 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2023-05-11T23:50:06.822Z,1683849006.822 [WetLabsBB2FL](INFO): Powering up 2023-05-11T23:50:06.826Z,1683849006.826 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 662 2023-05-11T23:50:06.830Z,1683849006.830 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2023-05-11T23:50:06.832Z,1683849006.832 [CBIT](DEBUG): Initialize CBIT Component. 2023-05-11T23:50:06.846Z,1683849006.846 [CBIT](DEBUG): Initialized mux pins. 2023-05-11T23:50:06.846Z,1683849006.846 [CBIT](DEBUG): Initializing the watchdog timer. 2023-05-11T23:50:06.870Z,1683849006.870 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2023-05-11T23:50:06.870Z,1683849006.870 [CBIT](DEBUG): Initializing heartbeat. 2023-05-11T23:50:06.942Z,1683849006.942 [CBIT](DEBUG): Deactivating GF circuits. 2023-05-11T23:50:06.942Z,1683849006.942 [CBIT](DEBUG): Deactivating emergency mode. 2023-05-11T23:50:06.982Z,1683849006.982 [CBIT](DEBUG): Backplane powered. 2023-05-11T23:50:06.983Z,1683849006.983 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml 2023-05-11T23:50:07.003Z,1683849007.003 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2023-05-11T23:50:07.034Z,1683849007.034 [MissionManager](DEBUG): 2023-05-11T23:50:07.035Z,1683849007.035 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml 2023-05-11T23:50:07.109Z,1683849007.109 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2023-05-11T23:50:07.110Z,1683849007.110 [Default:A.Wait](DEBUG): Construct Wait. 2023-05-11T23:50:07.113Z,1683849007.113 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2023-05-11T23:50:07.151Z,1683849007.151 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2023-05-11T23:50:07.170Z,1683849007.170 [Radio_Surface](INFO): Powering up 2023-05-11T23:50:07.178Z,1683849007.178 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2023-05-11T23:50:07.184Z,1683849007.184 [Default:E.Execute](DEBUG): Construct Execute. 2023-05-11T23:50:07.203Z,1683849007.203 [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 2023-05-11T23:50:07.208Z,1683849007.208 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,VerticalHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2023-05-11T23:50:07.230Z,1683849007.230 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2023-05-11T23:50:07.323Z,1683849007.323 [Power24vConverter](INFO): Powering up. 2023-05-11T23:50:07.396Z,1683849007.396 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2023-05-11T23:50:07.402Z,1683849007.402 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2023-05-11T23:50:07.403Z,1683849007.403 [ElevatorServo](DEBUG): Initializing EZServoServo. 2023-05-11T23:50:07.410Z,1683849007.410 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2023-05-11T23:50:07.411Z,1683849007.411 [MassServo](DEBUG): Initializing EZServoServo. 2023-05-11T23:50:07.418Z,1683849007.418 [MassServo](DEBUG): Initializing MassServo. 2023-05-11T23:50:07.419Z,1683849007.419 [RudderServo](DEBUG): Initializing EZServoServo. 2023-05-11T23:50:07.426Z,1683849007.426 [RudderServo](DEBUG): Initializing RudderServo. 2023-05-11T23:50:07.427Z,1683849007.427 [ThrusterHE](DEBUG): Initializing EZServoServo. 2023-05-11T23:50:07.434Z,1683849007.434 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2023-05-11T23:50:07.663Z,1683849007.663 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2023-05-11T23:50:07.663Z,1683849007.663 [DropWeight] Hardware Fault, FailCount= 1 2023-05-11T23:50:07.663Z,1683849007.663 [DropWeight](ERROR): Hardware Fault 2023-05-11T23:50:07.712Z,1683849007.712 [CommandExec](FAULT): Scheduling is paused 2023-05-11T23:50:07.713Z,1683849007.713 [CBIT](INFO): Critical error at 20230511T235007 2023-05-11T23:50:07.713Z,1683849007.713 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2023-05-11T23:50:07.723Z,1683849007.723 [CBIT](ERROR): Hardware Fault in component: DropWeight 2023-05-11T23:50:07.724Z,1683849007.724 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2023-05-11T23:50:08.044Z,1683849008.044 [CBIT](INFO): Critical error at 20230511T235007 2023-05-11T23:50:09.402Z,1683849009.402 [WetLabsBB2FL](INFO): Powering down 2023-05-11T23:50:13.015Z,1683849013.015 [ThrusterHE](ERROR): Zero Speed Commanded. 2023-05-11T23:50:14.707Z,1683849014.707 [CommandExec](IMPORTANT): got command strobe off 2023-05-11T23:50:14.707Z,1683849014.707 [CommandExec](IMPORTANT): Deactivating strobe 2023-05-11T23:50:14.874Z,1683849014.874 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit. 2023-05-11T23:50:18.614Z,1683849018.614 [DAT](INFO): DAT read: 2023-05-11T23:50:18.616Z,1683849018.616 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2023-05-11T23:50:20.127Z,1683849020.127 [DAT](INFO): DAT read: MF Frequency Band 2023-05-11T23:50:20.128Z,1683849020.128 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2023-05-11T23:50:20.128Z,1683849020.128 [DAT](INFO): DAT read: May 11 2023 23:50:25 2023-05-11T23:50:20.808Z,1683849020.808 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004586 2023-05-11T23:50:21.387Z,1683849021.387 [DAT](INFO): DAT read: Features enabled [Bearing] 2023-05-11T23:50:21.388Z,1683849021.388 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2023-05-11T23:50:21.388Z,1683849021.388 [DAT](INFO): commRate: 800 2023-05-11T23:50:23.458Z,1683849023.458 [DAT](INFO): entering command mode 2023-05-11T23:50:23.654Z,1683849023.654 [DAT](INFO): DAT read: 2023-05-11T23:50:23.655Z,1683849023.655 [DAT](INFO): DAT read: user:1> 2023-05-11T23:50:23.655Z,1683849023.655 [DAT](INFO): setting verbose to 3 2023-05-11T23:50:23.906Z,1683849023.906 [DAT](INFO): DAT read: user:1> 2023-05-11T23:50:23.907Z,1683849023.907 [DAT](INFO): DAT read: Verbose | 3 2023-05-11T23:50:23.908Z,1683849023.908 [DAT](INFO): set verbose to 3 2023-05-11T23:50:23.908Z,1683849023.908 [DAT](INFO): setting DatVerbose to 27440 2023-05-11T23:50:24.158Z,1683849024.158 [DAT](INFO): DAT read: user:2> 2023-05-11T23:50:24.159Z,1683849024.159 [DAT](INFO): DAT read: DatVerbose | 27440 2023-05-11T23:50:24.159Z,1683849024.159 [DAT](INFO): set DatVerbose to 27440 2023-05-11T23:50:24.160Z,1683849024.160 [DAT](INFO): setting transmit power to 8 2023-05-11T23:50:24.410Z,1683849024.410 [DAT](INFO): DAT read: user:3> 2023-05-11T23:50:24.411Z,1683849024.411 [DAT](INFO): DAT read: TxPower | 8 (Max) 2023-05-11T23:50:24.412Z,1683849024.412 [DAT](INFO): set transmit power to 8 2023-05-11T23:50:24.412Z,1683849024.412 [DAT](INFO): setting local address to 11 2023-05-11T23:50:24.662Z,1683849024.662 [DAT](INFO): DAT read: user:4> 2023-05-11T23:50:24.663Z,1683849024.663 [DAT](INFO): DAT read: LocalAddr | 11 2023-05-11T23:50:24.664Z,1683849024.664 [DAT](INFO): set local address to 11 2023-05-11T23:50:24.665Z,1683849024.665 [DAT](INFO): Setting time to: 23:50:24 And date to:5/11/2023 2023-05-11T23:50:24.914Z,1683849024.914 [DAT](INFO): DAT read: user:5> 2023-05-11T23:50:24.915Z,1683849024.915 [DAT](INFO): DAT read: Thu May 11, 2023 23:50:24 2023-05-11T23:50:24.915Z,1683849024.915 [DAT](INFO): Local DAT time set to Thu May 11, 2023 23:50:24 2023-05-11T23:50:35.505Z,1683849035.505 [NAL9602](INFO): Powering up NAL9602 2023-05-11T23:50:42.822Z,1683849042.822 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-05-11T23:50:42.823Z,1683849042.823 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+20.8,0000.0,1489.0I,+01182,+00068,+00871,+00000,A 2023-05-11T23:50:46.476Z,1683849046.476 [NAL9602](INFO): NAL9602 initialized 2023-05-11T23:52:21.437Z,1683849141.437 [SBIT](IMPORTANT): Beginning Startup BIT 2023-05-11T23:52:21.463Z,1683849141.463 [CBIT](IMPORTANT): Beginning ground fault scan 2023-05-11T23:52:24.680Z,1683849144.680 [DVL_micro](ERROR): Failed to parse: :.99,+9999.99,+9999.99,+9999.99 2023-05-11T23:52:32.446Z,1683849152.446 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): 0.004126 CHAN A1 (24V): -0.002479 CHAN A2 (12V): -0.000366 CHAN A3 (5V): -0.000104 CHAN B0 (3.3V): 0.001414 CHAN B1 (3.15aV): 0.000612 CHAN B2 (3.15bV): 0.000515 CHAN B3 (GND): 0.000614 OPEN: 0.004599 Full Scale: +/- 1 mA 2023-05-11T23:53:07.110Z,1683849187.110 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2023-05-11T23:53:07.110Z,1683849187.110 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-11T23:53:07.163Z,1683849187.163 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-11T23:53:07.550Z,1683849187.550 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-11T23:53:07.550Z,1683849187.550 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2023-05-11T23:53:15.177Z,1683849195.177 [SBIT](IMPORTANT): SBIT PASSED 2023-05-11T23:53:15.177Z,1683849195.177 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2023-05-11T23:53:15.178Z,1683849195.178 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=12 count; 2023-05-11T23:53:15.178Z,1683849195.178 [SBIT](IMPORTANT): DAT.sbdAddress=-1 enum; 2023-05-11T23:53:15.178Z,1683849195.178 [SBIT](IMPORTANT): Depth_Keller.offset=3.6 decibar; 2023-05-11T23:53:15.178Z,1683849195.178 [SBIT](IMPORTANT): Express none CBIT.ampHoursUsed; 2023-05-11T23:53:15.178Z,1683849195.178 [SBIT](IMPORTANT): Express linearApproximation VerticalHomogeneityIndexCalculator.vertical_salinity_homogeneity_index 0.050000 practical_salinity_unit; 2023-05-11T23:53:15.179Z,1683849195.179 [SBIT](IMPORTANT): Express linearApproximation VerticalHomogeneityIndexCalculator.vertical_temperature_homogeneity_index 0.050000 celsius; 2023-05-11T23:53:15.179Z,1683849195.179 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water; 2023-05-11T23:53:15.179Z,1683849195.179 [SBIT](IMPORTANT): Express none height_above_sea_floor; 2023-05-11T23:53:15.179Z,1683849195.179 [SBIT](IMPORTANT): StratificationFrontDetector.loadAtStartup=1 bool; 2023-05-11T23:53:15.179Z,1683849195.179 [SBIT](IMPORTANT): StratificationFrontDetector.threshold_VTHI=0.1 celsius; 2023-05-11T23:53:15.179Z,1683849195.179 [SBIT](IMPORTANT): StratificationFrontDetector.verbosity=1 count; 2023-05-11T23:53:15.179Z,1683849195.179 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=208.617815 cubic_centimeter; 2023-05-11T23:53:15.179Z,1683849195.179 [SBIT](IMPORTANT): VerticalControl.massDefault=28.688721 millimeter; 2023-05-11T23:53:15.180Z,1683849195.180 [SBIT](IMPORTANT): VerticalControl.massPositionLimitAft=-28 millimeter; 2023-05-11T23:53:15.180Z,1683849195.180 [SBIT](IMPORTANT): VerticalControl.massPositionLimitFwd=32 millimeter; 2023-05-11T23:53:15.180Z,1683849195.180 [SBIT](IMPORTANT): VerticalControl.surfaceThreshold=1.5 meter; 2023-05-11T23:53:15.180Z,1683849195.180 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth1=3 meter; 2023-05-11T23:53:15.180Z,1683849195.180 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth2=5 meter; 2023-05-11T23:53:15.180Z,1683849195.180 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth3=10 meter; 2023-05-11T23:53:15.180Z,1683849195.180 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth4=15 meter; 2023-05-11T23:53:15.180Z,1683849195.180 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.loadAtStartup=1 bool; 2023-05-11T23:53:15.590Z,1683849195.590 [MissionManager](IMPORTANT): Started mission Startup 2023-05-11T23:53:15.591Z,1683849195.591 [Startup] Running Loop=1 2023-05-11T23:53:15.591Z,1683849195.591 [Startup](DEBUG): Aggregate::initialize Startup 2023-05-11T23:53:15.591Z,1683849195.591 [Startup:A.GoToSurface] Running Loop=1 2023-05-11T23:53:15.591Z,1683849195.591 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2023-05-11T23:53:15.591Z,1683849195.591 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2023-05-11T23:53:15.592Z,1683849195.592 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2023-05-11T23:53:15.592Z,1683849195.592 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2023-05-11T23:53:15.592Z,1683849195.592 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2023-05-11T23:53:15.593Z,1683849195.593 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2023-05-11T23:53:15.595Z,1683849195.595 [Startup:StartupSatComms] Running Loop=1 2023-05-11T23:53:15.595Z,1683849195.595 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2023-05-11T23:53:15.595Z,1683849195.595 [Startup:StartupSatComms:A] Running Loop=1 2023-05-11T23:53:15.987Z,1683849195.987 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2023-05-11T23:53:24.931Z,1683849204.931 [DAT](INFO): DAT read: user:6>Lowpower 2023-05-11T23:53:24.931Z,1683849204.931 [DAT](DEBUG): Re-entering command mode due to deviceResponse_: user:6>Lowpower 2023-05-11T23:53:30.928Z,1683849210.928 [DVL_micro](ERROR): only read 3 of 4 data items 2023-05-11T23:53:30.928Z,1683849210.928 [DVL_micro](ERROR): Failed to parse: :BI,+01350,-0144,+00000,I 2023-05-11T23:54:15.772Z,1683849255.772 [Startup:StartupSatComms:A](INFO): Timed out from 2023-05-11T23:53:15.6Z 2023-05-11T23:54:15.772Z,1683849255.772 [Startup:StartupSatComms:A] Stopped 2023-05-11T23:54:15.772Z,1683849255.772 [Startup:StartupSatComms:B] Running Loop=1 2023-05-11T23:54:16.176Z,1683849256.176 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2023-05-11T23:54:21.325Z,1683849261.325 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230511T212536/Courier0019.lzma 2023-05-11T23:54:22.328Z,1683849262.328 [DataOverHttps](INFO): Moved sent file to Logs/20230511T212536/Courier0019.lzma.bak 2023-05-11T23:54:22.328Z,1683849262.328 [DataOverHttps](INFO): SBD MOMSN=18294380 2023-05-11T23:54:38.105Z,1683849278.105 [DataOverHttps](INFO): Sending 241 bytes from file Logs/20230511T234956/Courier0000.lzma 2023-05-11T23:54:39.107Z,1683849279.107 [DataOverHttps](INFO): Moved sent file to Logs/20230511T234956/Courier0000.lzma.bak 2023-05-11T23:54:39.108Z,1683849279.108 [DataOverHttps](INFO): SBD MOMSN=18294385 2023-05-11T23:54:54.866Z,1683849294.866 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230511T212536/Express0020.lzma 2023-05-11T23:54:55.867Z,1683849295.867 [DataOverHttps](INFO): Moved sent file to Logs/20230511T212536/Express0020.lzma.bak 2023-05-11T23:54:55.868Z,1683849295.868 [DataOverHttps](INFO): SBD MOMSN=18294396 2023-05-11T23:55:11.467Z,1683849311.467 [DataOverHttps](INFO): Sending 1178 bytes from file Logs/20230511T234956/Express0001.lzma 2023-05-11T23:55:12.467Z,1683849312.467 [DataOverHttps](INFO): Moved sent file to Logs/20230511T234956/Express0001.lzma.bak 2023-05-11T23:55:12.468Z,1683849312.468 [DataOverHttps](INFO): SBD MOMSN=18294400 2023-05-11T23:55:14.364Z,1683849314.364 [Startup:StartupSatComms:B] Stopped 2023-05-11T23:55:14.365Z,1683849314.365 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2023-05-11T23:55:14.365Z,1683849314.365 [Startup:StartupSatComms] Stopped 2023-05-11T23:55:14.365Z,1683849314.365 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2023-05-11T23:55:14.366Z,1683849314.366 [Startup](INFO): Completed Startup 2023-05-11T23:55:14.366Z,1683849314.366 [MissionManager](INFO): Startup is completed. 2023-05-11T23:55:14.366Z,1683849314.366 [MissionManager](INFO): Uninitializing Mission Startup 2023-05-11T23:55:14.366Z,1683849314.366 [Startup] Stopped 2023-05-11T23:55:14.366Z,1683849314.366 [Startup](DEBUG): Aggregate::uninitialize Startup 2023-05-11T23:55:14.366Z,1683849314.366 [Startup:A.GoToSurface] Stopped 2023-05-11T23:55:14.366Z,1683849314.366 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2023-05-11T23:55:14.756Z,1683849314.756 [MissionManager](IMPORTANT): Started mission Default 2023-05-11T23:55:14.757Z,1683849314.757 [Default] Running Loop=1 2023-05-11T23:55:14.757Z,1683849314.757 [Default](DEBUG): Aggregate::initialize Default 2023-05-11T23:55:14.757Z,1683849314.757 [Default:B.GoToSurface] Running Loop=1 2023-05-11T23:55:14.757Z,1683849314.757 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2023-05-11T23:55:14.757Z,1683849314.757 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2023-05-11T23:55:14.782Z,1683849314.782 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2023-05-11T23:55:14.782Z,1683849314.782 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2023-05-11T23:55:14.782Z,1683849314.782 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2023-05-11T23:55:14.783Z,1683849314.783 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2023-05-11T23:55:14.783Z,1683849314.783 [Default:A.Wait] Running Loop=1 2023-05-11T23:55:14.783Z,1683849314.783 [Default:A.Wait](DEBUG): Initialize Wait Component. 2023-05-11T23:55:28.134Z,1683849328.134 [Default:A.Wait](INFO): Done Waiting. 2023-05-11T23:55:28.134Z,1683849328.134 [Default:A.Wait] Stopped 2023-05-11T23:55:28.134Z,1683849328.134 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2023-05-11T23:55:28.513Z,1683849328.513 [Default:CheckIn] Running Loop=1 2023-05-11T23:55:28.513Z,1683849328.513 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-11T23:55:28.513Z,1683849328.513 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-11T23:55:28.921Z,1683849328.921 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2023-05-11T23:55:49.897Z,1683849349.897 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-05-11T23:56:08.101Z,1683849368.101 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2023-05-11T23:56:08.101Z,1683849368.101 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-11T23:56:08.112Z,1683849368.112 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-11T23:56:08.525Z,1683849368.525 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-11T23:56:08.525Z,1683849368.525 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2023-05-11T23:57:41.392Z,1683849461.392 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-05-11T23:57:42.209Z,1683849462.209 [BPC1](INFO): Calculating totals. Valid battery stick count: 45. Valid reserve battery stick count: 5. 2023-05-11T23:57:42.212Z,1683849462.212 [BPC1](INFO): Received data from all battery sticks. 2023-05-11T23:59:09.083Z,1683849549.083 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2023-05-11T23:59:09.083Z,1683849549.083 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-11T23:59:09.095Z,1683849549.095 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-11T23:59:09.525Z,1683849549.525 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-11T23:59:09.525Z,1683849549.525 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2023-05-11T23:59:30.079Z,1683849570.079 [DVL_micro](ERROR): Failed to parse:136,+00073,+01248,+00000,A 2023-05-12T00:00:28.677Z,1683849628.677 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-05-11T23:55:28.5Z 2023-05-12T00:00:28.678Z,1683849628.678 [Default:CheckIn:Read_GPS] Stopped 2023-05-12T00:00:28.678Z,1683849628.678 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-12T00:00:29.077Z,1683849629.077 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2023-05-12T00:00:35.809Z,1683849635.809 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20230511T234956/Courier0004.lzma 2023-05-12T00:00:36.811Z,1683849636.811 [DataOverHttps](INFO): Moved sent file to Logs/20230511T234956/Courier0004.lzma.bak 2023-05-12T00:00:36.811Z,1683849636.811 [DataOverHttps](INFO): SBD MOMSN=18294439 2023-05-12T00:00:48.498Z,1683849648.498 [NAL9602](FAULT): GPS failed to acquire within timeout. 2023-05-12T00:00:48.498Z,1683849648.498 [NAL9602] Data Fault, FailCount= 1 2023-05-12T00:00:48.498Z,1683849648.498 [NAL9602](ERROR): Data Fault 2023-05-12T00:00:48.573Z,1683849648.573 [CBIT](ERROR): Data Fault in component: NAL9602 2023-05-12T00:00:48.926Z,1683849648.926 [NAL9602](INFO): Powering down 2023-05-12T00:00:49.771Z,1683849649.771 [CBIT](INFO): Clearing failed state for component NAL9602 2023-05-12T00:00:49.771Z,1683849649.771 [NAL9602] No Fault, FailCount= 1 2023-05-12T00:00:56.857Z,1683849656.857 [DataOverHttps](INFO): Sending 187 bytes from file Logs/20230511T234956/Express0005.lzma 2023-05-12T00:00:57.864Z,1683849657.864 [DataOverHttps](INFO): Moved sent file to Logs/20230511T234956/Express0005.lzma.bak 2023-05-12T00:00:57.864Z,1683849657.864 [DataOverHttps](INFO): SBD MOMSN=18294468 2023-05-12T00:01:01.069Z,1683849661.069 [Default:CheckIn:Read_Iridium] Stopped 2023-05-12T00:01:01.069Z,1683849661.069 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-12T00:01:01.069Z,1683849661.069 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-12T00:01:19.211Z,1683849679.211 [NAL9602](INFO): Powering up NAL9602 2023-05-12T00:01:30.119Z,1683849690.119 [NAL9602](INFO): NAL9602 initialized 2023-05-12T00:01:52.374Z,1683849712.374 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-05-12T00:01:52.374Z,1683849712.374 [DVL_micro](ERROR): Failed to parse: :TS,000000035.0,+21.0,00000,000 2023-05-12T00:02:10.123Z,1683849730.123 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2023-05-12T00:02:10.123Z,1683849730.123 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-12T00:02:10.134Z,1683849730.134 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-12T00:02:10.547Z,1683849730.547 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-12T00:02:10.547Z,1683849730.547 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2023-05-12T00:05:07.919Z,1683849907.919 [CBIT](INFO): Clearing failed state for component DropWeight 2023-05-12T00:05:07.919Z,1683849907.919 [DropWeight] No Fault, FailCount= 1 2023-05-12T00:05:11.128Z,1683849911.128 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2023-05-12T00:05:11.128Z,1683849911.128 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-12T00:05:11.139Z,1683849911.139 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-12T00:05:11.535Z,1683849911.535 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-12T00:05:11.535Z,1683849911.535 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2023-05-12T00:06:01.617Z,1683849961.617 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-12T00:06:01.617Z,1683849961.617 [Default:CheckIn:C.Wait] Stopped 2023-05-12T00:06:01.617Z,1683849961.617 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-12T00:06:01.617Z,1683849961.617 [Default:CheckIn:D] Running Loop=1 2023-05-12T00:06:02.030Z,1683849962.030 [Default:CheckIn:D] Stopped 2023-05-12T00:06:02.030Z,1683849962.030 [Default:CheckIn:E] Running Loop=1 2023-05-12T00:06:02.428Z,1683849962.428 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.787894 min 2023-05-12T00:06:02.428Z,1683849962.428 [Default:CheckIn:E] Stopped 2023-05-12T00:06:02.429Z,1683849962.429 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-12T00:06:02.429Z,1683849962.429 [Default:CheckIn] Stopped 2023-05-12T00:06:02.429Z,1683849962.429 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-12T00:06:02.429Z,1683849962.429 [Default:CheckIn](INFO): Running loop #2 2023-05-12T00:06:02.429Z,1683849962.429 [Default:CheckIn] Running Loop=2 2023-05-12T00:06:02.429Z,1683849962.429 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-12T00:06:02.429Z,1683849962.429 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-12T00:08:12.107Z,1683850092.107 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2023-05-12T00:08:12.107Z,1683850092.107 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-12T00:08:12.142Z,1683850092.142 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-12T00:08:12.520Z,1683850092.520 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-12T00:08:12.520Z,1683850092.520 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2023-05-12T00:09:07.862Z,1683850147.862 [DVL_micro](ERROR): only read 1 of 4 data items 2023-05-12T00:09:07.862Z,1683850147.862 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,++9999.99,+ 2023-05-12T00:10:01.188Z,1683850201.188 [DVL_micro](ERROR): only read 3 of 4 data items 2023-05-12T00:10:01.188Z,1683850201.188 [DVL_micro](ERROR): Failed to parse: :RD,+99999.99,+9999.99,+9999.99 2023-05-12T00:11:02.618Z,1683850262.618 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-05-12T00:06:02.4Z 2023-05-12T00:11:02.618Z,1683850262.618 [Default:CheckIn:Read_GPS] Stopped 2023-05-12T00:11:02.618Z,1683850262.618 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-12T00:11:09.761Z,1683850269.761 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230511T234956/Courier0007.lzma 2023-05-12T00:11:10.763Z,1683850270.763 [DataOverHttps](INFO): Moved sent file to Logs/20230511T234956/Courier0007.lzma.bak 2023-05-12T00:11:10.763Z,1683850270.763 [DataOverHttps](INFO): SBD MOMSN=18294482 2023-05-12T00:11:13.113Z,1683850273.113 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2023-05-12T00:11:13.113Z,1683850273.113 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-12T00:11:13.147Z,1683850273.147 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-12T00:11:13.558Z,1683850273.558 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-12T00:11:13.558Z,1683850273.558 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2023-05-12T00:11:26.357Z,1683850286.357 [DataOverHttps](INFO): Sending 181 bytes from file Logs/20230511T234956/Express0008.lzma 2023-05-12T00:11:27.359Z,1683850287.359 [DataOverHttps](INFO): Moved sent file to Logs/20230511T234956/Express0008.lzma.bak 2023-05-12T00:11:27.360Z,1683850287.360 [DataOverHttps](INFO): SBD MOMSN=18294484 2023-05-12T00:11:29.300Z,1683850289.300 [Default:CheckIn:Read_Iridium] Stopped 2023-05-12T00:11:29.300Z,1683850289.300 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-12T00:11:29.301Z,1683850289.301 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-12T00:11:31.284Z,1683850291.284 [NAL9602](FAULT): GPS failed to acquire within timeout. 2023-05-12T00:11:31.284Z,1683850291.284 [NAL9602] Data Fault, FailCount= 2 2023-05-12T00:11:31.284Z,1683850291.284 [NAL9602](ERROR): Data Fault 2023-05-12T00:11:31.359Z,1683850291.359 [CBIT](ERROR): Data Fault in component: NAL9602 2023-05-12T00:11:31.687Z,1683850291.687 [NAL9602](INFO): Powering down 2023-05-12T00:11:32.536Z,1683850292.536 [CBIT](INFO): Clearing failed state for component NAL9602 2023-05-12T00:11:32.536Z,1683850292.536 [NAL9602] No Fault, FailCount= 2 2023-05-12T00:11:38.159Z,1683850298.159 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-05-12T00:11:38.159Z,1683850298.159 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+21.3,0000.0,1489.0I,+01318,-00943,+01107,+00000,A 2023-05-12T00:12:01.991Z,1683850321.991 [NAL9602](INFO): Powering up NAL9602 2023-05-12T00:12:12.903Z,1683850332.903 [NAL9602](INFO): NAL9602 initialized 2023-05-12T00:14:08.047Z,1683850448.047 [DVL_micro](ERROR): Failed to parse: :BI,+01115,-01190,+0114,I 2023-05-12T00:14:14.113Z,1683850454.113 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2023-05-12T00:14:14.114Z,1683850454.114 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-12T00:14:14.124Z,1683850454.124 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-12T00:14:14.541Z,1683850454.541 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-12T00:14:14.541Z,1683850454.541 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2023-05-12T00:16:29.857Z,1683850589.857 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-12T00:16:29.857Z,1683850589.857 [Default:CheckIn:C.Wait] Stopped 2023-05-12T00:16:29.857Z,1683850589.857 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-12T00:16:29.857Z,1683850589.857 [Default:CheckIn:D] Running Loop=1 2023-05-12T00:16:30.270Z,1683850590.270 [Default:CheckIn:D] Stopped 2023-05-12T00:16:30.270Z,1683850590.270 [Default:CheckIn:E] Running Loop=1 2023-05-12T00:16:30.691Z,1683850590.691 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.258559 min 2023-05-12T00:16:30.691Z,1683850590.691 [Default:CheckIn:E] Stopped 2023-05-12T00:16:30.692Z,1683850590.691 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-12T00:16:30.692Z,1683850590.692 [Default:CheckIn] Stopped 2023-05-12T00:16:30.692Z,1683850590.692 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-12T00:16:30.692Z,1683850590.692 [Default:CheckIn](INFO): Running loop #3 2023-05-12T00:16:30.692Z,1683850590.692 [Default:CheckIn] Running Loop=3 2023-05-12T00:16:30.692Z,1683850590.692 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-12T00:16:30.692Z,1683850590.692 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-12T00:17:15.124Z,1683850635.124 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9 2023-05-12T00:17:15.124Z,1683850635.124 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-12T00:17:15.134Z,1683850635.134 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-12T00:17:15.542Z,1683850635.542 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-12T00:17:15.542Z,1683850635.542 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9 2023-05-12T00:20:06.811Z,1683850806.811 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2023-05-12T00:20:16.095Z,1683850816.095 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10 2023-05-12T00:20:16.095Z,1683850816.095 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-12T00:20:16.106Z,1683850816.106 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-12T00:20:16.533Z,1683850816.533 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-12T00:20:16.533Z,1683850816.533 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10 2023-05-12T00:21:30.847Z,1683850890.847 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-05-12T00:16:30.7Z 2023-05-12T00:21:30.847Z,1683850890.847 [Default:CheckIn:Read_GPS] Stopped 2023-05-12T00:21:30.847Z,1683850890.847 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-12T00:21:38.105Z,1683850898.105 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230511T234956/Courier0010.lzma 2023-05-12T00:21:39.107Z,1683850899.107 [DataOverHttps](INFO): Moved sent file to Logs/20230511T234956/Courier0010.lzma.bak 2023-05-12T00:21:39.107Z,1683850899.107 [DataOverHttps](INFO): SBD MOMSN=18294509 2023-05-12T00:21:54.753Z,1683850914.753 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20230511T234956/Express0011.lzma 2023-05-12T00:21:55.755Z,1683850915.755 [DataOverHttps](INFO): Moved sent file to Logs/20230511T234956/Express0011.lzma.bak 2023-05-12T00:21:55.756Z,1683850915.756 [DataOverHttps](INFO): SBD MOMSN=18294511 2023-05-12T00:21:57.517Z,1683850917.517 [Default:CheckIn:Read_Iridium] Stopped 2023-05-12T00:21:57.517Z,1683850917.517 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-12T00:21:57.517Z,1683850917.517 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-12T00:22:15.268Z,1683850935.268 [NAL9602](FAULT): GPS failed to acquire within timeout. 2023-05-12T00:22:15.268Z,1683850935.268 [NAL9602] Data Fault, FailCount= 3 2023-05-12T00:22:15.268Z,1683850935.268 [NAL9602](ERROR): Data Fault 2023-05-12T00:22:15.285Z,1683850935.285 [CBIT](ERROR): Data Fault in component: NAL9602 2023-05-12T00:22:15.668Z,1683850935.668 [NAL9602](INFO): Powering down 2023-05-12T00:22:16.496Z,1683850936.496 [CBIT](INFO): Clearing failed state for component NAL9602 2023-05-12T00:22:16.496Z,1683850936.496 [NAL9602] No Fault, FailCount= 3 2023-05-12T00:22:45.972Z,1683850965.972 [NAL9602](INFO): Powering up NAL9602 2023-05-12T00:22:56.881Z,1683850976.881 [NAL9602](INFO): NAL9602 initialized 2023-05-12T00:23:17.099Z,1683850997.099 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11 2023-05-12T00:23:17.099Z,1683850997.099 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-12T00:23:17.109Z,1683850997.109 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-12T00:23:17.528Z,1683850997.528 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-12T00:23:17.528Z,1683850997.528 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11 2023-05-12T00:25:12.627Z,1683851112.627 [DVL_micro](ERROR): only read 3 of 4 data items 2023-05-12T00:25:12.627Z,1683851112.627 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+9 2023-05-12T00:25:58.275Z,1683851158.275 [DVL_micro](ERROR): DVL BIT error. See manual. Result code: 9 2023-05-12T00:25:58.278Z,1683851158.278 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+21.6,0000.0,1489.0,000 2023-05-12T00:26:18.078Z,1683851178.078 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12 2023-05-12T00:26:18.078Z,1683851178.078 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-12T00:26:18.088Z,1683851178.088 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-12T00:26:18.526Z,1683851178.526 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-12T00:26:18.526Z,1683851178.526 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12 2023-05-12T00:26:31.407Z,1683851191.407 [DVL_micro](ERROR): Failed to parse:99.99,+99999.99,+9999.99 2023-05-12T00:26:58.077Z,1683851218.077 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-12T00:26:58.077Z,1683851218.077 [Default:CheckIn:C.Wait] Stopped 2023-05-12T00:26:58.077Z,1683851218.077 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-12T00:26:58.077Z,1683851218.077 [Default:CheckIn:D] Running Loop=1 2023-05-12T00:26:58.485Z,1683851218.485 [Default:CheckIn:D] Stopped 2023-05-12T00:26:58.485Z,1683851218.485 [Default:CheckIn:E] Running Loop=1 2023-05-12T00:26:58.882Z,1683851218.882 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.728811 min 2023-05-12T00:26:58.882Z,1683851218.882 [Default:CheckIn:E] Stopped 2023-05-12T00:26:58.882Z,1683851218.882 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-12T00:26:58.882Z,1683851218.882 [Default:CheckIn] Stopped 2023-05-12T00:26:58.882Z,1683851218.882 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-12T00:26:58.883Z,1683851218.883 [Default:CheckIn](INFO): Running loop #4 2023-05-12T00:26:58.883Z,1683851218.883 [Default:CheckIn] Running Loop=4 2023-05-12T00:26:58.883Z,1683851218.883 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-12T00:26:58.883Z,1683851218.883 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-12T00:29:19.067Z,1683851359.067 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13 2023-05-12T00:29:19.068Z,1683851359.068 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-12T00:29:19.116Z,1683851359.116 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-12T00:29:19.532Z,1683851359.532 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-12T00:29:19.533Z,1683851359.533 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13 2023-05-12T00:31:23.901Z,1683851483.901 [DVL_micro](ERROR): Failed to parse: 83,-01377,00000,00000000.0000.00,+00000000.00,9999.99,000.00 2023-05-12T00:31:59.053Z,1683851519.053 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-05-12T00:26:58.9Z 2023-05-12T00:31:59.053Z,1683851519.053 [Default:CheckIn:Read_GPS] Stopped 2023-05-12T00:31:59.053Z,1683851519.053 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-12T00:32:06.717Z,1683851526.717 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230511T234956/Courier0013.lzma 2023-05-12T00:32:07.719Z,1683851527.719 [DataOverHttps](INFO): Moved sent file to Logs/20230511T234956/Courier0013.lzma.bak 2023-05-12T00:32:07.720Z,1683851527.720 [DataOverHttps](INFO): SBD MOMSN=18294534 2023-05-12T00:32:20.089Z,1683851540.089 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 14 2023-05-12T00:32:20.089Z,1683851540.089 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-12T00:32:20.129Z,1683851540.129 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-12T00:32:20.529Z,1683851540.529 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-12T00:32:20.529Z,1683851540.529 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 14 2023-05-12T00:32:23.453Z,1683851543.453 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20230511T234956/Express0014.lzma 2023-05-12T00:32:25.197Z,1683851545.197 [DataOverHttps](INFO): Moved sent file to Logs/20230511T234956/Express0014.lzma.bak 2023-05-12T00:32:25.197Z,1683851545.197 [DataOverHttps](INFO): SBD MOMSN=18294536 2023-05-12T00:32:26.155Z,1683851546.155 [Default:CheckIn:Read_Iridium] Stopped 2023-05-12T00:32:26.156Z,1683851546.156 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-12T00:32:26.156Z,1683851546.156 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-12T00:32:58.039Z,1683851578.039 [NAL9602](FAULT): GPS failed to acquire within timeout. 2023-05-12T00:32:58.039Z,1683851578.039 [NAL9602] Data Fault, FailCount= 4 2023-05-12T00:32:58.039Z,1683851578.039 [NAL9602](ERROR): Data Fault 2023-05-12T00:32:58.057Z,1683851578.057 [CBIT](ERROR): Data Fault in component: NAL9602 2023-05-12T00:32:58.437Z,1683851578.437 [NAL9602](INFO): Powering down 2023-05-12T00:32:59.277Z,1683851579.277 [CBIT](INFO): Clearing failed state for component NAL9602 2023-05-12T00:32:59.277Z,1683851579.277 [NAL9602] No Fault, FailCount= 4 2023-05-12T00:33:28.742Z,1683851608.742 [NAL9602](INFO): Powering up NAL9602 2023-05-12T00:33:39.640Z,1683851619.640 [NAL9602](INFO): NAL9602 initialized 2023-05-12T00:35:09.335Z,1683851709.335 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2023-05-12T00:35:09.335Z,1683851709.335 [DropWeight] Hardware Fault, FailCount= 1 2023-05-12T00:35:09.335Z,1683851709.335 [DropWeight](ERROR): Hardware Fault 2023-05-12T00:35:09.352Z,1683851709.352 [CBIT](INFO): Critical error at 20230512T003509 2023-05-12T00:35:09.354Z,1683851709.354 [CBIT](ERROR): Hardware Fault in component: DropWeight 2023-05-12T00:35:09.355Z,1683851709.355 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2023-05-12T00:35:09.757Z,1683851709.757 [CBIT](INFO): Critical error at 20230512T003509 2023-05-12T00:35:21.055Z,1683851721.055 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 15 2023-05-12T00:35:21.055Z,1683851721.055 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-12T00:35:21.066Z,1683851721.066 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-12T00:35:21.470Z,1683851721.470 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-12T00:35:21.470Z,1683851721.470 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 15 2023-05-12T00:37:26.694Z,1683851846.694 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-12T00:37:26.694Z,1683851846.694 [Default:CheckIn:C.Wait] Stopped 2023-05-12T00:37:26.694Z,1683851846.694 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-12T00:37:26.694Z,1683851846.694 [Default:CheckIn:D] Running Loop=1 2023-05-12T00:37:27.113Z,1683851847.113 [Default:CheckIn:D] Stopped 2023-05-12T00:37:27.113Z,1683851847.113 [Default:CheckIn:E] Running Loop=1 2023-05-12T00:37:27.529Z,1683851847.529 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.205933 min 2023-05-12T00:37:27.529Z,1683851847.529 [Default:CheckIn:E] Stopped 2023-05-12T00:37:27.529Z,1683851847.529 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-12T00:37:27.529Z,1683851847.529 [Default:CheckIn] Stopped 2023-05-12T00:37:27.529Z,1683851847.529 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-12T00:37:27.530Z,1683851847.530 [Default:CheckIn](INFO): Running loop #5 2023-05-12T00:37:27.530Z,1683851847.530 [Default:CheckIn] Running Loop=5 2023-05-12T00:37:27.530Z,1683851847.530 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-12T00:37:27.530Z,1683851847.530 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-12T00:38:22.047Z,1683851902.047 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 16 2023-05-12T00:38:22.047Z,1683851902.047 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-12T00:38:22.058Z,1683851902.058 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-12T00:38:22.482Z,1683851902.482 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-12T00:38:22.482Z,1683851902.482 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 16 2023-05-12T00:39:02.039Z,1683851942.039 [DVL_micro](ERROR): only read 3 of 4 data items 2023-05-12T00:39:02.039Z,1683851942.039 [DVL_micro](ERROR): Failed to parse: :BI,+01139,-01150,00000,I 2023-05-12T00:41:14.611Z,1683852074.611 [DVL_micro](ERROR): Failed to parse: 32,-01143,00000,I 2023-05-12T00:41:23.123Z,1683852083.123 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 17 2023-05-12T00:41:23.124Z,1683852083.124 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-12T00:41:23.147Z,1683852083.147 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-12T00:41:23.528Z,1683852083.528 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-12T00:41:23.528Z,1683852083.528 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 17 2023-05-12T00:42:27.765Z,1683852147.765 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-05-12T00:37:27.5Z 2023-05-12T00:42:27.765Z,1683852147.765 [Default:CheckIn:Read_GPS] Stopped 2023-05-12T00:42:27.766Z,1683852147.766 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-12T00:42:35.522Z,1683852155.522 [DataOverHttps](INFO): Sending 114 bytes from file Logs/20230511T234956/Courier0016.lzma 2023-05-12T00:42:36.523Z,1683852156.523 [DataOverHttps](INFO): Moved sent file to Logs/20230511T234956/Courier0016.lzma.bak 2023-05-12T00:42:36.524Z,1683852156.524 [DataOverHttps](INFO): SBD MOMSN=18294562 2023-05-12T00:42:52.097Z,1683852172.097 [DataOverHttps](INFO): Sending 149 bytes from file Logs/20230511T234956/Express0017.lzma 2023-05-12T00:42:53.099Z,1683852173.099 [DataOverHttps](INFO): Moved sent file to Logs/20230511T234956/Express0017.lzma.bak 2023-05-12T00:42:53.100Z,1683852173.100 [DataOverHttps](INFO): SBD MOMSN=18294566 2023-05-12T00:42:54.832Z,1683852174.832 [Default:CheckIn:Read_Iridium] Stopped 2023-05-12T00:42:54.832Z,1683852174.832 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-12T00:42:54.832Z,1683852174.832 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-12T00:43:41.664Z,1683852221.664 [NAL9602](FAULT): GPS failed to acquire within timeout. 2023-05-12T00:43:41.665Z,1683852221.665 [NAL9602] Data Fault, FailCount= 5 2023-05-12T00:43:41.665Z,1683852221.665 [NAL9602](ERROR): Data Fault 2023-05-12T00:43:41.682Z,1683852221.682 [CBIT](ERROR): Data Fault in component: NAL9602 2023-05-12T00:43:41.683Z,1683852221.683 [CBIT](CRITICAL): Data Fault in component: NAL9602 2023-05-12T00:43:42.087Z,1683852222.087 [NAL9602](INFO): Powering down 2023-05-12T00:43:42.104Z,1683852222.104 [CBIT](INFO): Critical error at 20230512T004341 2023-05-12T00:44:24.100Z,1683852264.100 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 18 2023-05-12T00:44:24.100Z,1683852264.100 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-12T00:44:24.111Z,1683852264.111 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-12T00:44:24.526Z,1683852264.526 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-12T00:44:24.526Z,1683852264.526 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 18 2023-05-12T00:45:41.694Z,1683852341.694 [CBIT](INFO): Clearing failed state for component NAL9602 2023-05-12T00:45:41.694Z,1683852341.694 [NAL9602] No Fault, FailCount= 5 2023-05-12T00:45:42.055Z,1683852342.055 [NAL9602](INFO): Powering up NAL9602 2023-05-12T00:45:52.964Z,1683852352.964 [NAL9602](INFO): NAL9602 initialized 2023-05-12T00:46:09.933Z,1683852369.933 [DVL_micro](ERROR): only read 3 of 4 data items 2023-05-12T00:46:09.933Z,1683852369.933 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,9 2023-05-12T00:47:25.089Z,1683852445.089 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 19 2023-05-12T00:47:25.089Z,1683852445.089 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-12T00:47:25.100Z,1683852445.100 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-12T00:47:25.512Z,1683852445.512 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-12T00:47:25.512Z,1683852445.512 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 19 2023-05-12T00:47:55.405Z,1683852475.405 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-12T00:47:55.405Z,1683852475.405 [Default:CheckIn:C.Wait] Stopped 2023-05-12T00:47:55.405Z,1683852475.405 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-12T00:47:55.405Z,1683852475.405 [Default:CheckIn:D] Running Loop=1 2023-05-12T00:47:55.798Z,1683852475.798 [Default:CheckIn:D] Stopped 2023-05-12T00:47:55.798Z,1683852475.798 [Default:CheckIn:E] Running Loop=1 2023-05-12T00:47:56.188Z,1683852476.188 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 52.684013 min 2023-05-12T00:47:56.188Z,1683852476.188 [Default:CheckIn:E] Stopped 2023-05-12T00:47:56.188Z,1683852476.188 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-12T00:47:56.189Z,1683852476.189 [Default:CheckIn] Stopped 2023-05-12T00:47:56.189Z,1683852476.189 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-12T00:47:56.189Z,1683852476.189 [Default:CheckIn](INFO): Running loop #6 2023-05-12T00:47:56.189Z,1683852476.189 [Default:CheckIn] Running Loop=6 2023-05-12T00:47:56.189Z,1683852476.189 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-12T00:47:56.189Z,1683852476.189 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-12T00:50:09.546Z,1683852609.546 [CBIT](INFO): Clearing failed state for component DropWeight 2023-05-12T00:50:09.546Z,1683852609.546 [DropWeight] No Fault, FailCount= 1 2023-05-12T00:50:26.072Z,1683852626.072 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 20 2023-05-12T00:50:26.072Z,1683852626.072 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-12T00:50:26.083Z,1683852626.083 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-12T00:50:26.494Z,1683852626.494 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-12T00:50:26.494Z,1683852626.494 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 20 2023-05-12T00:51:02.439Z,1683852662.439 [DVL_micro](ERROR): Failed to parse: :SA,-01.73,+00.97,234.9 2023-05-12T00:52:56.364Z,1683852776.364 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-05-12T00:47:56.2Z 2023-05-12T00:52:56.364Z,1683852776.364 [Default:CheckIn:Read_GPS] Stopped 2023-05-12T00:52:56.364Z,1683852776.364 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-12T00:53:02.789Z,1683852782.789 [DataOverHttps](INFO): Sending 82 bytes from file Logs/20230511T234956/Courier0019.lzma 2023-05-12T00:53:03.792Z,1683852783.792 [DataOverHttps](INFO): Moved sent file to Logs/20230511T234956/Courier0019.lzma.bak 2023-05-12T00:53:03.792Z,1683852783.792 [DataOverHttps](INFO): SBD MOMSN=18294590 2023-05-12T00:53:19.461Z,1683852799.461 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20230511T234956/Express0020.lzma 2023-05-12T00:53:20.463Z,1683852800.463 [DataOverHttps](INFO): Moved sent file to Logs/20230511T234956/Express0020.lzma.bak 2023-05-12T00:53:20.464Z,1683852800.464 [DataOverHttps](INFO): SBD MOMSN=18294593 2023-05-12T00:53:22.251Z,1683852802.251 [Default:CheckIn:Read_Iridium] Stopped 2023-05-12T00:53:22.251Z,1683852802.251 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-12T00:53:22.251Z,1683852802.251 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-12T00:53:25.041Z,1683852805.041 [DVL_micro](ERROR): only read 3 of 4 data items 2023-05-12T00:53:25.062Z,1683852805.062 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+99999.99 2023-05-12T00:53:27.068Z,1683852807.068 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 21 2023-05-12T00:53:27.068Z,1683852807.068 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-12T00:53:27.123Z,1683852807.123 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-12T00:53:27.510Z,1683852807.510 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-12T00:53:27.510Z,1683852807.510 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 21 2023-05-12T00:55:56.560Z,1683852956.560 [NAL9602](FAULT): GPS failed to acquire within timeout. 2023-05-12T00:55:56.560Z,1683852956.560 [NAL9602] Data Fault, FailCount= 1 2023-05-12T00:55:56.560Z,1683852956.560 [NAL9602](ERROR): Data Fault 2023-05-12T00:55:56.578Z,1683852956.578 [CBIT](ERROR): Data Fault in component: NAL9602 2023-05-12T00:55:56.968Z,1683852956.968 [NAL9602](INFO): Powering down 2023-05-12T00:55:57.827Z,1683852957.827 [CBIT](INFO): Clearing failed state for component NAL9602 2023-05-12T00:55:57.827Z,1683852957.827 [NAL9602] No Fault, FailCount= 1 2023-05-12T00:56:27.268Z,1683852987.268 [NAL9602](INFO): Powering up NAL9602 2023-05-12T00:56:28.079Z,1683852988.079 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 22 2023-05-12T00:56:28.079Z,1683852988.079 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-12T00:56:28.109Z,1683852988.109 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-12T00:56:28.522Z,1683852988.522 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-12T00:56:28.522Z,1683852988.522 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 22 2023-05-12T00:56:38.176Z,1683852998.176 [NAL9602](INFO): NAL9602 initialized 2023-05-12T00:58:22.860Z,1683853102.860 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-12T00:58:22.860Z,1683853102.860 [Default:CheckIn:C.Wait] Stopped 2023-05-12T00:58:22.860Z,1683853102.860 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-12T00:58:22.860Z,1683853102.860 [Default:CheckIn:D] Running Loop=1 2023-05-12T00:58:23.265Z,1683853103.265 [Default:CheckIn:D] Stopped 2023-05-12T00:58:23.265Z,1683853103.265 [Default:CheckIn:E] Running Loop=1 2023-05-12T00:58:23.649Z,1683853103.649 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 63.141801 min 2023-05-12T00:58:23.649Z,1683853103.649 [Default:CheckIn:E] Stopped 2023-05-12T00:58:23.649Z,1683853103.649 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-12T00:58:23.650Z,1683853103.650 [Default:CheckIn] Stopped 2023-05-12T00:58:23.650Z,1683853103.650 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-12T00:58:23.650Z,1683853103.650 [Default:CheckIn](INFO): Running loop #7 2023-05-12T00:58:23.650Z,1683853103.650 [Default:CheckIn] Running Loop=7 2023-05-12T00:58:23.650Z,1683853103.650 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-12T00:58:23.650Z,1683853103.650 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-12T00:59:29.108Z,1683853169.108 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 23 2023-05-12T00:59:29.108Z,1683853169.108 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-12T00:59:29.135Z,1683853169.135 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-12T00:59:29.512Z,1683853169.512 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-12T00:59:29.512Z,1683853169.512 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 23 2023-05-12T01:02:30.117Z,1683853350.117 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 24 2023-05-12T01:02:30.117Z,1683853350.117 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-12T01:02:30.159Z,1683853350.159 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-12T01:02:30.518Z,1683853350.518 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-12T01:02:30.518Z,1683853350.518 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 24 2023-05-12T01:03:23.846Z,1683853403.846 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-05-12T00:58:23.7Z 2023-05-12T01:03:23.846Z,1683853403.846 [Default:CheckIn:Read_GPS] Stopped 2023-05-12T01:03:23.846Z,1683853403.846 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-12T01:03:31.157Z,1683853411.157 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230511T234956/Courier0022.lzma 2023-05-12T01:03:32.159Z,1683853412.159 [DataOverHttps](INFO): Moved sent file to Logs/20230511T234956/Courier0022.lzma.bak 2023-05-12T01:03:32.160Z,1683853412.160 [DataOverHttps](INFO): SBD MOMSN=18294610 2023-05-12T01:03:47.997Z,1683853427.997 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20230511T234956/Express0023.lzma 2023-05-12T01:03:48.999Z,1683853428.999 [DataOverHttps](INFO): Moved sent file to Logs/20230511T234956/Express0023.lzma.bak 2023-05-12T01:03:48.000Z,1683853429.000 [DataOverHttps](INFO): SBD MOMSN=18294618 2023-05-12T01:03:50.945Z,1683853430.945 [Default:CheckIn:Read_Iridium] Stopped 2023-05-12T01:03:50.945Z,1683853430.945 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-12T01:03:50.945Z,1683853430.945 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-12T01:05:16.538Z,1683853516.538 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-05-12T01:05:21.790Z,1683853521.790 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-05-12T01:05:21.797Z,1683853521.797 [BPC1](INFO): Calculating totals. Valid battery stick count: 48. Valid reserve battery stick count: 5. 2023-05-12T01:05:21.800Z,1683853521.800 [BPC1](INFO): Received data from all battery sticks. 2023-05-12T01:05:25.842Z,1683853525.842 [DVL_micro](ERROR): only read 0 of 4 data items 2023-05-12T01:05:25.842Z,1683853525.842 [DVL_micro](ERROR): Failed to parse: :RD9,+9999.99,+9999.99,+9999.99 2023-05-12T01:05:31.103Z,1683853531.103 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 25 2023-05-12T01:05:31.103Z,1683853531.103 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-12T01:05:31.137Z,1683853531.137 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-12T01:05:31.511Z,1683853531.511 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-12T01:05:31.511Z,1683853531.511 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 25 2023-05-12T01:06:01.662Z,1683853561.662 [CommandExec](IMPORTANT): got command quit 2023-05-12T01:06:02.666Z,1683853562.666 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-12T01:06:02.666Z,1683853562.666 [CommandExec](INFO): Uninitializing the command executive. 2023-05-12T01:06:02.666Z,1683853562.666 [CommandExec](INFO): Uninitializing the command scheduler. 2023-05-12T01:06:02.666Z,1683853562.666 [CommandExec ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:02.821Z,1683853562.821 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2023-05-12T01:06:02.822Z,1683853562.822 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2023-05-12T01:06:02.822Z,1683853562.822 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:02.823Z,1683853562.823 [NavChartDb](INFO): Join timeout helper Thread ID is 722 2023-05-12T01:06:02.926Z,1683853562.926 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-12T01:06:02.926Z,1683853562.926 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:02.946Z,1683853562.946 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2023-05-12T01:06:02.946Z,1683853562.946 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:02.946Z,1683853562.946 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 723 2023-05-12T01:06:03.254Z,1683853563.254 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-12T01:06:03.254Z,1683853563.254 [WetLabsBB2FL](INFO): Powering down 2023-05-12T01:06:03.255Z,1683853563.255 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:03.266Z,1683853563.266 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2023-05-12T01:06:03.266Z,1683853563.266 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:03.266Z,1683853563.266 [CTD_Seabird](INFO): Join timeout helper Thread ID is 724 2023-05-12T01:06:03.646Z,1683853563.646 [CTD_Seabird](INFO): Powering down 2023-05-12T01:06:03.658Z,1683853563.658 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-12T01:06:03.659Z,1683853563.659 [CTD_Seabird](INFO): Powering down 2023-05-12T01:06:03.674Z,1683853563.674 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:03.690Z,1683853563.690 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler 2023-05-12T01:06:03.691Z,1683853563.691 [DAT ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:03.691Z,1683853563.691 [DAT](INFO): Join timeout helper Thread ID is 725 2023-05-12T01:06:03.826Z,1683853563.826 [DAT](INFO): Powering down 2023-05-12T01:06:03.898Z,1683853563.898 [DAT ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-12T01:06:03.898Z,1683853563.898 [DAT](INFO): Powering down 2023-05-12T01:06:03.899Z,1683853563.899 [DAT ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:03.914Z,1683853563.914 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2023-05-12T01:06:03.914Z,1683853563.914 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:03.914Z,1683853563.914 [Radio_Surface](INFO): Join timeout helper Thread ID is 726 2023-05-12T01:06:03.946Z,1683853563.946 [Radio_Surface](INFO): Powering down 2023-05-12T01:06:03.947Z,1683853563.947 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-12T01:06:03.947Z,1683853563.947 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:03.954Z,1683853563.954 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2023-05-12T01:06:03.955Z,1683853563.955 [Onboard ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:03.955Z,1683853563.955 [Onboard](INFO): Join timeout helper Thread ID is 727 2023-05-12T01:06:04.834Z,1683853564.834 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2023-05-12T01:06:05.534Z,1683853565.534 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-12T01:06:05.534Z,1683853565.534 [Onboard ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:05.546Z,1683853565.546 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2023-05-12T01:06:05.547Z,1683853565.547 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:05.547Z,1683853565.547 [DataOverHttps](INFO): Join timeout helper Thread ID is 728 2023-05-12T01:06:05.838Z,1683853565.838 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-12T01:06:05.838Z,1683853565.838 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:05.854Z,1683853565.854 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler 2023-05-12T01:06:05.854Z,1683853565.854 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:05.855Z,1683853565.855 [BackseatComponent](INFO): Join timeout helper Thread ID is 729 2023-05-12T01:06:05.954Z,1683853565.954 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-12T01:06:05.954Z,1683853565.954 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:05.974Z,1683853565.974 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2023-05-12T01:06:05.974Z,1683853565.974 [logger ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:05.975Z,1683853565.975 [logger](INFO): Join timeout helper Thread ID is 730 2023-05-12T01:06:05.986Z,1683853565.986 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-12T01:06:05.986Z,1683853565.986 [logger ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:05.994Z,1683853565.994 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2023-05-12T01:06:05.994Z,1683853565.994 [CommandLine ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:05.995Z,1683853565.995 [CommandLine](INFO): Join timeout helper Thread ID is 731 2023-05-12T01:06:06.038Z,1683853566.038 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-12T01:06:06.038Z,1683853566.038 [CommandLine ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:06.054Z,1683853566.054 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2023-05-12T01:06:06.054Z,1683853566.054 [CommandExec ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:06.055Z,1683853566.055 [CommandExec](INFO): Join timeout helper Thread ID is 732 2023-05-12T01:06:06.056Z,1683853566.056 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2023-05-12T01:06:06.056Z,1683853566.056 [controlThread ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:06.056Z,1683853566.056 [controlThread](INFO): Join timeout helper Thread ID is 733 2023-05-12T01:06:06.222Z,1683853566.222 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-12T01:06:06.222Z,1683853566.222 [controlThread](DEBUG): Uninitializing ControlThread 2023-05-12T01:06:06.223Z,1683853566.223 [AHRS_M2](INFO): Powering down 2023-05-12T01:06:06.366Z,1683853566.366 [DVL_micro](INFO): Powering down 2023-05-12T01:06:06.367Z,1683853566.367 [NAL9602](INFO): Powering down 2023-05-12T01:06:06.370Z,1683853566.370 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2023-05-12T01:06:06.371Z,1683853566.371 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2023-05-12T01:06:06.371Z,1683853566.371 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2023-05-12T01:06:06.372Z,1683853566.372 [MissionManager](INFO): Uninitializing Mission Default 2023-05-12T01:06:06.372Z,1683853566.372 [Default] Stopped 2023-05-12T01:06:06.372Z,1683853566.372 [Default](DEBUG): Aggregate::uninitialize Default 2023-05-12T01:06:06.372Z,1683853566.372 [Default:B.GoToSurface] Stopped 2023-05-12T01:06:06.372Z,1683853566.372 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2023-05-12T01:06:06.372Z,1683853566.372 [Default:CheckIn] Stopped 2023-05-12T01:06:06.372Z,1683853566.372 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-12T01:06:06.372Z,1683853566.372 [Default:CheckIn:C.Wait] Stopped 2023-05-12T01:06:06.373Z,1683853566.373 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-12T01:06:06.375Z,1683853566.375 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2023-05-12T01:06:06.376Z,1683853566.376 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2023-05-12T01:06:06.376Z,1683853566.376 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2023-05-12T01:06:06.376Z,1683853566.376 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2023-05-12T01:06:06.377Z,1683853566.377 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2023-05-12T01:06:06.377Z,1683853566.377 [BuoyancyServo](INFO): Powering down 2023-05-12T01:06:06.390Z,1683853566.390 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2023-05-12T01:06:06.390Z,1683853566.390 [ElevatorServo](INFO): Powering down 2023-05-12T01:06:06.391Z,1683853566.391 [MassServo](DEBUG): Uninitialize Mass Servo. 2023-05-12T01:06:06.391Z,1683853566.391 [MassServo](INFO): Powering down 2023-05-12T01:06:06.392Z,1683853566.392 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2023-05-12T01:06:06.392Z,1683853566.392 [RudderServo](INFO): Powering down 2023-05-12T01:06:06.393Z,1683853566.393 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2023-05-12T01:06:06.393Z,1683853566.393 [ThrusterHE](INFO): Powering down 2023-05-12T01:06:06.394Z,1683853566.394 [SBIT](DEBUG): Uninitialize SBIT Component. 2023-05-12T01:06:06.394Z,1683853566.394 [IBIT](DEBUG): Uninitialize IBIT Component. 2023-05-12T01:06:06.394Z,1683853566.394 [CBIT](DEBUG): Uninitialize CBIT Component. 2023-05-12T01:06:06.394Z,1683853566.394 [CBIT](DEBUG): Powering off loads. 2023-05-12T01:06:06.405Z,1683853566.405 [CBIT](DEBUG): Disabling WDT. 2023-05-12T01:06:06.417Z,1683853566.417 [CBIT](DEBUG): Opening all GF detection circuits. 2023-05-12T01:06:06.418Z,1683853566.418 [controlThread ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:06.470Z,1683853566.470 [DAT ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:06.475Z,1683853566.475 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:06.476Z,1683853566.476 [Onboard ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:06.483Z,1683853566.483 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:06.526Z,1683853566.526 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:06.578Z,1683853566.578 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:06.582Z,1683853566.582 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:06.604Z,1683853566.604 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2023-05-12T01:06:06.664Z,1683853566.664 [logger ThreadHandler](INFO): Thread cancelled.