2024-07-26T00:35:30.481Z,1721954130.481 [Supervisor](DEBUG): Initializing supervisor. 2024-07-26T00:35:30.485Z,1721954130.485 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2024-07-26T00:35:30.485Z,1721954130.485 [SyncHandler](INFO): Protected caller Thread ID is 841 2024-07-26T00:35:30.486Z,1721954130.486 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2024-07-26T00:35:30.487Z,1721954130.487 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2024-07-26T00:35:30.487Z,1721954130.487 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 842 2024-07-26T00:35:30.491Z,1721954130.491 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2024-07-26T00:35:30.508Z,1721954130.508 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2024-07-26T00:35:30.509Z,1721954130.509 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2024-07-26T00:35:30.509Z,1721954130.509 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 843 2024-07-26T00:35:30.514Z,1721954130.514 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2024-07-26T00:35:30.515Z,1721954130.515 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2024-07-26T00:35:30.515Z,1721954130.515 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 844 2024-07-26T00:35:30.517Z,1721954130.517 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2024-07-26T00:35:30.518Z,1721954130.518 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2024-07-26T00:35:30.518Z,1721954130.518 [logger ThreadHandler](INFO): Protected caller Thread ID is 845 2024-07-26T00:35:30.522Z,1721954130.522 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2024-07-26T00:35:30.522Z,1721954130.522 [Supervisor](INFO): Looking for Config files in directory: Config/ 2024-07-26T00:35:30.526Z,1721954130.526 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2024-07-26T00:35:30.635Z,1721954130.635 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2024-07-26T00:35:30.637Z,1721954130.637 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2024-07-26T00:35:31.429Z,1721954131.429 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2024-07-26T00:35:31.431Z,1721954131.431 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2024-07-26T00:35:31.680Z,1721954131.680 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2024-07-26T00:35:31.682Z,1721954131.682 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2024-07-26T00:35:31.773Z,1721954131.773 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2024-07-26T00:35:31.918Z,1721954131.918 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2024-07-26T00:35:31.920Z,1721954131.920 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2024-07-26T00:35:32.014Z,1721954132.014 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2024-07-26T00:35:32.134Z,1721954132.134 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2024-07-26T00:35:32.136Z,1721954132.136 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2024-07-26T00:35:32.554Z,1721954132.554 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2024-07-26T00:35:32.556Z,1721954132.556 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2024-07-26T00:35:33.369Z,1721954133.369 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2024-07-26T00:35:33.371Z,1721954133.371 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2024-07-26T00:35:33.609Z,1721954133.609 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2024-07-26T00:35:33.611Z,1721954133.611 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2024-07-26T00:35:33.813Z,1721954133.813 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2024-07-26T00:35:33.815Z,1721954133.815 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2024-07-26T00:35:34.379Z,1721954134.379 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2024-07-26T00:35:34.381Z,1721954134.381 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2024-07-26T00:35:34.691Z,1721954134.691 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2024-07-26T00:35:34.692Z,1721954134.692 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2024-07-26T00:35:34.940Z,1721954134.940 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2024-07-26T00:35:34.941Z,1721954134.941 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2024-07-26T00:35:35.353Z,1721954135.353 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2024-07-26T00:35:35.353Z,1721954135.353 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2024-07-26T00:35:35.724Z,1721954135.724 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2024-07-26T00:35:35.726Z,1721954135.726 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/ 2024-07-26T00:35:35.728Z,1721954135.728 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg 2024-07-26T00:35:35.824Z,1721954135.824 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg 2024-07-26T00:35:36.010Z,1721954136.010 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Dock.cfg 2024-07-26T00:35:36.159Z,1721954136.159 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/workSite.cfg 2024-07-26T00:35:36.269Z,1721954136.269 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg 2024-07-26T00:35:36.389Z,1721954136.389 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg 2024-07-26T00:35:36.487Z,1721954136.487 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg 2024-07-26T00:35:36.594Z,1721954136.594 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg 2024-07-26T00:35:36.719Z,1721954136.719 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg 2024-07-26T00:35:36.997Z,1721954136.997 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2024-07-26T00:35:36.997Z,1721954136.997 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg 2024-07-26T00:35:37.104Z,1721954137.104 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg 2024-07-26T00:35:37.209Z,1721954137.209 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg 2024-07-26T00:35:37.365Z,1721954137.365 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg 2024-07-26T00:35:37.475Z,1721954137.475 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2024-07-26T00:35:37.481Z,1721954137.481 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2024-07-26T00:35:37.627Z,1721954137.627 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2024-07-26T00:35:37.629Z,1721954137.629 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2024-07-26T00:35:37.700Z,1721954137.700 [VerticalControl](DEBUG): Construct VerticalControl. 2024-07-26T00:35:37.760Z,1721954137.760 [VerticalControl] Loaded 2024-07-26T00:35:37.760Z,1721954137.760 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2024-07-26T00:35:37.763Z,1721954137.763 [HorizontalControl](DEBUG): Construct HorizontalControl. 2024-07-26T00:35:37.810Z,1721954137.810 [HorizontalControl] Loaded 2024-07-26T00:35:37.810Z,1721954137.810 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2024-07-26T00:35:37.813Z,1721954137.813 [SpeedControl](DEBUG): Construct SpeedControl. 2024-07-26T00:35:37.816Z,1721954137.816 [SpeedControl] Loaded 2024-07-26T00:35:37.816Z,1721954137.816 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2024-07-26T00:35:37.818Z,1721954137.818 [LoopControl](DEBUG): Construct LoopControl. 2024-07-26T00:35:37.819Z,1721954137.819 [LoopControl] Loaded 2024-07-26T00:35:37.819Z,1721954137.819 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2024-07-26T00:35:37.820Z,1721954137.820 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2024-07-26T00:35:37.820Z,1721954137.820 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2024-07-26T00:35:37.890Z,1721954137.890 [DepthRateCalculator] Loaded 2024-07-26T00:35:37.891Z,1721954137.891 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2024-07-26T00:35:37.895Z,1721954137.895 [PitchRateCalculator] Loaded 2024-07-26T00:35:37.896Z,1721954137.896 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2024-07-26T00:35:37.906Z,1721954137.906 [SpeedCalculator] Loaded 2024-07-26T00:35:37.906Z,1721954137.906 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2024-07-26T00:35:37.910Z,1721954137.910 [YawRateCalculator] Loaded 2024-07-26T00:35:37.910Z,1721954137.910 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2024-07-26T00:35:37.928Z,1721954137.928 [ElevatorOffsetCalculator] Loaded 2024-07-26T00:35:37.929Z,1721954137.929 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2024-07-26T00:35:37.929Z,1721954137.929 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2024-07-26T00:35:37.930Z,1721954137.930 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2024-07-26T00:35:37.973Z,1721954137.973 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2024-07-26T00:35:37.974Z,1721954137.974 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2024-07-26T00:35:38.056Z,1721954138.056 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2024-07-26T00:35:38.056Z,1721954138.056 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2024-07-26T00:35:38.455Z,1721954138.455 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2024-07-26T00:35:38.456Z,1721954138.456 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2024-07-26T00:35:38.972Z,1721954138.972 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2024-07-26T00:35:38.973Z,1721954138.973 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2024-07-26T00:35:40.182Z,1721954140.182 [AHRS_M2] Loaded 2024-07-26T00:35:40.182Z,1721954140.182 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2024-07-26T00:35:40.435Z,1721954140.435 [BackseatComponent] Loaded 2024-07-26T00:35:40.435Z,1721954140.435 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2024-07-26T00:35:40.437Z,1721954140.437 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 409C54E0 2024-07-26T00:35:40.437Z,1721954140.437 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 933 2024-07-26T00:35:40.440Z,1721954140.440 [LcmUniversalReporter] Loaded 2024-07-26T00:35:40.440Z,1721954140.440 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2024-07-26T00:35:41.249Z,1721954141.249 [BPC1] Loaded 2024-07-26T00:35:41.249Z,1721954141.249 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2024-07-26T00:35:41.389Z,1721954141.389 [DataOverHttps] Loaded 2024-07-26T00:35:41.389Z,1721954141.389 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2024-07-26T00:35:41.390Z,1721954141.390 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409F54E0 2024-07-26T00:35:41.390Z,1721954141.390 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 934 2024-07-26T00:35:41.413Z,1721954141.413 [Depth_Keller] Loaded 2024-07-26T00:35:41.413Z,1721954141.413 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2024-07-26T00:35:41.418Z,1721954141.418 [DropWeight] Loaded 2024-07-26T00:35:41.419Z,1721954141.419 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2024-07-26T00:35:41.482Z,1721954141.482 [NAL9602] Loaded 2024-07-26T00:35:41.482Z,1721954141.482 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2024-07-26T00:35:41.512Z,1721954141.512 [Onboard] Loaded 2024-07-26T00:35:41.512Z,1721954141.512 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2024-07-26T00:35:41.513Z,1721954141.513 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40A254E0 2024-07-26T00:35:41.513Z,1721954141.513 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 935 2024-07-26T00:35:41.527Z,1721954141.527 [Power24vConverter] Loaded 2024-07-26T00:35:41.527Z,1721954141.527 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2024-07-26T00:35:41.543Z,1721954141.543 [Radio_Surface] Loaded 2024-07-26T00:35:41.543Z,1721954141.543 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2024-07-26T00:35:41.544Z,1721954141.544 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40A554E0 2024-07-26T00:35:41.545Z,1721954141.545 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 936 2024-07-26T00:35:41.591Z,1721954141.591 [RDI_Pathfinder] Loaded 2024-07-26T00:35:41.591Z,1721954141.591 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread. 2024-07-26T00:35:41.606Z,1721954141.606 [Sonardyne_Nano] Loaded 2024-07-26T00:35:41.607Z,1721954141.607 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread. 2024-07-26T00:35:41.701Z,1721954141.701 [DAT] Loaded 2024-07-26T00:35:41.701Z,1721954141.701 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2024-07-26T00:35:41.702Z,1721954141.702 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40A854E0 2024-07-26T00:35:41.702Z,1721954141.702 [DAT ThreadHandler](INFO): Protected caller Thread ID is 937 2024-07-26T00:35:41.703Z,1721954141.703 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2024-07-26T00:35:41.704Z,1721954141.704 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2024-07-26T00:35:41.840Z,1721954141.840 [DeadReckonUsingMultipleVelocitySources] Loaded 2024-07-26T00:35:41.841Z,1721954141.841 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2024-07-26T00:35:41.854Z,1721954141.854 [NavChart] Loaded 2024-07-26T00:35:41.855Z,1721954141.855 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2024-07-26T00:35:41.860Z,1721954141.860 [UniversalFixResidualReporter] Loaded 2024-07-26T00:35:41.860Z,1721954141.860 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2024-07-26T00:35:41.861Z,1721954141.861 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2024-07-26T00:35:41.861Z,1721954141.861 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2024-07-26T00:35:42.032Z,1721954142.032 [SBIT](DEBUG): Construct Startup Built In Test. 2024-07-26T00:35:42.041Z,1721954142.041 [SBIT] Loaded 2024-07-26T00:35:42.041Z,1721954142.041 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2024-07-26T00:35:42.044Z,1721954142.044 [IBIT](DEBUG): Construct Initiated Built In Test. 2024-07-26T00:35:42.056Z,1721954142.056 [IBIT] Loaded 2024-07-26T00:35:42.057Z,1721954142.057 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2024-07-26T00:35:42.062Z,1721954142.062 [CBIT](DEBUG): Construct Continuous Built In Test. 2024-07-26T00:35:42.167Z,1721954142.167 [CBIT] Loaded 2024-07-26T00:35:42.167Z,1721954142.167 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2024-07-26T00:35:42.168Z,1721954142.168 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2024-07-26T00:35:42.168Z,1721954142.168 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2024-07-26T00:35:42.331Z,1721954142.331 [BuoyancyServo] Loaded 2024-07-26T00:35:42.332Z,1721954142.332 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2024-07-26T00:35:42.355Z,1721954142.355 [ElevatorServo] Loaded 2024-07-26T00:35:42.355Z,1721954142.355 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2024-07-26T00:35:42.385Z,1721954142.385 [DockingStepper] Loaded 2024-07-26T00:35:42.385Z,1721954142.385 [ComponentRegistry](DEBUG): SyncComponent "DockingStepper" handled in the control thread. 2024-07-26T00:35:42.407Z,1721954142.407 [MassServo] Loaded 2024-07-26T00:35:42.407Z,1721954142.407 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2024-07-26T00:35:42.427Z,1721954142.427 [RudderServo] Loaded 2024-07-26T00:35:42.428Z,1721954142.428 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2024-07-26T00:35:42.446Z,1721954142.446 [ThrusterServo] Loaded 2024-07-26T00:35:42.446Z,1721954142.446 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2024-07-26T00:35:42.447Z,1721954142.447 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2024-07-26T00:35:42.447Z,1721954142.447 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2024-07-26T00:35:42.463Z,1721954142.463 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2024-07-26T00:35:42.464Z,1721954142.464 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2024-07-26T00:35:42.687Z,1721954142.687 [CTD_Seabird] Loaded 2024-07-26T00:35:42.687Z,1721954142.687 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2024-07-26T00:35:42.688Z,1721954142.688 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40BD94E0 2024-07-26T00:35:42.689Z,1721954142.689 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 938 2024-07-26T00:35:42.711Z,1721954142.711 [PAR_Licor] Loaded 2024-07-26T00:35:42.711Z,1721954142.711 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2024-07-26T00:35:42.755Z,1721954142.755 [WetLabsBB2FL] Loaded 2024-07-26T00:35:42.756Z,1721954142.756 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2024-07-26T00:35:42.757Z,1721954142.757 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40C094E0 2024-07-26T00:35:42.757Z,1721954142.757 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 939 2024-07-26T00:35:42.778Z,1721954142.778 [WetLabsUBAT] Loaded 2024-07-26T00:35:42.778Z,1721954142.778 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread. 2024-07-26T00:35:42.779Z,1721954142.779 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40C394E0 2024-07-26T00:35:42.780Z,1721954142.780 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 940 2024-07-26T00:35:42.780Z,1721954142.780 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2024-07-26T00:35:42.787Z,1721954142.787 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2024-07-26T00:35:42.790Z,1721954142.790 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2024-07-26T00:35:42.801Z,1721954142.801 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2024-07-26T00:35:42.802Z,1721954142.802 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C694E0 2024-07-26T00:35:42.802Z,1721954142.802 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 941 2024-07-26T00:35:42.807Z,1721954142.807 [Supervisor](INFO): Main Thread ID is 832 2024-07-26T00:35:42.807Z,1721954142.807 [Supervisor](DEBUG): Running supervisor. 2024-07-26T00:35:42.807Z,1721954142.807 [CommandExec ThreadHandler](INFO): Handler Thread ID is 942 2024-07-26T00:35:42.808Z,1721954142.808 [CommandExec](INFO): Initializing the command executive. 2024-07-26T00:35:42.809Z,1721954142.809 [CommandLine ThreadHandler](INFO): Handler Thread ID is 943 2024-07-26T00:35:42.811Z,1721954142.811 [controlThread ThreadHandler](INFO): Handler Thread ID is 944 2024-07-26T00:35:42.812Z,1721954142.812 [controlThread](DEBUG): Initializing ControlThread 2024-07-26T00:35:42.813Z,1721954142.813 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2024-07-26T00:35:42.814Z,1721954142.814 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2024-07-26T00:35:42.815Z,1721954142.815 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2024-07-26T00:35:42.815Z,1721954142.815 [LoopControl](DEBUG): Initialize LoopControlComponent. 2024-07-26T00:35:42.816Z,1721954142.816 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2024-07-26T00:35:42.816Z,1721954142.816 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2024-07-26T00:35:42.817Z,1721954142.817 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2024-07-26T00:35:42.817Z,1721954142.817 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2024-07-26T00:35:42.817Z,1721954142.817 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2024-07-26T00:35:42.822Z,1721954142.822 [NavChart](DEBUG): Initialize NavChart Navigation. 2024-07-26T00:35:42.823Z,1721954142.823 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2024-07-26T00:35:42.823Z,1721954142.823 [SBIT](INFO): Initialize SBIT Component. 2024-07-26T00:35:42.823Z,1721954142.823 [SBIT](IMPORTANT): git: 2024-07-22 2024-07-26T00:35:42.824Z,1721954142.824 [SBIT](INFO): git hash: e1b6f6712780a14e9094a1a5fcaaf0d5e88f6716 2024-07-26T00:35:42.824Z,1721954142.824 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2024-07-26T00:35:42.825Z,1721954142.825 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019 Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021 2024-07-26T00:35:42.826Z,1721954142.826 [SBIT](INFO): Beginning SBIT in 46.000000 seconds. 2024-07-26T00:35:42.827Z,1721954142.827 [IBIT](INFO): Initialize IBIT Component. 2024-07-26T00:35:42.828Z,1721954142.828 [CBIT](DEBUG): Initialize CBIT Component. 2024-07-26T00:35:42.829Z,1721954142.829 [logger ThreadHandler](INFO): Handler Thread ID is 945 2024-07-26T00:35:42.840Z,1721954142.840 [CBIT](DEBUG): Initialized mux pins. 2024-07-26T00:35:42.840Z,1721954142.840 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2024-07-26T00:35:42.840Z,1721954142.840 [CBIT](DEBUG): Initializing the watchdog timer. 2024-07-26T00:35:42.848Z,1721954142.848 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 946 2024-07-26T00:35:42.860Z,1721954142.860 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 947 2024-07-26T00:35:42.862Z,1721954142.862 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2024-07-26T00:35:42.864Z,1721954142.864 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET. 2024-07-26T00:35:42.864Z,1721954142.864 [CBIT](DEBUG): Initializing heartbeat. 2024-07-26T00:35:42.872Z,1721954142.872 [Onboard ThreadHandler](INFO): Handler Thread ID is 948 2024-07-26T00:35:42.890Z,1721954142.890 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 949 2024-07-26T00:35:42.913Z,1721954142.913 [DAT ThreadHandler](INFO): Handler Thread ID is 950 2024-07-26T00:35:42.913Z,1721954142.913 [DAT](INFO): Powering up 2024-07-26T00:35:42.914Z,1721954142.914 [DAT](DEBUG): Initializing DAT. 2024-07-26T00:35:42.917Z,1721954142.917 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 952 2024-07-26T00:35:42.918Z,1721954142.918 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2024-07-26T00:35:42.921Z,1721954142.921 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 954 2024-07-26T00:35:42.924Z,1721954142.924 [WetLabsBB2FL](INFO): Powering up 2024-07-26T00:35:42.926Z,1721954142.926 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 956 2024-07-26T00:35:42.929Z,1721954142.929 [WetLabsUBAT](INFO): Powering up 2024-07-26T00:35:42.930Z,1721954142.930 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 958 2024-07-26T00:35:42.936Z,1721954142.936 [CBIT](DEBUG): Deactivating GF circuits. 2024-07-26T00:35:42.936Z,1721954142.936 [CBIT](DEBUG): Deactivating emergency mode. 2024-07-26T00:35:42.938Z,1721954142.938 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2024-07-26T00:35:42.939Z,1721954142.939 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2024-07-26T00:35:42.939Z,1721954142.939 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2024-07-26T00:35:42.939Z,1721954142.939 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2024-07-26T00:35:42.939Z,1721954142.939 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2024-07-26T00:35:42.939Z,1721954142.939 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2024-07-26T00:35:42.939Z,1721954142.939 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2024-07-26T00:35:42.940Z,1721954142.940 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2024-07-26T00:35:42.980Z,1721954142.980 [CBIT](DEBUG): Backplane powered. 2024-07-26T00:35:42.984Z,1721954142.984 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2024-07-26T00:35:42.985Z,1721954142.985 [MissionManager](INFO): Loading Mission from file: Missions/underIce/StartupUnder.tl 2024-07-26T00:35:42.985Z,1721954142.985 [MissionManager](DEBUG): TethyslAPI: loading: Missions/underIce/StartupUnder.tl 2024-07-26T00:35:43.009Z,1721954143.009 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/underIce/StartupUnder.tl 2024-07-26T00:35:43.026Z,1721954143.026 [MissionManager](DEBUG): TethyslAPI: Missions/underIce/StartupUnder.tl translated into: 2024-07-26T00:35:43.027Z,1721954143.027 [MissionManager](ERROR): Top node has no child nodes: Mission 2024-07-26T00:35:43.027Z,1721954143.027 [MissionManager](ERROR): Could not load startup mission. 2024-07-26T00:35:43.027Z,1721954143.027 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl 2024-07-26T00:35:43.028Z,1721954143.028 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl 2024-07-26T00:35:43.032Z,1721954143.032 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl 2024-07-26T00:35:43.275Z,1721954143.275 [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 2024-07-26T00:35:43.293Z,1721954143.293 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2024-07-26T00:35:43.294Z,1721954143.294 [Default:A.Wait](DEBUG): Construct Wait. 2024-07-26T00:35:43.296Z,1721954143.296 [Radio_Surface](INFO): Powering up 2024-07-26T00:35:43.303Z,1721954143.303 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2024-07-26T00:35:43.339Z,1721954143.339 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2024-07-26T00:35:43.366Z,1721954143.366 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2024-07-26T00:35:43.388Z,1721954143.388 [Default:E.Execute](DEBUG): Construct Execute. 2024-07-26T00:35:43.391Z,1721954143.391 [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" } } 2024-07-26T00:35:43.396Z,1721954143.396 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,RDI_Pathfinder,Sonardyne_Nano,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,DockingStepper,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2024-07-26T00:35:43.402Z,1721954143.402 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2024-07-26T00:35:43.549Z,1721954143.549 [Depth_Keller](ERROR): Pressure or depth reading out of range: -1.000394 decibar, -0.993022 m 2024-07-26T00:35:43.551Z,1721954143.551 [Power24vConverter](INFO): Powering up. 2024-07-26T00:35:43.551Z,1721954143.551 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format 2024-07-26T00:35:43.561Z,1721954143.561 [Sonardyne_Nano](INFO): Initializing. 2024-07-26T00:35:43.608Z,1721954143.608 [DepthRateCalculator](ERROR): Depth measurement is not active 2024-07-26T00:35:43.634Z,1721954143.634 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2024-07-26T00:35:43.641Z,1721954143.641 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2024-07-26T00:35:43.642Z,1721954143.642 [ElevatorServo](DEBUG): Initializing EZServoServo. 2024-07-26T00:35:43.648Z,1721954143.648 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2024-07-26T00:35:43.649Z,1721954143.649 [DockingStepper](INFO): Start 2024-07-26T00:35:43.649Z,1721954143.649 [DockingStepper](DEBUG): Initializing EZServoServo. 2024-07-26T00:35:43.656Z,1721954143.656 [DockingStepper](DEBUG): Initializing DockingStepper. 2024-07-26T00:35:43.657Z,1721954143.657 [MassServo](DEBUG): Initializing EZServoServo. 2024-07-26T00:35:43.665Z,1721954143.665 [MassServo](DEBUG): Initializing MassServo. 2024-07-26T00:35:43.665Z,1721954143.665 [RudderServo](DEBUG): Initializing EZServoServo. 2024-07-26T00:35:43.672Z,1721954143.672 [RudderServo](DEBUG): Initializing RudderServo. 2024-07-26T00:35:43.673Z,1721954143.673 [ThrusterServo](DEBUG): Initializing EZServoServo. 2024-07-26T00:35:43.680Z,1721954143.680 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2024-07-26T00:35:43.682Z,1721954143.682 [CommandExec](FAULT): Scheduling is paused 2024-07-26T00:35:43.682Z,1721954143.682 [CBIT](INFO): Critical error at 20240726T003542 2024-07-26T00:35:43.683Z,1721954143.683 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2024-07-26T00:35:43.893Z,1721954143.893 [DockingStepper](INFO): Starting 2024-07-26T00:35:44.247Z,1721954144.247 [DockingStepper](INFO): Starting 2024-07-26T00:35:44.760Z,1721954144.760 [DockingStepper](INFO): Starting 2024-07-26T00:35:44.809Z,1721954144.809 [DockingStepper](INFO): Init string: /1z16368aE13561N3m50 2024-07-26T00:35:45.039Z,1721954145.039 [DockingStepper](INFO): Starting 2024-07-26T00:35:45.445Z,1721954145.445 [DockingStepper](INFO): Starting 2024-07-26T00:35:45.536Z,1721954145.536 [WetLabsBB2FL](INFO): Powering down 2024-07-26T00:35:45.831Z,1721954145.831 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART 2024-07-26T00:35:45.880Z,1721954145.880 [DockingStepper](INFO): Starting 2024-07-26T00:35:46.308Z,1721954146.308 [DockingStepper](INFO): Starting 2024-07-26T00:35:46.333Z,1721954146.333 [DockingStepper](INFO): Sent speed cmd:/1V10000 Response:ÿ/0@ 2024-07-26T00:35:46.831Z,1721954146.831 [DockingStepper](INFO): Starting 2024-07-26T00:35:47.081Z,1721954147.081 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2103 2024-07-26T00:35:47.517Z,1721954147.517 [DockingStepper](INFO): Pause 2024-07-26T00:35:48.549Z,1721954148.549 [Radio_Surface](INFO): Checking local IP, expecting subnet 10.89.10 2024-07-26T00:35:48.549Z,1721954148.549 [Radio_Surface](INFO): No local IP found 2024-07-26T00:35:52.228Z,1721954152.228 [WetLabsUBAT](INFO): Powering down 2024-07-26T00:35:56.268Z,1721954156.268 [DAT](INFO): DAT read: 2024-07-26T00:35:56.270Z,1721954156.270 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2024-07-26T00:35:58.033Z,1721954158.033 [DAT](INFO): DAT read: MF Frequency Band 2024-07-26T00:35:58.034Z,1721954158.034 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.17.2 2024-07-26T00:35:58.035Z,1721954158.035 [DAT](INFO): DAT read: Jul 26 2024 00:35:14 2024-07-26T00:35:59.041Z,1721954159.041 [DAT](INFO): DAT read: Features enabled [Bearing] 2024-07-26T00:35:59.042Z,1721954159.042 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2024-07-26T00:35:59.042Z,1721954159.042 [DAT](INFO): commRate: 800 2024-07-26T00:36:01.108Z,1721954161.108 [DAT](INFO): entering command mode 2024-07-26T00:36:01.309Z,1721954161.309 [DAT](INFO): DAT read: 2024-07-26T00:36:01.309Z,1721954161.309 [DAT](INFO): DAT read: user1> 2024-07-26T00:36:01.310Z,1721954161.310 [DAT](INFO): unknown deviceResponse_: user1> 2024-07-26T00:36:01.310Z,1721954161.310 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:01.560Z,1721954161.560 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:01.812Z,1721954161.812 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:02.064Z,1721954162.064 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:02.316Z,1721954162.316 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:02.571Z,1721954162.571 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:02.820Z,1721954162.820 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:03.072Z,1721954163.072 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:03.324Z,1721954163.324 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:03.576Z,1721954163.576 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:03.828Z,1721954163.828 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:04.080Z,1721954164.080 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:04.332Z,1721954164.332 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:04.584Z,1721954164.584 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:04.836Z,1721954164.836 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:05.088Z,1721954165.088 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:05.340Z,1721954165.340 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:05.592Z,1721954165.592 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:05.844Z,1721954165.844 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:06.096Z,1721954166.096 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:06.348Z,1721954166.348 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:06.600Z,1721954166.600 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:06.852Z,1721954166.852 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:07.104Z,1721954167.104 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:07.356Z,1721954167.356 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:07.608Z,1721954167.608 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:07.860Z,1721954167.860 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:08.112Z,1721954168.112 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:08.364Z,1721954168.364 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:08.616Z,1721954168.616 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:08.868Z,1721954168.868 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:09.122Z,1721954169.122 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:09.372Z,1721954169.372 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:09.624Z,1721954169.624 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:09.876Z,1721954169.876 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:10.128Z,1721954170.128 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:10.380Z,1721954170.380 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:10.632Z,1721954170.632 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:10.884Z,1721954170.884 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:11.138Z,1721954171.138 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:11.388Z,1721954171.388 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:11.640Z,1721954171.640 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:11.694Z,1721954171.694 [NAL9602](INFO): Powering up NAL9602 2024-07-26T00:36:11.892Z,1721954171.892 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:12.145Z,1721954172.145 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:12.396Z,1721954172.396 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:12.648Z,1721954172.648 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:12.901Z,1721954172.901 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:13.154Z,1721954173.154 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:13.404Z,1721954173.404 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:13.656Z,1721954173.656 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:13.908Z,1721954173.908 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:14.160Z,1721954174.160 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:14.414Z,1721954174.414 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:14.664Z,1721954174.664 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:14.916Z,1721954174.916 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:15.170Z,1721954175.170 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:15.420Z,1721954175.420 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:15.672Z,1721954175.672 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:15.924Z,1721954175.924 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:16.193Z,1721954176.193 [DAT](DEBUG): checking for command mode acknowledgment 2024-07-26T00:36:16.193Z,1721954176.193 [DAT](FAULT): failed to enter command mode 2024-07-26T00:36:16.496Z,1721954176.496 [DAT](INFO): entering command mode 2024-07-26T00:36:16.697Z,1721954176.697 [DAT](INFO): DAT read: user:1> 2024-07-26T00:36:16.697Z,1721954176.697 [DAT](INFO): DAT read: Command '+++' not found 2024-07-26T00:36:16.698Z,1721954176.698 [DAT](INFO): DAT read: Error 2024-07-26T00:36:16.698Z,1721954176.698 [DAT](INFO): setting verbose to 3 2024-07-26T00:36:16.948Z,1721954176.948 [DAT](INFO): DAT read: user:2> 2024-07-26T00:36:16.949Z,1721954176.949 [DAT](INFO): DAT read: Verbose | 3 2024-07-26T00:36:16.950Z,1721954176.950 [DAT](INFO): set verbose to 3 2024-07-26T00:36:16.950Z,1721954176.950 [DAT](INFO): setting DatVerbose to 27440 2024-07-26T00:36:17.201Z,1721954177.201 [DAT](INFO): DAT read: user:3> 2024-07-26T00:36:17.201Z,1721954177.201 [DAT](INFO): DAT read: DatVerbose | 27440 2024-07-26T00:36:17.202Z,1721954177.202 [DAT](INFO): set DatVerbose to 27440 2024-07-26T00:36:17.202Z,1721954177.202 [DAT](INFO): setting transmit power to 8 2024-07-26T00:36:17.453Z,1721954177.453 [DAT](INFO): DAT read: user:4> 2024-07-26T00:36:17.453Z,1721954177.453 [DAT](INFO): DAT read: TxPower | 8 (Max) 2024-07-26T00:36:17.454Z,1721954177.454 [DAT](INFO): set transmit power to 8 2024-07-26T00:36:17.454Z,1721954177.454 [DAT](INFO): setting local address to 10 2024-07-26T00:36:17.705Z,1721954177.705 [DAT](INFO): DAT read: user:5> 2024-07-26T00:36:17.705Z,1721954177.705 [DAT](INFO): DAT read: LocalAddr | 10 2024-07-26T00:36:17.706Z,1721954177.706 [DAT](INFO): set local address to 10 2024-07-26T00:36:17.707Z,1721954177.707 [DAT](INFO): Setting time to: 0:36:17 And date to:7/26/2024 2024-07-26T00:36:17.957Z,1721954177.957 [DAT](INFO): DAT read: user:6> 2024-07-26T00:36:17.957Z,1721954177.957 [DAT](INFO): DAT read: Fri Jul 26, 2024 00:36:17 2024-07-26T00:36:17.958Z,1721954177.958 [DAT](INFO): Local DAT time set to Fri Jul 26, 2024 00:36:17 2024-07-26T00:36:22.597Z,1721954182.597 [NAL9602](INFO): NAL9602 initialized 2024-07-26T00:36:29.554Z,1721954189.554 [SBIT](IMPORTANT): Beginning Startup BIT 2024-07-26T00:36:29.559Z,1721954189.559 [CBIT](IMPORTANT): Beginning ground fault scan 2024-07-26T00:36:40.425Z,1721954200.425 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.062277 CHAN A1 (24V): 0.114612 CHAN A2 (12V): 0.046376 CHAN A3 (5V): 0.016398 CHAN B0 (3.3V): 0.012483 CHAN B1 (3.15aV): 0.011234 CHAN B2 (3.15bV): 0.012125 CHAN B3 (GND): -0.000550 OPEN: 0.009434 Full Scale: +/- 1 mA 2024-07-26T00:36:44.447Z,1721954204.447 [NAL9602](INFO): SBD MO Status=0, MOMSN=39801, MT Status=0, MTMSN=0 2024-07-26T00:36:44.447Z,1721954204.447 [NAL9602](INFO): No messages in MT queue 2024-07-26T00:37:23.633Z,1721954243.633 [SBIT](IMPORTANT): SBIT PASSED 2024-07-26T00:37:23.633Z,1721954243.633 [SBIT](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2024-07-26T00:37:24.018Z,1721954244.018 [MissionManager](IMPORTANT): Started mission Default 2024-07-26T00:37:24.019Z,1721954244.019 [Default] Running Loop=1 2024-07-26T00:37:24.019Z,1721954244.019 [Default](DEBUG): Aggregate::initialize Default 2024-07-26T00:37:24.019Z,1721954244.019 [Default:B.GoToSurface] Running Loop=1 2024-07-26T00:37:24.019Z,1721954244.019 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2024-07-26T00:37:24.019Z,1721954244.019 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2024-07-26T00:37:24.021Z,1721954244.021 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2024-07-26T00:37:24.021Z,1721954244.021 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2024-07-26T00:37:24.022Z,1721954244.022 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2024-07-26T00:37:24.022Z,1721954244.022 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2024-07-26T00:37:24.022Z,1721954244.022 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2024-07-26T00:37:24.023Z,1721954244.023 [Default:A.Wait] Running Loop=1 2024-07-26T00:37:24.023Z,1721954244.023 [Default:A.Wait](DEBUG): Initialize Wait Component. 2024-07-26T00:37:37.375Z,1721954257.375 [Default:A.Wait](INFO): Done Waiting. 2024-07-26T00:37:37.375Z,1721954257.375 [Default:A.Wait] Stopped 2024-07-26T00:37:37.375Z,1721954257.375 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2024-07-26T00:37:37.782Z,1721954257.782 [Default:CheckIn] Running Loop=1 2024-07-26T00:37:37.782Z,1721954257.782 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-07-26T00:37:37.782Z,1721954257.782 [Default:CheckIn:Read_GPS] Running Loop=1 2024-07-26T00:37:38.250Z,1721954258.250 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2024-07-26T00:37:50.272Z,1721954270.272 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,003748.00,A,3649.38623,N,12152.60638,W,17.067,282.68,260724,,,A*4A 2024-07-26T00:37:50.275Z,1721954270.275 [NAL9602](INFO): GPS fix at 20240726T003748: (36.823104, -121.876773) 2024-07-26T00:37:50.287Z,1721954270.287 [Default:CheckIn:Read_GPS] Stopped 2024-07-26T00:37:50.287Z,1721954270.287 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-07-26T00:37:50.700Z,1721954270.700 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2024-07-26T00:38:09.738Z,1721954289.738 [NAL9602](INFO): SBD MO Status=1, MOMSN=39802, MT Status=0, MTMSN=0 2024-07-26T00:38:09.876Z,1721954289.876 [NAL9602](INFO): Sent 18 bytes from file Logs/20240725T232836/Courier0031.lzma 2024-07-26T00:38:09.876Z,1721954289.876 [NAL9602](INFO): Packets left to send: 0 2024-07-26T00:38:28.127Z,1721954308.127 [NAL9602](INFO): SBD MO Status=1, MOMSN=39803, MT Status=0, MTMSN=0 2024-07-26T00:38:28.180Z,1721954308.180 [NAL9602](INFO): Sent 331 bytes from file Logs/20240726T003530/Courier0000.lzma 2024-07-26T00:38:28.180Z,1721954308.180 [NAL9602](INFO): Packets left to send: 0 2024-07-26T00:38:36.315Z,1721954316.315 [NAL9602](INFO): SBD MO Status=1, MOMSN=39804, MT Status=0, MTMSN=0 2024-07-26T00:38:36.366Z,1721954316.366 [NAL9602](INFO): Sent 18 bytes from file Logs/20240725T232836/Express0032.lzma 2024-07-26T00:38:36.366Z,1721954316.366 [NAL9602](INFO): Packets left to send: 0 2024-07-26T00:38:42.656Z,1721954322.656 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2024-07-26T00:38:44.488Z,1721954324.488 [NAL9602](INFO): SBD MO Status=1, MOMSN=39805, MT Status=0, MTMSN=0 2024-07-26T00:38:44.538Z,1721954324.538 [NAL9602](INFO): Sent 332 bytes from file Logs/20240726T003530/Express0001.lzma 2024-07-26T00:38:44.538Z,1721954324.538 [NAL9602](INFO): Packets left to send: 2 2024-07-26T00:38:59.530Z,1721954339.530 [NAL9602](INFO): SBD MO Status=2, MOMSN=39806, MT Status=2, MTMSN=0 2024-07-26T00:38:59.530Z,1721954339.530 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-07-26T00:39:13.828Z,1721954353.828 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2024-07-26T00:39:19.448Z,1721954359.448 [NAL9602](INFO): SBD MO Status=1, MOMSN=39806, MT Status=0, MTMSN=0 2024-07-26T00:39:19.499Z,1721954359.499 [NAL9602](INFO): Sent 332 bytes from file Logs/20240726T003530/Express0001.lzma 2024-07-26T00:39:19.499Z,1721954359.499 [NAL9602](INFO): Packets left to send: 1 2024-07-26T00:39:28.893Z,1721954368.893 [NAL9602](INFO): SBD MO Status=1, MOMSN=39807, MT Status=0, MTMSN=0 2024-07-26T00:39:28.952Z,1721954368.952 [NAL9602](INFO): Sent 207 bytes from file Logs/20240726T003530/Express0001.lzma 2024-07-26T00:39:28.952Z,1721954368.952 [NAL9602](INFO): Packets left to send: 0 2024-07-26T00:39:44.952Z,1721954384.952 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2024-07-26T00:39:45.051Z,1721954385.051 [NAL9602](INFO): SBD MO Status=0, MOMSN=39808, MT Status=0, MTMSN=0 2024-07-26T00:39:45.179Z,1721954385.179 [Default:CheckIn:Read_Iridium] Stopped 2024-07-26T00:39:45.179Z,1721954385.179 [Default:CheckIn:C.Wait] Running Loop=1 2024-07-26T00:39:45.179Z,1721954385.179 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-07-26T00:40:15.757Z,1721954415.757 [NAL9602](INFO): Not Powering down - fast GPS 2024-07-26T00:40:16.076Z,1721954416.076 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2024-07-26T00:40:47.200Z,1721954447.200 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2024-07-26T00:41:18.352Z,1721954478.352 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2024-07-26T00:41:49.476Z,1721954509.476 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2024-07-26T00:42:20.604Z,1721954540.604 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2024-07-26T00:42:51.732Z,1721954571.732 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2024-07-26T00:43:22.856Z,1721954602.856 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2024-07-26T00:43:53.980Z,1721954633.980 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2024-07-26T00:44:01.993Z,1721954641.993 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2024-07-26T00:44:15.329Z,1721954655.329 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2024-07-26T00:44:25.109Z,1721954665.109 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2024-07-26T00:44:28.251Z,1721954668.251 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2024-07-26T00:44:41.189Z,1721954681.189 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2024-07-26T00:44:45.639Z,1721954685.639 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-07-26T00:44:45.639Z,1721954685.639 [Default:CheckIn:C.Wait] Stopped 2024-07-26T00:44:45.639Z,1721954685.639 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-07-26T00:44:45.639Z,1721954685.639 [Default:CheckIn:D] Running Loop=1 2024-07-26T00:44:46.044Z,1721954686.044 [Default:CheckIn:D] Stopped 2024-07-26T00:44:46.044Z,1721954686.044 [Default:CheckIn:E] Running Loop=1 2024-07-26T00:44:46.445Z,1721954686.445 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 7.367082 min 2024-07-26T00:44:46.445Z,1721954686.445 [Default:CheckIn:E] Stopped 2024-07-26T00:44:46.445Z,1721954686.445 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-07-26T00:44:46.445Z,1721954686.445 [Default:CheckIn] Stopped 2024-07-26T00:44:46.445Z,1721954686.445 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-07-26T00:44:46.445Z,1721954686.445 [Default:CheckIn](INFO): Running loop #2 2024-07-26T00:44:46.445Z,1721954686.445 [Default:CheckIn] Running Loop=2 2024-07-26T00:44:46.445Z,1721954686.445 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-07-26T00:44:46.445Z,1721954686.445 [Default:CheckIn:Read_GPS] Running Loop=1 2024-07-26T00:44:48.455Z,1721954688.455 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,004446.00,A,3649.97551,N,12155.12300,W,19.361,284.29,260724,,,A*47 2024-07-26T00:44:48.457Z,1721954688.457 [NAL9602](INFO): GPS fix at 20240726T004446: (36.832925, -121.918717) 2024-07-26T00:44:48.469Z,1721954688.469 [Default:CheckIn:Read_GPS] Stopped 2024-07-26T00:44:48.469Z,1721954688.469 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-07-26T00:44:54.510Z,1721954694.510 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2024-07-26T00:44:56.272Z,1721954696.272 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2024-07-26T00:45:07.103Z,1721954707.103 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2024-07-26T00:45:19.289Z,1721954719.289 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=39809, MT Status=1, MTMSN=2170 2024-07-26T00:45:19.340Z,1721954719.340 [NAL9602](INFO): Sent 72 bytes from file Logs/20240726T003530/Courier0004.lzma 2024-07-26T00:45:19.340Z,1721954719.340 [NAL9602](INFO): Packets left to send: 0 2024-07-26T00:45:19.965Z,1721954719.965 [NAL9602](INFO): Received command: restart sys 2024-07-26T00:45:19.994Z,1721954719.994 [CommandExec](IMPORTANT): got command restart system 2024-07-26T00:45:20.043Z,1721954720.043 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2024-07-26T00:45:22.053Z,1721954722.053 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2024-07-26T00:45:22.053Z,1721954722.053 [CommandExec](INFO): Uninitializing the command executive. 2024-07-26T00:45:22.053Z,1721954722.053 [CommandExec](INFO): Uninitializing the command scheduler. 2024-07-26T00:45:22.053Z,1721954722.053 [CommandExec ThreadHandler](INFO): Thread cancelled. 2024-07-26T00:45:22.063Z,1721954722.063 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2024-07-26T00:45:22.063Z,1721954722.063 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2024-07-26T00:45:22.063Z,1721954722.063 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2024-07-26T00:45:22.080Z,1721954722.080 [NavChartDb](INFO): Join timeout helper Thread ID is 991 2024-07-26T00:45:22.192Z,1721954722.192 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2024-07-26T00:45:22.192Z,1721954722.192 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2024-07-26T00:45:22.200Z,1721954722.200 [ComponentRegistry](INFO): Shutting down WetLabsUBAT ThreadHandler 2024-07-26T00:45:22.200Z,1721954722.200 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2024-07-26T00:45:22.200Z,1721954722.200 [WetLabsUBAT](INFO): Join timeout helper Thread ID is 992 2024-07-26T00:45:22.204Z,1721954722.204 [WetLabsUBAT ThreadHandler](INFO): Uninitializing protected caller thread. 2024-07-26T00:45:22.204Z,1721954722.204 [WetLabsUBAT](INFO): Powering down 2024-07-26T00:45:22.205Z,1721954722.205 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2024-07-26T00:45:22.223Z,1721954722.223 [ComponentRegistry](INFO): Shutting down