2000-02-23T20:21:35.500Z,951337295.500 [Supervisor](DEBUG): Initializing supervisor. 2000-02-23T20:21:35.504Z,951337295.504 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2000-02-23T20:21:35.505Z,951337295.505 [SyncHandler](INFO): Protected caller Thread ID is 835 2000-02-23T20:21:35.505Z,951337295.505 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2000-02-23T20:21:35.506Z,951337295.506 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2000-02-23T20:21:35.507Z,951337295.507 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 836 2000-02-23T20:21:35.510Z,951337295.510 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2000-02-23T20:21:35.528Z,951337295.528 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2000-02-23T20:21:35.529Z,951337295.529 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2000-02-23T20:21:35.529Z,951337295.529 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 837 2000-02-23T20:21:35.533Z,951337295.533 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2000-02-23T20:21:35.534Z,951337295.534 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2000-02-23T20:21:35.535Z,951337295.535 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 838 2000-02-23T20:21:35.537Z,951337295.537 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2000-02-23T20:21:35.538Z,951337295.538 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2000-02-23T20:21:35.538Z,951337295.538 [logger ThreadHandler](INFO): Protected caller Thread ID is 839 2000-02-23T20:21:35.541Z,951337295.541 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2000-02-23T20:21:35.542Z,951337295.542 [Supervisor](INFO): Looking for Config files in directory: Config/ 2000-02-23T20:21:35.546Z,951337295.546 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2000-02-23T20:21:35.892Z,951337295.892 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2000-02-23T20:21:35.894Z,951337295.894 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2000-02-23T20:21:36.683Z,951337296.683 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2000-02-23T20:21:36.685Z,951337296.685 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2000-02-23T20:21:36.806Z,951337296.806 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2000-02-23T20:21:36.808Z,951337296.808 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2000-02-23T20:21:37.376Z,951337297.376 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2000-02-23T20:21:37.377Z,951337297.377 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2000-02-23T20:21:37.486Z,951337297.486 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2000-02-23T20:21:37.487Z,951337297.487 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2000-02-23T20:21:37.581Z,951337297.581 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2000-02-23T20:21:38.013Z,951337298.013 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2000-02-23T20:21:38.014Z,951337298.014 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2000-02-23T20:21:38.253Z,951337298.253 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2000-02-23T20:21:38.255Z,951337298.255 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2000-02-23T20:21:38.428Z,951337298.428 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2000-02-23T20:21:38.442Z,951337298.442 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2000-02-23T20:21:39.268Z,951337299.268 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2000-02-23T20:21:39.269Z,951337299.269 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2000-02-23T20:21:39.879Z,951337299.879 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2000-02-23T20:21:39.880Z,951337299.880 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2000-02-23T20:21:40.283Z,951337300.283 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2000-02-23T20:21:40.284Z,951337300.284 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2000-02-23T20:21:40.378Z,951337300.378 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2000-02-23T20:21:40.587Z,951337300.587 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2000-02-23T20:21:40.589Z,951337300.589 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2000-02-23T20:21:40.836Z,951337300.836 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2000-02-23T20:21:40.838Z,951337300.838 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2000-02-23T20:21:41.152Z,951337301.152 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2000-02-23T20:21:41.154Z,951337301.154 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-brizo/ 2000-02-23T20:21:41.158Z,951337301.158 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Control.cfg 2000-02-23T20:21:41.279Z,951337301.279 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Sensor.cfg 2000-02-23T20:21:41.443Z,951337301.443 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Simulator.cfg 2000-02-23T20:21:41.541Z,951337301.541 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/secure.cfg 2000-02-23T20:21:41.637Z,951337301.637 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Servo.cfg 2000-02-23T20:21:41.757Z,951337301.757 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/workSite.cfg 2000-02-23T20:21:41.853Z,951337301.853 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/vehicle.cfg 2000-02-23T20:21:41.971Z,951337301.971 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Battery.cfg 2000-02-23T20:21:42.246Z,951337302.246 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2000-02-23T20:21:42.247Z,951337302.247 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Science.cfg 2000-02-23T20:21:42.393Z,951337302.393 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/logger.cfg 2000-02-23T20:21:42.498Z,951337302.498 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/BIT.cfg 2000-02-23T20:21:42.603Z,951337302.603 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Navigation.cfg 2000-02-23T20:21:42.710Z,951337302.710 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg 2000-02-23T20:21:42.724Z,951337302.724 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2000-02-23T20:21:42.864Z,951337302.864 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2000-02-23T20:21:42.865Z,951337302.865 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2000-02-23T20:21:42.880Z,951337302.880 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2000-02-23T20:21:42.882Z,951337302.882 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2000-02-23T20:21:42.951Z,951337302.951 [DepthRateCalculator] Loaded 2000-02-23T20:21:42.951Z,951337302.951 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2000-02-23T20:21:42.957Z,951337302.957 [PitchRateCalculator] Loaded 2000-02-23T20:21:42.957Z,951337302.957 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2000-02-23T20:21:42.967Z,951337302.967 [SpeedCalculator] Loaded 2000-02-23T20:21:42.967Z,951337302.967 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2000-02-23T20:21:42.972Z,951337302.972 [YawRateCalculator] Loaded 2000-02-23T20:21:42.972Z,951337302.972 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2000-02-23T20:21:42.993Z,951337302.993 [ElevatorOffsetCalculator] Loaded 2000-02-23T20:21:42.994Z,951337302.994 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2000-02-23T20:21:42.994Z,951337302.994 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2000-02-23T20:21:42.995Z,951337302.995 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2000-02-23T20:21:43.063Z,951337303.063 [VerticalControl](DEBUG): Construct VerticalControl. 2000-02-23T20:21:43.119Z,951337303.119 [VerticalControl] Loaded 2000-02-23T20:21:43.119Z,951337303.119 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2000-02-23T20:21:43.122Z,951337303.122 [HorizontalControl](DEBUG): Construct HorizontalControl. 2000-02-23T20:21:43.168Z,951337303.168 [HorizontalControl] Loaded 2000-02-23T20:21:43.168Z,951337303.168 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2000-02-23T20:21:43.171Z,951337303.171 [SpeedControl](DEBUG): Construct SpeedControl. 2000-02-23T20:21:43.173Z,951337303.173 [SpeedControl] Loaded 2000-02-23T20:21:43.174Z,951337303.174 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2000-02-23T20:21:43.176Z,951337303.176 [LoopControl](DEBUG): Construct LoopControl. 2000-02-23T20:21:43.177Z,951337303.177 [LoopControl] Loaded 2000-02-23T20:21:43.177Z,951337303.177 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2000-02-23T20:21:43.177Z,951337303.177 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2000-02-23T20:21:43.178Z,951337303.178 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2000-02-23T20:21:43.313Z,951337303.313 [DeadReckonUsingMultipleVelocitySources] Loaded 2000-02-23T20:21:43.313Z,951337303.313 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2000-02-23T20:21:43.327Z,951337303.327 [NavChart] Loaded 2000-02-23T20:21:43.328Z,951337303.328 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2000-02-23T20:21:43.333Z,951337303.333 [UniversalFixResidualReporter] Loaded 2000-02-23T20:21:43.333Z,951337303.333 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2000-02-23T20:21:43.334Z,951337303.334 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2000-02-23T20:21:43.334Z,951337303.334 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2000-02-23T20:21:43.542Z,951337303.542 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2000-02-23T20:21:43.543Z,951337303.543 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2000-02-23T20:21:44.844Z,951337304.844 [AHRS_M2] Loaded 2000-02-23T20:21:44.844Z,951337304.844 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2000-02-23T20:21:45.098Z,951337305.098 [BackseatComponent] Loaded 2000-02-23T20:21:45.098Z,951337305.098 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2000-02-23T20:21:45.099Z,951337305.099 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 409384E0 2000-02-23T20:21:45.100Z,951337305.100 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 924 2000-02-23T20:21:45.103Z,951337305.103 [LcmUniversalReporter] Loaded 2000-02-23T20:21:45.103Z,951337305.103 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2000-02-23T20:21:45.929Z,951337305.929 [BPC1] Loaded 2000-02-23T20:21:45.929Z,951337305.929 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2000-02-23T20:21:46.015Z,951337306.015 [DATMMP] Loaded 2000-02-23T20:21:46.016Z,951337306.016 [ComponentRegistry](DEBUG): Component "DATMMP" handled in its own thread. 2000-02-23T20:21:46.017Z,951337306.017 [DATMMP ThreadHandler](DEBUG): Created PCaller Thread at 409694E0 2000-02-23T20:21:46.017Z,951337306.017 [DATMMP ThreadHandler](INFO): Protected caller Thread ID is 925 2000-02-23T20:21:46.161Z,951337306.161 [DataOverHttps] Loaded 2000-02-23T20:21:46.162Z,951337306.162 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2000-02-23T20:21:46.163Z,951337306.163 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409994E0 2000-02-23T20:21:46.163Z,951337306.163 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 926 2000-02-23T20:21:46.186Z,951337306.186 [Depth_Keller] Loaded 2000-02-23T20:21:46.186Z,951337306.186 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2000-02-23T20:21:46.226Z,951337306.226 [DVL_micro] Loaded 2000-02-23T20:21:46.226Z,951337306.226 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2000-02-23T20:21:46.289Z,951337306.289 [NAL9602] Loaded 2000-02-23T20:21:46.289Z,951337306.289 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2000-02-23T20:21:46.320Z,951337306.320 [Onboard] Loaded 2000-02-23T20:21:46.320Z,951337306.320 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2000-02-23T20:21:46.321Z,951337306.321 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409C94E0 2000-02-23T20:21:46.322Z,951337306.322 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 927 2000-02-23T20:21:46.336Z,951337306.336 [Power24vConverter] Loaded 2000-02-23T20:21:46.336Z,951337306.336 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2000-02-23T20:21:46.351Z,951337306.351 [Radio_Surface] Loaded 2000-02-23T20:21:46.351Z,951337306.351 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2000-02-23T20:21:46.352Z,951337306.352 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409F94E0 2000-02-23T20:21:46.352Z,951337306.352 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 928 2000-02-23T20:21:46.368Z,951337306.368 [Sonardyne_Nano] Loaded 2000-02-23T20:21:46.368Z,951337306.368 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread. 2000-02-23T20:21:46.368Z,951337306.368 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2000-02-23T20:21:46.369Z,951337306.369 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2000-02-23T20:21:46.528Z,951337306.528 [BuoyancyServo] Loaded 2000-02-23T20:21:46.528Z,951337306.528 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2000-02-23T20:21:46.551Z,951337306.551 [ElevatorServo] Loaded 2000-02-23T20:21:46.551Z,951337306.551 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2000-02-23T20:21:46.573Z,951337306.573 [MassServo] Loaded 2000-02-23T20:21:46.573Z,951337306.573 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2000-02-23T20:21:46.594Z,951337306.594 [RudderServo] Loaded 2000-02-23T20:21:46.594Z,951337306.594 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2000-02-23T20:21:46.610Z,951337306.610 [ThrusterHE] Loaded 2000-02-23T20:21:46.610Z,951337306.610 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2000-02-23T20:21:46.611Z,951337306.611 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2000-02-23T20:21:46.611Z,951337306.611 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2000-02-23T20:21:46.707Z,951337306.707 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2000-02-23T20:21:46.708Z,951337306.708 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2000-02-23T20:21:46.750Z,951337306.750 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2000-02-23T20:21:46.751Z,951337306.751 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2000-02-23T20:21:47.139Z,951337307.139 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2000-02-23T20:21:47.140Z,951337307.140 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2000-02-23T20:21:47.363Z,951337307.363 [CTD_Seabird] Loaded 2000-02-23T20:21:47.363Z,951337307.363 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2000-02-23T20:21:47.365Z,951337307.365 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40BB34E0 2000-02-23T20:21:47.365Z,951337307.365 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 929 2000-02-23T20:21:47.401Z,951337307.401 [ESPComponent] Loaded 2000-02-23T20:21:47.401Z,951337307.401 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2000-02-23T20:21:47.423Z,951337307.423 [PAR_Licor] Loaded 2000-02-23T20:21:47.424Z,951337307.424 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2000-02-23T20:21:47.468Z,951337307.468 [WetLabsBB2FL] Loaded 2000-02-23T20:21:47.468Z,951337307.468 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2000-02-23T20:21:47.469Z,951337307.469 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40BE34E0 2000-02-23T20:21:47.469Z,951337307.469 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 930 2000-02-23T20:21:47.470Z,951337307.470 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2000-02-23T20:21:47.471Z,951337307.471 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2000-02-23T20:21:47.637Z,951337307.637 [SBIT](DEBUG): Construct Startup Built In Test. 2000-02-23T20:21:47.646Z,951337307.646 [SBIT] Loaded 2000-02-23T20:21:47.646Z,951337307.646 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2000-02-23T20:21:47.649Z,951337307.649 [IBIT](DEBUG): Construct Initiated Built In Test. 2000-02-23T20:21:47.662Z,951337307.662 [IBIT] Loaded 2000-02-23T20:21:47.662Z,951337307.662 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2000-02-23T20:21:47.668Z,951337307.668 [CBIT](DEBUG): Construct Continuous Built In Test. 2000-02-23T20:21:47.773Z,951337307.773 [CBIT] Loaded 2000-02-23T20:21:47.773Z,951337307.773 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2000-02-23T20:21:47.774Z,951337307.774 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2000-02-23T20:21:47.780Z,951337307.780 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2000-02-23T20:21:47.783Z,951337307.783 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2000-02-23T20:21:47.795Z,951337307.795 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2000-02-23T20:21:47.796Z,951337307.796 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C524E0 2000-02-23T20:21:47.796Z,951337307.796 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 931 2000-02-23T20:21:47.800Z,951337307.800 [Supervisor](INFO): Main Thread ID is 828 2000-02-23T20:21:47.801Z,951337307.801 [Supervisor](DEBUG): Running supervisor. 2000-02-23T20:21:47.801Z,951337307.801 [CommandExec ThreadHandler](INFO): Handler Thread ID is 932 2000-02-23T20:21:47.802Z,951337307.802 [CommandExec](INFO): Initializing the command executive. 2000-02-23T20:21:47.803Z,951337307.803 [CommandLine ThreadHandler](INFO): Handler Thread ID is 933 2000-02-23T20:21:47.805Z,951337307.805 [controlThread ThreadHandler](INFO): Handler Thread ID is 934 2000-02-23T20:21:47.806Z,951337307.806 [controlThread](DEBUG): Initializing ControlThread 2000-02-23T20:21:47.806Z,951337307.806 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2000-02-23T20:21:47.807Z,951337307.807 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2000-02-23T20:21:47.807Z,951337307.807 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2000-02-23T20:21:47.807Z,951337307.807 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2000-02-23T20:21:47.808Z,951337307.808 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2000-02-23T20:21:47.808Z,951337307.808 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2000-02-23T20:21:47.810Z,951337307.810 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2000-02-23T20:21:47.811Z,951337307.811 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2000-02-23T20:21:47.811Z,951337307.811 [LoopControl](DEBUG): Initialize LoopControlComponent. 2000-02-23T20:21:47.812Z,951337307.812 [NavChart](DEBUG): Initialize NavChart Navigation. 2000-02-23T20:21:47.812Z,951337307.812 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2000-02-23T20:21:47.822Z,951337307.822 [SBIT](INFO): Initialize SBIT Component. 2000-02-23T20:21:47.822Z,951337307.822 [SBIT](IMPORTANT): git: 2024-09-04 2000-02-23T20:21:47.822Z,951337307.822 [SBIT](INFO): git hash: c3a48f2091374af655f27818376c2e16c84a5fcd 2000-02-23T20:21:47.823Z,951337307.823 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2000-02-23T20:21:47.824Z,951337307.824 [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 2000-02-23T20:21:47.825Z,951337307.825 [SBIT](INFO): Beginning SBIT in 128.000000 seconds. 2000-02-23T20:21:47.825Z,951337307.825 [IBIT](INFO): Initialize IBIT Component. 2000-02-23T20:21:47.826Z,951337307.826 [CBIT](DEBUG): Initialize CBIT Component. 2000-02-23T20:21:47.827Z,951337307.827 [logger ThreadHandler](INFO): Handler Thread ID is 935 2000-02-23T20:21:47.837Z,951337307.837 [CBIT](DEBUG): Initialized mux pins. 2000-02-23T20:21:47.837Z,951337307.837 [CBIT](DEBUG): Initializing the watchdog timer. 2000-02-23T20:21:47.846Z,951337307.846 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 936 2000-02-23T20:21:47.858Z,951337307.858 [DATMMP ThreadHandler](INFO): Handler Thread ID is 937 2000-02-23T20:21:47.858Z,951337307.858 [DATMMP](INFO): Start 2000-02-23T20:21:47.859Z,951337307.859 [DATMMP](INFO): Powering up 2000-02-23T20:21:47.859Z,951337307.859 [DATMMP](DEBUG): Initializing DATMMP. 2000-02-23T20:21:47.861Z,951337307.861 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2000-02-23T20:21:47.862Z,951337307.862 [CBIT](DEBUG): Initializing heartbeat. 2000-02-23T20:21:47.864Z,951337307.864 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 939 2000-02-23T20:21:47.865Z,951337307.865 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2000-02-23T20:21:47.874Z,951337307.874 [Onboard ThreadHandler](INFO): Handler Thread ID is 940 2000-02-23T20:21:47.904Z,951337307.904 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 941 2000-02-23T20:21:47.914Z,951337307.914 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 942 2000-02-23T20:21:47.914Z,951337307.914 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2000-02-23T20:21:47.919Z,951337307.919 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 944 2000-02-23T20:21:47.922Z,951337307.922 [WetLabsBB2FL](INFO): Powering up 2000-02-23T20:21:47.923Z,951337307.923 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 946 2000-02-23T20:21:47.928Z,951337307.928 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2000-02-23T20:21:47.930Z,951337307.930 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US1WC07M.000 2000-02-23T20:21:47.930Z,951337307.930 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2000-02-23T20:21:47.931Z,951337307.931 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US2WC11M.000 2000-02-23T20:21:47.931Z,951337307.931 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2000-02-23T20:21:47.933Z,951337307.933 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US3CA52M.000 2000-02-23T20:21:47.933Z,951337307.933 [CBIT](DEBUG): Deactivating GF circuits. 2000-02-23T20:21:47.934Z,951337307.934 [CBIT](DEBUG): Deactivating emergency mode. 2000-02-23T20:21:47.934Z,951337307.934 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2000-02-23T20:21:47.935Z,951337307.935 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA50M.000 2000-02-23T20:21:47.938Z,951337307.938 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US5CA50M.000 2000-02-23T20:21:47.973Z,951337307.973 [CBIT](DEBUG): Backplane powered. 2000-02-23T20:21:47.974Z,951337307.974 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2000-02-23T20:21:47.975Z,951337307.975 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl 2000-02-23T20:21:47.975Z,951337307.975 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl 2000-02-23T20:21:47.982Z,951337307.982 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl 2000-02-23T20:21:48.011Z,951337308.011 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into: 2000-02-23T20:21:48.032Z,951337308.032 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2000-02-23T20:21:48.076Z,951337308.076 [MissionManager](DEBUG): # Copyright (c) 2024 MBARI # MBARI Proprietary Information. Confidential. All Rights Reserved # Unauthorized copying or distribution of this file via any medium is strictly # prohibited. # # WARNING - This file contains information whose export is restricted by the # Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as # amended. Violations of these export laws are subject to severe civil and/or # criminal penalties. mission Startup { behavior Guidance:GoToSurface { run in progression } aggregate StartupSatComms { run in sequence readDatum { timeout duration=P1M Universal:latitude_fix } readDatum { timeout duration=P1M Universal:platform_communications } } } 2000-02-23T20:21:48.076Z,951337308.076 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl 2000-02-23T20:21:48.077Z,951337308.077 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl 2000-02-23T20:21:48.080Z,951337308.080 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl 2000-02-23T20:21:48.109Z,951337308.109 [DATMMP](INFO): Starting 2000-02-23T20:21:48.306Z,951337308.306 [Radio_Surface](INFO): Powering up 2000-02-23T20:21:48.334Z,951337308.334 [MissionManager](DEBUG): TethyslAPI: Missions/Default.tl translated into: 0 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2000-02-23T20:21:48.339Z,951337308.339 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2000-02-23T20:21:48.341Z,951337308.341 [Default:A.Wait](DEBUG): Construct Wait. 2000-02-23T20:21:48.343Z,951337308.343 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2000-02-23T20:21:48.361Z,951337308.361 [DATMMP](INFO): Starting 2000-02-23T20:21:48.395Z,951337308.395 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2000-02-23T20:21:48.398Z,951337308.398 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2000-02-23T20:21:48.412Z,951337308.412 [Default:E.Execute](DEBUG): Construct Execute. 2000-02-23T20:21:48.415Z,951337308.415 [MissionManager](DEBUG): # Copyright (c) 2024 MBARI # MBARI Proprietary Information. Confidential. All Rights Reserved # Unauthorized copying or distribution of this file via any medium is strictly # prohibited. # # WARNING - This file contains information whose export is restricted by the # Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as # amended. Violations of these export laws are subject to severe civil and/or # criminal penalties. mission Default { arguments { ElapsedSinceDefaultStarted = 0 minute } behavior Guidance:Wait { """ Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. """ run in sequence set duration = 13 second } behavior Guidance:GoToSurface { run in progression } aggregate CheckIn { run in sequence repeat=288 readDatum id="Read_GPS" { timeout duration=P5M Universal:time_fix } readDatum id="Read_Iridium" { timeout duration=P4H { behavior Guidance:Execute { run in sequence set command = "Burn on" } syslog critical "Dropped weight due to communications timeout." } Universal:platform_communications } behavior Guidance:Wait { run in sequence set duration = 5 minute } assign in sequence ElapsedSinceDefaultStarted = elapsed ( Universal:mission_started ) syslog important "Default mission has been running for " + ElapsedSinceDefaultStarted~minute } syslog important "Restarting logs and Default mission." behavior Guidance:Execute { run in sequence set command = "restart logs" } } 2000-02-23T20:21:48.426Z,951337308.426 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DVL_micro,NAL9602,Power24vConverter,Sonardyne_Nano,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2000-02-23T20:21:48.433Z,951337308.433 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2000-02-23T20:21:48.613Z,951337308.613 [DATMMP](INFO): Starting 2000-02-23T20:21:48.630Z,951337308.630 [Power24vConverter](INFO): Powering up. 2000-02-23T20:21:48.631Z,951337308.631 [Sonardyne_Nano](INFO): Initializing. 2000-02-23T20:21:48.712Z,951337308.712 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2000-02-23T20:21:48.717Z,951337308.717 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2000-02-23T20:21:48.734Z,951337308.734 [ElevatorServo](DEBUG): Initializing EZServoServo. 2000-02-23T20:21:48.742Z,951337308.742 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2000-02-23T20:21:48.743Z,951337308.743 [MassServo](DEBUG): Initializing EZServoServo. 2000-02-23T20:21:48.750Z,951337308.750 [MassServo](DEBUG): Initializing MassServo. 2000-02-23T20:21:48.750Z,951337308.750 [RudderServo](DEBUG): Initializing EZServoServo. 2000-02-23T20:21:48.758Z,951337308.758 [RudderServo](DEBUG): Initializing RudderServo. 2000-02-23T20:21:48.758Z,951337308.758 [ThrusterHE](DEBUG): Initializing EZServoServo. 2000-02-23T20:21:48.766Z,951337308.766 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2000-02-23T20:21:48.866Z,951337308.866 [DATMMP](INFO): Starting 2000-02-23T20:21:49.117Z,951337309.117 [DATMMP](INFO): Starting 2000-02-23T20:21:49.369Z,951337309.369 [DATMMP](INFO): Starting 2000-02-23T20:21:49.621Z,951337309.621 [DATMMP](INFO): Starting 2000-02-23T20:21:49.873Z,951337309.873 [DATMMP](INFO): Starting 2000-02-23T20:21:50.126Z,951337310.126 [DATMMP](INFO): Starting 2000-02-23T20:21:50.378Z,951337310.378 [DATMMP](INFO): Starting 2000-02-23T20:21:50.562Z,951337310.562 [WetLabsBB2FL](INFO): Powering down 2000-02-23T20:21:50.629Z,951337310.629 [DATMMP](INFO): Starting 2000-02-23T20:21:50.864Z,951337310.864 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART 2000-02-23T20:21:50.881Z,951337310.881 [DATMMP](INFO): Starting 2000-02-23T20:21:51.133Z,951337311.133 [DATMMP](INFO): Starting 2000-02-23T20:21:51.387Z,951337311.387 [DATMMP](INFO): Starting 2000-02-23T20:21:51.637Z,951337311.637 [DATMMP](INFO): Starting 2000-02-23T20:21:51.889Z,951337311.889 [DATMMP](INFO): Starting 2000-02-23T20:21:52.118Z,951337312.118 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2207 2000-02-23T20:21:52.141Z,951337312.141 [DATMMP](INFO): Starting 2000-02-23T20:21:52.394Z,951337312.394 [DATMMP](INFO): Starting 2000-02-23T20:21:52.646Z,951337312.646 [DATMMP](INFO): Starting 2000-02-23T20:21:52.901Z,951337312.901 [DATMMP](INFO): Starting 2000-02-23T20:21:53.154Z,951337313.154 [DATMMP](INFO): Starting 2000-02-23T20:21:53.406Z,951337313.406 [DATMMP](INFO): Starting 2000-02-23T20:21:53.657Z,951337313.657 [DATMMP](INFO): Starting 2000-02-23T20:21:53.910Z,951337313.910 [DATMMP](INFO): Starting 2000-02-23T20:21:54.163Z,951337314.163 [DATMMP](INFO): Starting 2000-02-23T20:21:54.194Z,951337314.194 [ThrusterHE](ERROR): Zero Speed Commanded. 2000-02-23T20:21:54.337Z,951337314.337 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US5CA50M.000 2000-02-23T20:21:54.413Z,951337314.413 [DATMMP](INFO): Starting 2000-02-23T20:21:54.666Z,951337314.666 [DATMMP](INFO): Starting 2000-02-23T20:21:54.923Z,951337314.923 [DATMMP](INFO): Starting 2000-02-23T20:21:55.173Z,951337315.173 [DATMMP](INFO): Starting 2000-02-23T20:21:55.425Z,951337315.425 [DATMMP](INFO): Starting 2000-02-23T20:21:55.677Z,951337315.677 [DATMMP](INFO): Starting 2000-02-23T20:21:55.930Z,951337315.930 [DATMMP](INFO): Starting 2000-02-23T20:21:56.182Z,951337316.182 [DATMMP](INFO): Starting 2000-02-23T20:21:56.434Z,951337316.434 [DATMMP](INFO): Starting 2000-02-23T20:21:56.685Z,951337316.685 [DATMMP](INFO): Starting 2000-02-23T20:21:56.938Z,951337316.938 [DATMMP](INFO): Starting 2000-02-23T20:21:57.190Z,951337317.190 [DATMMP](INFO): Starting 2000-02-23T20:21:57.442Z,951337317.442 [DATMMP](INFO): Starting 2000-02-23T20:21:57.694Z,951337317.694 [DATMMP](INFO): Starting 2000-02-23T20:21:57.946Z,951337317.946 [DATMMP](INFO): Starting 2000-02-23T20:21:58.198Z,951337318.198 [DATMMP](INFO): Starting 2000-02-23T20:21:58.450Z,951337318.450 [DATMMP](INFO): Starting 2000-02-23T20:21:58.702Z,951337318.702 [DATMMP](INFO): Starting 2000-02-23T20:21:58.953Z,951337318.953 [DATMMP](INFO): Starting 2000-02-23T20:21:59.206Z,951337319.206 [DATMMP](INFO): Starting 2000-02-23T20:21:59.458Z,951337319.458 [DATMMP](INFO): Starting 2000-02-23T20:21:59.710Z,951337319.710 [DATMMP](INFO): Starting 2000-02-23T20:21:59.962Z,951337319.962 [DATMMP](INFO): Starting 2000-02-23T20:21:59.962Z,951337319.962 [DATMMP](INFO): DAT read: 2000-02-23T20:21:59.963Z,951337319.963 [DATMMP](INFO): DAT read: Teledyne Benthos DAT-900 Series 2000-02-23T20:22:00.214Z,951337320.214 [DATMMP](INFO): Starting 2000-02-23T20:22:00.465Z,951337320.465 [DATMMP](INFO): Starting 2000-02-23T20:22:00.718Z,951337320.718 [DATMMP](INFO): Starting 2000-02-23T20:22:00.970Z,951337320.970 [DATMMP](INFO): Starting 2000-02-23T20:22:01.222Z,951337321.222 [DATMMP](INFO): Starting 2000-02-23T20:22:01.474Z,951337321.474 [DATMMP](INFO): Starting 2000-02-23T20:22:01.730Z,951337321.730 [DATMMP](INFO): Starting 2000-02-23T20:22:01.730Z,951337321.730 [DATMMP](INFO): DAT read: MF Frequency Band 2000-02-23T20:22:01.732Z,951337321.732 [DATMMP](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2000-02-23T20:22:01.732Z,951337321.732 [DATMMP](INFO): DAT read: Feb 23 2000 20:21:55 2000-02-23T20:22:01.978Z,951337321.978 [DATMMP](INFO): Starting 2000-02-23T20:22:02.230Z,951337322.230 [DATMMP](INFO): Starting 2000-02-23T20:22:02.482Z,951337322.482 [DATMMP](INFO): Starting 2000-02-23T20:22:02.734Z,951337322.734 [DATMMP](INFO): Starting 2000-02-23T20:22:02.734Z,951337322.734 [DATMMP](INFO): DAT read: Features enabled [Bearing] 2000-02-23T20:22:02.736Z,951337322.736 [DATMMP](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2000-02-23T20:22:02.736Z,951337322.736 [DATMMP](INFO): commRate: 800 2000-02-23T20:22:02.986Z,951337322.986 [DATMMP](INFO): Starting 2000-02-23T20:22:03.237Z,951337323.237 [DATMMP](INFO): Starting 2000-02-23T20:22:03.490Z,951337323.490 [DATMMP](INFO): Starting 2000-02-23T20:22:03.746Z,951337323.746 [DATMMP](INFO): Starting 2000-02-23T20:22:04.002Z,951337324.002 [DATMMP](INFO): Starting 2000-02-23T20:22:04.254Z,951337324.254 [DATMMP](INFO): Starting 2000-02-23T20:22:04.505Z,951337324.505 [DATMMP](INFO): Starting 2000-02-23T20:22:04.758Z,951337324.758 [DATMMP](INFO): Starting 2000-02-23T20:22:04.810Z,951337324.810 [DATMMP](INFO): entering command mode 2000-02-23T20:22:05.009Z,951337325.009 [DATMMP](INFO): Starting 2000-02-23T20:22:05.010Z,951337325.010 [DATMMP](INFO): DAT read: 2000-02-23T20:22:05.010Z,951337325.010 [DATMMP](INFO): DAT read: user:1> 2000-02-23T20:22:05.010Z,951337325.010 [DATMMP](DEBUG): read user prompt 1: user:1> 2000-02-23T20:22:05.011Z,951337325.011 [DATMMP](INFO): entering MMP mode 2000-02-23T20:22:05.262Z,951337325.262 [DATMMP](INFO): Starting 2000-02-23T20:22:05.262Z,951337325.262 [DATMMP](INFO): GSXN notify for xid: 0 2000-02-23T20:22:05.264Z,951337325.264 [DATMMP](INFO): status rx: x1 2000-02-23T20:22:05.264Z,951337325.264 [DATMMP](INFO): MMP status: 1: started 2000-02-23T20:22:05.264Z,951337325.264 [DATMMP](INFO): Received message type: status 2000-02-23T20:22:05.265Z,951337325.265 [DATMMP](INFO): Handled 2000-02-23T20:22:05.514Z,951337325.514 [DATMMP](INFO): Starting 2000-02-23T20:22:05.515Z,951337325.515 [DATMMP](INFO): Sent Tx Power Config 8 2000-02-23T20:22:05.515Z,951337325.515 [DATMMP](INFO): Setting local address: 11 2000-02-23T20:22:05.517Z,951337325.517 [DATMMP](INFO): Setting time to: 20:22:5 And date to:2/23/2000 2000-02-23T20:22:05.766Z,951337325.766 [DATMMP](INFO): Starting 2000-02-23T20:22:05.766Z,951337325.766 [DATMMP](INFO): GSXN notify for xid: 0 2000-02-23T20:22:05.767Z,951337325.767 [DATMMP](INFO): mdmpower rx: x8 x0 x5 x0 2000-02-23T20:22:05.767Z,951337325.767 [DATMMP](INFO): Received message type: mdmpower 2000-02-23T20:22:05.767Z,951337325.767 [DATMMP](INFO): Handled 2000-02-23T20:22:06.018Z,951337326.018 [DATMMP](INFO): Starting 2000-02-23T20:22:06.018Z,951337326.018 [DATMMP](INFO): GSXN notify for xid: 10 2000-02-23T20:22:06.019Z,951337326.019 [DATMMP](INFO): sreg_txpower rx: x8 2000-02-23T20:22:06.019Z,951337326.019 [DATMMP](INFO): Received message type: sreg_txpower 2000-02-23T20:22:06.019Z,951337326.019 [DATMMP](INFO): Match for : sreg_txpower 2000-02-23T20:22:06.019Z,951337326.019 [DATMMP](INFO): ACK 2000-02-23T20:22:06.270Z,951337326.270 [DATMMP](INFO): Starting 2000-02-23T20:22:06.271Z,951337326.271 [DATMMP](INFO): GSXN notify for xid: 0 2000-02-23T20:22:06.272Z,951337326.272 [DATMMP](INFO): mdmlocal rx: xB x0 x0 x0 2000-02-23T20:22:06.272Z,951337326.272 [DATMMP](INFO): Received message type: mdmlocal 2000-02-23T20:22:06.272Z,951337326.272 [DATMMP](INFO): Handled 2000-02-23T20:22:06.521Z,951337326.521 [DATMMP](INFO): Starting 2000-02-23T20:22:06.522Z,951337326.522 [DATMMP](INFO): GSXN notify for xid: 11 2000-02-23T20:22:06.522Z,951337326.522 [DATMMP](INFO): sreg_locaddr rx: xB 2000-02-23T20:22:06.523Z,951337326.523 [DATMMP](INFO): Received message type: sreg_locaddr 2000-02-23T20:22:06.523Z,951337326.523 [DATMMP](INFO): Match for : sreg_locaddr 2000-02-23T20:22:06.523Z,951337326.523 [DATMMP](INFO): ACK 2000-02-23T20:22:06.774Z,951337326.774 [DATMMP](INFO): Starting 2000-02-23T20:22:06.775Z,951337326.775 [DATMMP](INFO): GSXN notify for xid: 12 2000-02-23T20:22:06.776Z,951337326.776 [DATMMP](INFO): timedate rx: x0 x14 x16 x5 x1 x17 x64 x0 2000-02-23T20:22:06.776Z,951337326.776 [DATMMP](INFO): Received message type: timedate 2000-02-23T20:22:06.776Z,951337326.776 [DATMMP](INFO): Match for : timedate 2000-02-23T20:22:06.776Z,951337326.776 [DATMMP](INFO): ACK 2000-02-23T20:22:07.025Z,951337327.025 [DATMMP](INFO): Starting 2000-02-23T20:22:07.026Z,951337327.026 [DATMMP](INFO): GSXN notify for xid: 0 2000-02-23T20:22:07.027Z,951337327.027 [DATMMP](INFO): sys_verb rx: x0 x0 x0 x0 2000-02-23T20:22:07.027Z,951337327.027 [DATMMP](INFO): Received message type: sys_verb 2000-02-23T20:22:07.027Z,951337327.027 [DATMMP](INFO): Handled 2000-02-23T20:22:07.278Z,951337327.278 [DATMMP](INFO): Starting 2000-02-23T20:22:07.278Z,951337327.278 [DATMMP](INFO): GSXN notify for xid: 13 2000-02-23T20:22:07.279Z,951337327.279 [DATMMP](INFO): sreg_verbosity rx: x0 2000-02-23T20:22:07.279Z,951337327.279 [DATMMP](INFO): Received message type: sreg_verbosity 2000-02-23T20:22:07.279Z,951337327.279 [DATMMP](INFO): Match for : sreg_verbosity 2000-02-23T20:22:07.279Z,951337327.279 [DATMMP](INFO): ACK 2000-02-23T20:22:07.530Z,951337327.530 [DATMMP](INFO): Starting 2000-02-23T20:22:07.530Z,951337327.530 [DATMMP](INFO): GSXN notify for xid: 14 2000-02-23T20:22:07.531Z,951337327.531 [DATMMP](INFO): version rx: x2 x5 2000-02-23T20:22:07.531Z,951337327.531 [DATMMP](INFO): DatMMPVersion: 2.5 2000-02-23T20:22:07.531Z,951337327.531 [DATMMP](INFO): Received message type: version 2000-02-23T20:22:07.531Z,951337327.531 [DATMMP](INFO): Match for : version 2000-02-23T20:22:07.531Z,951337327.531 [DATMMP](INFO): ACK 2000-02-23T20:22:07.531Z,951337327.531 [DATMMP](INFO): in MMP mode: config complete going to runnable 2000-02-23T20:22:11.424Z,951337331.424 [NavChartDb](INFO): # of records loaded: 5000 2000-02-23T20:22:16.327Z,951337336.327 [NAL9602](INFO): Powering up NAL9602 2000-02-23T20:22:19.356Z,951337339.356 [NavChartDb](INFO): # of records loaded: 10000 2000-02-23T20:22:20.890Z,951337340.890 [DATMMP](INFO): GSXN notify for xid: 0 2000-02-23T20:22:20.891Z,951337340.891 [DATMMP](INFO): timesync rx: x0 x1 x1 x0 2000-02-23T20:22:20.891Z,951337340.891 [DATMMP](INFO): Received message type: timesync 2000-02-23T20:22:20.891Z,951337340.891 [DATMMP](INFO): Handled 2000-02-23T20:22:26.803Z,951337346.803 [NavChartDb](INFO): # of records loaded: 15000 2000-02-23T20:22:27.252Z,951337347.252 [NAL9602](INFO): NAL9602 initialized 2000-02-23T20:22:30.734Z,951337350.734 [DATMMP](INFO): GSXN notify for xid: 0 2000-02-23T20:22:30.735Z,951337350.735 [DATMMP](INFO): timesync rx: x1 x0 x1 x0 2000-02-23T20:22:30.735Z,951337350.735 [DATMMP](INFO): Received message type: timesync 2000-02-23T20:22:30.735Z,951337350.735 [DATMMP](INFO): Handled 2000-02-23T20:22:34.483Z,951337354.483 [NavChartDb](INFO): # of records loaded: 20000 2000-02-23T20:22:41.970Z,951337361.970 [NavChartDb](INFO): # of records loaded: 25000 2000-02-23T20:22:49.433Z,951337369.433 [NavChartDb](INFO): # of records loaded: 30000 2000-02-23T20:22:58.439Z,951337378.439 [NavChartDb](INFO): # of records loaded: 35000 2000-02-23T20:23:08.009Z,951337388.009 [NavChartDb](INFO): # of records loaded: 40000 2000-02-23T20:23:15.976Z,951337395.976 [NavChartDb](INFO): # of records loaded: 45000 2000-02-23T20:23:23.583Z,951337403.583 [NavChartDb](INFO): # of records loaded: 50000 2000-02-23T20:23:34.355Z,951337414.355 [NavChartDb](INFO): # of records loaded: 55000 2000-02-23T20:23:35.838Z,951337415.838 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US5CA50M.000 2000-02-23T20:23:40.443Z,951337420.443 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US5CA50M.000 2000-02-23T20:23:45.108Z,951337425.108 [NavChartDb](INFO): # of records loaded: 60000 2000-02-23T20:23:46.569Z,951337426.569 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2024-09-05T15:56:47.570Z,1725551807.570 [CBIT](IMPORTANT): Beginning ground fault scan 2024-09-05T15:56:47.589Z,1725551807.589 [AHRS_M2](FAULT): Failed to acquire valid data within timeout. 2024-09-05T15:56:47.589Z,1725551807.589 [AHRS_M2] Data Fault, FailCount= 1 2024-09-05T15:56:47.589Z,1725551807.589 [AHRS_M2](ERROR): Data Fault 2024-09-05T15:56:47.611Z,1725551807.611 [BPC1](INFO): Calculating totals. Valid battery stick count: 14. Valid reserve battery stick count: 1. 2024-09-05T15:56:47.642Z,1725551807.642 [BPC1](FAULT): Failed to receive data from 47 sticks prior to timeout. Missing stick IDs are: 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20, 21, 22, 23, 24, 32, 33, 34, 35, 36, 37, 38, 39, 40, 41, 42, 43, 44, 45, 46, 47, 56, 57, 58, 59, 60, 61, 62. 2024-09-05T15:56:47.642Z,1725551807.642 [BPC1] Data Fault, FailCount= 1 2024-09-05T15:56:47.642Z,1725551807.642 [BPC1](ERROR): Data Fault 2024-09-05T15:56:47.645Z,1725551807.645 [DVL_micro](ERROR): No DVL communication! Re-initializing 2024-09-05T15:56:47.645Z,1725551807.645 [DVL_micro] Communications Fault, FailCount= 1 2024-09-05T15:56:47.645Z,1725551807.645 [DVL_micro](ERROR): Communications Fault 2024-09-05T15:56:47.646Z,1725551807.646 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-09-05T15:56:47.648Z,1725551807.648 [Sonardyne_Nano](FAULT): Failed to receive valid data within the specified timeout. 2024-09-05T15:56:47.648Z,1725551807.648 [Sonardyne_Nano] Communications Fault, FailCount= 1 2024-09-05T15:56:47.657Z,1725551807.657 [Sonardyne_Nano](ERROR): Communications Fault 2024-09-05T15:56:47.670Z,1725551807.670 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2024-09-05T15:56:47.670Z,1725551807.670 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2024-09-05T15:56:47.670Z,1725551807.670 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-09-05T15:56:47.715Z,1725551807.715 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-09-05T15:56:47.715Z,1725551807.715 [CBIT](ERROR): Data Fault in component: AHRS_M2 2024-09-05T15:56:47.715Z,1725551807.715 [CBIT](ERROR): Data Fault in component: BPC1 2024-09-05T15:56:47.715Z,1725551807.715 [CBIT](ERROR): Communications Fault in component: DVL_micro 2024-09-05T15:56:47.716Z,1725551807.716 [CBIT](ERROR): Communications Fault in component: Sonardyne_Nano 2024-09-05T15:56:47.978Z,1725551807.978 [AHRS_M2](INFO): Powering down 2024-09-05T15:56:48.153Z,1725551808.153 [DVL_micro](INFO): Powering down 2024-09-05T15:56:48.155Z,1725551808.155 [Sonardyne_Nano](INFO): Powering down 2024-09-05T15:56:48.290Z,1725551808.290 [SBIT](IMPORTANT): Beginning Startup BIT 2024-09-05T15:56:48.294Z,1725551808.294 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-09-05T15:56:48.294Z,1725551808.294 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2024-09-05T15:56:48.388Z,1725551808.388 [NAL9602](FAULT): GPS failed to acquire within timeout. 2024-09-05T15:56:48.388Z,1725551808.388 [NAL9602] Data Fault, FailCount= 1 2024-09-05T15:56:48.388Z,1725551808.388 [NAL9602](ERROR): Data Fault 2024-09-05T15:56:48.506Z,1725551808.506 [CBIT](ERROR): Data Fault in component: NAL9602 2024-09-05T15:56:48.798Z,1725551808.798 [NAL9602](INFO): Powering down 2024-09-05T15:56:48.877Z,1725551808.877 [CBIT](INFO): Clearing failed state for component AHRS_M2 2024-09-05T15:56:48.877Z,1725551808.877 [AHRS_M2] No Fault, FailCount= 1 2024-09-05T15:56:48.878Z,1725551808.878 [CBIT](INFO): Clearing failed state for component DVL_micro 2024-09-05T15:56:48.878Z,1725551808.878 [DVL_micro] No Fault, FailCount= 1 2024-09-05T15:56:48.878Z,1725551808.878 [CBIT](INFO): Clearing failed state for component Sonardyne_Nano 2024-09-05T15:56:48.878Z,1725551808.878 [Sonardyne_Nano] No Fault, FailCount= 1 2024-09-05T15:56:48.979Z,1725551808.979 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004968 2024-09-05T15:56:49.190Z,1725551809.190 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2024-09-05T15:56:49.209Z,1725551809.209 [Sonardyne_Nano](INFO): Initializing. 2024-09-05T15:56:49.805Z,1725551809.805 [CBIT](INFO): Clearing failed state for component NAL9602 2024-09-05T15:56:49.805Z,1725551809.805 [NAL9602] No Fault, FailCount= 1 2024-09-05T15:56:51.223Z,1725551811.223 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART 2024-09-05T15:56:56.470Z,1725551816.470 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US5CA50M.000 2024-09-05T15:56:56.594Z,1725551816.594 [NavChartDb](INFO): # of records loaded: 62052 2024-09-05T15:56:56.604Z,1725551816.604 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US5CA50M.000 2024-09-05T15:56:56.609Z,1725551816.609 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US3CA52M.000 2024-09-05T15:56:58.537Z,1725551818.537 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.059642 CHAN A1 (24V): 0.016100 CHAN A2 (12V): -0.015082 CHAN A3 (5V): -0.022766 CHAN B0 (3.3V): -0.011594 CHAN B1 (3.15aV): -0.005629 CHAN B2 (3.15bV): 0.000194 CHAN B3 (GND): -0.008003 OPEN: 0.001500 Full Scale: +/- 1 mA 2024-09-05T15:56:59.671Z,1725551819.671 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US3CA52M.000 2024-09-05T15:57:04.170Z,1725551824.170 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2024-09-05T15:57:04.170Z,1725551824.170 [DVL_micro] Data Fault, FailCount= 2 2024-09-05T15:57:04.170Z,1725551824.170 [DVL_micro](ERROR): Data Fault 2024-09-05T15:57:04.310Z,1725551824.310 [CBIT](ERROR): Data Fault in component: DVL_micro 2024-09-05T15:57:04.661Z,1725551824.661 [DVL_micro](INFO): Powering down 2024-09-05T15:57:05.474Z,1725551825.474 [CBIT](INFO): Clearing failed state for component DVL_micro 2024-09-05T15:57:05.474Z,1725551825.474 [DVL_micro] No Fault, FailCount= 2 2024-09-05T15:57:10.584Z,1725551830.584 [NavChartDb](INFO): # of records loaded: 5000 2024-09-05T15:57:19.106Z,1725551839.106 [NAL9602](INFO): Powering up NAL9602 2024-09-05T15:57:19.462Z,1725551839.462 [NavChartDb](INFO): # of records loaded: 10000 2024-09-05T15:57:22.836Z,1725551842.836 [NavChartDb](INFO): # of records loaded: 15000 2024-09-05T15:57:25.781Z,1725551845.781 [NavChartDb](INFO): # of records loaded: 20000 2024-09-05T15:57:30.019Z,1725551850.019 [NAL9602](INFO): NAL9602 initialized 2024-09-05T15:57:34.240Z,1725551854.240 [NavChartDb](INFO): # of records loaded: 25000 2024-09-05T15:57:39.336Z,1725551859.336 [NavChartDb](INFO): # of records loaded: 30000 2024-09-05T15:57:41.816Z,1725551861.816 [NavChartDb](INFO): # of records loaded: 35000 2024-09-05T15:57:42.200Z,1725551862.200 [SBIT](IMPORTANT): SBIT PASSED 2024-09-05T15:57:42.200Z,1725551862.200 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2024-09-05T15:57:42.205Z,1725551862.205 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool; 2024-09-05T15:57:42.205Z,1725551862.205 [SBIT](IMPORTANT): DATMMP.loadAtStartup=1 bool; 2024-09-05T15:57:42.205Z,1725551862.205 [SBIT](IMPORTANT): DATMMP.simulateHardware=0 bool; 2024-09-05T15:57:42.206Z,1725551862.206 [SBIT](IMPORTANT): Depth_Keller.offset=3.6 decibar; 2024-09-05T15:57:42.206Z,1725551862.206 [SBIT](IMPORTANT): DropWeight.loadAtStartup=0 bool; 2024-09-05T15:57:42.206Z,1725551862.206 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=3 minute; 2024-09-05T15:57:42.206Z,1725551862.206 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=186.137647 cubic_centimeter; 2024-09-05T15:57:42.206Z,1725551862.206 [SBIT](IMPORTANT): VerticalControl.massDefault=27.004010 millimeter; 2024-09-05T15:57:42.586Z,1725551862.586 [MissionManager](IMPORTANT): Started mission Startup 2024-09-05T15:57:42.587Z,1725551862.587 [Startup] Running Loop=1 2024-09-05T15:57:42.587Z,1725551862.587 [Startup](DEBUG): Aggregate::initialize Startup 2024-09-05T15:57:42.587Z,1725551862.587 [Startup:A.GoToSurface] Running Loop=1 2024-09-05T15:57:42.587Z,1725551862.587 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2024-09-05T15:57:42.588Z,1725551862.588 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2024-09-05T15:57:42.588Z,1725551862.588 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2024-09-05T15:57:42.588Z,1725551862.588 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2024-09-05T15:57:42.593Z,1725551862.593 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2024-09-05T15:57:42.593Z,1725551862.593 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2024-09-05T15:57:42.594Z,1725551862.594 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2024-09-05T15:57:42.595Z,1725551862.595 [Startup:StartupSatComms] Running Loop=1 2024-09-05T15:57:42.595Z,1725551862.595 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2024-09-05T15:57:42.595Z,1725551862.595 [Startup:StartupSatComms:A] Running Loop=1 2024-09-05T15:57:42.983Z,1725551862.983 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2024-09-05T15:57:46.697Z,1725551866.697 [NavChartDb](INFO): # of records loaded: 40000 2024-09-05T15:57:53.349Z,1725551873.349 [NavChartDb](INFO): # of records loaded: 45000 2024-09-05T15:58:00.905Z,1725551880.905 [NavChartDb](INFO): # of records loaded: 50000 2024-09-05T15:58:10.775Z,1725551890.775 [NavChartDb](INFO): # of records loaded: 55000 2024-09-05T15:58:15.941Z,1725551895.941 [NavChartDb](INFO): # of records loaded: 60000 2024-09-05T15:58:20.255Z,1725551900.255 [NavChartDb](INFO): # of records loaded: 65000 2024-09-05T15:58:24.123Z,1725551904.123 [NavChartDb](INFO): # of records loaded: 70000 2024-09-05T15:58:31.125Z,1725551911.125 [NavChartDb](INFO): # of records loaded: 75000 2024-09-05T15:58:38.446Z,1725551918.446 [NavChartDb](INFO): # of records loaded: 80000 2024-09-05T15:58:42.750Z,1725551922.750 [Startup:StartupSatComms:A](INFO): Timed out from 2024-09-05T15:57:42.6Z 2024-09-05T15:58:42.750Z,1725551922.750 [Startup:StartupSatComms:A] Stopped 2024-09-05T15:58:42.750Z,1725551922.750 [Startup:StartupSatComms:B] Running Loop=1 2024-09-05T15:58:43.218Z,1725551923.218 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2024-09-05T15:58:45.878Z,1725551925.878 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20000223T025904/Courier0277.lzma 2024-09-05T15:58:46.151Z,1725551926.151 [DataOverHttps](INFO): Moved sent file to Logs/20000223T025904/Courier0277.lzma.bak 2024-09-05T15:58:46.151Z,1725551926.151 [DataOverHttps](INFO): SBD MOMSN=23130306 2024-09-05T15:58:46.794Z,1725551926.794 [NavChartDb](INFO): # of records loaded: 85000 2024-09-05T15:58:57.867Z,1725551937.867 [NavChartDb](INFO): # of records loaded: 90000 2024-09-05T15:59:06.172Z,1725551946.172 [NavChartDb](INFO): # of records loaded: 95000 2024-09-05T15:59:08.701Z,1725551948.701 [DataOverHttps](INFO): Sending 195 bytes from file Logs/20000223T202135/Courier0000.lzma 2024-09-05T15:59:09.699Z,1725551949.699 [DataOverHttps](INFO): Moved sent file to Logs/20000223T202135/Courier0000.lzma.bak 2024-09-05T15:59:09.699Z,1725551949.699 [DataOverHttps](INFO): SBD MOMSN=23130308 2024-09-05T15:59:17.911Z,1725551957.911 [NavChartDb](INFO): # of records loaded: 100000 2024-09-05T15:59:29.178Z,1725551969.178 [NavChartDb](INFO): # of records loaded: 105000 2024-09-05T15:59:38.924Z,1725551978.924 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20000223T025904/Express0278.lzma 2024-09-05T15:59:39.883Z,1725551979.883 [DataOverHttps](INFO): Moved sent file to Logs/20000223T025904/Express0278.lzma.bak 2024-09-05T15:59:39.883Z,1725551979.883 [DataOverHttps](INFO): SBD MOMSN=23130311 2024-09-05T15:59:42.951Z,1725551982.951 [Startup:StartupSatComms:B](INFO): Timed out from 2024-09-05T15:58:42.7Z 2024-09-05T15:59:42.951Z,1725551982.951 [Startup:StartupSatComms:B] Stopped 2024-09-05T15:59:42.951Z,1725551982.951 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2024-09-05T15:59:42.951Z,1725551982.951 [Startup:StartupSatComms] Stopped 2024-09-05T15:59:42.951Z,1725551982.951 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2024-09-05T15:59:42.952Z,1725551982.952 [Startup](INFO): Completed Startup 2024-09-05T15:59:42.952Z,1725551982.952 [MissionManager](INFO): Startup is completed. 2024-09-05T15:59:42.952Z,1725551982.952 [MissionManager](INFO): Uninitializing Mission Startup 2024-09-05T15:59:42.952Z,1725551982.952 [Startup] Stopped 2024-09-05T15:59:42.985Z,1725551982.985 [Startup](DEBUG): Aggregate::uninitialize Startup 2024-09-05T15:59:42.985Z,1725551982.985 [Startup:A.GoToSurface] Stopped 2024-09-05T15:59:42.985Z,1725551982.985 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2024-09-05T15:59:43.230Z,1725551983.230 [NavChartDb](INFO): # of records loaded: 110000 2024-09-05T15:59:43.346Z,1725551983.346 [MissionManager](IMPORTANT): Started mission Default 2024-09-05T15:59:43.346Z,1725551983.346 [Default] Running Loop=1 2024-09-05T15:59:43.346Z,1725551983.346 [Default](DEBUG): Aggregate::initialize Default 2024-09-05T15:59:43.346Z,1725551983.346 [Default:B.GoToSurface] Running Loop=1 2024-09-05T15:59:43.346Z,1725551983.346 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2024-09-05T15:59:43.347Z,1725551983.347 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2024-09-05T15:59:43.347Z,1725551983.347 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2024-09-05T15:59:43.347Z,1725551983.347 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2024-09-05T15:59:43.348Z,1725551983.348 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2024-09-05T15:59:43.348Z,1725551983.348 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2024-09-05T15:59:43.348Z,1725551983.348 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2024-09-05T15:59:43.357Z,1725551983.357 [Default:A.Wait] Running Loop=1 2024-09-05T15:59:43.357Z,1725551983.357 [Default:A.Wait](DEBUG): Initialize Wait Component. 2024-09-05T15:59:48.613Z,1725551988.613 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2024-09-05T15:59:48.613Z,1725551988.613 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-09-05T15:59:48.632Z,1725551988.632 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-09-05T15:59:49.064Z,1725551989.064 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-09-05T15:59:49.073Z,1725551989.073 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2024-09-05T15:59:53.575Z,1725551993.575 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US3CA52M.000 2024-09-05T15:59:54.514Z,1725551994.514 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US3CA52M.000 2024-09-05T15:59:56.679Z,1725551996.679 [Default:A.Wait](INFO): Done Waiting. 2024-09-05T15:59:56.679Z,1725551996.679 [Default:A.Wait] Stopped 2024-09-05T15:59:56.679Z,1725551996.679 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2024-09-05T15:59:56.945Z,1725551996.945 [NavChartDb](INFO): # of records loaded: 115000 2024-09-05T15:59:57.110Z,1725551997.110 [Default:CheckIn] Running Loop=1 2024-09-05T15:59:57.110Z,1725551997.110 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-09-05T15:59:57.110Z,1725551997.110 [Default:CheckIn:Read_GPS] Running Loop=1 2024-09-05T15:59:57.501Z,1725551997.501 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2024-09-05T16:00:04.218Z,1725552004.218 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US3CA52M.000 2024-09-05T16:00:04.352Z,1725552004.352 [NavChartDb](INFO): # of records loaded: 117310 2024-09-05T16:00:04.373Z,1725552004.373 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US3CA52M.000 2024-09-05T16:00:04.380Z,1725552004.380 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US2WC11M.000 2024-09-05T16:00:08.280Z,1725552008.280 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US2WC11M.000 2024-09-05T16:00:18.078Z,1725552018.078 [NavChartDb](INFO): # of records loaded: 5000 2024-09-05T16:00:27.482Z,1725552027.482 [NavChartDb](INFO): # of records loaded: 10000 2024-09-05T16:00:30.058Z,1725552030.058 [DataOverHttps](INFO): Sending 1339 bytes from file Logs/20000223T202135/Express0001.lzma 2024-09-05T16:00:31.058Z,1725552031.058 [DataOverHttps](INFO): Moved sent file to Logs/20000223T202135/Express0001.lzma.bak 2024-09-05T16:00:31.059Z,1725552031.059 [DataOverHttps](INFO): SBD MOMSN=23130313 2024-09-05T16:00:35.700Z,1725552035.700 [NavChartDb](INFO): # of records loaded: 15000 2024-09-05T16:00:43.383Z,1725552043.383 [NavChartDb](INFO): # of records loaded: 20000 2024-09-05T16:00:56.799Z,1725552056.799 [NavChartDb](INFO): # of records loaded: 25000 2024-09-05T16:01:19.688Z,1725552079.688 [NavChartDb](INFO): # of records loaded: 30000 2024-09-05T16:01:42.402Z,1725552102.402 [NavChartDb](INFO): # of records loaded: 35000 2024-09-05T16:01:55.435Z,1725552115.435 [NavChartDb](INFO): # of records loaded: 40000 2024-09-05T16:01:57.378Z,1725552117.378 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US2WC11M.000 2024-09-05T16:01:58.035Z,1725552118.035 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US2WC11M.000 2024-09-05T16:02:07.123Z,1725552127.123 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US2WC11M.000 2024-09-05T16:02:07.242Z,1725552127.242 [NavChartDb](INFO): # of records loaded: 44941 2024-09-05T16:02:07.250Z,1725552127.250 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US2WC11M.000 2024-09-05T16:02:07.251Z,1725552127.251 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US1WC07M.000 2024-09-05T16:02:12.765Z,1725552132.765 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US1WC07M.000 2024-09-05T16:02:23.476Z,1725552143.476 [NavChartDb](INFO): # of records loaded: 5000 2024-09-05T16:02:32.807Z,1725552152.807 [NavChartDb](INFO): # of records loaded: 10000 2024-09-05T16:02:42.501Z,1725552162.501 [NavChartDb](INFO): # of records loaded: 15000 2024-09-05T16:02:49.582Z,1725552169.582 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2024-09-05T16:02:49.582Z,1725552169.582 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-09-05T16:02:49.635Z,1725552169.635 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-09-05T16:02:50.007Z,1725552170.007 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-09-05T16:02:50.007Z,1725552170.007 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2024-09-05T16:02:55.193Z,1725552175.193 [NavChartDb](INFO): # of records loaded: 20000 2024-09-05T16:02:57.551Z,1725552177.551 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US1WC07M.000 2024-09-05T16:02:59.014Z,1725552179.014 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US1WC07M.000 2024-09-05T16:03:18.783Z,1725552198.783 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US1WC07M.000 2024-09-05T16:03:19.325Z,1725552199.325 [NavChartDb](INFO): # of records loaded: 24439 2024-09-05T16:03:19.354Z,1725552199.354 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US1WC07M.000 2024-09-05T16:03:22.431Z,1725552202.431 [NavChartDb](INFO): Creating index for soundings 2024-09-05T16:03:28.144Z,1725552208.144 [NavChartDb](INFO): Creating index for 0p0 2024-09-05T16:03:29.671Z,1725552209.671 [NavChartDb](INFO): Creating index for 1p8 2024-09-05T16:03:29.803Z,1725552209.803 [NavChartDb](INFO): Creating index for 3p6 2024-09-05T16:03:30.501Z,1725552210.501 [NavChartDb](INFO): Creating index for 5p4 2024-09-05T16:03:30.967Z,1725552210.967 [NavChartDb](INFO): Creating index for 9p1 2024-09-05T16:03:31.028Z,1725552211.028 [NavChartDb](INFO): Creating index for 10p9 2024-09-05T16:03:31.903Z,1725552211.903 [NavChartDb](INFO): Creating index for 18p2 2024-09-05T16:03:33.005Z,1725552213.005 [NavChartDb](INFO): Creating index for 36p5 2024-09-05T16:03:34.595Z,1725552214.595 [NavChartDb](INFO): Creating index for 54p8 2024-09-05T16:03:35.844Z,1725552215.844 [NavChartDb](INFO): Creating index for 73p1 2024-09-05T16:03:37.170Z,1725552217.170 [NavChartDb](INFO): Creating index for 91p4 2024-09-05T16:03:39.433Z,1725552219.433 [NavChartDb](INFO): Creating index for 182p8 2024-09-05T16:03:41.215Z,1725552221.215 [NavChartDb](INFO): Creating index for 365p7 2024-09-05T16:03:42.651Z,1725552222.651 [NavChartDb](INFO): Creating index for 548p6 2024-09-05T16:03:43.932Z,1725552223.932 [NavChartDb](INFO): Creating index for 731p5 2024-09-05T16:03:46.436Z,1725552226.436 [NavChartDb](INFO): Creating index for 914p4 2024-09-05T16:03:48.231Z,1725552228.231 [NavChartDb](INFO): Creating index for 1097p2 2024-09-05T16:03:49.208Z,1725552229.208 [NavChartDb](INFO): Creating index for 1280p1 2024-09-05T16:03:50.134Z,1725552230.134 [NavChartDb](INFO): Creating index for 1463p0 2024-09-05T16:03:51.102Z,1725552231.102 [NavChartDb](INFO): Creating index for 1645p9 2024-09-05T16:03:53.133Z,1725552233.133 [NavChartDb](INFO): Creating index for 1828p8 2024-09-05T16:03:54.422Z,1725552234.422 [NavChartDb](INFO): Creating index for 2011p6 2024-09-05T16:03:55.197Z,1725552235.197 [NavChartDb](INFO): Creating index for 2194p5 2024-09-05T16:03:56.256Z,1725552236.256 [NavChartDb](INFO): Creating index for 2377p4 2024-09-05T16:03:57.182Z,1725552237.182 [NavChartDb](INFO): Creating index for 2560p3 2024-09-05T16:03:58.894Z,1725552238.894 [NavChartDb](INFO): Creating index for 2743p2 2024-09-05T16:04:00.276Z,1725552240.276 [NavChartDb](INFO): Creating index for 2926p0 2024-09-05T16:04:01.404Z,1725552241.404 [NavChartDb](INFO): Creating index for 3108p9 2024-09-05T16:04:02.049Z,1725552242.049 [NavChartDb](INFO): Creating index for 3291p8 2024-09-05T16:04:02.388Z,1725552242.388 [NavChartDb](INFO): Creating index for 3474p7 2024-09-05T16:04:06.878Z,1725552246.878 [NavChartDb](INFO): Creating index for 3657p6 2024-09-05T16:04:57.248Z,1725552297.248 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-09-05T15:59:57.1Z 2024-09-05T16:04:57.248Z,1725552297.248 [Default:CheckIn:Read_GPS] Stopped 2024-09-05T16:04:57.248Z,1725552297.248 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-09-05T16:04:57.647Z,1725552297.647 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2024-09-05T16:05:04.584Z,1725552304.584 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20000223T202135/Courier0004.lzma 2024-09-05T16:05:05.586Z,1725552305.586 [DataOverHttps](INFO): Moved sent file to Logs/20000223T202135/Courier0004.lzma.bak 2024-09-05T16:05:05.587Z,1725552305.587 [DataOverHttps](INFO): SBD MOMSN=23130354 2024-09-05T16:05:24.740Z,1725552324.740 [DataOverHttps](INFO): Sending 158 bytes from file Logs/20000223T202135/Express0005.lzma 2024-09-05T16:05:25.742Z,1725552325.742 [DataOverHttps](INFO): Moved sent file to Logs/20000223T202135/Express0005.lzma.bak 2024-09-05T16:05:25.743Z,1725552325.743 [DataOverHttps](INFO): SBD MOMSN=23130356 2024-09-05T16:05:32.002Z,1725552332.002 [Default:CheckIn:Read_Iridium] Stopped 2024-09-05T16:05:32.002Z,1725552332.002 [Default:CheckIn:C.Wait] Running Loop=1 2024-09-05T16:05:32.002Z,1725552332.002 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-09-05T16:05:50.576Z,1725552350.576 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2024-09-05T16:05:50.576Z,1725552350.576 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-09-05T16:05:50.588Z,1725552350.588 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-09-05T16:05:50.997Z,1725552350.997 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-09-05T16:05:50.997Z,1725552350.997 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2024-09-05T16:06:48.783Z,1725552408.783 [CBIT](INFO): Clearing failed state for component BPC1 2024-09-05T16:06:48.783Z,1725552408.783 [BPC1] No Fault, FailCount= 1 2024-09-05T16:07:31.962Z,1725552451.962 [NAL9602](FAULT): GPS failed to acquire within timeout. 2024-09-05T16:07:31.962Z,1725552451.962 [NAL9602] Data Fault, FailCount= 2 2024-09-05T16:07:31.962Z,1725552451.962 [NAL9602](ERROR): Data Fault 2024-09-05T16:07:31.995Z,1725552451.995 [CBIT](ERROR): Data Fault in component: NAL9602 2024-09-05T16:07:32.379Z,1725552452.379 [NAL9602](INFO): Powering down 2024-09-05T16:07:33.223Z,1725552453.223 [CBIT](INFO): Clearing failed state for component NAL9602 2024-09-05T16:07:33.223Z,1725552453.223 [NAL9602] No Fault, FailCount= 2 2024-09-05T16:08:02.670Z,1725552482.670 [NAL9602](INFO): Powering up NAL9602 2024-09-05T16:08:07.574Z,1725552487.574 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2024-09-05T16:08:13.582Z,1725552493.582 [NAL9602](INFO): NAL9602 initialized 2024-09-05T16:08:51.596Z,1725552531.596 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2024-09-05T16:08:51.596Z,1725552531.596 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-09-05T16:08:51.622Z,1725552531.622 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-09-05T16:08:52.011Z,1725552532.011 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-09-05T16:08:52.011Z,1725552532.011 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2024-09-05T16:09:13.820Z,1725552553.820 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2024-09-05T16:10:32.579Z,1725552632.579 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-09-05T16:10:32.579Z,1725552632.579 [Default:CheckIn:C.Wait] Stopped 2024-09-05T16:10:32.579Z,1725552632.579 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-09-05T16:10:32.579Z,1725552632.579 [Default:CheckIn:D] Running Loop=1 2024-09-05T16:10:32.990Z,1725552632.990 [Default:CheckIn:D] Stopped 2024-09-05T16:10:32.991Z,1725552632.991 [Default:CheckIn:E] Running Loop=1 2024-09-05T16:10:33.404Z,1725552633.404 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.827403 min 2024-09-05T16:10:33.404Z,1725552633.404 [Default:CheckIn:E] Stopped 2024-09-05T16:10:33.404Z,1725552633.404 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-09-05T16:10:33.404Z,1725552633.404 [Default:CheckIn] Stopped 2024-09-05T16:10:33.405Z,1725552633.405 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-09-05T16:10:33.405Z,1725552633.405 [Default:CheckIn](INFO): Running loop #2 2024-09-05T16:10:33.405Z,1725552633.405 [Default:CheckIn] Running Loop=2 2024-09-05T16:10:33.405Z,1725552633.405 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-09-05T16:10:33.405Z,1725552633.405 [Default:CheckIn:Read_GPS] Running Loop=1 2024-09-05T16:11:52.582Z,1725552712.582 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2024-09-05T16:11:52.582Z,1725552712.582 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-09-05T16:11:52.645Z,1725552712.645 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-09-05T16:11:53.033Z,1725552713.033 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-09-05T16:11:53.033Z,1725552713.033 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2024-09-05T16:11:59.319Z,1725552719.319 [CommandExec](IMPORTANT): got command get Sonardyne_Nano.chargePercent 2024-09-05T16:11:59.319Z,1725552719.319 [CommandExec](IMPORTANT): Sonardyne_Nano.chargePercent 100.000000 % 2024-09-05T16:12:42.636Z,1725552762.636 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file). 2024-09-05T16:12:56.427Z,1725552776.427 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2024-09-05T16:13:25.137Z,1725552805.137 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2024-09-05T16:14:53.572Z,1725552893.572 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2024-09-05T16:14:53.572Z,1725552893.572 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-09-05T16:14:53.582Z,1725552893.582 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-09-05T16:14:53.959Z,1725552893.959 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-09-05T16:14:53.959Z,1725552893.959 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2024-09-05T16:15:14.142Z,1725552914.142 [BPC1](INFO): Calculating totals. Valid battery stick count: 35. Valid reserve battery stick count: 3. 2024-09-05T16:15:14.144Z,1725552914.144 [BPC1](INFO): Received data from all battery sticks. 2024-09-05T16:15:33.543Z,1725552933.543 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-09-05T16:10:33.4Z 2024-09-05T16:15:33.543Z,1725552933.543 [Default:CheckIn:Read_GPS] Stopped 2024-09-05T16:15:33.543Z,1725552933.543 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-09-05T16:15:40.836Z,1725552940.836 [DataOverHttps](INFO): Sending 51 bytes from file Logs/20000223T202135/Courier0007.lzma 2024-09-05T16:15:41.839Z,1725552941.839 [DataOverHttps](INFO): Moved sent file to Logs/20000223T202135/Courier0007.lzma.bak 2024-09-05T16:15:41.839Z,1725552941.839 [DataOverHttps](INFO): SBD MOMSN=23130379 2024-09-05T16:15:59.598Z,1725552959.598 [DataOverHttps](INFO): Sending 255 bytes from file Logs/20000223T202135/Express0008.lzma 2024-09-05T16:16:00.599Z,1725552960.599 [DataOverHttps](INFO): Moved sent file to Logs/20000223T202135/Express0008.lzma.bak 2024-09-05T16:16:00.599Z,1725552960.599 [DataOverHttps](INFO): SBD MOMSN=23130381 2024-09-05T16:16:05.474Z,1725552965.474 [Default:CheckIn:Read_Iridium] Stopped 2024-09-05T16:16:05.474Z,1725552965.474 [Default:CheckIn:C.Wait] Running Loop=1 2024-09-05T16:16:05.474Z,1725552965.474 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-09-05T16:17:54.681Z,1725553074.681 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2024-09-05T16:17:54.681Z,1725553074.681 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-09-05T16:17:54.692Z,1725553074.692 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-09-05T16:17:55.105Z,1725553075.105 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-09-05T16:17:55.105Z,1725553075.105 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2024-09-05T16:18:15.681Z,1725553095.681 [NAL9602](FAULT): GPS failed to acquire within timeout. 2024-09-05T16:18:15.682Z,1725553095.682 [NAL9602] Data Fault, FailCount= 3 2024-09-05T16:18:15.682Z,1725553095.682 [NAL9602](ERROR): Data Fault 2024-09-05T16:18:15.719Z,1725553095.719 [CBIT](ERROR): Data Fault in component: NAL9602 2024-09-05T16:18:16.085Z,1725553096.085 [NAL9602](INFO): Powering down 2024-09-05T16:18:16.911Z,1725553096.911 [CBIT](INFO): Clearing failed state for component NAL9602 2024-09-05T16:18:16.911Z,1725553096.911 [NAL9602] No Fault, FailCount= 3 2024-09-05T16:18:46.385Z,1725553126.385 [NAL9602](INFO): Powering up NAL9602 2024-09-05T16:18:57.298Z,1725553137.298 [NAL9602](INFO): NAL9602 initialized 2024-09-05T16:20:55.678Z,1725553255.678 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9 2024-09-05T16:20:55.678Z,1725553255.678 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-09-05T16:20:55.689Z,1725553255.689 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-09-05T16:20:56.100Z,1725553256.100 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-09-05T16:20:56.100Z,1725553256.100 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9 2024-09-05T16:21:06.199Z,1725553266.199 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-09-05T16:21:06.200Z,1725553266.200 [Default:CheckIn:C.Wait] Stopped 2024-09-05T16:21:06.200Z,1725553266.200 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-09-05T16:21:06.200Z,1725553266.200 [Default:CheckIn:D] Running Loop=1 2024-09-05T16:21:06.581Z,1725553266.581 [Default:CheckIn:D] Stopped 2024-09-05T16:21:06.581Z,1725553266.581 [Default:CheckIn:E] Running Loop=1 2024-09-05T16:21:07.002Z,1725553267.002 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.387242 min 2024-09-05T16:21:07.002Z,1725553267.002 [Default:CheckIn:E] Stopped 2024-09-05T16:21:07.003Z,1725553267.003 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-09-05T16:21:07.003Z,1725553267.003 [Default:CheckIn] Stopped 2024-09-05T16:21:07.003Z,1725553267.003 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-09-05T16:21:07.003Z,1725553267.003 [Default:CheckIn](INFO): Running loop #3 2024-09-05T16:21:07.003Z,1725553267.003 [Default:CheckIn] Running Loop=3 2024-09-05T16:21:07.003Z,1725553267.003 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-09-05T16:21:07.003Z,1725553267.003 [Default:CheckIn:Read_GPS] Running Loop=1 2024-09-05T16:23:56.708Z,1725553436.708 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10 2024-09-05T16:23:56.708Z,1725553436.708 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-09-05T16:23:56.719Z,1725553436.719 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-09-05T16:23:57.113Z,1725553437.113 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-09-05T16:23:57.113Z,1725553437.113 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10 2024-09-05T16:26:07.165Z,1725553567.165 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-09-05T16:21:07.0Z 2024-09-05T16:26:07.165Z,1725553567.165 [Default:CheckIn:Read_GPS] Stopped 2024-09-05T16:26:07.166Z,1725553567.166 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-09-05T16:26:14.355Z,1725553574.355 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20000223T202135/Courier0010.lzma 2024-09-05T16:26:15.357Z,1725553575.357 [DataOverHttps](INFO): Moved sent file to Logs/20000223T202135/Courier0010.lzma.bak 2024-09-05T16:26:15.357Z,1725553575.357 [DataOverHttps](INFO): SBD MOMSN=23130485 2024-09-05T16:26:33.903Z,1725553593.903 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20000223T202135/Express0011.lzma 2024-09-05T16:26:34.902Z,1725553594.902 [DataOverHttps](INFO): Moved sent file to Logs/20000223T202135/Express0011.lzma.bak 2024-09-05T16:26:34.902Z,1725553594.902 [DataOverHttps](INFO): SBD MOMSN=23130488 2024-09-05T16:26:39.910Z,1725553599.910 [Default:CheckIn:Read_Iridium] Stopped 2024-09-05T16:26:39.910Z,1725553599.910 [Default:CheckIn:C.Wait] Running Loop=1 2024-09-05T16:26:39.910Z,1725553599.910 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-09-05T16:26:47.332Z,1725553607.332 [DATMMP](INFO): GSXN notify for xid: 0 2024-09-05T16:26:47.333Z,1725553607.333 [DATMMP](INFO): timesync rx: x2 x0 x0 x0 2024-09-05T16:26:47.333Z,1725553607.333 [DATMMP](INFO): Received message type: timesync 2024-09-05T16:26:47.333Z,1725553607.333 [DATMMP](INFO): Handled 2024-09-05T16:26:57.420Z,1725553617.420 [DATMMP](INFO): GSXN notify for xid: 0 2024-09-05T16:26:57.421Z,1725553617.421 [DATMMP](INFO): timesync rx: x2 x1 x1 x0 2024-09-05T16:26:57.421Z,1725553617.421 [DATMMP](INFO): Received message type: timesync 2024-09-05T16:26:57.421Z,1725553617.421 [DATMMP](INFO): Handled 2024-09-05T16:26:57.668Z,1725553617.668 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11 2024-09-05T16:26:57.668Z,1725553617.668 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-09-05T16:26:57.680Z,1725553617.680 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-09-05T16:26:58.084Z,1725553618.084 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-09-05T16:26:58.084Z,1725553618.084 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11 2024-09-05T16:27:07.248Z,1725553627.248 [DATMMP](INFO): GSXN notify for xid: 0 2024-09-05T16:27:08.179Z,1725553628.179 [DATMMP](INFO): timesync rx: x1 x0 x1 x0 2024-09-05T16:27:08.180Z,1725553628.180 [DATMMP](INFO): Received message type: timesync 2024-09-05T16:27:08.180Z,1725553628.180 [DATMMP](INFO): Handled 2024-09-05T16:28:58.453Z,1725553738.453 [NAL9602](FAULT): GPS failed to acquire within timeout. 2024-09-05T16:28:58.453Z,1725553738.453 [NAL9602] Data Fault, FailCount= 4 2024-09-05T16:28:58.454Z,1725553738.454 [NAL9602](ERROR): Data Fault 2024-09-05T16:28:58.471Z,1725553738.471 [CBIT](ERROR): Data Fault in component: NAL9602 2024-09-05T16:28:58.857Z,1725553738.857 [NAL9602](INFO): Powering down 2024-09-05T16:28:59.682Z,1725553739.682 [CBIT](INFO): Clearing failed state for component NAL9602 2024-09-05T16:28:59.682Z,1725553739.682 [NAL9602] No Fault, FailCount= 4 2024-09-05T16:29:29.156Z,1725553769.156 [NAL9602](INFO): Powering up NAL9602 2024-09-05T16:29:40.078Z,1725553780.078 [NAL9602](INFO): NAL9602 initialized 2024-09-05T16:29:58.664Z,1725553798.664 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12 2024-09-05T16:29:58.665Z,1725553798.665 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-09-05T16:29:58.675Z,1725553798.675 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-09-05T16:29:59.076Z,1725553799.076 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-09-05T16:29:59.077Z,1725553799.077 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12 2024-09-05T16:31:40.465Z,1725553900.465 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-09-05T16:31:40.465Z,1725553900.465 [Default:CheckIn:C.Wait] Stopped 2024-09-05T16:31:40.465Z,1725553900.465 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-09-05T16:31:40.465Z,1725553900.465 [Default:CheckIn:D] Running Loop=1 2024-09-05T16:31:40.868Z,1725553900.868 [Default:CheckIn:D] Stopped 2024-09-05T16:31:40.869Z,1725553900.869 [Default:CheckIn:E] Running Loop=1 2024-09-05T16:31:41.293Z,1725553901.293 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.958704 min 2024-09-05T16:31:41.293Z,1725553901.293 [Default:CheckIn:E] Stopped 2024-09-05T16:31:41.293Z,1725553901.293 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-09-05T16:31:41.293Z,1725553901.293 [Default:CheckIn] Stopped 2024-09-05T16:31:41.293Z,1725553901.293 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-09-05T16:31:41.294Z,1725553901.294 [Default:CheckIn](INFO): Running loop #4 2024-09-05T16:31:41.294Z,1725553901.294 [Default:CheckIn] Running Loop=4 2024-09-05T16:31:41.294Z,1725553901.294 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-09-05T16:31:41.294Z,1725553901.294 [Default:CheckIn:Read_GPS] Running Loop=1 2024-09-05T16:32:59.649Z,1725553979.649 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13 2024-09-05T16:32:59.649Z,1725553979.649 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-09-05T16:32:59.660Z,1725553979.660 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-09-05T16:33:00.081Z,1725553980.081 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-09-05T16:33:00.081Z,1725553980.081 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13 2024-09-05T16:36:00.672Z,1725554160.672 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 14 2024-09-05T16:36:00.672Z,1725554160.672 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-09-05T16:36:00.683Z,1725554160.683 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-09-05T16:36:01.064Z,1725554161.064 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-09-05T16:36:01.064Z,1725554161.064 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 14 2024-09-05T16:36:41.446Z,1725554201.446 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-09-05T16:31:41.3Z 2024-09-05T16:36:41.446Z,1725554201.446 [Default:CheckIn:Read_GPS] Stopped 2024-09-05T16:36:41.446Z,1725554201.446 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-09-05T16:36:49.010Z,1725554209.010 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20000223T202135/Courier0013.lzma 2024-09-05T16:36:50.012Z,1725554210.012 [DataOverHttps](INFO): Moved sent file to Logs/20000223T202135/Courier0013.lzma.bak 2024-09-05T16:36:50.013Z,1725554210.013 [DataOverHttps](INFO): SBD MOMSN=23130543 2024-09-05T16:37:07.638Z,1725554227.638 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20000223T202135/Express0014.lzma 2024-09-05T16:37:08.640Z,1725554228.640 [DataOverHttps](INFO): Moved sent file to Logs/20000223T202135/Express0014.lzma.bak 2024-09-05T16:37:08.641Z,1725554228.641 [DataOverHttps](INFO): SBD MOMSN=23130545 2024-09-05T16:37:13.630Z,1725554233.630 [Default:CheckIn:Read_Iridium] Stopped 2024-09-05T16:37:13.630Z,1725554233.630 [Default:CheckIn:C.Wait] Running Loop=1 2024-09-05T16:37:13.630Z,1725554233.630 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-09-05T16:39:01.509Z,1725554341.509 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 15 2024-09-05T16:39:01.509Z,1725554341.509 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-09-05T16:39:01.520Z,1725554341.520 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-09-05T16:39:01.926Z,1725554341.926 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-09-05T16:39:01.926Z,1725554341.926 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 15 2024-09-05T16:39:42.282Z,1725554382.282 [NAL9602](FAULT): GPS failed to acquire within timeout. 2024-09-05T16:39:42.282Z,1725554382.282 [NAL9602] Data Fault, FailCount= 5 2024-09-05T16:39:42.282Z,1725554382.282 [NAL9602](ERROR): Data Fault 2024-09-05T16:39:42.323Z,1725554382.323 [CBIT](ERROR): Data Fault in component: NAL9602 2024-09-05T16:39:42.328Z,1725554382.328 [CBIT](CRITICAL): Data Fault in component: NAL9602 2024-09-05T16:39:42.689Z,1725554382.689 [NAL9602](INFO): Powering down 2024-09-05T16:39:42.706Z,1725554382.706 [CommandExec](FAULT): Scheduling is paused 2024-09-05T16:39:42.706Z,1725554382.706 [CBIT](INFO): Critical error at 20240905T163942 2024-09-05T16:39:42.706Z,1725554382.706 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2024-09-05T16:41:42.327Z,1725554502.327 [CBIT](INFO): Clearing failed state for component NAL9602 2024-09-05T16:41:42.328Z,1725554502.328 [NAL9602] No Fault, FailCount= 5 2024-09-05T16:41:42.681Z,1725554502.681 [NAL9602](INFO): Powering up NAL9602 2024-09-05T16:41:53.591Z,1725554513.591 [NAL9602](INFO): NAL9602 initialized 2024-09-05T16:42:02.550Z,1725554522.550 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 16 2024-09-05T16:42:02.550Z,1725554522.550 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-09-05T16:42:02.591Z,1725554522.591 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-09-05T16:42:02.958Z,1725554522.958 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-09-05T16:42:02.958Z,1725554522.958 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 16 2024-09-05T16:42:14.225Z,1725554534.225 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-09-05T16:42:14.225Z,1725554534.225 [Default:CheckIn:C.Wait] Stopped 2024-09-05T16:42:14.225Z,1725554534.225 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-09-05T16:42:14.225Z,1725554534.225 [Default:CheckIn:D] Running Loop=1 2024-09-05T16:42:14.626Z,1725554534.626 [Default:CheckIn:D] Stopped 2024-09-05T16:42:14.626Z,1725554534.626 [Default:CheckIn:E] Running Loop=1 2024-09-05T16:42:15.011Z,1725554535.011 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.521330 min 2024-09-05T16:42:15.011Z,1725554535.011 [Default:CheckIn:E] Stopped 2024-09-05T16:42:15.011Z,1725554535.011 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-09-05T16:42:15.011Z,1725554535.011 [Default:CheckIn] Stopped 2024-09-05T16:42:15.011Z,1725554535.011 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-09-05T16:42:15.011Z,1725554535.011 [Default:CheckIn](INFO): Running loop #5 2024-09-05T16:42:15.011Z,1725554535.011 [Default:CheckIn] Running Loop=5 2024-09-05T16:42:15.011Z,1725554535.011 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-09-05T16:42:15.011Z,1725554535.011 [Default:CheckIn:Read_GPS] Running Loop=1 2024-09-05T16:42:52.693Z,1725554572.693 [CommandExec](IMPORTANT): got command strobe off 2024-09-05T16:42:52.693Z,1725554572.693 [CommandExec](IMPORTANT): Deactivating strobe 2024-09-05T16:45:03.477Z,1725554703.477 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 17 2024-09-05T16:45:03.477Z,1725554703.477 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-09-05T16:45:03.487Z,1725554703.487 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-09-05T16:45:03.907Z,1725554703.907 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-09-05T16:45:03.907Z,1725554703.907 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 17 2024-09-05T16:47:15.332Z,1725554835.332 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-09-05T16:42:15.0Z 2024-09-05T16:47:15.332Z,1725554835.332 [Default:CheckIn:Read_GPS] Stopped 2024-09-05T16:47:15.332Z,1725554835.332 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-09-05T16:47:22.860Z,1725554842.860 [DataOverHttps](INFO): Sending 105 bytes from file Logs/20000223T202135/Courier0016.lzma 2024-09-05T16:47:23.860Z,1725554843.860 [DataOverHttps](INFO): Moved sent file to Logs/20000223T202135/Courier0016.lzma.bak 2024-09-05T16:47:23.860Z,1725554843.860 [DataOverHttps](INFO): SBD MOMSN=23130568 2024-09-05T16:47:41.610Z,1725554861.610 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20000223T202135/Express0017.lzma 2024-09-05T16:47:42.612Z,1725554862.612 [DataOverHttps](INFO): Moved sent file to Logs/20000223T202135/Express0017.lzma.bak 2024-09-05T16:47:42.612Z,1725554862.612 [DataOverHttps](INFO): SBD MOMSN=23130571 2024-09-05T16:47:48.831Z,1725554868.831 [Default:CheckIn:Read_Iridium] Stopped 2024-09-05T16:4