2022-11-08T18:25:39.810Z,1667931939.810 [Supervisor](DEBUG): Initializing supervisor. 2022-11-08T18:25:39.815Z,1667931939.815 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2022-11-08T18:25:39.815Z,1667931939.815 [SyncHandler](INFO): Protected caller Thread ID is 835 2022-11-08T18:25:39.816Z,1667931939.816 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2022-11-08T18:25:39.817Z,1667931939.817 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2022-11-08T18:25:39.817Z,1667931939.817 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 836 2022-11-08T18:25:39.821Z,1667931939.821 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2022-11-08T18:25:39.838Z,1667931939.838 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2022-11-08T18:25:39.839Z,1667931939.839 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2022-11-08T18:25:39.840Z,1667931939.840 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 837 2022-11-08T18:25:39.844Z,1667931939.844 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2022-11-08T18:25:39.845Z,1667931939.845 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2022-11-08T18:25:39.845Z,1667931939.845 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 838 2022-11-08T18:25:39.847Z,1667931939.847 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2022-11-08T18:25:39.848Z,1667931939.848 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2022-11-08T18:25:39.849Z,1667931939.849 [logger ThreadHandler](INFO): Protected caller Thread ID is 839 2022-11-08T18:25:39.852Z,1667931939.852 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2022-11-08T18:25:39.853Z,1667931939.853 [Supervisor](INFO): Looking for Config files in directory: Config/ 2022-11-08T18:25:39.857Z,1667931939.857 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2022-11-08T18:25:40.271Z,1667931940.271 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2022-11-08T18:25:40.273Z,1667931940.273 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2022-11-08T18:25:40.483Z,1667931940.483 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2022-11-08T18:25:40.484Z,1667931940.484 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2022-11-08T18:25:40.662Z,1667931940.662 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2022-11-08T18:25:40.663Z,1667931940.663 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2022-11-08T18:25:40.768Z,1667931940.768 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2022-11-08T18:25:40.769Z,1667931940.769 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2022-11-08T18:25:41.132Z,1667931941.132 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2022-11-08T18:25:41.134Z,1667931941.134 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2022-11-08T18:25:41.445Z,1667931941.445 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2022-11-08T18:25:41.447Z,1667931941.447 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2022-11-08T18:25:41.542Z,1667931941.542 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2022-11-08T18:25:41.544Z,1667931941.544 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2022-11-08T18:25:41.756Z,1667931941.756 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2022-11-08T18:25:41.758Z,1667931941.758 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2022-11-08T18:25:42.253Z,1667931942.253 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2022-11-08T18:25:42.253Z,1667931942.253 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2022-11-08T18:25:42.597Z,1667931942.597 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2022-11-08T18:25:42.598Z,1667931942.598 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2022-11-08T18:25:42.679Z,1667931942.679 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2022-11-08T18:25:42.884Z,1667931942.884 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2022-11-08T18:25:42.884Z,1667931942.884 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2022-11-08T18:25:43.018Z,1667931943.018 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2022-11-08T18:25:43.019Z,1667931943.019 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2022-11-08T18:25:43.775Z,1667931943.775 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2022-11-08T18:25:43.776Z,1667931943.776 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2022-11-08T18:25:44.824Z,1667931944.824 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2022-11-08T18:25:45.105Z,1667931945.105 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2022-11-08T18:25:45.107Z,1667931945.107 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/ 2022-11-08T18:25:45.111Z,1667931945.111 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/vehicle.cfg 2022-11-08T18:25:45.284Z,1667931945.284 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/logger.cfg 2022-11-08T18:25:45.376Z,1667931945.376 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Servo.cfg 2022-11-08T18:25:45.487Z,1667931945.487 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Control.cfg 2022-11-08T18:25:45.586Z,1667931945.586 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/secure.cfg 2022-11-08T18:25:45.668Z,1667931945.668 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Simulator.cfg 2022-11-08T18:25:45.753Z,1667931945.753 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Science.cfg 2022-11-08T18:25:45.865Z,1667931945.865 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/BIT.cfg 2022-11-08T18:25:45.962Z,1667931945.962 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Sensor.cfg 2022-11-08T18:25:46.443Z,1667931946.443 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Battery.cfg 2022-11-08T18:25:46.896Z,1667931946.896 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2022-11-08T18:25:46.896Z,1667931946.896 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Navigation.cfg 2022-11-08T18:25:46.988Z,1667931946.988 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2022-11-08T18:25:46.992Z,1667931946.992 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2022-11-08T18:25:47.348Z,1667931947.348 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2022-11-08T18:25:47.348Z,1667931947.348 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2022-11-08T18:25:47.486Z,1667931947.486 [DeadReckonUsingMultipleVelocitySources] Loaded 2022-11-08T18:25:47.486Z,1667931947.486 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2022-11-08T18:25:47.525Z,1667931947.525 [DeadReckonUsingSpeedCalculator] Loaded 2022-11-08T18:25:47.525Z,1667931947.525 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2022-11-08T18:25:47.538Z,1667931947.538 [NavChart] Loaded 2022-11-08T18:25:47.539Z,1667931947.539 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2022-11-08T18:25:47.544Z,1667931947.544 [UniversalFixResidualReporter] Loaded 2022-11-08T18:25:47.544Z,1667931947.544 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2022-11-08T18:25:47.545Z,1667931947.545 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2022-11-08T18:25:47.545Z,1667931947.545 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2022-11-08T18:25:47.561Z,1667931947.561 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2022-11-08T18:25:47.561Z,1667931947.561 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2022-11-08T18:25:47.803Z,1667931947.803 [CTD_Seabird] Loaded 2022-11-08T18:25:47.803Z,1667931947.803 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2022-11-08T18:25:47.805Z,1667931947.805 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 4065A4E0 2022-11-08T18:25:47.805Z,1667931947.805 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 921 2022-11-08T18:25:47.825Z,1667931947.825 [PAR_Licor] Loaded 2022-11-08T18:25:47.825Z,1667931947.825 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2022-11-08T18:25:47.855Z,1667931947.855 [WetLabsBB2FL] Loaded 2022-11-08T18:25:47.856Z,1667931947.856 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2022-11-08T18:25:47.857Z,1667931947.857 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4068A4E0 2022-11-08T18:25:47.857Z,1667931947.857 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 922 2022-11-08T18:25:47.858Z,1667931947.858 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2022-11-08T18:25:47.860Z,1667931947.860 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2022-11-08T18:25:47.927Z,1667931947.927 [VerticalControl](DEBUG): Construct VerticalControl. 2022-11-08T18:25:47.987Z,1667931947.987 [VerticalControl] Loaded 2022-11-08T18:25:47.987Z,1667931947.987 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2022-11-08T18:25:47.990Z,1667931947.990 [HorizontalControl](DEBUG): Construct HorizontalControl. 2022-11-08T18:25:48.031Z,1667931948.031 [HorizontalControl] Loaded 2022-11-08T18:25:48.032Z,1667931948.032 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2022-11-08T18:25:48.034Z,1667931948.034 [SpeedControl](DEBUG): Construct SpeedControl. 2022-11-08T18:25:48.037Z,1667931948.037 [SpeedControl] Loaded 2022-11-08T18:25:48.037Z,1667931948.037 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2022-11-08T18:25:48.040Z,1667931948.040 [LoopControl](DEBUG): Construct LoopControl. 2022-11-08T18:25:48.041Z,1667931948.041 [LoopControl] Loaded 2022-11-08T18:25:48.041Z,1667931948.041 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2022-11-08T18:25:48.041Z,1667931948.041 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2022-11-08T18:25:48.042Z,1667931948.042 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2022-11-08T18:25:48.111Z,1667931948.111 [DepthRateCalculator] Loaded 2022-11-08T18:25:48.111Z,1667931948.111 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2022-11-08T18:25:48.116Z,1667931948.116 [PitchRateCalculator] Loaded 2022-11-08T18:25:48.117Z,1667931948.117 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2022-11-08T18:25:48.126Z,1667931948.126 [SpeedCalculator] Loaded 2022-11-08T18:25:48.126Z,1667931948.126 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2022-11-08T18:25:48.130Z,1667931948.130 [YawRateCalculator] Loaded 2022-11-08T18:25:48.131Z,1667931948.131 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2022-11-08T18:25:48.149Z,1667931948.149 [ElevatorOffsetCalculator] Loaded 2022-11-08T18:25:48.149Z,1667931948.149 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2022-11-08T18:25:48.150Z,1667931948.150 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2022-11-08T18:25:48.150Z,1667931948.150 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2022-11-08T18:25:48.269Z,1667931948.269 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2022-11-08T18:25:48.269Z,1667931948.269 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2022-11-08T18:25:48.351Z,1667931948.351 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2022-11-08T18:25:48.352Z,1667931948.352 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2022-11-08T18:25:48.500Z,1667931948.500 [BuoyancyServo] Loaded 2022-11-08T18:25:48.500Z,1667931948.500 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2022-11-08T18:25:48.520Z,1667931948.520 [ElevatorServo] Loaded 2022-11-08T18:25:48.520Z,1667931948.520 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2022-11-08T18:25:48.539Z,1667931948.539 [MassServo] Loaded 2022-11-08T18:25:48.540Z,1667931948.540 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2022-11-08T18:25:48.558Z,1667931948.558 [RudderServo] Loaded 2022-11-08T18:25:48.559Z,1667931948.559 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2022-11-08T18:25:48.574Z,1667931948.574 [ThrusterHE] Loaded 2022-11-08T18:25:48.574Z,1667931948.574 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2022-11-08T18:25:48.574Z,1667931948.574 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2022-11-08T18:25:48.575Z,1667931948.575 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2022-11-08T18:25:48.758Z,1667931948.758 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2022-11-08T18:25:48.758Z,1667931948.758 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2022-11-08T18:25:49.470Z,1667931949.470 [AHRS_M2] Loaded 2022-11-08T18:25:49.470Z,1667931949.470 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2022-11-08T18:25:49.734Z,1667931949.734 [BackseatComponent] Loaded 2022-11-08T18:25:49.735Z,1667931949.735 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2022-11-08T18:25:49.736Z,1667931949.736 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A854E0 2022-11-08T18:25:49.736Z,1667931949.736 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 923 2022-11-08T18:25:49.739Z,1667931949.739 [LcmUniversalReporter] Loaded 2022-11-08T18:25:49.739Z,1667931949.739 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2022-11-08T18:25:50.557Z,1667931950.557 [BPC1] Loaded 2022-11-08T18:25:50.558Z,1667931950.558 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2022-11-08T18:25:50.700Z,1667931950.700 [DataOverHttps] Loaded 2022-11-08T18:25:50.701Z,1667931950.701 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2022-11-08T18:25:50.702Z,1667931950.702 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40AB54E0 2022-11-08T18:25:50.702Z,1667931950.702 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 924 2022-11-08T18:25:50.722Z,1667931950.722 [Depth_Keller] Loaded 2022-11-08T18:25:50.723Z,1667931950.723 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2022-11-08T18:25:50.727Z,1667931950.727 [DropWeight] Loaded 2022-11-08T18:25:50.728Z,1667931950.728 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2022-11-08T18:25:50.745Z,1667931950.745 [MultiRay] Loaded 2022-11-08T18:25:50.745Z,1667931950.745 [ComponentRegistry](DEBUG): SyncComponent "MultiRay" handled in the control thread. 2022-11-08T18:25:50.807Z,1667931950.807 [NAL9602] Loaded 2022-11-08T18:25:50.808Z,1667931950.808 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2022-11-08T18:25:50.837Z,1667931950.837 [Onboard] Loaded 2022-11-08T18:25:50.838Z,1667931950.838 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2022-11-08T18:25:50.839Z,1667931950.839 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40AE54E0 2022-11-08T18:25:50.839Z,1667931950.839 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 925 2022-11-08T18:25:50.845Z,1667931950.845 [PowerOnly](INFO): Adding load control power supply at /dev/loadC3 2022-11-08T18:25:50.856Z,1667931950.856 [PowerOnly] Loaded 2022-11-08T18:25:50.856Z,1667931950.856 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread. 2022-11-08T18:25:50.868Z,1667931950.868 [Power24vConverter] Loaded 2022-11-08T18:25:50.868Z,1667931950.868 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2022-11-08T18:25:50.882Z,1667931950.882 [Radio_Surface] Loaded 2022-11-08T18:25:50.882Z,1667931950.882 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2022-11-08T18:25:50.883Z,1667931950.883 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40B154E0 2022-11-08T18:25:50.883Z,1667931950.883 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 926 2022-11-08T18:25:50.976Z,1667931950.976 [DAT] Loaded 2022-11-08T18:25:50.976Z,1667931950.976 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2022-11-08T18:25:50.977Z,1667931950.977 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40B454E0 2022-11-08T18:25:50.978Z,1667931950.978 [DAT ThreadHandler](INFO): Protected caller Thread ID is 927 2022-11-08T18:25:50.978Z,1667931950.978 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2022-11-08T18:25:50.980Z,1667931950.980 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2022-11-08T18:25:51.351Z,1667931951.351 [SBIT](DEBUG): Construct Startup Built In Test. 2022-11-08T18:25:51.361Z,1667931951.361 [SBIT] Loaded 2022-11-08T18:25:51.361Z,1667931951.361 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2022-11-08T18:25:51.364Z,1667931951.364 [IBIT](DEBUG): Construct Initiated Built In Test. 2022-11-08T18:25:51.377Z,1667931951.377 [IBIT] Loaded 2022-11-08T18:25:51.377Z,1667931951.377 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2022-11-08T18:25:51.383Z,1667931951.383 [CBIT](DEBUG): Construct Continuous Built In Test. 2022-11-08T18:25:51.487Z,1667931951.487 [CBIT] Loaded 2022-11-08T18:25:51.487Z,1667931951.487 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2022-11-08T18:25:51.487Z,1667931951.487 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2022-11-08T18:25:51.488Z,1667931951.488 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2022-11-08T18:25:51.530Z,1667931951.530 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2022-11-08T18:25:51.537Z,1667931951.537 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2022-11-08T18:25:51.540Z,1667931951.540 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2022-11-08T18:25:51.551Z,1667931951.551 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2022-11-08T18:25:51.552Z,1667931951.552 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BD34E0 2022-11-08T18:25:51.552Z,1667931951.552 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 928 2022-11-08T18:25:51.557Z,1667931951.557 [Supervisor](INFO): Main Thread ID is 829 2022-11-08T18:25:51.557Z,1667931951.557 [Supervisor](DEBUG): Running supervisor. 2022-11-08T18:25:51.558Z,1667931951.558 [CommandExec ThreadHandler](INFO): Handler Thread ID is 929 2022-11-08T18:25:51.558Z,1667931951.558 [CommandExec](INFO): Initializing the command executive. 2022-11-08T18:25:51.559Z,1667931951.559 [CommandLine ThreadHandler](INFO): Handler Thread ID is 930 2022-11-08T18:25:51.562Z,1667931951.562 [controlThread ThreadHandler](INFO): Handler Thread ID is 931 2022-11-08T18:25:51.562Z,1667931951.562 [controlThread](DEBUG): Initializing ControlThread 2022-11-08T18:25:51.563Z,1667931951.563 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2022-11-08T18:25:51.564Z,1667931951.564 [NavChart](DEBUG): Initialize NavChart Navigation. 2022-11-08T18:25:51.564Z,1667931951.564 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2022-11-08T18:25:51.568Z,1667931951.568 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2022-11-08T18:25:51.570Z,1667931951.570 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2022-11-08T18:25:51.570Z,1667931951.570 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2022-11-08T18:25:51.571Z,1667931951.571 [LoopControl](DEBUG): Initialize LoopControlComponent. 2022-11-08T18:25:51.571Z,1667931951.571 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2022-11-08T18:25:51.571Z,1667931951.571 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2022-11-08T18:25:51.572Z,1667931951.572 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2022-11-08T18:25:51.572Z,1667931951.572 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2022-11-08T18:25:51.573Z,1667931951.573 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2022-11-08T18:25:51.578Z,1667931951.578 [SBIT](INFO): Initialize SBIT Component. 2022-11-08T18:25:51.579Z,1667931951.579 [SBIT](IMPORTANT): git: 2022-10-11-45-gb822ed017 2022-11-08T18:25:51.579Z,1667931951.579 [SBIT](INFO): git hash: b822ed017b998e9f5c0380c5dda45bcbd9b57e7d 2022-11-08T18:25:51.579Z,1667931951.579 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2022-11-08T18:25:51.581Z,1667931951.581 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021 2022-11-08T18:25:51.582Z,1667931951.582 [SBIT](INFO): Beginning SBIT in 28.000000 seconds. 2022-11-08T18:25:51.582Z,1667931951.582 [IBIT](INFO): Initialize IBIT Component. 2022-11-08T18:25:51.583Z,1667931951.583 [CBIT](DEBUG): Initialize CBIT Component. 2022-11-08T18:25:51.584Z,1667931951.584 [logger ThreadHandler](INFO): Handler Thread ID is 932 2022-11-08T18:25:51.596Z,1667931951.596 [CBIT](DEBUG): Initialized mux pins. 2022-11-08T18:25:51.596Z,1667931951.596 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2022-11-08T18:25:51.596Z,1667931951.596 [CBIT](DEBUG): Initializing the watchdog timer. 2022-11-08T18:25:51.604Z,1667931951.604 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 933 2022-11-08T18:25:51.605Z,1667931951.605 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2022-11-08T18:25:51.609Z,1667931951.609 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 935 2022-11-08T18:25:51.612Z,1667931951.612 [WetLabsBB2FL](INFO): Powering up 2022-11-08T18:25:51.613Z,1667931951.613 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 937 2022-11-08T18:25:51.620Z,1667931951.620 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2022-11-08T18:25:51.620Z,1667931951.620 [CBIT](DEBUG): Initializing heartbeat. 2022-11-08T18:25:51.621Z,1667931951.621 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 938 2022-11-08T18:25:51.622Z,1667931951.622 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2022-11-08T18:25:51.628Z,1667931951.628 [Onboard ThreadHandler](INFO): Handler Thread ID is 939 2022-11-08T18:25:51.658Z,1667931951.658 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 940 2022-11-08T18:25:51.668Z,1667931951.668 [DAT ThreadHandler](INFO): Handler Thread ID is 941 2022-11-08T18:25:51.669Z,1667931951.669 [DAT](INFO): Powering up 2022-11-08T18:25:51.669Z,1667931951.669 [DAT](DEBUG): Initializing DAT. 2022-11-08T18:25:51.673Z,1667931951.673 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 943 2022-11-08T18:25:51.681Z,1667931951.681 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2022-11-08T18:25:51.681Z,1667931951.681 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2022-11-08T18:25:51.682Z,1667931951.682 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2022-11-08T18:25:51.682Z,1667931951.682 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2022-11-08T18:25:51.682Z,1667931951.682 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2022-11-08T18:25:51.682Z,1667931951.682 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2022-11-08T18:25:51.682Z,1667931951.682 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2022-11-08T18:25:51.682Z,1667931951.682 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2022-11-08T18:25:51.692Z,1667931951.692 [CBIT](DEBUG): Deactivating GF circuits. 2022-11-08T18:25:51.699Z,1667931951.699 [CBIT](DEBUG): Deactivating emergency mode. 2022-11-08T18:25:51.736Z,1667931951.736 [CBIT](DEBUG): Backplane powered. 2022-11-08T18:25:51.737Z,1667931951.737 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml 2022-11-08T18:25:51.774Z,1667931951.774 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2022-11-08T18:25:51.802Z,1667931951.802 [MissionManager](DEBUG): 2022-11-08T18:25:51.803Z,1667931951.803 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml 2022-11-08T18:25:51.872Z,1667931951.872 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2022-11-08T18:25:51.873Z,1667931951.873 [Default:A.Wait](DEBUG): Construct Wait. 2022-11-08T18:25:51.900Z,1667931951.900 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2022-11-08T18:25:51.924Z,1667931951.924 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2022-11-08T18:25:51.927Z,1667931951.927 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2022-11-08T18:25:51.949Z,1667931951.949 [Default:E.Execute](DEBUG): Construct Execute. 2022-11-08T18:25:51.968Z,1667931951.968 [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 2022-11-08T18:25:51.974Z,1667931951.974 [controlThread](DEBUG): Component order: CycleStarter,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,MultiRay,NAL9602,PowerOnly,Power24vConverter,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2022-11-08T18:25:51.990Z,1667931951.990 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2022-11-08T18:25:52.060Z,1667931952.060 [Radio_Surface](INFO): Powering up 2022-11-08T18:25:52.151Z,1667931952.151 [MultiRay](INFO): Powering up MultiRay Lights 2022-11-08T18:25:52.185Z,1667931952.185 [Power24vConverter](INFO): Powering up. 2022-11-08T18:25:52.217Z,1667931952.217 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2022-11-08T18:25:52.225Z,1667931952.225 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2022-11-08T18:25:52.226Z,1667931952.226 [ElevatorServo](DEBUG): Initializing EZServoServo. 2022-11-08T18:25:52.232Z,1667931952.232 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2022-11-08T18:25:52.233Z,1667931952.233 [MassServo](DEBUG): Initializing EZServoServo. 2022-11-08T18:25:52.240Z,1667931952.240 [MassServo](DEBUG): Initializing MassServo. 2022-11-08T18:25:52.241Z,1667931952.241 [RudderServo](DEBUG): Initializing EZServoServo. 2022-11-08T18:25:52.248Z,1667931952.248 [RudderServo](DEBUG): Initializing RudderServo. 2022-11-08T18:25:52.249Z,1667931952.249 [ThrusterHE](DEBUG): Initializing EZServoServo. 2022-11-08T18:25:52.256Z,1667931952.256 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2022-11-08T18:25:52.445Z,1667931952.445 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2022-11-08T18:25:52.445Z,1667931952.445 [DropWeight] Hardware Fault, FailCount= 1 2022-11-08T18:25:52.445Z,1667931952.445 [DropWeight](ERROR): Hardware Fault 2022-11-08T18:25:52.473Z,1667931952.473 [MultiRay](IMPORTANT): All lights off 2022-11-08T18:25:52.519Z,1667931952.519 [CommandExec](FAULT): Scheduling is paused 2022-11-08T18:25:52.519Z,1667931952.519 [CBIT](INFO): Critical error at 20221108T182552 2022-11-08T18:25:52.519Z,1667931952.519 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2022-11-08T18:25:52.530Z,1667931952.530 [CBIT](ERROR): Hardware Fault in component: DropWeight 2022-11-08T18:25:52.530Z,1667931952.530 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2022-11-08T18:25:53.124Z,1667931953.124 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2022-11-08T18:25:53.124Z,1667931953.124 [RudderServo](FAULT): Rudder failed to initialize 2022-11-08T18:25:53.124Z,1667931953.124 [RudderServo] Communications Fault, FailCount= 1 2022-11-08T18:25:53.124Z,1667931953.124 [RudderServo](ERROR): Communications Fault 2022-11-08T18:25:53.126Z,1667931953.126 [CBIT](INFO): Critical error at 20221108T182552 2022-11-08T18:25:53.128Z,1667931953.128 [CBIT](ERROR): Communications Fault in component: RudderServo 2022-11-08T18:25:53.341Z,1667931953.341 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2022-11-08T18:25:53.341Z,1667931953.341 [RudderServo](INFO): Powering down 2022-11-08T18:25:54.021Z,1667931954.021 [RudderServo](DEBUG): Initializing EZServoServo. 2022-11-08T18:25:54.141Z,1667931954.141 [RudderServo](DEBUG): Initializing RudderServo. 2022-11-08T18:25:54.145Z,1667931954.145 [CBIT](INFO): Clearing failed state for component RudderServo 2022-11-08T18:25:54.145Z,1667931954.145 [RudderServo] No Fault, FailCount= 1 2022-11-08T18:25:54.224Z,1667931954.224 [WetLabsBB2FL](INFO): Powering down 2022-11-08T18:25:57.961Z,1667931957.961 [ThrusterHE](ERROR): Zero Speed Commanded. 2022-11-08T18:26:07.298Z,1667931967.298 [DAT](INFO): commRate: 800 2022-11-08T18:26:09.364Z,1667931969.364 [DAT](INFO): entering command mode 2022-11-08T18:26:09.565Z,1667931969.565 [DAT](INFO): setting verbose to 3 2022-11-08T18:26:09.818Z,1667931969.818 [DAT](INFO): set verbose to 3 2022-11-08T18:26:09.819Z,1667931969.819 [DAT](INFO): setting DatVerbose to 27440 2022-11-08T18:26:10.069Z,1667931970.069 [DAT](INFO): set DatVerbose to 27440 2022-11-08T18:26:10.070Z,1667931970.070 [DAT](INFO): setting transmit power to 8 2022-11-08T18:26:10.321Z,1667931970.321 [DAT](INFO): set transmit power to 8 2022-11-08T18:26:10.322Z,1667931970.322 [DAT](INFO): setting local address to 10 2022-11-08T18:26:10.573Z,1667931970.573 [DAT](INFO): set local address to 10 2022-11-08T18:26:10.574Z,1667931970.574 [DAT](INFO): Setting time to: 18:26:10 And date to:11/8/2022 2022-11-08T18:26:10.825Z,1667931970.825 [DAT](INFO): Local DAT time set to Tue Nov 8, 2022 18:26:10 2022-11-08T18:26:20.349Z,1667931980.349 [SBIT](IMPORTANT): Beginning Startup BIT 2022-11-08T18:26:20.354Z,1667931980.354 [CBIT](IMPORTANT): Beginning ground fault scan 2022-11-08T18:26:21.086Z,1667931981.086 [NAL9602](INFO): Powering up NAL9602 2022-11-08T18:26:31.260Z,1667931991.260 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): 0.012118 CHAN A1 (24V): -0.000311 CHAN A2 (12V): -0.005669 CHAN A3 (5V): -0.002495 CHAN B0 (3.3V): -0.001075 CHAN B1 (3.15aV): -0.001882 CHAN B2 (3.15bV): -0.001326 CHAN B3 (GND): -0.000438 OPEN: 0.006400 Full Scale: +/- 1 mA 2022-11-08T18:26:31.990Z,1667931991.990 [NAL9602](INFO): NAL9602 initialized 2022-11-08T18:26:33.681Z,1667931993.681 [SBIT](FAULT): Mass: EXPECTED:0.009400 ACTUAL:0.007361 2022-11-08T18:27:14.419Z,1667932034.419 [SBIT](CRITICAL): SBIT FAILED 2022-11-08T18:27:14.419Z,1667932034.419 [SBIT](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2022-11-08T18:27:14.421Z,1667932034.421 [CBIT](INFO): Critical error at 20221108T182714 2022-11-08T18:27:14.821Z,1667932034.821 [MissionManager](IMPORTANT): Started mission Startup 2022-11-08T18:27:14.821Z,1667932034.821 [Startup] Running Loop=1 2022-11-08T18:27:14.822Z,1667932034.822 [Startup](DEBUG): Aggregate::initialize Startup 2022-11-08T18:27:14.822Z,1667932034.822 [Startup:A.GoToSurface] Running Loop=1 2022-11-08T18:27:14.822Z,1667932034.822 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-11-08T18:27:14.822Z,1667932034.822 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-11-08T18:27:14.823Z,1667932034.823 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-11-08T18:27:14.823Z,1667932034.823 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-11-08T18:27:14.823Z,1667932034.823 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-11-08T18:27:14.824Z,1667932034.824 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-11-08T18:27:14.825Z,1667932034.825 [Startup:StartupSatComms] Running Loop=1 2022-11-08T18:27:14.825Z,1667932034.825 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2022-11-08T18:27:14.826Z,1667932034.826 [Startup:StartupSatComms:A] Running Loop=1 2022-11-08T18:27:15.229Z,1667932035.229 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2022-11-08T18:28:15.042Z,1667932095.042 [Startup:StartupSatComms:A](INFO): Timed out from 2022-11-08T18:27:14.8Z 2022-11-08T18:28:15.042Z,1667932095.042 [Startup:StartupSatComms:A] Stopped 2022-11-08T18:28:15.042Z,1667932095.042 [Startup:StartupSatComms:B] Running Loop=1 2022-11-08T18:28:15.455Z,1667932095.455 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2022-11-08T18:28:32.535Z,1667932112.535 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004972 2022-11-08T18:27:30.002Z,1667932050.002 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20221108T180042/Courier0007.lzma 2022-11-08T18:27:31.006Z,1667932051.006 [DataOverHttps](INFO): Moved sent file to Logs/20221108T180042/Courier0007.lzma.bak 2022-11-08T18:27:31.007Z,1667932051.007 [DataOverHttps](INFO): SBD MOMSN=17274025 2022-11-08T18:27:47.678Z,1667932067.678 [DataOverHttps](INFO): Sending 267 bytes from file Logs/20221108T182539/Courier0000.lzma 2022-11-08T18:27:48.680Z,1667932068.680 [DataOverHttps](INFO): Moved sent file to Logs/20221108T182539/Courier0000.lzma.bak 2022-11-08T18:27:48.680Z,1667932068.680 [DataOverHttps](INFO): SBD MOMSN=17274027 2022-11-08T18:28:05.663Z,1667932085.663 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20221107T225542/Express0020.lzma 2022-11-08T18:28:06.664Z,1667932086.664 [DataOverHttps](INFO): Moved sent file to Logs/20221107T225542/Express0020.lzma.bak 2022-11-08T18:28:06.664Z,1667932086.664 [DataOverHttps](INFO): SBD MOMSN=17274035 2022-11-08T18:28:23.947Z,1667932103.947 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20221107T225542/Express0023.lzma 2022-11-08T18:28:24.948Z,1667932104.948 [DataOverHttps](INFO): Moved sent file to Logs/20221107T225542/Express0023.lzma.bak 2022-11-08T18:28:24.948Z,1667932104.948 [DataOverHttps](INFO): SBD MOMSN=17274038 2022-11-08T18:28:40.781Z,1667932120.781 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20221107T225542/Express0026.lzma 2022-11-08T18:28:41.776Z,1667932121.776 [DataOverHttps](INFO): Moved sent file to Logs/20221107T225542/Express0026.lzma.bak 2022-11-08T18:28:41.776Z,1667932121.776 [DataOverHttps](INFO): SBD MOMSN=17274041 2022-11-08T18:28:51.929Z,1667932131.929 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2022-11-08T18:28:51.929Z,1667932131.929 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2022-11-08T18:28:51.930Z,1667932131.930 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1 2022-11-08T18:28:51.930Z,1667932131.930 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2022-11-08T18:28:51.945Z,1667932131.945 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2022-11-08T18:28:51.945Z,1667932131.945 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2022-11-08T18:28:52.357Z,1667932132.357 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2022-11-08T18:28:52.357Z,1667932132.357 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2022-11-08T18:28:52.358Z,1667932132.358 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2022-11-08T18:28:52.358Z,1667932132.358 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1 2022-11-08T18:28:52.743Z,1667932132.743 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2022-11-08T18:28:58.768Z,1667932138.768 [DataOverHttps](INFO): Sending 772 bytes from file Logs/20221107T225542/Express0029.lzma 2022-11-08T18:28:59.768Z,1667932139.768 [DataOverHttps](INFO): Moved sent file to Logs/20221107T225542/Express0029.lzma.bak 2022-11-08T18:28:59.768Z,1667932139.768 [DataOverHttps](INFO): SBD MOMSN=17274044 2022-11-08T18:29:15.392Z,1667932155.392 [Startup:StartupSatComms:B](INFO): Timed out from 2022-11-08T18:28:15.0Z 2022-11-08T18:29:15.392Z,1667932155.392 [Startup:StartupSatComms:B] Stopped 2022-11-08T18:29:15.392Z,1667932155.392 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2022-11-08T18:29:15.393Z,1667932155.393 [Startup:StartupSatComms] Stopped 2022-11-08T18:29:15.393Z,1667932155.393 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2022-11-08T18:29:15.393Z,1667932155.393 [Startup](INFO): Completed Startup 2022-11-08T18:29:15.394Z,1667932155.394 [MissionManager](INFO): Startup is completed. 2022-11-08T18:29:15.394Z,1667932155.394 [MissionManager](INFO): Uninitializing Mission Startup 2022-11-08T18:29:15.394Z,1667932155.394 [Startup] Stopped 2022-11-08T18:29:15.394Z,1667932155.394 [Startup](DEBUG): Aggregate::uninitialize Startup 2022-11-08T18:29:15.398Z,1667932155.398 [Startup:A.GoToSurface] Stopped 2022-11-08T18:29:15.398Z,1667932155.398 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-11-08T18:29:15.798Z,1667932155.798 [MissionManager](IMPORTANT): Started mission Default 2022-11-08T18:29:15.798Z,1667932155.798 [Default] Running Loop=1 2022-11-08T18:29:15.798Z,1667932155.798 [Default](DEBUG): Aggregate::initialize Default 2022-11-08T18:29:15.798Z,1667932155.798 [Default:B.GoToSurface] Running Loop=1 2022-11-08T18:29:15.799Z,1667932155.799 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-11-08T18:29:15.799Z,1667932155.799 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-11-08T18:29:15.799Z,1667932155.799 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-11-08T18:29:15.799Z,1667932155.799 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-11-08T18:29:15.800Z,1667932155.800 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-11-08T18:29:15.800Z,1667932155.800 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-11-08T18:29:15.800Z,1667932155.800 [Default:A.Wait] Running Loop=1 2022-11-08T18:29:15.800Z,1667932155.800 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-11-08T18:29:17.807Z,1667932157.807 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20221107T225542/Express0032.lzma 2022-11-08T18:29:18.800Z,1667932158.800 [DataOverHttps](INFO): Moved sent file to Logs/20221107T225542/Express0032.lzma.bak 2022-11-08T18:29:18.800Z,1667932158.800 [DataOverHttps](INFO): SBD MOMSN=17274070 2022-11-08T18:29:29.108Z,1667932169.108 [Default:A.Wait](INFO): Done Waiting. 2022-11-08T18:29:29.109Z,1667932169.109 [Default:A.Wait] Stopped 2022-11-08T18:29:29.109Z,1667932169.109 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-11-08T18:29:29.501Z,1667932169.501 [Default:CheckIn] Running Loop=1 2022-11-08T18:29:29.502Z,1667932169.502 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-08T18:29:29.502Z,1667932169.502 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-08T18:29:29.908Z,1667932169.908 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2022-11-08T18:31:35.236Z,1667932295.236 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-11-08T18:31:52.919Z,1667932312.919 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2022-11-08T18:31:52.919Z,1667932312.919 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2022-11-08T18:31:52.920Z,1667932312.920 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2 2022-11-08T18:31:52.920Z,1667932312.920 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2022-11-08T18:31:52.947Z,1667932312.947 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2022-11-08T18:31:52.947Z,1667932312.947 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2022-11-08T18:31:53.375Z,1667932313.375 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2022-11-08T18:31:53.375Z,1667932313.375 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2022-11-08T18:31:53.376Z,1667932313.376 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2022-11-08T18:31:53.376Z,1667932313.376 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2 2022-11-08T18:31:53.754Z,1667932313.754 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2022-11-08T18:33:08.871Z,1667932388.871 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2022-11-08T18:33:08.874Z,1667932388.874 [BPC1](INFO): Received data from all battery sticks. 2022-11-08T18:34:24.758Z,1667932464.758 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T18:34:24.758Z,1667932464.758 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T18:34:24.780Z,1667932464.780 [MissionManager](INFO): DefineArg multiray_lab.MissionTimeout = 1.000000 min 2022-11-08T18:34:24.823Z,1667932464.823 [MissionManager](INFO): DefineArg multiray_lab.LightDuration = 1.000000 s 2022-11-08T18:34:24.826Z,1667932464.826 [MissionManager](INFO): DefineArg multiray_lab.LightMode0 = 0.000000 count 2022-11-08T18:34:24.829Z,1667932464.829 [MissionManager](INFO): DefineArg multiray_lab.LightMode1 = 1.000000 count 2022-11-08T18:34:24.841Z,1667932464.841 [MissionManager](INFO): DefineArg multiray_lab.LightMode2 = 2.000000 count 2022-11-08T18:34:24.861Z,1667932464.861 [MissionManager](DEBUG): This mission is designed to run in the lab only. Turns on and off MultiRay lights. How long to let the mission run. 1 How long to wait before turning on / off lights, default 1 second 1 Light mode = 0 0 Light mode = 1 1 Light mode = 2 2 2022-11-08T18:34:24.869Z,1667932464.869 [Default] Stopped 2022-11-08T18:34:24.870Z,1667932464.870 [Default](DEBUG): Aggregate::uninitialize Default 2022-11-08T18:34:24.870Z,1667932464.870 [Default:B.GoToSurface] Stopped 2022-11-08T18:34:24.870Z,1667932464.870 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-11-08T18:34:24.870Z,1667932464.870 [Default:CheckIn] Stopped 2022-11-08T18:34:24.870Z,1667932464.870 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-08T18:34:24.876Z,1667932464.876 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T18:34:24.876Z,1667932464.876 [Default:CheckIn:Read_GPS] Stopped 2022-11-08T18:34:24.877Z,1667932464.877 [MissionManager](IMPORTANT): Started mission multiray_lab 2022-11-08T18:34:24.877Z,1667932464.877 [multiray_lab] Running Loop=1 2022-11-08T18:34:24.877Z,1667932464.877 [multiray_lab](DEBUG): Aggregate::initialize multiray_lab 2022-11-08T18:34:26.032Z,1667932466.032 [multiray_lab](INFO): Timed out from 2022-11-08T18:34:24.9Z 2022-11-08T18:34:26.032Z,1667932466.032 [multiray_lab:A_Timeout] Running Loop=1 2022-11-08T18:34:26.033Z,1667932466.033 [multiray_lab:A_Timeout](DEBUG): Aggregate::initialize multiray_lab:A_Timeout 2022-11-08T18:34:26.033Z,1667932466.033 [multiray_lab:A_Timeout:A] Running Loop=1 2022-11-08T18:34:26.033Z,1667932466.033 [multiray_lab:A_Timeout:A] Stopped 2022-11-08T18:34:26.033Z,1667932466.033 [multiray_lab:A_Timeout](INFO): Completed multiray_lab:A_Timeout 2022-11-08T18:34:26.033Z,1667932466.033 [MissionManager](INFO): multiray_lab is completed. 2022-11-08T18:34:26.033Z,1667932466.033 [MissionManager](INFO): Uninitializing Mission multiray_lab 2022-11-08T18:34:26.034Z,1667932466.034 [multiray_lab] Stopped 2022-11-08T18:34:26.034Z,1667932466.034 [multiray_lab](DEBUG): Aggregate::uninitialize multiray_lab 2022-11-08T18:34:26.515Z,1667932466.515 [MultiRay](INFO): Red lights on 2022-11-08T18:34:26.563Z,1667932466.563 [MissionManager](IMPORTANT): Started mission Default 2022-11-08T18:34:26.564Z,1667932466.564 [Default] Running Loop=1 2022-11-08T18:34:26.564Z,1667932466.564 [Default](DEBUG): Aggregate::initialize Default 2022-11-08T18:34:26.564Z,1667932466.564 [Default:B.GoToSurface] Running Loop=1 2022-11-08T18:34:26.564Z,1667932466.564 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-11-08T18:34:26.564Z,1667932466.564 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-11-08T18:34:26.565Z,1667932466.565 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-11-08T18:34:26.565Z,1667932466.565 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-11-08T18:34:26.565Z,1667932466.565 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-11-08T18:34:26.565Z,1667932466.565 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-11-08T18:34:26.566Z,1667932466.566 [Default:A.Wait] Running Loop=1 2022-11-08T18:34:26.566Z,1667932466.566 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-11-08T18:34:30.312Z,1667932470.312 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T18:34:30.312Z,1667932470.312 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T18:34:30.333Z,1667932470.333 [MissionManager](INFO): DefineArg multiray_lab.MissionTimeout = 1.000000 min 2022-11-08T18:34:30.357Z,1667932470.357 [MissionManager](INFO): DefineArg multiray_lab.LightDuration = 1.000000 s 2022-11-08T18:34:30.360Z,1667932470.360 [MissionManager](INFO): DefineArg multiray_lab.LightMode0 = 0.000000 count 2022-11-08T18:34:30.361Z,1667932470.361 [MissionManager](INFO): DefineArg multiray_lab.LightMode1 = 1.000000 count 2022-11-08T18:34:30.364Z,1667932470.364 [MissionManager](INFO): DefineArg multiray_lab.LightMode2 = 2.000000 count 2022-11-08T18:34:30.368Z,1667932470.368 [MissionManager](DEBUG): This mission is designed to run in the lab only. Turns on and off MultiRay lights. How long to let the mission run. 1 How long to wait before turning on / off lights, default 1 second 1 Light mode = 0 0 Light mode = 1 1 Light mode = 2 2 2022-11-08T18:34:30.370Z,1667932470.370 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T18:34:30.507Z,1667932470.507 [Default] Stopped 2022-11-08T18:34:30.507Z,1667932470.507 [Default](DEBUG): Aggregate::uninitialize Default 2022-11-08T18:34:30.507Z,1667932470.507 [Default:A.Wait] Stopped 2022-11-08T18:34:30.507Z,1667932470.507 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-11-08T18:34:30.507Z,1667932470.507 [Default:B.GoToSurface] Stopped 2022-11-08T18:34:30.507Z,1667932470.507 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-11-08T18:34:30.507Z,1667932470.507 [MissionManager](IMPORTANT): Started mission multiray_lab 2022-11-08T18:34:30.508Z,1667932470.508 [multiray_lab] Running Loop=1 2022-11-08T18:34:30.508Z,1667932470.508 [multiray_lab](DEBUG): Aggregate::initialize multiray_lab 2022-11-08T18:34:31.703Z,1667932471.703 [multiray_lab](INFO): Timed out from 2022-11-08T18:34:30.5Z 2022-11-08T18:34:31.703Z,1667932471.703 [multiray_lab:A_Timeout] Running Loop=1 2022-11-08T18:34:31.703Z,1667932471.703 [multiray_lab:A_Timeout](DEBUG): Aggregate::initialize multiray_lab:A_Timeout 2022-11-08T18:34:31.704Z,1667932471.704 [multiray_lab:A_Timeout:A] Running Loop=1 2022-11-08T18:34:31.704Z,1667932471.704 [multiray_lab:A_Timeout:A] Stopped 2022-11-08T18:34:31.704Z,1667932471.704 [multiray_lab:A_Timeout](INFO): Completed multiray_lab:A_Timeout 2022-11-08T18:34:31.704Z,1667932471.704 [MissionManager](INFO): multiray_lab is completed. 2022-11-08T18:34:31.704Z,1667932471.704 [MissionManager](INFO): Uninitializing Mission multiray_lab 2022-11-08T18:34:31.704Z,1667932471.704 [multiray_lab] Stopped 2022-11-08T18:34:31.705Z,1667932471.705 [multiray_lab](DEBUG): Aggregate::uninitialize multiray_lab 2022-11-08T18:34:32.168Z,1667932472.168 [MultiRay](INFO): Red lights on 2022-11-08T18:34:32.205Z,1667932472.205 [MissionManager](IMPORTANT): Started mission Default 2022-11-08T18:34:32.205Z,1667932472.205 [Default] Running Loop=1 2022-11-08T18:34:32.205Z,1667932472.205 [Default](DEBUG): Aggregate::initialize Default 2022-11-08T18:34:32.206Z,1667932472.206 [Default:B.GoToSurface] Running Loop=1 2022-11-08T18:34:32.206Z,1667932472.206 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-11-08T18:34:32.206Z,1667932472.206 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-11-08T18:34:32.206Z,1667932472.206 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-11-08T18:34:32.207Z,1667932472.207 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-11-08T18:34:32.207Z,1667932472.207 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-11-08T18:34:32.207Z,1667932472.207 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-11-08T18:34:32.208Z,1667932472.208 [Default:A.Wait] Running Loop=1 2022-11-08T18:34:32.208Z,1667932472.208 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-11-08T18:34:37.195Z,1667932477.195 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/multiray_mode0.xml 2022-11-08T18:34:37.196Z,1667932477.196 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/multiray_mode0.xml 2022-11-08T18:34:37.234Z,1667932477.234 [MissionManager](INFO): DefineArg multiray_lab.MissionTimeout = 1.000000 min 2022-11-08T18:34:37.236Z,1667932477.236 [MissionManager](INFO): DefineArg multiray_lab.LightDuration = 1.000000 s 2022-11-08T18:34:37.238Z,1667932477.238 [MissionManager](INFO): DefineArg multiray_lab.LightMode0 = 0.000000 count 2022-11-08T18:34:37.241Z,1667932477.241 [MissionManager](INFO): DefineArg multiray_lab.LightMode1 = 1.000000 count 2022-11-08T18:34:37.243Z,1667932477.243 [MissionManager](INFO): DefineArg multiray_lab.LightMode2 = 2.000000 count 2022-11-08T18:34:37.247Z,1667932477.247 [MissionManager](DEBUG): This mission is designed to run in the lab only. Turns on and off MultiRay lights. How long to let the mission run. 1 How long to wait before turning on / off lights, default 1 second 1 Light mode = 0 0 Light mode = 1 1 Light mode = 2 2 2022-11-08T18:34:37.249Z,1667932477.249 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/multiray_mode0.xml 2022-11-08T18:34:37.368Z,1667932477.368 [Default] Stopped 2022-11-08T18:34:37.368Z,1667932477.368 [Default](DEBUG): Aggregate::uninitialize Default 2022-11-08T18:34:37.368Z,1667932477.368 [Default:A.Wait] Stopped 2022-11-08T18:34:37.368Z,1667932477.368 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-11-08T18:34:37.368Z,1667932477.368 [Default:B.GoToSurface] Stopped 2022-11-08T18:34:37.369Z,1667932477.369 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-11-08T18:34:37.369Z,1667932477.369 [MissionManager](IMPORTANT): Started mission multiray_lab 2022-11-08T18:34:37.369Z,1667932477.369 [multiray_lab] Running Loop=1 2022-11-08T18:34:37.369Z,1667932477.369 [multiray_lab](DEBUG): Aggregate::initialize multiray_lab 2022-11-08T18:34:38.561Z,1667932478.561 [multiray_lab](INFO): Timed out from 2022-11-08T18:34:37.4Z 2022-11-08T18:34:38.561Z,1667932478.561 [multiray_lab:A_Timeout] Running Loop=1 2022-11-08T18:34:38.561Z,1667932478.561 [multiray_lab:A_Timeout](DEBUG): Aggregate::initialize multiray_lab:A_Timeout 2022-11-08T18:34:38.562Z,1667932478.562 [multiray_lab:A_Timeout:A] Running Loop=1 2022-11-08T18:34:38.562Z,1667932478.562 [multiray_lab:A_Timeout:A] Stopped 2022-11-08T18:34:38.562Z,1667932478.562 [multiray_lab:A_Timeout](INFO): Completed multiray_lab:A_Timeout 2022-11-08T18:34:38.563Z,1667932478.563 [MissionManager](INFO): multiray_lab is completed. 2022-11-08T18:34:38.563Z,1667932478.563 [MissionManager](INFO): Uninitializing Mission multiray_lab 2022-11-08T18:34:38.563Z,1667932478.563 [multiray_lab] Stopped 2022-11-08T18:34:38.563Z,1667932478.563 [multiray_lab](DEBUG): Aggregate::uninitialize multiray_lab 2022-11-08T18:34:39.027Z,1667932479.027 [MultiRay](IMPORTANT): All lights off 2022-11-08T18:34:39.055Z,1667932479.055 [MissionManager](IMPORTANT): Started mission Default 2022-11-08T18:34:39.055Z,1667932479.055 [Default] Running Loop=1 2022-11-08T18:34:39.055Z,1667932479.055 [Default](DEBUG): Aggregate::initialize Default 2022-11-08T18:34:39.056Z,1667932479.056 [Default:B.GoToSurface] Running Loop=1 2022-11-08T18:34:39.056Z,1667932479.056 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-11-08T18:34:39.056Z,1667932479.056 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-11-08T18:34:39.056Z,1667932479.056 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-11-08T18:34:39.056Z,1667932479.056 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-11-08T18:34:39.057Z,1667932479.057 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-11-08T18:34:39.057Z,1667932479.057 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-11-08T18:34:39.057Z,1667932479.057 [Default:A.Wait] Running Loop=1 2022-11-08T18:34:39.058Z,1667932479.058 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-11-08T18:34:44.717Z,1667932484.717 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T18:34:44.717Z,1667932484.717 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T18:34:44.735Z,1667932484.735 [MissionManager](INFO): DefineArg multiray_lab.MissionTimeout = 1.000000 min 2022-11-08T18:34:44.737Z,1667932484.737 [MissionManager](INFO): DefineArg multiray_lab.LightDuration = 1.000000 s 2022-11-08T18:34:44.739Z,1667932484.739 [MissionManager](INFO): DefineArg multiray_lab.LightMode0 = 0.000000 count 2022-11-08T18:34:44.741Z,1667932484.741 [MissionManager](INFO): DefineArg multiray_lab.LightMode1 = 1.000000 count 2022-11-08T18:34:44.743Z,1667932484.743 [MissionManager](INFO): DefineArg multiray_lab.LightMode2 = 2.000000 count 2022-11-08T18:34:44.748Z,1667932484.748 [MissionManager](DEBUG): This mission is designed to run in the lab only. Turns on and off MultiRay lights. How long to let the mission run. 1 How long to wait before turning on / off lights, default 1 second 1 Light mode = 0 0 Light mode = 1 1 Light mode = 2 2 2022-11-08T18:34:44.749Z,1667932484.749 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/multiray_mode1.xml 2022-11-08T18:34:45.028Z,1667932485.028 [Default] Stopped 2022-11-08T18:34:45.028Z,1667932485.028 [Default](DEBUG): Aggregate::uninitialize Default 2022-11-08T18:34:45.028Z,1667932485.028 [Default:A.Wait] Stopped 2022-11-08T18:34:45.028Z,1667932485.028 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-11-08T18:34:45.028Z,1667932485.028 [Default:B.GoToSurface] Stopped 2022-11-08T18:34:45.028Z,1667932485.028 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-11-08T18:34:45.028Z,1667932485.028 [MissionManager](IMPORTANT): Started mission multiray_lab 2022-11-08T18:34:45.029Z,1667932485.029 [multiray_lab] Running Loop=1 2022-11-08T18:34:45.029Z,1667932485.029 [multiray_lab](DEBUG): Aggregate::initialize multiray_lab 2022-11-08T18:34:46.261Z,1667932486.261 [multiray_lab](INFO): Timed out from 2022-11-08T18:34:45.0Z 2022-11-08T18:34:46.261Z,1667932486.261 [multiray_lab:A_Timeout] Running Loop=1 2022-11-08T18:34:46.261Z,1667932486.261 [multiray_lab:A_Timeout](DEBUG): Aggregate::initialize multiray_lab:A_Timeout 2022-11-08T18:34:46.262Z,1667932486.262 [multiray_lab:A_Timeout:A] Running Loop=1 2022-11-08T18:34:46.263Z,1667932486.263 [multiray_lab:A_Timeout:A] Stopped 2022-11-08T18:34:46.263Z,1667932486.263 [multiray_lab:A_Timeout](INFO): Completed multiray_lab:A_Timeout 2022-11-08T18:34:46.263Z,1667932486.263 [MissionManager](INFO): multiray_lab is completed. 2022-11-08T18:34:46.263Z,1667932486.263 [MissionManager](INFO): Uninitializing Mission multiray_lab 2022-11-08T18:34:46.263Z,1667932486.263 [multiray_lab] Stopped 2022-11-08T18:34:46.263Z,1667932486.263 [multiray_lab](DEBUG): Aggregate::uninitialize multiray_lab 2022-11-08T18:34:46.795Z,1667932486.795 [MissionManager](IMPORTANT): Started mission Default 2022-11-08T18:34:46.796Z,1667932486.796 [Default] Running Loop=1 2022-11-08T18:34:46.796Z,1667932486.796 [Default](DEBUG): Aggregate::initialize Default 2022-11-08T18:34:46.797Z,1667932486.797 [Default:B.GoToSurface] Running Loop=1 2022-11-08T18:34:46.797Z,1667932486.797 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-11-08T18:34:46.799Z,1667932486.799 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-11-08T18:34:46.800Z,1667932486.800 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-11-08T18:34:46.826Z,1667932486.826 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-11-08T18:34:46.827Z,1667932486.827 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-11-08T18:34:46.827Z,1667932486.827 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-11-08T18:34:46.827Z,1667932486.827 [Default:A.Wait] Running Loop=1 2022-11-08T18:34:46.827Z,1667932486.827 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-11-08T18:34:51.920Z,1667932491.920 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/multiray_mode0.xml 2022-11-08T18:34:51.920Z,1667932491.920 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/multiray_mode0.xml 2022-11-08T18:34:51.994Z,1667932491.994 [MissionManager](INFO): DefineArg multiray_lab.MissionTimeout = 1.000000 min 2022-11-08T18:34:51.996Z,1667932491.996 [MissionManager](INFO): DefineArg multiray_lab.LightDuration = 1.000000 s 2022-11-08T18:34:51.998Z,1667932491.998 [MissionManager](INFO): DefineArg multiray_lab.LightMode0 = 0.000000 count 2022-11-08T18:34:52.000Z,1667932492.000 [MissionManager](INFO): DefineArg multiray_lab.LightMode1 = 1.000000 count 2022-11-08T18:34:52.003Z,1667932492.003 [MissionManager](INFO): DefineArg multiray_lab.LightMode2 = 2.000000 count 2022-11-08T18:34:52.024Z,1667932492.024 [MissionManager](DEBUG): This mission is designed to run in the lab only. Turns on and off MultiRay lights. How long to let the mission run. 1 How long to wait before turning on / off lights, default 1 second 1 Light mode = 0 0 Light mode = 1 1 Light mode = 2 2 2022-11-08T18:34:52.026Z,1667932492.026 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/multiray_mode0.xml 2022-11-08T18:34:52.336Z,1667932492.336 [Default] Stopped 2022-11-08T18:34:52.336Z,1667932492.336 [Default](DEBUG): Aggregate::uninitialize Default 2022-11-08T18:34:52.336Z,1667932492.336 [Default:A.Wait] Stopped 2022-11-08T18:34:52.336Z,1667932492.336 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-11-08T18:34:52.336Z,1667932492.336 [Default:B.GoToSurface] Stopped 2022-11-08T18:34:52.336Z,1667932492.336 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-11-08T18:34:52.336Z,1667932492.336 [MissionManager](IMPORTANT): Started mission multiray_lab 2022-11-08T18:34:52.337Z,1667932492.337 [multiray_lab] Running Loop=1 2022-11-08T18:34:52.337Z,1667932492.337 [multiray_lab](DEBUG): Aggregate::initialize multiray_lab 2022-11-08T18:34:53.505Z,1667932493.505 [multiray_lab](INFO): Timed out from 2022-11-08T18:34:52.3Z 2022-11-08T18:34:53.506Z,1667932493.506 [multiray_lab:A_Timeout] Running Loop=1 2022-11-08T18:34:53.506Z,1667932493.506 [multiray_lab:A_Timeout](DEBUG): Aggregate::initialize multiray_lab:A_Timeout 2022-11-08T18:34:53.506Z,1667932493.506 [multiray_lab:A_Timeout:A] Running Loop=1 2022-11-08T18:34:53.507Z,1667932493.507 [multiray_lab:A_Timeout:A] Stopped 2022-11-08T18:34:53.507Z,1667932493.507 [multiray_lab:A_Timeout](INFO): Completed multiray_lab:A_Timeout 2022-11-08T18:34:53.507Z,1667932493.507 [MissionManager](INFO): multiray_lab is completed. 2022-11-08T18:34:53.507Z,1667932493.507 [MissionManager](INFO): Uninitializing Mission multiray_lab 2022-11-08T18:34:53.507Z,1667932493.507 [multiray_lab] Stopped 2022-11-08T18:34:53.507Z,1667932493.507 [multiray_lab](DEBUG): Aggregate::uninitialize multiray_lab 2022-11-08T18:34:53.987Z,1667932493.987 [MultiRay](IMPORTANT): All lights off 2022-11-08T18:34:54.003Z,1667932494.003 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2022-11-08T18:34:54.003Z,1667932494.003 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2022-11-08T18:34:54.004Z,1667932494.004 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3 2022-11-08T18:34:54.004Z,1667932494.004 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2022-11-08T18:34:54.006Z,1667932494.006 [MissionManager](IMPORTANT): Started mission Default 2022-11-08T18:34:54.006Z,1667932494.006 [Default] Running Loop=1 2022-11-08T18:34:54.006Z,1667932494.006 [Default](DEBUG): Aggregate::initialize Default 2022-11-08T18:34:54.006Z,1667932494.006 [Default:B.GoToSurface] Running Loop=1 2022-11-08T18:34:54.006Z,1667932494.006 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-11-08T18:34:54.007Z,1667932494.007 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-11-08T18:34:54.007Z,1667932494.007 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-11-08T18:34:54.007Z,1667932494.007 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-11-08T18:34:54.008Z,1667932494.008 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-11-08T18:34:54.008Z,1667932494.008 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-11-08T18:34:54.008Z,1667932494.008 [Default:A.Wait] Running Loop=1 2022-11-08T18:34:54.008Z,1667932494.008 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-11-08T18:34:54.018Z,1667932494.018 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2022-11-08T18:34:54.019Z,1667932494.019 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2022-11-08T18:34:54.585Z,1667932494.585 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2022-11-08T18:34:54.585Z,1667932494.585 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2022-11-08T18:34:54.586Z,1667932494.586 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2022-11-08T18:34:54.586Z,1667932494.586 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3 2022-11-08T18:34:54.759Z,1667932494.759 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2022-11-08T18:34:56.848Z,1667932496.848 [CommandLine](INFO): End of History 2022-11-08T18:34:57.226Z,1667932497.226 [CommandLine](INFO): End of History 2022-11-08T18:34:57.647Z,1667932497.647 [CommandLine](INFO): End of History 2022-11-08T18:34:58.128Z,1667932498.128 [CommandLine](INFO): End of History 2022-11-08T18:35:01.734Z,1667932501.734 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/multiray_mode2.xml 2022-11-08T18:35:01.735Z,1667932501.735 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/multiray_mode2.xml 2022-11-08T18:35:01.769Z,1667932501.769 [MissionManager](INFO): DefineArg multiray_lab.MissionTimeout = 1.000000 min 2022-11-08T18:35:01.772Z,1667932501.772 [MissionManager](INFO): DefineArg multiray_lab.LightDuration = 1.000000 s 2022-11-08T18:35:01.773Z,1667932501.773 [MissionManager](INFO): DefineArg multiray_lab.LightMode0 = 0.000000 count 2022-11-08T18:35:01.776Z,1667932501.776 [MissionManager](INFO): DefineArg multiray_lab.LightMode1 = 1.000000 count 2022-11-08T18:35:01.778Z,1667932501.778 [MissionManager](INFO): DefineArg multiray_lab.LightMode2 = 2.000000 count 2022-11-08T18:35:01.782Z,1667932501.782 [MissionManager](DEBUG): This mission is designed to run in the lab only. Turns on and off MultiRay lights. How long to let the mission run. 1 How long to wait before turning on / off lights, default 1 second 1 Light mode = 0 0 Light mode = 1 1 Light mode = 2 2 2022-11-08T18:35:01.784Z,1667932501.784 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/multiray_mode2.xml 2022-11-08T18:35:02.024Z,1667932502.024 [Default] Stopped 2022-11-08T18:35:02.024Z,1667932502.024 [Default](DEBUG): Aggregate::uninitialize Default 2022-11-08T18:35:02.024Z,1667932502.024 [Default:A.Wait] Stopped 2022-11-08T18:35:02.024Z,1667932502.024 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-11-08T18:35:02.025Z,1667932502.025 [Default:B.GoToSurface] Stopped 2022-11-08T18:35:02.025Z,1667932502.025 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-11-08T18:35:02.025Z,1667932502.025 [MissionManager](IMPORTANT): Started mission multiray_lab 2022-11-08T18:35:02.025Z,1667932502.025 [multiray_lab] Running Loop=1 2022-11-08T18:35:02.025Z,1667932502.025 [multiray_lab](DEBUG): Aggregate::initialize multiray_lab 2022-11-08T18:35:03.207Z,1667932503.207 [multiray_lab](INFO): Timed out from 2022-11-08T18:35:02.0Z 2022-11-08T18:35:03.207Z,1667932503.207 [multiray_lab:A_Timeout] Running Loop=1 2022-11-08T18:35:03.207Z,1667932503.207 [multiray_lab:A_Timeout](DEBUG): Aggregate::initialize multiray_lab:A_Timeout 2022-11-08T18:35:03.208Z,1667932503.208 [multiray_lab:A_Timeout:A] Running Loop=1 2022-11-08T18:35:03.208Z,1667932503.208 [multiray_lab:A_Timeout:A] Stopped 2022-11-08T18:35:03.208Z,1667932503.208 [multiray_lab:A_Timeout](INFO): Completed multiray_lab:A_Timeout 2022-11-08T18:35:03.208Z,1667932503.208 [MissionManager](INFO): multiray_lab is completed. 2022-11-08T18:35:03.209Z,1667932503.209 [MissionManager](INFO): Uninitializing Mission multiray_lab 2022-11-08T18:35:03.209Z,1667932503.209 [multiray_lab] Stopped 2022-11-08T18:35:03.209Z,1667932503.209 [multiray_lab](DEBUG): Aggregate::uninitialize multiray_lab 2022-11-08T18:35:03.781Z,1667932503.781 [MissionManager](IMPORTANT): Started mission Default 2022-11-08T18:35:03.781Z,1667932503.781 [Default] Running Loop=1 2022-11-08T18:35:03.781Z,1667932503.781 [Default](DEBUG): Aggregate::initialize Default 2022-11-08T18:35:03.781Z,1667932503.781 [Default:B.GoToSurface] Running Loop=1 2022-11-08T18:35:03.781Z,1667932503.781 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-11-08T18:35:03.781Z,1667932503.781 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-11-08T18:35:03.782Z,1667932503.782 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-11-08T18:35:03.783Z,1667932503.783 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-11-08T18:35:03.783Z,1667932503.783 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-11-08T18:35:03.783Z,1667932503.783 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-11-08T18:35:03.784Z,1667932503.784 [Default:A.Wait] Running Loop=1 2022-11-08T18:35:03.784Z,1667932503.784 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-11-08T18:35:16.977Z,1667932516.977 [Default:A.Wait](INFO): Done Waiting. 2022-11-08T18:35:16.977Z,1667932516.977 [Default:A.Wait] Stopped 2022-11-08T18:35:16.977Z,1667932516.977 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-11-08T18:35:17.381Z,1667932517.381 [Default:CheckIn] Running Loop=1 2022-11-08T18:35:17.381Z,1667932517.381 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-08T18:35:17.381Z,1667932517.381 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-08T18:36:32.885Z,1667932592.885 [NAL9602](FAULT): GPS failed to acquire within timeout. 2022-11-08T18:36:32.885Z,1667932592.885 [NAL9602] Data Fault, FailCount= 1 2022-11-08T18:36:32.885Z,1667932592.885 [NAL9602](ERROR): Data Fault 2022-11-08T18:36:32.930Z,1667932592.930 [CBIT](ERROR): Data Fault in component: NAL9602 2022-11-08T18:36:33.284Z,1667932593.284 [NAL9602](INFO): Powering down 2022-11-08T18:36:34.123Z,1667932594.123 [CBIT](INFO): Clearing failed state for component NAL9602 2022-11-08T18:36:34.123Z,1667932594.123 [NAL9602] No Fault, FailCount= 1 2022-11-08T18:37:03.588Z,1667932623.588 [NAL9602](INFO): Powering up NAL9602 2022-11-08T18:37:14.496Z,1667932634.496 [NAL9602](INFO): NAL9602 initialized 2022-11-08T18:37:54.916Z,1667932674.916 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2022-11-08T18:37:54.916Z,1667932674.916 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2022-11-08T18:37:54.917Z,1667932674.917 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 4 2022-11-08T18:37:54.917Z,1667932674.917 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2022-11-08T18:37:54.928Z,1667932674.928 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2022-11-08T18:37:54.928Z,1667932674.928 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2022-11-08T18:37:55.331Z,1667932675.331 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2022-11-08T18:37:55.331Z,1667932675.331 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2022-11-08T18:37:55.332Z,1667932675.332 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2022-11-08T18:37:55.332Z,1667932675.332 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 4 2022-11-08T18:37:55.713Z,1667932675.713 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2022-11-08T18:37:59.599Z,1667932679.599 [CommandExec](IMPORTANT): got command restart system 2022-11-08T18:38:01.682Z,1667932681.682 [Supervisor](INFO): Stop Mission called by Supervisor::terminate 2022-11-08T18:38:01.683Z,1667932681.683 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-08T18:38:01.683Z,1667932681.683 [CommandExec](INFO): Uninitializing the command executive. 2022-11-08T18:38:01.683Z,1667932681.683 [CommandExec](INFO): Uninitializing the command scheduler. 2022-11-08T18:38:01.683Z,1667932681.683 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-11-08T18:38:01.878Z,1667932681.878 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2022-11-08T18:38:01.879Z,1667932681.879 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2022-11-08T18:38:01.879Z,1667932681.879 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-11-08T18:38:01.879Z,1667932681.879 [NavChartDb](INFO): Join timeout helper Thread ID is 988 2022-11-08T18:38:02.075Z,1667932682.075 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-08T18:38:02.075Z,1667932682.075 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-11-08T18:38:02.082Z,1667932682.082 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler 2022-11-08T18:38:02.082Z,1667932682.082 [DAT ThreadHandler](INFO): Thread cancelled. 2022-11-08T18:38:02.083Z,1667932682.083 [DAT](INFO