2024-05-22T16:05:53.581Z,1716393953.581 [Supervisor](DEBUG): Initializing supervisor. 2024-05-22T16:05:53.585Z,1716393953.585 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2024-05-22T16:05:53.586Z,1716393953.586 [SyncHandler](INFO): Protected caller Thread ID is 837 2024-05-22T16:05:53.586Z,1716393953.586 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2024-05-22T16:05:53.587Z,1716393953.587 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2024-05-22T16:05:53.588Z,1716393953.588 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 838 2024-05-22T16:05:53.591Z,1716393953.591 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2024-05-22T16:05:53.609Z,1716393953.609 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2024-05-22T16:05:53.610Z,1716393953.610 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2024-05-22T16:05:53.610Z,1716393953.610 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 839 2024-05-22T16:05:53.614Z,1716393953.614 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2024-05-22T16:05:53.615Z,1716393953.615 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2024-05-22T16:05:53.616Z,1716393953.616 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 840 2024-05-22T16:05:53.618Z,1716393953.618 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2024-05-22T16:05:53.619Z,1716393953.619 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2024-05-22T16:05:53.619Z,1716393953.619 [logger ThreadHandler](INFO): Protected caller Thread ID is 841 2024-05-22T16:05:53.623Z,1716393953.623 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2024-05-22T16:05:53.623Z,1716393953.623 [Supervisor](INFO): Looking for Config files in directory: Config/ 2024-05-22T16:05:53.627Z,1716393953.627 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2024-05-22T16:05:53.904Z,1716393953.904 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2024-05-22T16:05:53.906Z,1716393953.906 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2024-05-22T16:05:53.000Z,1716393954.000 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2024-05-22T16:05:54.552Z,1716393954.552 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2024-05-22T16:05:54.554Z,1716393954.554 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2024-05-22T16:05:54.914Z,1716393954.914 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2024-05-22T16:05:54.915Z,1716393954.915 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2024-05-22T16:05:55.024Z,1716393955.024 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2024-05-22T16:05:55.026Z,1716393955.026 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2024-05-22T16:05:55.446Z,1716393955.446 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2024-05-22T16:05:55.448Z,1716393955.448 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2024-05-22T16:05:55.677Z,1716393955.677 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2024-05-22T16:05:55.679Z,1716393955.679 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2024-05-22T16:05:56.256Z,1716393956.256 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2024-05-22T16:05:56.259Z,1716393956.259 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2024-05-22T16:05:56.704Z,1716393956.704 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2024-05-22T16:05:56.938Z,1716393956.938 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2024-05-22T16:05:57.029Z,1716393957.029 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2024-05-22T16:05:57.882Z,1716393957.882 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2024-05-22T16:05:57.883Z,1716393957.883 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2024-05-22T16:05:58.281Z,1716393958.281 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2024-05-22T16:05:58.282Z,1716393958.282 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2024-05-22T16:05:58.488Z,1716393958.488 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2024-05-22T16:05:58.489Z,1716393958.489 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2024-05-22T16:05:58.614Z,1716393958.614 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2024-05-22T16:05:58.614Z,1716393958.614 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2024-05-22T16:05:58.854Z,1716393958.854 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2024-05-22T16:05:58.855Z,1716393958.855 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2024-05-22T16:05:59.119Z,1716393959.119 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2024-05-22T16:05:59.121Z,1716393959.121 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2024-05-22T16:05:59.123Z,1716393959.123 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg 2024-05-22T16:05:59.228Z,1716393959.228 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2024-05-22T16:05:59.324Z,1716393959.324 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2024-05-22T16:05:59.439Z,1716393959.439 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2024-05-22T16:05:59.535Z,1716393959.535 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2024-05-22T16:05:59.650Z,1716393959.650 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2024-05-22T16:05:59.754Z,1716393959.754 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2024-05-22T16:05:59.878Z,1716393959.878 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2024-05-22T16:06:00.044Z,1716393960.044 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2024-05-22T16:06:00.195Z,1716393960.195 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2024-05-22T16:06:00.317Z,1716393960.317 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2024-05-22T16:06:00.595Z,1716393960.595 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2024-05-22T16:06:00.595Z,1716393960.595 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg 2024-05-22T16:06:00.605Z,1716393960.605 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2024-05-22T16:06:00.691Z,1716393960.691 [VerticalControl](DEBUG): Construct VerticalControl. 2024-05-22T16:06:00.751Z,1716393960.751 [VerticalControl] Loaded 2024-05-22T16:06:00.752Z,1716393960.752 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2024-05-22T16:06:00.755Z,1716393960.755 [HorizontalControl](DEBUG): Construct HorizontalControl. 2024-05-22T16:06:00.801Z,1716393960.801 [HorizontalControl] Loaded 2024-05-22T16:06:00.802Z,1716393960.802 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2024-05-22T16:06:00.804Z,1716393960.804 [SpeedControl](DEBUG): Construct SpeedControl. 2024-05-22T16:06:00.807Z,1716393960.807 [SpeedControl] Loaded 2024-05-22T16:06:00.807Z,1716393960.807 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2024-05-22T16:06:00.810Z,1716393960.810 [LoopControl](DEBUG): Construct LoopControl. 2024-05-22T16:06:00.810Z,1716393960.810 [LoopControl] Loaded 2024-05-22T16:06:00.811Z,1716393960.811 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2024-05-22T16:06:00.811Z,1716393960.811 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2024-05-22T16:06:00.813Z,1716393960.813 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2024-05-22T16:06:00.828Z,1716393960.828 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2024-05-22T16:06:00.829Z,1716393960.829 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2024-05-22T16:06:01.041Z,1716393961.041 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2024-05-22T16:06:01.042Z,1716393961.042 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2024-05-22T16:06:01.228Z,1716393961.228 [BuoyancyServo] Loaded 2024-05-22T16:06:01.229Z,1716393961.229 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2024-05-22T16:06:01.250Z,1716393961.250 [ElevatorServo] Loaded 2024-05-22T16:06:01.250Z,1716393961.250 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2024-05-22T16:06:01.271Z,1716393961.271 [MassServo] Loaded 2024-05-22T16:06:01.272Z,1716393961.272 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2024-05-22T16:06:01.292Z,1716393961.292 [RudderServo] Loaded 2024-05-22T16:06:01.292Z,1716393961.292 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2024-05-22T16:06:01.308Z,1716393961.308 [ThrusterHE] Loaded 2024-05-22T16:06:01.308Z,1716393961.308 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2024-05-22T16:06:01.309Z,1716393961.309 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2024-05-22T16:06:01.309Z,1716393961.309 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2024-05-22T16:06:01.728Z,1716393961.728 [DeadReckonUsingMultipleVelocitySources] Loaded 2024-05-22T16:06:01.728Z,1716393961.728 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2024-05-22T16:06:01.780Z,1716393961.780 [NavChart] Loaded 2024-05-22T16:06:01.780Z,1716393961.780 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2024-05-22T16:06:01.822Z,1716393961.822 [UniversalFixResidualReporter] Loaded 2024-05-22T16:06:01.822Z,1716393961.822 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2024-05-22T16:06:01.822Z,1716393961.822 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2024-05-22T16:06:01.823Z,1716393961.823 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2024-05-22T16:06:02.303Z,1716393962.303 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2024-05-22T16:06:02.303Z,1716393962.303 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2024-05-22T16:06:03.065Z,1716393963.065 [AHRS_M2] Loaded 2024-05-22T16:06:03.065Z,1716393963.065 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2024-05-22T16:06:03.891Z,1716393963.891 [BPC1] Loaded 2024-05-22T16:06:03.891Z,1716393963.891 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2024-05-22T16:06:04.032Z,1716393964.032 [DataOverHttps] Loaded 2024-05-22T16:06:04.032Z,1716393964.032 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2024-05-22T16:06:04.033Z,1716393964.033 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409314E0 2024-05-22T16:06:04.033Z,1716393964.033 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 923 2024-05-22T16:06:04.057Z,1716393964.057 [Depth_Keller] Loaded 2024-05-22T16:06:04.057Z,1716393964.057 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2024-05-22T16:06:04.062Z,1716393964.062 [DropWeight] Loaded 2024-05-22T16:06:04.062Z,1716393964.062 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2024-05-22T16:06:04.126Z,1716393964.126 [NAL9602] Loaded 2024-05-22T16:06:04.126Z,1716393964.126 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2024-05-22T16:06:04.156Z,1716393964.156 [Onboard] Loaded 2024-05-22T16:06:04.156Z,1716393964.156 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2024-05-22T16:06:04.157Z,1716393964.157 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409614E0 2024-05-22T16:06:04.158Z,1716393964.158 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 924 2024-05-22T16:06:04.173Z,1716393964.173 [Power24vConverter] Loaded 2024-05-22T16:06:04.173Z,1716393964.173 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2024-05-22T16:06:04.188Z,1716393964.188 [Radio_Surface] Loaded 2024-05-22T16:06:04.188Z,1716393964.188 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2024-05-22T16:06:04.189Z,1716393964.189 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409914E0 2024-05-22T16:06:04.190Z,1716393964.190 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 925 2024-05-22T16:06:04.205Z,1716393964.205 [Sonardyne_Nano] Loaded 2024-05-22T16:06:04.205Z,1716393964.205 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread. 2024-05-22T16:06:04.300Z,1716393964.300 [DAT] Loaded 2024-05-22T16:06:04.300Z,1716393964.300 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2024-05-22T16:06:04.301Z,1716393964.301 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 409C14E0 2024-05-22T16:06:04.302Z,1716393964.302 [DAT ThreadHandler](INFO): Protected caller Thread ID is 926 2024-05-22T16:06:04.302Z,1716393964.302 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2024-05-22T16:06:04.303Z,1716393964.303 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2024-05-22T16:06:04.379Z,1716393964.379 [DepthRateCalculator] Loaded 2024-05-22T16:06:04.379Z,1716393964.379 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2024-05-22T16:06:04.384Z,1716393964.384 [PitchRateCalculator] Loaded 2024-05-22T16:06:04.385Z,1716393964.385 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2024-05-22T16:06:04.393Z,1716393964.393 [SpeedCalculator] Loaded 2024-05-22T16:06:04.394Z,1716393964.394 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2024-05-22T16:06:04.398Z,1716393964.398 [YawRateCalculator] Loaded 2024-05-22T16:06:04.398Z,1716393964.398 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2024-05-22T16:06:04.417Z,1716393964.417 [ElevatorOffsetCalculator] Loaded 2024-05-22T16:06:04.418Z,1716393964.418 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2024-05-22T16:06:04.418Z,1716393964.418 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2024-05-22T16:06:04.419Z,1716393964.419 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2024-05-22T16:06:04.609Z,1716393964.609 [CANONSampler] Loaded 2024-05-22T16:06:04.609Z,1716393964.609 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread. 2024-05-22T16:06:04.674Z,1716393964.674 [CTD_Seabird] Loaded 2024-05-22T16:06:04.675Z,1716393964.675 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2024-05-22T16:06:04.676Z,1716393964.676 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A7D4E0 2024-05-22T16:06:04.676Z,1716393964.676 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 927 2024-05-22T16:06:04.696Z,1716393964.696 [PAR_Licor] Loaded 2024-05-22T16:06:04.696Z,1716393964.696 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2024-05-22T16:06:04.740Z,1716393964.740 [WetLabsBB2FL] Loaded 2024-05-22T16:06:04.741Z,1716393964.741 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2024-05-22T16:06:04.742Z,1716393964.742 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AAD4E0 2024-05-22T16:06:04.742Z,1716393964.742 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 928 2024-05-22T16:06:04.743Z,1716393964.743 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2024-05-22T16:06:04.745Z,1716393964.745 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2024-05-22T16:06:04.789Z,1716393964.789 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2024-05-22T16:06:04.790Z,1716393964.790 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2024-05-22T16:06:05.196Z,1716393965.196 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2024-05-22T16:06:05.198Z,1716393965.198 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2024-05-22T16:06:05.374Z,1716393965.374 [SBIT](DEBUG): Construct Startup Built In Test. 2024-05-22T16:06:05.383Z,1716393965.383 [SBIT] Loaded 2024-05-22T16:06:05.384Z,1716393965.384 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2024-05-22T16:06:05.386Z,1716393965.386 [IBIT](DEBUG): Construct Initiated Built In Test. 2024-05-22T16:06:05.399Z,1716393965.399 [IBIT] Loaded 2024-05-22T16:06:05.399Z,1716393965.399 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2024-05-22T16:06:05.405Z,1716393965.405 [CBIT](DEBUG): Construct Continuous Built In Test. 2024-05-22T16:06:05.511Z,1716393965.511 [CBIT] Loaded 2024-05-22T16:06:05.511Z,1716393965.511 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2024-05-22T16:06:05.511Z,1716393965.511 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2024-05-22T16:06:05.512Z,1716393965.512 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2024-05-22T16:06:05.655Z,1716393965.655 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2024-05-22T16:06:05.661Z,1716393965.661 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2024-05-22T16:06:05.664Z,1716393965.664 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2024-05-22T16:06:05.676Z,1716393965.676 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2024-05-22T16:06:05.677Z,1716393965.677 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C074E0 2024-05-22T16:06:05.677Z,1716393965.677 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 929 2024-05-22T16:06:05.682Z,1716393965.682 [Supervisor](INFO): Main Thread ID is 830 2024-05-22T16:06:05.682Z,1716393965.682 [Supervisor](DEBUG): Running supervisor. 2024-05-22T16:06:05.682Z,1716393965.682 [CommandExec ThreadHandler](INFO): Handler Thread ID is 930 2024-05-22T16:06:05.683Z,1716393965.683 [CommandExec](INFO): Initializing the command executive. 2024-05-22T16:06:05.685Z,1716393965.685 [CommandLine ThreadHandler](INFO): Handler Thread ID is 931 2024-05-22T16:06:05.686Z,1716393965.686 [controlThread ThreadHandler](INFO): Handler Thread ID is 932 2024-05-22T16:06:05.687Z,1716393965.687 [controlThread](DEBUG): Initializing ControlThread 2024-05-22T16:06:05.688Z,1716393965.688 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2024-05-22T16:06:05.690Z,1716393965.690 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2024-05-22T16:06:05.690Z,1716393965.690 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2024-05-22T16:06:05.691Z,1716393965.691 [LoopControl](DEBUG): Initialize LoopControlComponent. 2024-05-22T16:06:05.693Z,1716393965.693 [NavChart](DEBUG): Initialize NavChart Navigation. 2024-05-22T16:06:05.693Z,1716393965.693 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2024-05-22T16:06:05.699Z,1716393965.699 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2024-05-22T16:06:05.699Z,1716393965.699 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2024-05-22T16:06:05.699Z,1716393965.699 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2024-05-22T16:06:05.699Z,1716393965.699 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2024-05-22T16:06:05.700Z,1716393965.700 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2024-05-22T16:06:05.705Z,1716393965.705 [SBIT](INFO): Initialize SBIT Component. 2024-05-22T16:06:05.705Z,1716393965.705 [SBIT](IMPORTANT): git: 2024-05-10 2024-05-22T16:06:05.706Z,1716393965.706 [SBIT](INFO): git hash: a134c88d686ec779525c21b16fbeda2a3b596732 2024-05-22T16:06:05.706Z,1716393965.706 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2024-05-22T16:06:05.707Z,1716393965.707 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021 2024-05-22T16:06:05.708Z,1716393965.708 [SBIT](INFO): Beginning SBIT in 59.000000 seconds. 2024-05-22T16:06:05.709Z,1716393965.709 [IBIT](INFO): Initialize IBIT Component. 2024-05-22T16:06:05.710Z,1716393965.710 [CBIT](DEBUG): Initialize CBIT Component. 2024-05-22T16:06:05.710Z,1716393965.710 [logger ThreadHandler](INFO): Handler Thread ID is 933 2024-05-22T16:06:05.721Z,1716393965.721 [CBIT](DEBUG): Initialized mux pins. 2024-05-22T16:06:05.721Z,1716393965.721 [CBIT](DEBUG): Initializing the watchdog timer. 2024-05-22T16:06:05.729Z,1716393965.729 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 934 2024-05-22T16:06:05.731Z,1716393965.731 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2024-05-22T16:06:05.741Z,1716393965.741 [Onboard ThreadHandler](INFO): Handler Thread ID is 935 2024-05-22T16:06:05.745Z,1716393965.745 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2024-05-22T16:06:05.746Z,1716393965.746 [CBIT](DEBUG): Initializing heartbeat. 2024-05-22T16:06:05.762Z,1716393965.762 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 936 2024-05-22T16:06:05.781Z,1716393965.781 [DAT ThreadHandler](INFO): Handler Thread ID is 937 2024-05-22T16:06:05.782Z,1716393965.782 [DAT](INFO): Powering up 2024-05-22T16:06:05.782Z,1716393965.782 [DAT](DEBUG): Initializing DAT. 2024-05-22T16:06:05.787Z,1716393965.787 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 939 2024-05-22T16:06:05.787Z,1716393965.787 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2024-05-22T16:06:05.794Z,1716393965.794 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 941 2024-05-22T16:06:05.797Z,1716393965.797 [WetLabsBB2FL](INFO): Powering up 2024-05-22T16:06:05.799Z,1716393965.799 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 943 2024-05-22T16:06:05.809Z,1716393965.809 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2024-05-22T16:06:05.809Z,1716393965.809 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2024-05-22T16:06:05.809Z,1716393965.809 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2024-05-22T16:06:05.809Z,1716393965.809 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2024-05-22T16:06:05.809Z,1716393965.809 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2024-05-22T16:06:05.809Z,1716393965.809 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2024-05-22T16:06:05.810Z,1716393965.810 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2024-05-22T16:06:05.810Z,1716393965.810 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2024-05-22T16:06:05.817Z,1716393965.817 [CBIT](DEBUG): Deactivating GF circuits. 2024-05-22T16:06:05.817Z,1716393965.817 [CBIT](DEBUG): Deactivating emergency mode. 2024-05-22T16:06:05.857Z,1716393965.857 [CBIT](DEBUG): Backplane powered. 2024-05-22T16:06:05.857Z,1716393965.857 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2024-05-22T16:06:05.858Z,1716393965.858 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl 2024-05-22T16:06:05.858Z,1716393965.858 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl 2024-05-22T16:06:05.865Z,1716393965.865 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl 2024-05-22T16:06:05.904Z,1716393965.904 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into: 2024-05-22T16:06:05.924Z,1716393965.924 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2024-05-22T16:06:05.952Z,1716393965.952 [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 } } } 2024-05-22T16:06:05.969Z,1716393965.969 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl 2024-05-22T16:06:05.969Z,1716393965.969 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl 2024-05-22T16:06:05.981Z,1716393965.981 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl 2024-05-22T16:06:06.165Z,1716393966.165 [Radio_Surface](INFO): Powering up 2024-05-22T16:06:06.277Z,1716393966.277 [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-05-22T16:06:06.295Z,1716393966.295 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2024-05-22T16:06:06.296Z,1716393966.296 [Default:A.Wait](DEBUG): Construct Wait. 2024-05-22T16:06:06.307Z,1716393966.307 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2024-05-22T16:06:06.328Z,1716393966.328 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2024-05-22T16:06:06.355Z,1716393966.355 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2024-05-22T16:06:06.361Z,1716393966.361 [Default:E.Execute](DEBUG): Construct Execute. 2024-05-22T16:06:06.364Z,1716393966.364 [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-05-22T16:06:06.380Z,1716393966.380 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,CANONSampler,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,Reporter,LogSplitter, 2024-05-22T16:06:06.393Z,1716393966.393 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2024-05-22T16:06:06.555Z,1716393966.555 [Power24vConverter](INFO): Powering up. 2024-05-22T16:06:06.556Z,1716393966.556 [Sonardyne_Nano](INFO): Initializing. 2024-05-22T16:06:06.573Z,1716393966.573 [CANONSampler](INFO): Powering down 2024-05-22T16:06:06.608Z,1716393966.608 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2024-05-22T16:06:06.617Z,1716393966.617 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2024-05-22T16:06:06.618Z,1716393966.618 [ElevatorServo](DEBUG): Initializing EZServoServo. 2024-05-22T16:06:06.625Z,1716393966.625 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2024-05-22T16:06:06.626Z,1716393966.626 [MassServo](DEBUG): Initializing EZServoServo. 2024-05-22T16:06:06.633Z,1716393966.633 [MassServo](DEBUG): Initializing MassServo. 2024-05-22T16:06:06.634Z,1716393966.634 [RudderServo](DEBUG): Initializing EZServoServo. 2024-05-22T16:06:06.641Z,1716393966.641 [RudderServo](DEBUG): Initializing RudderServo. 2024-05-22T16:06:06.642Z,1716393966.642 [ThrusterHE](DEBUG): Initializing EZServoServo. 2024-05-22T16:06:06.649Z,1716393966.649 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2024-05-22T16:06:07.905Z,1716393967.905 [WetLabsBB2FL](INFO): Powering down 2024-05-22T16:06:08.819Z,1716393968.819 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART 2024-05-22T16:06:10.054Z,1716393970.054 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2109 2024-05-22T16:06:12.306Z,1716393972.306 [ThrusterHE](ERROR): Zero Speed Commanded. 2024-05-22T16:06:12.821Z,1716393972.821 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit. 2024-05-22T16:06:18.637Z,1716393978.637 [DAT](INFO): DAT read: 2024-05-22T16:06:18.639Z,1716393978.639 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2024-05-22T16:06:20.402Z,1716393980.402 [DAT](INFO): DAT read: MF Frequency Band 2024-05-22T16:06:20.403Z,1716393980.403 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2024-05-22T16:06:20.403Z,1716393980.403 [DAT](INFO): DAT read: May 22 2024 16:06:15 2024-05-22T16:06:21.410Z,1716393981.410 [DAT](INFO): DAT read: Features enabled [Bearing] 2024-05-22T16:06:21.411Z,1716393981.411 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2024-05-22T16:06:21.411Z,1716393981.411 [DAT](INFO): commRate: 1200 2024-05-22T16:06:23.477Z,1716393983.477 [DAT](INFO): entering command mode 2024-05-22T16:06:23.677Z,1716393983.677 [DAT](INFO): DAT read: 2024-05-22T16:06:23.678Z,1716393983.678 [DAT](INFO): DAT read: user:1> 2024-05-22T16:06:23.678Z,1716393983.678 [DAT](INFO): setting verbose to 3 2024-05-22T16:06:23.930Z,1716393983.930 [DAT](INFO): DAT read: user:1> 2024-05-22T16:06:23.931Z,1716393983.931 [DAT](INFO): DAT read: Verbose | 3 2024-05-22T16:06:23.931Z,1716393983.931 [DAT](INFO): set verbose to 3 2024-05-22T16:06:23.931Z,1716393983.931 [DAT](INFO): setting DatVerbose to 27440 2024-05-22T16:06:24.181Z,1716393984.181 [DAT](INFO): DAT read: user:2> 2024-05-22T16:06:24.182Z,1716393984.182 [DAT](INFO): DAT read: DatVerbose | 27440 2024-05-22T16:06:24.183Z,1716393984.183 [DAT](INFO): set DatVerbose to 27440 2024-05-22T16:06:24.183Z,1716393984.183 [DAT](INFO): setting transmit power to 8 2024-05-22T16:06:24.433Z,1716393984.433 [DAT](INFO): DAT read: user:3> 2024-05-22T16:06:24.434Z,1716393984.434 [DAT](INFO): DAT read: TxPower | 8 (Max) 2024-05-22T16:06:24.435Z,1716393984.435 [DAT](INFO): set transmit power to 8 2024-05-22T16:06:24.435Z,1716393984.435 [DAT](INFO): setting local address to 8 2024-05-22T16:06:24.685Z,1716393984.685 [DAT](INFO): DAT read: user:4> 2024-05-22T16:06:24.686Z,1716393984.686 [DAT](INFO): DAT read: LocalAddr | 8 2024-05-22T16:06:24.687Z,1716393984.687 [DAT](INFO): set local address to 8 2024-05-22T16:06:24.688Z,1716393984.688 [DAT](INFO): Setting time to: 16:6:24 And date to:5/22/2024 2024-05-22T16:06:24.937Z,1716393984.937 [DAT](INFO): DAT read: user:5> 2024-05-22T16:06:24.938Z,1716393984.938 [DAT](INFO): DAT read: Wed May 22, 2024 16:06:24 2024-05-22T16:06:24.939Z,1716393984.939 [DAT](INFO): Local DAT time set to Wed May 22, 2024 16:06:24 2024-05-22T16:06:34.270Z,1716393994.270 [NAL9602](INFO): Powering up NAL9602 2024-05-22T16:06:45.190Z,1716394005.190 [NAL9602](INFO): NAL9602 initialized 2024-05-22T16:07:05.448Z,1716394025.448 [SBIT](IMPORTANT): Beginning Startup BIT 2024-05-22T16:07:05.453Z,1716394025.453 [CBIT](IMPORTANT): Beginning ground fault scan 2024-05-22T16:07:14.678Z,1716394034.678 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-22T16:07:16.314Z,1716394036.314 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan. 2024-05-22T16:07:16.724Z,1716394036.724 [CBIT](IMPORTANT): Beginning ground fault scan 2024-05-22T16:07:28.118Z,1716394048.118 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan. 2024-05-22T16:07:28.517Z,1716394048.517 [CBIT](IMPORTANT): Beginning ground fault scan 2024-05-22T16:07:33.262Z,1716394053.262 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-22T16:07:39.412Z,1716394059.412 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.003406 CHAN A1 (24V): 0.000322 CHAN A2 (12V): -0.002041 CHAN A3 (5V): -0.001510 CHAN B0 (3.3V): 0.000070 CHAN B1 (3.15aV): -0.000039 CHAN B2 (3.15bV): -0.000176 CHAN B3 (GND): -0.000219 OPEN: 4.764929 Full Scale: +/- 1 mA 2024-05-22T16:07:50.694Z,1716394070.694 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2024-05-22T16:07:51.845Z,1716394071.845 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-22T16:07:59.546Z,1716394079.546 [SBIT](IMPORTANT): SBIT PASSED 2024-05-22T16:07:59.546Z,1716394079.546 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2024-05-22T16:07:59.547Z,1716394079.547 [SBIT](IMPORTANT): Normal all WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water; 2024-05-22T16:07:59.954Z,1716394079.954 [MissionManager](IMPORTANT): Started mission Startup 2024-05-22T16:07:59.954Z,1716394079.954 [Startup] Running Loop=1 2024-05-22T16:07:59.954Z,1716394079.954 [Startup](DEBUG): Aggregate::initialize Startup 2024-05-22T16:07:59.954Z,1716394079.954 [Startup:A.GoToSurface] Running Loop=1 2024-05-22T16:07:59.954Z,1716394079.954 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2024-05-22T16:07:59.955Z,1716394079.955 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2024-05-22T16:07:59.955Z,1716394079.955 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2024-05-22T16:07:59.956Z,1716394079.956 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2024-05-22T16:07:59.956Z,1716394079.956 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2024-05-22T16:07:59.956Z,1716394079.956 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2024-05-22T16:07:59.957Z,1716394079.957 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2024-05-22T16:07:59.958Z,1716394079.958 [Startup:StartupSatComms] Running Loop=1 2024-05-22T16:07:59.959Z,1716394079.959 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2024-05-22T16:07:59.959Z,1716394079.959 [Startup:StartupSatComms:A] Running Loop=1 2024-05-22T16:08:00.351Z,1716394080.351 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2024-05-22T16:08:02.808Z,1716394082.808 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2024-05-22T16:08:39.727Z,1716394119.727 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004560 2024-05-22T16:08:59.985Z,1716394139.985 [Startup:StartupSatComms:A](INFO): Timed out from 2024-05-22T16:07:59.0Z 2024-05-22T16:08:59.985Z,1716394139.985 [Startup:StartupSatComms:A] Stopped 2024-05-22T16:08:59.985Z,1716394139.985 [Startup:StartupSatComms:B] Running Loop=1 2024-05-22T16:09:00.405Z,1716394140.405 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2024-05-22T16:09:05.703Z,1716394145.703 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2024-05-22T16:09:05.703Z,1716394145.703 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-05-22T16:09:05.722Z,1716394145.722 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-05-22T16:09:06.092Z,1716394146.092 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-05-22T16:09:06.092Z,1716394146.092 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2024-05-22T16:09:07.190Z,1716394147.190 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20240522T150241/Courier0022.lzma 2024-05-22T16:09:08.195Z,1716394148.195 [DataOverHttps](INFO): Moved sent file to Logs/20240522T150241/Courier0022.lzma.bak 2024-05-22T16:09:08.195Z,1716394148.195 [DataOverHttps](INFO): SBD MOMSN=21068767 2024-05-22T16:09:12.056Z,1716394152.056 [CommandExec](IMPORTANT): got command strobe off 2024-05-22T16:09:12.056Z,1716394152.056 [CommandExec](IMPORTANT): Deactivating strobe 2024-05-22T16:09:23.887Z,1716394163.887 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20240522T160553/Courier0000.lzma 2024-05-22T16:09:24.268Z,1716394164.268 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2024-05-22T16:09:24.889Z,1716394164.889 [DataOverHttps](INFO): Moved sent file to Logs/20240522T160553/Courier0000.lzma.bak 2024-05-22T16:09:24.889Z,1716394164.889 [DataOverHttps](INFO): SBD MOMSN=21068773 2024-05-22T16:09:39.623Z,1716394179.623 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2024-05-22T16:09:40.444Z,1716394180.444 [DataOverHttps](INFO): Sending 236 bytes from file Logs/20240522T150241/Express0020.lzma 2024-05-22T16:09:41.445Z,1716394181.445 [DataOverHttps](INFO): Moved sent file to Logs/20240522T150241/Express0020.lzma.bak 2024-05-22T16:09:41.445Z,1716394181.445 [DataOverHttps](INFO): SBD MOMSN=21068776 2024-05-22T16:09:57.382Z,1716394197.382 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20240522T150241/Express0023.lzma 2024-05-22T16:09:58.384Z,1716394198.384 [DataOverHttps](INFO): Moved sent file to Logs/20240522T150241/Express0023.lzma.bak 2024-05-22T16:09:58.385Z,1716394198.385 [DataOverHttps](INFO): SBD MOMSN=21068782 2024-05-22T16:10:00.191Z,1716394200.191 [Startup:StartupSatComms:B](INFO): Timed out from 2024-05-22T16:08:59.0Z 2024-05-22T16:10:00.192Z,1716394200.192 [Startup:StartupSatComms:B] Stopped 2024-05-22T16:10:00.192Z,1716394200.192 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2024-05-22T16:10:00.192Z,1716394200.192 [Startup:StartupSatComms] Stopped 2024-05-22T16:10:00.192Z,1716394200.192 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2024-05-22T16:10:00.193Z,1716394200.193 [Startup](INFO): Completed Startup 2024-05-22T16:10:00.193Z,1716394200.193 [MissionManager](INFO): Startup is completed. 2024-05-22T16:10:00.193Z,1716394200.193 [MissionManager](INFO): Uninitializing Mission Startup 2024-05-22T16:10:00.193Z,1716394200.193 [Startup] Stopped 2024-05-22T16:10:00.193Z,1716394200.193 [Startup](DEBUG): Aggregate::uninitialize Startup 2024-05-22T16:10:00.193Z,1716394200.193 [Startup:A.GoToSurface] Stopped 2024-05-22T16:10:00.193Z,1716394200.193 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2024-05-22T16:10:00.589Z,1716394200.589 [MissionManager](IMPORTANT): Started mission Default 2024-05-22T16:10:00.589Z,1716394200.589 [Default] Running Loop=1 2024-05-22T16:10:00.589Z,1716394200.589 [Default](DEBUG): Aggregate::initialize Default 2024-05-22T16:10:00.589Z,1716394200.589 [Default:B.GoToSurface] Running Loop=1 2024-05-22T16:10:00.589Z,1716394200.589 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2024-05-22T16:10:00.589Z,1716394200.589 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2024-05-22T16:10:00.590Z,1716394200.590 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2024-05-22T16:10:00.590Z,1716394200.590 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2024-05-22T16:10:00.590Z,1716394200.590 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2024-05-22T16:10:00.591Z,1716394200.591 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2024-05-22T16:10:00.591Z,1716394200.591 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2024-05-22T16:10:00.591Z,1716394200.591 [Default:A.Wait] Running Loop=1 2024-05-22T16:10:00.591Z,1716394200.591 [Default:A.Wait](DEBUG): Initialize Wait Component. 2024-05-22T16:10:13.600Z,1716394213.600 [Default:A.Wait](INFO): Done Waiting. 2024-05-22T16:10:13.600Z,1716394213.600 [Default:A.Wait] Stopped 2024-05-22T16:10:13.600Z,1716394213.600 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2024-05-22T16:10:14.013Z,1716394214.013 [Default:CheckIn] Running Loop=1 2024-05-22T16:10:14.013Z,1716394214.013 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-05-22T16:10:14.013Z,1716394214.013 [Default:CheckIn:Read_GPS] Running Loop=1 2024-05-22T16:10:14.412Z,1716394214.412 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2024-05-22T16:10:22.906Z,1716394222.906 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2024-05-22T16:10:24.489Z,1716394224.489 [CommandExec](IMPORTANT): got command configSet list 2024-05-22T16:10:24.489Z,1716394224.489 [CommandExec](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2024-05-22T16:10:24.490Z,1716394224.490 [CommandExec](IMPORTANT): Normal all WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water; 2024-05-22T16:10:35.708Z,1716394235.708 [DataOverHttps](INFO): Sending 729 bytes from file Logs/20240522T160553/Express0001.lzma 2024-05-22T16:10:36.708Z,1716394236.708 [DataOverHttps](INFO): Moved sent file to Logs/20240522T160553/Express0001.lzma.bak 2024-05-22T16:10:36.709Z,1716394236.709 [DataOverHttps](INFO): SBD MOMSN=21068785 2024-05-22T16:10:44.263Z,1716394244.263 [BPC1](ERROR): BPC1A: No match for serial number FFFF in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file). 2024-05-22T16:10:51.994Z,1716394251.994 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2024-05-22T16:11:25.519Z,1716394285.519 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2024-05-22T16:11:48.904Z,1716394308.904 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-05-22T16:12:06.688Z,1716394326.688 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2024-05-22T16:12:06.688Z,1716394326.688 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-05-22T16:12:06.699Z,1716394326.699 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-05-22T16:12:07.141Z,1716394327.141 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-05-22T16:12:07.141Z,1716394327.141 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2024-05-22T16:12:35.042Z,1716394355.042 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2024-05-22T16:14:39.842Z,1716394479.842 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2024-05-22T16:15:07.688Z,1716394507.688 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2024-05-22T16:15:07.688Z,1716394507.688 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-05-22T16:15:07.711Z,1716394507.711 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-05-22T16:15:08.116Z,1716394508.116 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-05-22T16:15:08.116Z,1716394508.116 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2024-05-22T16:15:14.145Z,1716394514.145 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-05-22T16:10:14.0Z 2024-05-22T16:15:14.145Z,1716394514.145 [Default:CheckIn:Read_GPS] Stopped 2024-05-22T16:15:14.145Z,1716394514.145 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-05-22T16:15:14.549Z,1716394514.549 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2024-05-22T16:15:19.438Z,1716394519.438 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2024-05-22T16:15:21.471Z,1716394521.471 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2024-05-22T16:15:21.534Z,1716394521.534 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20240522T160553/Courier0004.lzma 2024-05-22T16:15:22.536Z,1716394522.536 [DataOverHttps](INFO): Moved sent file to Logs/20240522T160553/Courier0004.lzma.bak 2024-05-22T16:15:22.537Z,1716394522.537 [DataOverHttps](INFO): SBD MOMSN=21068821 2024-05-22T16:15:35.654Z,1716394535.654 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2024-05-22T16:15:37.155Z,1716394537.155 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-22T16:15:38.307Z,1716394538.307 [DataOverHttps](INFO): Sending 372 bytes from file Logs/20240522T160553/Express0005.lzma 2024-05-22T16:15:39.309Z,1716394539.309 [DataOverHttps](INFO): Moved sent file to Logs/20240522T160553/Express0005.lzma.bak 2024-05-22T16:15:39.309Z,1716394539.309 [DataOverHttps](INFO): SBD MOMSN=21068823 2024-05-22T16:15:40.411Z,1716394540.411 [Default:CheckIn:Read_Iridium] Stopped 2024-05-22T16:15:40.411Z,1716394540.411 [Default:CheckIn:C.Wait] Running Loop=1 2024-05-22T16:15:40.411Z,1716394540.411 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-05-22T16:15:56.144Z,1716394556.144 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-22T16:16:14.323Z,1716394574.323 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-22T16:16:30.118Z,1716394590.118 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2024-05-22T16:16:34.579Z,1716394594.579 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2024-05-22T16:16:47.100Z,1716394607.100 [NAL9602](FAULT): GPS failed to acquire within timeout. 2024-05-22T16:16:47.100Z,1716394607.100 [NAL9602] Data Fault, FailCount= 1 2024-05-22T16:16:47.100Z,1716394607.100 [NAL9602](ERROR): Data Fault 2024-05-22T16:16:47.118Z,1716394607.118 [CBIT](ERROR): Data Fault in component: NAL9602 2024-05-22T16:16:47.452Z,1716394607.452 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-22T16:16:47.461Z,1716394607.461 [NAL9602](INFO): Powering down 2024-05-22T16:16:47.876Z,1716394607.876 [NAL9602](FAULT): LCB fault: Current Limiter Activated. 2024-05-22T16:16:47.876Z,1716394607.876 [NAL9602] Hardware Fault, FailCount= 1 2024-05-22T16:16:47.876Z,1716394607.876 [NAL9602](ERROR): Hardware Fault 2024-05-22T16:16:48.312Z,1716394608.312 [CBIT](INFO): Clearing failed state for component NAL9602 2024-05-22T16:16:48.312Z,1716394608.312 [NAL9602] No Fault, FailCount= 1 2024-05-22T16:17:04.876Z,1716394624.876 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2024-05-22T16:17:17.776Z,1716394637.776 [NAL9602](INFO): Powering up NAL9602 2024-05-22T16:17:22.643Z,1716394642.643 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2024-05-22T16:17:28.668Z,1716394648.668 [NAL9602](INFO): NAL9602 initialized 2024-05-22T16:18:08.690Z,1716394688.690 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2024-05-22T16:18:08.690Z,1716394688.690 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-05-22T16:18:08.700Z,1716394688.700 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-05-22T16:18:09.113Z,1716394689.113 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-05-22T16:18:09.113Z,1716394689.113 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2024-05-22T16:20:40.977Z,1716394840.977 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-05-22T16:20:40.978Z,1716394840.978 [Default:CheckIn:C.Wait] Stopped 2024-05-22T16:20:40.978Z,1716394840.978 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-05-22T16:20:40.978Z,1716394840.978 [Default:CheckIn:D] Running Loop=1 2024-05-22T16:20:41.401Z,1716394841.401 [Default:CheckIn:D] Stopped 2024-05-22T16:20:41.401Z,1716394841.401 [Default:CheckIn:E] Running Loop=1 2024-05-22T16:20:41.812Z,1716394841.812 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.680199 min 2024-05-22T16:20:41.812Z,1716394841.812 [Default:CheckIn:E] Stopped 2024-05-22T16:20:41.812Z,1716394841.812 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-05-22T16:20:41.813Z,1716394841.813 [Default:CheckIn] Stopped 2024-05-22T16:20:41.813Z,1716394841.813 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-05-22T16:20:41.813Z,1716394841.813 [Default:CheckIn](INFO): Running loop #2 2024-05-22T16:20:41.813Z,1716394841.813 [Default:CheckIn] Running Loop=2 2024-05-22T16:20:41.813Z,1716394841.813 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-05-22T16:20:41.813Z,1716394841.813 [Default:CheckIn:Read_GPS] Running Loop=1 2024-05-22T16:21:09.663Z,1716394869.663 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2024-05-22T16:21:09.664Z,1716394869.664 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-05-22T16:21:09.674Z,1716394869.674 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-05-22T16:21:10.077Z,1716394870.077 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-05-22T16:21:10.077Z,1716394870.077 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2024-05-22T16:22:53.076Z,1716394973.076 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file). 2024-05-22T16:24:10.656Z,1716395050.656 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2024-05-22T16:24:10.656Z,1716395050.656 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-05-22T16:24:10.666Z,1716395050.666 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-05-22T16:24:11.068Z,1716395051.068 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-05-22T16:24:11.068Z,1716395051.068 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2024-05-22T16:24:54.708Z,1716395094.708 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-22T16:25:08.007Z,1716395108.007 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-22T16:25:20.127Z,1716395120.127 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-22T16:25:33.459Z,1716395133.459 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-22T16:25:41.963Z,1716395141.963 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-05-22T16:20:41.8Z 2024-05-22T16:25:41.963Z,1716395141.963 [Default:CheckIn:Read_GPS] Stopped 2024-05-22T16:25:41.963Z,1716395141.963 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-05-22T16:25:46.392Z,1716395146.392 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-22T16:25:49.262Z,1716395149.262 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20240522T160553/Courier0007.lzma 2024-05-22T16:25:50.264Z,1716395150.264 [DataOverHttps](INFO): Moved sent file to Logs/20240522T160553/Courier0007.lzma.bak 2024-05-22T16:25:50.265Z,1716395150.265 [DataOverHttps](INFO): SBD MOMSN=21068869 2024-05-22T16:25:59.720Z,1716395159.720 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-22T16:26:05.879Z,1716395165.879 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20240522T160553/Express0008.lzma 2024-05-22T16:26:06.880Z,1716395166.880 [DataOverHttps](INFO): Moved sent file to Logs/20240522T160553/Express0008.lzma.bak 2024-05-22T16:26:06.881Z,1716395166.881 [DataOverHttps](INFO): SBD MOMSN=21068874 2024-05-22T16:26:08.220Z,1716395168.220 [Default:CheckIn:Read_Iridium] Stopped 2024-05-22T16:26:08.220Z,1716395168.220 [Default:CheckIn:C.Wait] Running Loop=1 2024-05-22T16:26:08.220Z,1716395168.220 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-05-22T16:26:12.243Z,1716395172.243 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-22T16:26:25.172Z,1716395185.172 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-22T16:26:37.303Z,1716395197.303 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-22T16:26:49.880Z,1716395209.880 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-22T16:27:02.749Z,1716395222.749 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-22T16:27:11.665Z,1716395231.665 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2024-05-22T16:27:11.665Z,1716395231.665 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-05-22T16:27:11.688Z,1716395231.688 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-05-22T16:27:12.109Z,1716395232.109 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-05-22T16:27:12.109Z,1716395232.109 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2024-05-22T16:27:30.640Z,1716395250.640 [NAL9602](FAULT): GPS failed to acquire within timeout. 2024-05-22T16:27:30.640Z,1716395250.640 [NAL9602] Data Fault, FailCount= 2 2024-05-22T16:27:30.641Z,1716395250.641 [NAL9602](ERROR): Data Fault 2024-05-22T16:27:30.689Z,1716395250.689 [CBIT](ERROR): Data Fault in component: NAL9602 2024-05-22T16:27:31.032Z,1716395251.032 [NAL9602](INFO): Powering down 2024-05-22T16:27:31.864Z,1716395251.864 [CBIT](INFO): Clearing failed state for component NAL9602 2024-05-22T16:27:31.864Z,1716395251.864 [NAL9602] No Fault, FailCount= 2 2024-05-22T16:28:01.332Z,1716395281.332 [NAL9602](INFO): Powering up NAL9602 2024-05-22T16:28:12.253Z,1716395292.253 [NAL9602](INFO): NAL9602 initialized 2024-05-22T16:30:11.021Z,1716395411.021 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file). 2024-05-22T16:30:12.672Z,1716395412.672 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2024-05-22T16:30:12.672Z,1716395412.672 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-05-22T16:30:12.683Z,1716395412.683 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-05-22T16:30:13.101Z,1716395413.101 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-05-22T16:30:13.101Z,1716395413.101 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2024-05-22T16:31:08.801Z,1716395468.801 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-05-22T16:31:08.801Z,1716395468.801 [Default:CheckIn:C.Wait] Stopped 2024-05-22T16:31:08.801Z,1716395468.801 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-05-22T16:31:08.801Z,1716395468.801 [Default:CheckIn:D] Running Loop=1 2024-05-22T16:31:09.213Z,1716395469.213 [Default:CheckIn:D] Stopped 2024-05-22T16:31:09.213Z,1716395469.213 [Default:CheckIn:E] Running Loop=1 2024-05-22T16:31:09.614Z,1716395469.614 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.143742 min 2024-05-22T16:31:09.614Z,1716395469.614 [Default:CheckIn:E] Stopped 2024-05-22T16:31:09.614Z,1716395469.614 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-05-22T16:31:09.614Z,1716395469.614 [Default:CheckIn] Stopped 2024-05-22T16:31:09.614Z,1716395469.614 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-05-22T16:31:09.614Z,1716395469.614 [Default:CheckIn](INFO): Running loop #3 2024-05-22T16:31:09.614Z,1716395469.614 [Default:CheckIn] Running Loop=3 2024-05-22T16:31:09.635Z,1716395469.635 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-05-22T16:31:09.635Z,1716395469.635 [Default:CheckIn:Read_GPS] Running Loop=1 2024-05-22T16:33:13.680Z,1716395593.680 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9 2024-05-22T16:33:13.680Z,1716395593.680 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-05-22T16:33:13.691Z,1716395593.691 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-05-22T16:33:14.097Z,1716395594.097 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-05-22T16:33:14.097Z,1716395594.097 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9 2024-05-22T16:34:30.036Z,1716395670.036 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-22T16:34:42.965Z,1716395682.965 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-22T16:34:56.352Z,1716395696.352 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-22T16:35:09.279Z,1716395709.279 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-22T16:35:22.207Z,1716395722.207 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-22T16:35:34.731Z,1716395734.731 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-22T16:35:47.661Z,1716395747.661 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-22T16:36:00.183Z,1716395760.183 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-22T16:36:03.054Z,1716395763.054 [CommandExec](IMPORTANT): got command show variable nano 2024-05-22T16:36:03.112Z,1716395763.112 [CommandExec](IMPORTANT): NanoDVR.loadControl (none) 2024-05-22T16:36:03.113Z,1716395763.113 [CommandExec](IMPORTANT): NanoDVR.uart (none) 2024-05-22T16:36:03.113Z,1716395763.113 [CommandExec](IMPORTANT): NanoDVR.baud (bit_per_second) 2024-05-22T16:36:03.115Z,1716395763.115 [CommandExec](IMPORTANT): Sonardyne_Nano.loadControl (none) 2024-05-22T16:36:03.115Z,1716395763.115 [CommandExec](IMPORTANT): Sonardyne_Nano.uart (none) 2024-05-22T16:36:03.116Z,1716395763.116 [CommandExec](IMPORTANT): Sonardyne_Nano.baud (bit_per_second) 2024-05-22T16:36:03.126Z,1716395763.126 [CommandExec](IMPORTANT): NanoDVR.loadAtStartup (bool) 2024-05-22T16:36:03.126Z,1716395763.126 [CommandExec](IMPORTANT): NanoDVR.simulateHardware (bool) 2024-05-22T16:36:03.127Z,1716395763.127 [CommandExec](IMPORTANT): NanoDVR.sampleTime (second) 2024-05-22T16:36:03.130Z,1716395763.130 [CommandExec](IMPORTANT): Sonardyne_Nano.loadAtStartup (bool) 2024-05-22T16:36:03.131Z,1716395763.131 [CommandExec](IMPORTANT): Sonardyne_Nano.simulateHardware (bool) 2024-05-22T16:36:03.131Z,1716395763.131 [CommandExec](IMPORTANT): Sonardyne_Nano.chargeMin (percent) 2024-05-22T16:36:03.131Z,1716395763.131 [CommandExec](IMPORTANT): Sonardyne_Nano.chargeMax (percent) 2024-05-22T16:36:03.342Z,1716395763.342 [CommandExec](IMPORTANT): Sonardyne_Nano.enableBroadcast (bool) 2024-05-22T16:36:03.342Z,1716395763.342 [CommandExec](IMPORTANT): Sonardyne_Nano.component_voltage (volt) 2024-05-22T16:36:03.342Z,1716395763.342 [CommandExec](IMPORTANT): Sonardyne_Nano.component_avgVoltage (volt) 2024-05-22T16:36:03.343Z,1716395763.343 [CommandExec](IMPORTANT): Sonardyne_Nano.component_current (milliampere) 2024-05-22T16:36:03.344Z,1716395763.344 [CommandExec](IMPORTANT): Sonardyne_Nano.component_avgCurrent (milliampere) 2024-05-22T16:36:03.344Z,1716395763.344 [CommandExec](IMPORTANT): Sonardyne_Nano.component_discreteIn (bool) 2024-05-22T16:36:03.344Z,1716395763.344 [CommandExec](IMPORTANT): Sonardyne_Nano.chargePercent (percent) 2024-05-22T16:36:09.916Z,1716395769.916 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-05-22T16:31:09.6Z 2024-05-22T16:36:09.916Z,1716395769.916 [Default:CheckIn:Read_GPS] Stopped 2024-05-22T16:36:09.916Z,1716395769.916 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-05-22T16:36:12.707Z,1716395772.707 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-22T16:36:14.767Z,1716395774.767 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10 2024-05-22T16:36:14.767Z,1716395774.767 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-05-22T16:36:14.818Z,1716395774.818 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-05-22T16:36:15.199Z,1716395775.199 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-05-22T16:36:15.199Z,1716395775.199 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10 2024-05-22T16:36:18.930Z,1716395778.930 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20240522T160553/Courier0010.lzma 2024-05-22T16:36:19.414Z,1716395779.414 [CommandExec](IMPORTANT): got command get Sonardyne_Nano.chargePercent 2024-05-22T16:36:19.414Z,1716395779.414 [CommandExec](IMPORTANT): Sonardyne_Nano.chargePercent 98.000000 % 2024-05-22T16:36:19.933Z,1716395779.933 [DataOverHttps](INFO): Moved sent file to Logs/20240522T160553/Courier0010.lzma.bak 2024-05-22T16:36:19.933Z,1716395779.933 [DataOverHttps](INFO): SBD MOMSN=21068923 2024-05-22T16:36:25.677Z,1716395785.677 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-22T16:36:38.291Z,1716395798.291 [DataOverHttps](INFO): Sending 456 bytes from file Logs/20240522T160553/Express0011.lzma 2024-05-22T16:36:38.643Z,1716395798.643 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-22T16:36:39.292Z,1716395799.292 [DataOverHttps](INFO): Moved sent file to Logs/20240522T160553/Express0011.lzma.bak 2024-05-22T16:36:39.293Z,1716395799.293 [DataOverHttps](INFO): SBD MOMSN=21068925 2024-05-22T16:36:40.685Z,1716395800.685 [Default:CheckIn:Read_Iridium] Stopped 2024-05-22T16:36:40.685Z,1716395800.685 [Default:CheckIn:C.Wait] Running Loop=1 2024-05-22T16:36:40.685Z,1716395800.685 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-05-22T16:37:06.920Z,1716395826.920 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6. 2024-05-22T16:37:06.923Z,1716395826.923 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle. 2024-05-22T16:38:13.177Z,1716395893.177 [NAL9602](FAULT): GPS failed to acquire within timeout. 2024-05-22T16:38:13.177Z,1716395893.177 [NAL9602] Data Fault, FailCount= 3 2024-05-22T16:38:13.177Z,1716395893.177 [NAL9602](ERROR): Data Fault 2024-05-22T16:38:13.195Z,1716395893.195 [CBIT](ERROR): Data Fault in component: NAL9602 2024-05-22T16:38:13.576Z,1716395893.576 [NAL9602](INFO): Powering down 2024-05-22T16:38:14.442Z,1716395894.442 [CBIT](INFO): Clearing failed state for component NAL9602 2024-05-22T16:38:14.442Z,1716395894.442 [NAL9602] No Fault, FailCount= 3 2024-05-22T16:38:43.880Z,1716395923.880 [NAL9602](INFO): Powering up NAL9602 2024-05-22T16:38:54.793Z,1716395934.793 [NAL9602](INFO): NAL9602 initialized 2024-05-22T16:39:15.819Z,1716395955.819 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11 2024-05-22T16:39:15.819Z,1716395955.819 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-05-22T16:39:15.840Z,1716395955.840 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-05-22T16:39:16.255Z,1716395956.255 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-05-22T16:39:16.255Z,1716395956.255 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11 2024-05-22T16:41:41.277Z,1716396101.277 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-05-22T16:41:41.277Z,1716396101.277 [Default:CheckIn:C.Wait] Stopped 2024-05-22T16:41:41.277Z,1716396101.277 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-05-22T16:41:41.277Z,1716396101.277 [Default:CheckIn:D] Running Loop=1 2024-05-22T16:41:41.667Z,1716396101.667 [Default:CheckIn:D] Stopped 2024-05-22T16:41:41.667Z,1716396101.667 [Default:CheckIn:E] Running Loop=1 2024-05-22T16:41:42.060Z,1716396102.060 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.684635 min 2024-05-22T16:41:42.060Z,1716396102.060 [Default:CheckIn:E] Stopped 2024-05-22T16:41:42.060Z,1716396102.060 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-05-22T16:41:42.061Z,1716396102.061 [Default:CheckIn] Stopped 2024-05-22T16:41:42.061Z,1716396102.061 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-05-22T16:41:42.061Z,1716396102.061 [Default:CheckIn](INFO): Running loop #4 2024-05-22T16:41:42.061Z,1716396102.061 [Default:CheckIn] Running Loop=4 2024-05-22T16:41:42.061Z,1716396102.061 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-05-22T16:41:42.061Z,1716396102.061 [Default:CheckIn:Read_GPS] Running Loop=1 2024-05-22T16:42:16.827Z,1716396136.827 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12 2024-05-22T16:42:16.827Z,1716396136.827 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-05-22T16:42:16.846Z,1716396136.846 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-05-22T16:42:17.276Z,1716396137.276 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-05-22T16:42:17.276Z,1716396137.276 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12 2024-05-22T16:45:17.936Z,1716396317.936 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13 2024-05-22T16:45:17.936Z,1716396317.936 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-05-22T16:45:17.946Z,1716396317.946 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-05-22T16:45:18.354Z,1716396318.354 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-05-22T16:45:18.354Z,1716396318.354 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13 2024-05-22T16:46:34.746Z,1716396394.746 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164633.00,A,3648.16234,N,12147.28361,W,2.313,178.37,220524,,,A*77 2024-05-22T16:46:34.749Z,1716396394.749 [NAL9602](INFO): GPS fix at 20240522T164633: (36.802706, -121.788060) 2024-05-22T16:46:34.760Z,1716396394.760 [Default:CheckIn:Read_GPS] Stopped 2024-05-22T16:46:34.760Z,1716396394.760 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-05-22T16:46:44.015Z,1716396404.015 [DataOverHttps](INFO): Sending 288 bytes from file Logs/20240522T160553/Courier0013.lzma 2024-05-22T16:46:45.016Z,1716396405.016 [DataOverHttps](INFO): Moved sent file to Logs/20240522T160553/Courier0013.lzma.bak 2024-05-22T16:46:45.017Z,1716396405.017 [DataOverHttps](INFO): SBD MOMSN=21068997 2024-05-22T16:47:06.511Z,1716396426.511 [DataOverHttps](INFO): Sending 345 bytes from file Logs/20240522T160553/Express0014.lzma 2024-05-22T16:47:07.512Z,1716396427.512 [DataOverHttps](INFO): Moved sent file to Logs/20240522T160553/Express0014.lzma.bak 2024-05-22T16:47:07.513Z,1716396427.513 [DataOverHttps](INFO): SBD MOMSN=21069000 2024-05-22T16:47:07.558Z,1716396427.558 [NAL9602](INFO): Not Powering down - fast GPS 2024-05-22T16:47:08.766Z,1716396428.766 [Default:CheckIn:Read_Iridium] Stopped 2024-05-22T16:47:08.766Z,1716396428.766 [Default:CheckIn:C.Wait] Running Loop=1 2024-05-22T16:47:08.766Z,1716396428.766 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-05-22T16:52:09.349Z,1716396729.349 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-05-22T16:52:09.350Z,1716396729.350 [Default:CheckIn:C.Wait] Stopped 2024-05-22T16:52:09.350Z,1716396729.350 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-05-22T16:52:09.350Z,1716396729.350 [Default:CheckIn:D] Running Loop=1 2024-05-22T16:52:09.750Z,1716396729.750 [Default:CheckIn:D] Stopped 2024-05-22T16:52:09.750Z,1716396729.750 [Default:CheckIn:E] Running Loop=1 2024-05-22T16:52:10.158Z,1716396730.158 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.152677 min 2024-05-22T16:52:10.158Z,1716396730.158 [Default:CheckIn:E] Stopped 2024-05-22T16:52:10.158Z,1716396730.158 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-05-22T16:52:10.158Z,1716396730.158 [Default:CheckIn] Stopped 2024-05-22T16:52:10.159Z,1716396730.159 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-05-22T16:52:10.159Z,1716396730.159 [Default:CheckIn](INFO): Running loop #5 2024-05-22T16:52:10.159Z,1716396730.159 [Default:CheckIn] Running Loop=5 2024-05-22T16:52:10.159Z,1716396730.159 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-05-22T16:52:10.159Z,1716396730.159 [Default:CheckIn:Read_GPS] Running Loop=1 2024-05-22T16:52:12.169Z,1716396732.169 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165210.00,A,3648.16861,N,12147.28236,W,0.855,69.63,220524,,,A*41 2024-05-22T16:52:12.181Z,1716396732.181 [NAL9602](INFO): GPS fix at 20240522T165210: (36.802810, -121.788039) 2024-05-22T16:52:12.192Z,1716396732.192 [Default:CheckIn:Read_GPS] Stopped 2024-05-22T16:52:12.192Z,1716396732.192 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-05-22T16:52:21.031Z,1716396741.031 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20240522T160553/Courier0016.lzma 2024-05-22T16:52:22.033Z,1716396742.033 [DataOverHttps](INFO): Moved sent file to Logs/20240522T160553/Courier0016.lzma.bak 2024-05-22T16:52:22.033Z,1716396742.033 [DataOverHttps](INFO): SBD MOMSN=21069025 2024-05-22T16:52:34.457Z,1716396754.457 [NAL9602](INFO): SBD MO Status=2, MOMSN=51299, MT Status=2, MTMSN=0 2024-05-22T16:52:34.458Z,1716396754.458 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-05-22T16:52:39.643Z,1716396759.643 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20240522T160553/Express0017.lzma 2024-05-22T16:52:40.644Z,1716396760.644 [DataOverHttps](INFO): Moved sent file to Logs/20240522T160553/Express0017.lzma.bak 2024-05-22T16:52:40.645Z,1716396760.645 [DataOverHttps](INFO): SBD MOMSN=21069028 2024-05-22T16:52:41.739Z,1716396761.739 [Default:CheckIn:Read_Iridium] Stopped 2024-05-22T16:52:41.739Z,1716396761.739 [Default:CheckIn:C.Wait] Running Loop=1 2024-05-22T16:52:41.740Z,1716396761.740 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-05-22T16:52:59.097Z,1716396779.097 [NAL9602](INFO): SBD MO Status=2, MOMSN=51299, MT Status=2, MTMSN=0 2024-05-22T16:52:59.097Z,1716396779.097 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-05-22T16:53:26.165Z,1716396806.165 [NAL9602](INFO): SBD MO Status=2, MOMSN=51299, MT Status=2, MTMSN=0 2024-05-22T16:53:26.166Z,1716396806.166 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-05-22T16:53:43.128Z,1716396823.128 [NAL9602](INFO): SBD MO Status=2, MOMSN=51299, MT Status=2, MTMSN=0 2024-05-22T16:53:43.128Z,1716396823.128 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-05-22T16:55:15.297Z,1716396915.297 [NAL9602](INFO): SBD MO Status=2, MOMSN=51299, MT Status=2, MTMSN=0 2024-05-22T16:55:15.297Z,1716396915.297 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-05-22T16:55:48.417Z,1716396948.417 [NAL9602](INFO): SBD MO Status=0, MOMSN=51299, MT Status=0, MTMSN=0 2024-05-22T16:55:48.417Z,1716396948.417 [NAL9602](INFO): No messages in MT queue 2024-05-22T16:56:19.160Z,1716396979.160 [NAL9602](INFO): Not Powering down - fast GPS 2024-05-22T16:57:27.035Z,1716397047.035 [CommandExec](IMPORTANT): got command failComponent 2024-05-22T16:57:27.035Z,1716397047.035 [CommandExec](IMPORTANT): Failed components: 2024-05-22T16:57:27.036Z,1716397047.036 [CommandExec](IMPORTANT): No failed Components. 2024-05-22T16:57:42.479Z,1716397062.479 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-05-22T16:57:42.479Z,1716397062.479 [Default:CheckIn:C.Wait] Stopped 2024-05-22T16:57:42.479Z,1716397062.479 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-05-22T16:57:42.479Z,1716397062.479 [Default:CheckIn:D] Running Loop=1 2024-05-22T16:57:42.878Z,1716397062.878 [Default:CheckIn:D] Stopped 2024-05-22T16:57:42.878Z,1716397062.878 [Default:CheckIn:E] Running Loop=1 2024-05-22T16:57:43.287Z,1716397063.287 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 47.704818 min 2024-05-22T16:57:43.287Z,1716397063.287 [Default:CheckIn:E] Stopped 2024-05-22T16:57:43.287Z,1716397063.287 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-05-22T16:57:43.287Z,1716397063.287 [Default:CheckIn] Stopped 2024-05-22T16:57:43.287Z,1716397063.287 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-05-22T16:57:43.287Z,1716397063.287 [Default:CheckIn](INFO): Running loop #6 2024-05-22T16:57:43.287Z,1716397063.287 [Default:CheckIn] Running Loop=6 2024-05-22T16:57:43.287Z,1716397063.287 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-05-22T16:57:43.288Z,1716397063.288 [Default:CheckIn:Read_GPS] Running Loop=1 2024-05-22T16:57:45.306Z,1716397065.306 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165743.00,A,3648.15989,N,12147.25016,W,2.255,200.50,220524,,,A*7E 2024-05-22T16:57:45.308Z,1716397065.308 [NAL9602](INFO): GPS fix at 20240522T165743: (36.802665, -121.787503) 2024-05-22T16:57:45.319Z,1716397065.319 [Default:CheckIn:Read_GPS] Stopped 2024-05-22T16:57:45.319Z,1716397065.319 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-05-22T16:57:52.590Z,1716397072.590 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20240522T160553/Courier0019.lzma 2024-05-22T16:57:53.592Z,1716397073.592 [DataOverHttps](INFO): Moved sent file to Logs/20240522T160553/Courier0019.lzma.bak 2024-05-22T16:57:53.593Z,1716397073.593 [DataOverHttps](INFO): SBD MOMSN=21069055 2024-05-22T16:58:01.053Z,1716397081.053 [NAL9602](INFO): SBD MO Status=0, MOMSN=51300, MT Status=0, MTMSN=0 2024-05-22T16:58:01.053Z,1716397081.053 [NAL9602](INFO): No messages in MT queue 2024-05-22T16:58:02.061Z,1716397082.061 [DataOverHttps](IMPORTANT): SBD MTMSN=20240522T165801 2024-05-22T16:58:09.539Z,1716397089.539 [DataOverHttps](INFO): Sending 198 bytes from file Logs/20240522T160553/Express0020.lzma 2024-05-22T16:58:09.541Z,1716397089.541 [DataOverHttps](INFO): Received command: ibit 2024-05-22T16:58:09.619Z,1716397089.619 [CommandExec](IMPORTANT): got command ibit 2024-05-22T16:58:09.953Z,1716397089.953 [IBIT](IMPORTANT): Beginning Initiated BIT 2024-05-22T16:58:09.954Z,1716397089.954 [IBIT](IMPORTANT): Beginning control surface checks. 2024-05-22T16:58:09.957Z,1716397089.957 [CBIT](IMPORTANT): Beginning ground fault scan 2024-05-22T16:58:10.721Z,1716397090.721 [DataOverHttps](INFO): Moved sent file to Logs/20240522T160553/Express0020.lzma.bak 2024-05-22T16:58:10.721Z,1716397090.721 [DataOverHttps](INFO): SBD MOMSN=21069059 2024-05-22T16:58:11.566Z,1716397091.566 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165809.00,A,3648.15236,N,12147.25342,W,3.149,196.25,220524,,,A*73 2024-05-22T16:58:11.568Z,1716397091.568 [NAL9602](INFO): GPS fix at 20240522T165809: (36.802539, -121.787557) 2024-05-22T16:58:13.989Z,1716397093.989 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165812.00,A,3648.15004,N,12147.25379,W,3.149,181.57,220524,,,A*71 2024-05-22T16:58:13.992Z,1716397093.992 [NAL9602](INFO): GPS fix at 20240522T165812: (36.802501, -121.787563) 2024-05-22T16:58:16.818Z,1716397096.818 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165815.00,A,3648.14786,N,12147.25322,W,2.546,177.78,220524,,,A*7A 2024-05-22T16:58:16.829Z,1716397096.829 [NAL9602](INFO): GPS fix at 20240522T165815: (36.802464, -121.787554) 2024-05-22T16:58:20.044Z,1716397100.044 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165818.00,A,3648.14551,N,12147.25368,W,2.255,178.66,220524,,,A*74 2024-05-22T16:58:20.047Z,1716397100.047 [NAL9602](INFO): GPS fix at 20240522T165818: (36.802425, -121.787561) 2024-05-22T16:58:20.892Z,1716397100.892 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan. 2024-05-22T16:58:21.355Z,1716397101.355 [CBIT](IMPORTANT): Beginning ground fault scan 2024-05-22T16:58:22.903Z,1716397102.903 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165821.00,A,3648.14404,N,12147.25283,W,1.594,152.86,220524,,,A*74 2024-05-22T16:58:22.905Z,1716397102.905 [NAL9602](INFO): GPS fix at 20240522T165821: (36.802401, -121.787547) 2024-05-22T16:58:26.153Z,1716397106.153 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165824.00,A,3648.14353,N,12147.25170,W,0.330,110.86,220524,,,A*74 2024-05-22T16:58:26.172Z,1716397106.172 [NAL9602](INFO): GPS fix at 20240522T165824: (36.802392, -121.787528) 2024-05-22T16:58:29.014Z,1716397109.014 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165827.00,A,3648.14344,N,12147.25167,W,0.097,110.86,220524,,,A*79 2024-05-22T16:58:29.016Z,1716397109.016 [NAL9602](INFO): GPS fix at 20240522T165827: (36.802391, -121.787528) 2024-05-22T16:58:31.166Z,1716397111.166 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20240522T160553/Courier0022.lzma 2024-05-22T16:58:31.843Z,1716397111.843 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165830.00,A,3648.14271,N,12147.25098,W,1.886,124.60,220524,,,A*7F 2024-05-22T16:58:31.845Z,1716397111.845 [NAL9602](INFO): GPS fix at 20240522T165830: (36.802379, -121.787516) 2024-05-22T16:58:32.168Z,1716397112.168 [DataOverHttps](INFO): Moved sent file to Logs/20240522T160553/Courier0022.lzma.bak 2024-05-22T16:58:32.169Z,1716397112.169 [DataOverHttps](INFO): SBD MOMSN=21069067 2024-05-22T16:58:32.394Z,1716397112.394 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.002235 CHAN A1 (24V): 0.000474 CHAN A2 (12V): -0.002207 CHAN A3 (5V): -0.001503 CHAN B0 (3.3V): -0.000006 CHAN B1 (3.15aV): -0.000232 CHAN B2 (3.15bV): -0.000725 CHAN B3 (GND): -0.000409 OPEN: -0.000410 Full Scale: +/- 1 mA 2024-05-22T16:58:35.071Z,1716397115.071 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165833.00,A,3648.14180,N,12147.24863,W,2.663,113.56,220524,,,A*7B 2024-05-22T16:58:35.074Z,1716397115.074 [NAL9602](INFO): GPS fix at 20240522T165833: (36.802363, -121.787477) 2024-05-22T16:58:37.898Z,1716397117.898 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165836.00,A,3648.14104,N,12147.24572,W,3.324,109.41,220524,,,A*75 2024-05-22T16:58:37.900Z,1716397117.900 [NAL9602](INFO): GPS fix at 20240522T165836: (36.802351, -121.787429) 2024-05-22T16:58:41.131Z,1716397121.131 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165839.00,A,3648.13997,N,12147.24280,W,3.071,113.87,220524,,,A*77 2024-05-22T16:58:41.133Z,1716397121.133 [NAL9602](INFO): GPS fix at 20240522T165839: (36.802333, -121.787380) 2024-05-22T16:58:43.958Z,1716397123.958 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165842.00,A,3648.13952,N,12147.24013,W,2.449,98.17,220524,,,A*4F 2024-05-22T16:58:43.960Z,1716397123.960 [NAL9602](INFO): GPS fix at 20240522T165842: (36.802325, -121.787335) 2024-05-22T16:58:46.785Z,1716397126.785 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165845.00,A,3648.13993,N,12147.23718,W,2.760,76.42,220524,,,A*46 2024-05-22T16:58:46.788Z,1716397126.788 [NAL9602](INFO): GPS fix at 20240522T165845: (36.802332, -121.787286) 2024-05-22T16:58:49.249Z,1716397129.249 [DataOverHttps](INFO): Sending 247 bytes from file Logs/20240522T160553/Express0023.lzma 2024-05-22T16:58:50.017Z,1716397130.017 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165848.00,A,3648.14072,N,12147.23360,W,2.080,65.90,220524,,,A*45 2024-05-22T16:58:50.020Z,1716397130.020 [NAL9602](INFO): GPS fix at 20240522T165848: (36.802345, -121.787227) 2024-05-22T16:58:50.249Z,1716397130.249 [DataOverHttps](INFO): Moved sent file to Logs/20240522T160553/Express0023.lzma.bak 2024-05-22T16:58:50.249Z,1716397130.249 [DataOverHttps](INFO): SBD MOMSN=21069069 2024-05-22T16:58:52.844Z,1716397132.844 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165851.00,A,3648.14132,N,12147.23173,W,0.991,58.85,220524,,,A*49 2024-05-22T16:58:52.847Z,1716397132.847 [NAL9602](INFO): GPS fix at 20240522T165851: (36.802355, -121.787195) 2024-05-22T16:58:55.833Z,1716397135.833 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 5 Latitude: 36.802357 Longitude: -121.787193 2024-05-22T16:58:56.110Z,1716397136.110 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165854.00,A,3648.14134,N,12147.23126,W,0.136,58.85,220524,,,A*4F 2024-05-22T16:58:56.120Z,1716397136.120 [NAL9602](INFO): GPS fix at 20240522T165854: (36.802356, -121.787188) 2024-05-22T16:58:56.289Z,1716397136.289 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 0.000000 Voltage: 16.690001 2024-05-22T16:58:56.289Z,1716397136.289 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah 2024-05-22T16:58:56.289Z,1716397136.289 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V 2024-05-22T16:58:56.648Z,1716397136.648 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2024-05-22T16:58:56.648Z,1716397136.648 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2024-05-22T16:58:56.649Z,1716397136.649 [IBIT](IMPORTANT): Pressure:10.353308 PSI 2024-05-22T16:58:56.649Z,1716397136.649 [IBIT](IMPORTANT): Humidity:14.247344 % 2024-05-22T16:58:57.106Z,1716397137.106 [IBIT](IMPORTANT): Vehicle Pitch:-1.081620 degrees 2024-05-22T16:58:57.106Z,1716397137.106 [IBIT](IMPORTANT): Vehicle Roll:3.272608 degrees 2024-05-22T16:58:57.107Z,1716397137.107 [IBIT](IMPORTANT): Vehicle Heading:66.644966 degrees 2024-05-22T16:58:57.488Z,1716397137.488 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2024-05-22T16:58:57.488Z,1716397137.488 [IBIT](IMPORTANT): buoyancyNeutral: 260.000000 cc 2024-05-22T16:58:57.489Z,1716397137.489 [IBIT](IMPORTANT): massDefault: -0.980000 cm 2024-05-22T16:58:57.489Z,1716397137.489 [IBIT](IMPORTANT): stopDepth: 250.000000 m 2024-05-22T16:58:57.489Z,1716397137.489 [IBIT](IMPORTANT): abortDepth: 270.000000 m 2024-05-22T16:58:57.489Z,1716397137.489 [IBIT](IMPORTANT): IBIT PASSED 2024-05-22T16:58:57.812Z,1716397137.812 [Default:CheckIn:Read_Iridium] Stopped 2024-05-22T16:58:57.812Z,1716397137.812 [Default:CheckIn:C.Wait] Running Loop=1 2024-05-22T16:58:57.812Z,1716397137.812 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-05-22T16:59:28.436Z,1716397168.436 [NAL9602](INFO): Not Powering down - fast GPS 2024-05-22T17:03:58.325Z,1716397438.325 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-05-22T17:03:58.325Z,1716397438.325 [Default:CheckIn:C.Wait] Stopped 2024-05-22T17:03:58.325Z,1716397438.325 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-05-22T17:03:58.325Z,1716397438.325 [Default:CheckIn:D] Running Loop=1 2024-05-22T17:03:58.737Z,1716397438.737 [Default:CheckIn:D] Stopped 2024-05-22T17:03:58.737Z,1716397438.737 [Default:CheckIn:E] Running Loop=1 2024-05-22T17:03:59.144Z,1716397439.144 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 53.969120 min 2024-05-22T17:03:59.144Z,1716397439.144 [Default:CheckIn:E] Stopped 2024-05-22T17:03:59.144Z,1716397439.144 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-05-22T17:03:59.144Z,1716397439.144 [Default:CheckIn] Stopped 2024-05-22T17:03:59.145Z,1716397439.145 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-05-22T17:03:59.145Z,1716397439.145 [Default:CheckIn](INFO): Running loop #7 2024-05-22T17:03:59.145Z,1716397439.145 [Default:CheckIn] Running Loop=7 2024-05-22T17:03:59.145Z,1716397439.145 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-05-22T17:03:59.145Z,1716397439.145 [Default:CheckIn:Read_GPS] Running Loop=1 2024-05-22T17:04:01.153Z,1716397441.153 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170359.00,A,3648.14057,N,12147.22862,W,0.019,58.85,220524,,,D*48 2024-05-22T17:04:01.159Z,1716397441.159 [NAL9602](INFO): GPS fix at 20240522T170359: (36.802343, -121.787144) 2024-05-22T17:04:01.198Z,1716397441.198 [Default:CheckIn:Read_GPS] Stopped 2024-05-22T17:04:01.198Z,1716397441.198 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-05-22T17:04:08.170Z,1716397448.170 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20240522T160553/Courier0025.lzma 2024-05-22T17:04:09.174Z,1716397449.174 [DataOverHttps](INFO): Moved sent file to Logs/20240522T160553/Courier0025.lzma.bak 2024-05-22T17:04:09.175Z,1716397449.175 [DataOverHttps](INFO): SBD MOMSN=21069100 2024-05-22T17:04:20.141Z,1716397460.141 [NAL9602](INFO): SBD MO Status=2, MOMSN=51301, MT Status=2, MTMSN=0 2024-05-22T17:04:20.141Z,1716397460.141 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-05-22T17:04:27.808Z,1716397467.808 [DataOverHttps](INFO): Sending 703 bytes from file Logs/20240522T160553/Express0026.lzma 2024-05-22T17:04:28.808Z,1716397468.808 [DataOverHttps](INFO): Moved sent file to Logs/20240522T160553/Express0026.lzma.bak 2024-05-22T17:04:28.809Z,1716397468.809 [DataOverHttps](INFO): SBD MOMSN=21069103 2024-05-22T17:04:29.894Z,1716397469.894 [Default:CheckIn:Read_Iridium] Stopped 2024-05-22T17:04:29.894Z,1716397469.894 [Default:CheckIn:C.Wait] Running Loop=1 2024-05-22T17:04:29.895Z,1716397469.895 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-05-22T17:04:36.344Z,1716397476.344 [NAL9602](INFO): SBD MO Status=2, MOMSN=51301, MT Status=2, MTMSN=0 2024-05-22T17:04:36.344Z,1716397476.344 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-05-22T17:05:10.288Z,1716397510.288 [NAL9602](INFO): SBD MO Status=0, MOMSN=51301, MT Status=0, MTMSN=0 2024-05-22T17:05:10.288Z,1716397510.288 [NAL9602](INFO): No messages in MT queue 2024-05-22T17:05:40.996Z,1716397540.996 [NAL9602](INFO): Not Powering down - fast GPS 2024-05-22T17:06:39.289Z,1716397599.289 [DataOverHttps](IMPORTANT): SBD MTMSN=20240522T170638 2024-05-22T17:06:46.619Z,1716397606.619 [DataOverHttps](INFO): Received command: configSet BPC1.batteryMissingStickThreshold=20 count persist; configSet VerticalControl.buoyancyNeutral=111.682691 cubic_centimeter persist; configSet VerticalControl.massDefault=3.304286 millimeter persist; restart app 2024-05-22T17:06:48.519Z,1716397608.519 [CommandExec](IMPORTANT): got command configSet BPC1.batteryMissingStickThreshold n percent persist 2024-05-22T17:06:48.521Z,1716397608.521 [CommandExec](IMPORTANT): got command configSet VerticalControl.massDefault 2024-05-22T17:06:48.521Z,1716397608.521 [CommandExec](FAULT): Incomplete syntax. Try: help configSet 2024-05-22T17:09:30.478Z,1716397770.478 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-05-22T17:09:30.479Z,1716397770.479 [Default:CheckIn:C.Wait] Stopped 2024-05-22T17:09:30.479Z,1716397770.479 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-05-22T17:09:30.479Z,1716397770.479 [Default:CheckIn:D] Running Loop=1 2024-05-22T17:09:30.891Z,1716397770.891 [Default:CheckIn:D] Stopped 2024-05-22T17:09:30.891Z,1716397770.891 [Default:CheckIn:E] Running Loop=1 2024-05-22T17:09:31.284Z,1716397771.284 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 59.505037 min 2024-05-22T17:09:31.284Z,1716397771.284 [Default:CheckIn:E] Stopped 2024-05-22T17:09:31.285Z,1716397771.285 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-05-22T17:09:31.285Z,1716397771.285 [Default:CheckIn] Stopped 2024-05-22T17:09:31.285Z,1716397771.285 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-05-22T17:09:31.285Z,1716397771.285 [Default:CheckIn](INFO): Running loop #8 2024-05-22T17:09:31.285Z,1716397771.285 [Default:CheckIn] Running Loop=8 2024-05-22T17:09:31.285Z,1716397771.285 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-05-22T17:09:31.285Z,1716397771.285 [Default:CheckIn:Read_GPS] Running Loop=1 2024-05-22T17:09:33.295Z,1716397773.295 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170932.00,A,3648.14914,N,12147.22079,W,0.019,81.84,220524,,,D*46 2024-05-22T17:09:33.297Z,1716397773.297 [NAL9602](INFO): GPS fix at 20240522T170932: (36.802486, -121.787013) 2024-05-22T17:09:33.309Z,1716397773.309 [Default:CheckIn:Read_GPS] Stopped 2024-05-22T17:09:33.309Z,1716397773.309 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-05-22T17:09:40.938Z,1716397780.938 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20240522T160553/Courier0028.lzma 2024-05-22T17:09:41.940Z,1716397781.940 [DataOverHttps](INFO): Moved sent file to Logs/20240522T160553/Courier0028.lzma.bak 2024-05-22T17:09:41.941Z,1716397781.941 [DataOverHttps](INFO): SBD MOMSN=21069154 2024-05-22T17:09:53.088Z,1716397793.088 [NAL9602](INFO): SBD MO Status=0, MOMSN=51302, MT Status=0, MTMSN=0 2024-05-22T17:09:53.088Z,1716397793.088 [NAL9602](INFO): No messages in MT queue 2024-05-22T17:09:57.875Z,1716397797.875 [DataOverHttps](INFO): Sending 287 bytes from file Logs/20240522T160553/Express0029.lzma 2024-05-22T17:09:58.876Z,1716397798.876 [DataOverHttps](INFO): Moved sent file to Logs/20240522T160553/Express0029.lzma.bak 2024-05-22T17:09:58.877Z,1716397798.877 [DataOverHttps](INFO): SBD MOMSN=21069157 2024-05-22T17:10:18.922Z,1716397818.922 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20240522T160553/Express0032.lzma 2024-05-22T17:10:19.925Z,1716397819.925 [DataOverHttps](INFO): Moved sent file to Logs/20240522T160553/Express0032.lzma.bak 2024-05-22T17:10:19.925Z,1716397819.925 [DataOverHttps](INFO): SBD MOMSN=21069167 2024-05-22T17:10:20.997Z,1716397820.997 [Default:CheckIn:Read_Iridium] Stopped 2024-05-22T17:10:20.997Z,1716397820.997 [Default:CheckIn:C.Wait] Running Loop=1 2024-05-22T17:10:20.997Z,1716397820.997 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-05-22T17:10:23.820Z,1716397823.820 [NAL9602](INFO): Not Powering down - fast GPS 2024-05-22T17:15:21.606Z,1716398121.606 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-05-22T17:15:21.606Z,1716398121.606 [Default:CheckIn:C.Wait] Stopped 2024-05-22T17:15:21.606Z,1716398121.606 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-05-22T17:15:21.606Z,1716398121.606 [Default:CheckIn:D] Running Loop=1 2024-05-22T17:15:22.017Z,1716398122.017 [Default:CheckIn:D] Stopped 2024-05-22T17:15:22.017Z,1716398122.017 [Default:CheckIn:E] Running Loop=1 2024-05-22T17:15:22.433Z,1716398122.433 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 65.357137 min 2024-05-22T17:15:22.433Z,1716398122.433 [Default:CheckIn:E] Stopped 2024-05-22T17:15:22.433Z,1716398122.433 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-05-22T17:15:22.433Z,1716398122.433 [Default:CheckIn] Stopped 2024-05-22T17:15:22.433Z,1716398122.433 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-05-22T17:15:22.433Z,1716398122.433 [Default:CheckIn](INFO): Running loop #9 2024-05-22T17:15:22.434Z,1716398122.434 [Default:CheckIn] Running Loop=9 2024-05-22T17:15:22.434Z,1716398122.434 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-05-22T17:15:22.434Z,1716398122.434 [Default:CheckIn:Read_GPS] Running Loop=1 2024-05-22T17:15:24.430Z,1716398124.430 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171523.00,A,3648.16316,N,12147.19010,W,0.914,134.27,220524,,,D*74 2024-05-22T17:15:24.433Z,1716398124.433 [NAL9602](INFO): GPS fix at 20240522T171523: (36.802719, -121.786502) 2024-05-22T17:15:24.471Z,1716398124.471 [Default:CheckIn:Read_GPS] Stopped 2024-05-22T17:15:24.472Z,1716398124.472 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-05-22T17:15:31.790Z,1716398131.790 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20240522T160553/Courier0034.lzma 2024-05-22T17:15:32.792Z,1716398132.792 [DataOverHttps](INFO): Moved sent file to Logs/20240522T160553/Courier0034.lzma.bak 2024-05-22T17:15:32.793Z,1716398132.793 [DataOverHttps](INFO): SBD MOMSN=21069192 2024-05-22T17:15:47.053Z,1716398147.053 [NAL9602](INFO): SBD MO Status=0, MOMSN=51303, MT Status=0, MTMSN=0 2024-05-22T17:15:47.053Z,1716398147.053 [NAL9602](INFO): No messages in MT queue 2024-05-22T17:15:48.687Z,1716398148.687 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20240522T160553/Express0035.lzma 2024-05-22T17:15:49.689Z,1716398149.689 [DataOverHttps](INFO): Moved sent file to Logs/20240522T160553/Express0035.lzma.bak 2024-05-22T17:15:49.689Z,1716398149.689 [DataOverHttps](INFO): SBD MOMSN=21069195 2024-05-22T17:15:50.722Z,1716398150.722 [Default:CheckIn:Read_Iridium] Stopped 2024-05-22T17:15:50.723Z,1716398150.723 [Default:CheckIn:C.Wait] Running Loop=1 2024-05-22T17:15:50.723Z,1716398150.723 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-05-22T17:16:17.756Z,1716398177.756 [NAL9602](INFO): Not Powering down - fast GPS 2024-05-22T17:20:51.384Z,1716398451.384 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-05-22T17:20:51.384Z,1716398451.384 [Default:CheckIn:C.Wait] Stopped 2024-05-22T17:20:51.384Z,1716398451.384 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-05-22T17:20:51.384Z,1716398451.384 [Default:CheckIn:D] Running Loop=1 2024-05-22T17:20:51.790Z,1716398451.790 [Default:CheckIn:D] Stopped 2024-05-22T17:20:51.790Z,1716398451.790 [Default:CheckIn:E] Running Loop=1 2024-05-22T17:20:52.202Z,1716398452.202 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 70.853353 min 2024-05-22T17:20:52.202Z,1716398452.202 [Default:CheckIn:E] Stopped 2024-05-22T17:20:52.202Z,1716398452.202 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-05-22T17:20:52.202Z,1716398452.202 [Default:CheckIn] Stopped 2024-05-22T17:20:52.202Z,1716398452.202 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-05-22T17:20:52.202Z,1716398452.202 [Default:CheckIn](INFO): Running loop #10 2024-05-22T17:20:52.203Z,1716398452.203 [Default:CheckIn] Running Loop=10 2024-05-22T17:20:52.203Z,1716398452.203 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-05-22T17:20:52.203Z,1716398452.203 [Default:CheckIn:Read_GPS] Running Loop=1 2024-05-22T17:20:54.197Z,1716398454.197 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172053.00,A,3648.13629,N,12147.20655,W,0.078,224.25,220524,,,D*77 2024-05-22T17:20:54.200Z,1716398454.200 [NAL9602](INFO): GPS fix at 20240522T172053: (36.802272, -121.786776) 2024-05-22T17:20:54.219Z,1716398454.219 [Default:CheckIn:Read_GPS] Stopped 2024-05-22T17:20:54.219Z,1716398454.219 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-05-22T17:21:01.971Z,1716398461.971 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20240522T160553/Courier0037.lzma 2024-05-22T17:21:02.968Z,1716398462.968 [DataOverHttps](INFO): Moved sent file to Logs/20240522T160553/Courier0037.lzma.bak 2024-05-22T17:21:02.969Z,1716398462.969 [DataOverHttps](INFO): SBD MOMSN=21069227 2024-05-22T17:21:13.602Z,1716398473.602 [NAL9602](INFO): SBD MO Status=0, MOMSN=51304, MT Status=0, MTMSN=0 2024-05-22T17:21:13.603Z,1716398473.603 [NAL9602](INFO): No messages in MT queue 2024-05-22T17:21:18.787Z,1716398478.787 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20240522T160553/Express0038.lzma 2024-05-22T17:21:19.789Z,1716398479.789 [DataOverHttps](INFO): Moved sent file to Logs/20240522T160553/Express0038.lzma.bak 2024-05-22T17:21:19.789Z,1716398479.789 [DataOverHttps](INFO): SBD MOMSN=21069230 2024-05-22T17:21:20.881Z,1716398480.881 [Default:CheckIn:Read_Iridium] Stopped 2024-05-22T17:21:20.881Z,1716398480.881 [Default:CheckIn:C.Wait] Running Loop=1 2024-05-22T17:21:20.881Z,1716398480.881 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-05-22T17:21:44.291Z,1716398504.291 [NAL9602](INFO): Not Powering down - fast GPS 2024-05-22T17:26:21.454Z,1716398781.454 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-05-22T17:26:21.454Z,1716398781.454 [Default:CheckIn:C.Wait] Stopped 2024-05-22T17:26:21.454Z,1716398781.454 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-05-22T17:26:21.454Z,1716398781.454 [Default:CheckIn:D] Running Loop=1 2024-05-22T17:26:21.867Z,1716398781.867 [Default:CheckIn:D] Stopped 2024-05-22T17:26:21.867Z,1716398781.867 [Default:CheckIn:E] Running Loop=1 2024-05-22T17:26:22.288Z,1716398782.288 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 76.354639 min 2024-05-22T17:26:22.288Z,1716398782.288 [Default:CheckIn:E] Stopped 2024-05-22T17:26:22.288Z,1716398782.288 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-05-22T17:26:22.288Z,1716398782.288 [Default:CheckIn] Stopped 2024-05-22T17:26:22.288Z,1716398782.288 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-05-22T17:26:22.288Z,1716398782.288 [Default:CheckIn](INFO): Running loop #11 2024-05-22T17:26:22.288Z,1716398782.288 [Default:CheckIn] Running Loop=11 2024-05-22T17:26:22.288Z,1716398782.288 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-05-22T17:26:22.289Z,1716398782.289 [Default:CheckIn:Read_GPS] Running Loop=1 2024-05-22T17:26:24.269Z,1716398784.269 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172623.00,A,3648.13723,N,12147.20645,W,0.117,224.25,220524,,,D*74 2024-05-22T17:26:24.272Z,1716398784.272 [NAL9602](INFO): GPS fix at 20240522T172623: (36.802287, -121.786774) 2024-05-22T17:26:24.321Z,1716398784.321 [Default:CheckIn:Read_GPS] Stopped 2024-05-22T17:26:24.321Z,1716398784.321 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-05-22T17:26:31.338Z,1716398791.338 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20240522T160553/Courier0040.lzma 2024-05-22T17:26:32.340Z,1716398792.340 [DataOverHttps](INFO): Moved sent file to Logs/20240522T160553/Courier0040.lzma.bak 2024-05-22T17:26:32.341Z,1716398792.341 [DataOverHttps](INFO): SBD MOMSN=21069260 2024-05-22T17:26:42.229Z,1716398802.229 [NAL9602](INFO): SBD MO Status=0, MOMSN=51305, MT Status=0, MTMSN=0 2024-05-22T17:26:42.230Z,1716398802.230 [NAL9602](INFO): No messages in MT queue 2024-05-22T17:26:48.811Z,1716398808.811 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20240522T160553/Express0041.lzma 2024-05-22T17:26:49.813Z,1716398809.813 [DataOverHttps](INFO): Moved sent file to Logs/20240522T160553/Express0041.lzma.bak 2024-05-22T17:26:49.813Z,1716398809.813 [DataOverHttps](INFO): SBD MOMSN=21069263 2024-05-22T17:26:51.134Z,1716398811.134 [Default:CheckIn:Read_Iridium] Stopped 2024-05-22T17:26:51.134Z,1716398811.134 [Default:CheckIn:C.Wait] Running Loop=1 2024-05-22T17:26:51.135Z,1716398811.135 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-05-22T17:27:12.967Z,1716398832.967 [NAL9602](INFO): Not Powering down - fast GPS 2024-05-22T17:28:01.405Z,1716398881.405 [CommandExec](IMPORTANT): got command help configSet 2024-05-22T17:29:30.475Z,1716398970.475 [CommandExec](IMPORTANT): got command configSet BPC1.batteryMissingStickThreshold 20 count persist 2024-05-22T17:29:30.478Z,1716398970.478 [CommandExec](IMPORTANT): got command configSet VerticalControl.buoyancyNeutral 111.682691 cubic_centimeter persist 2024-05-22T17:29:30.480Z,1716398970.480 [CommandExec](IMPORTANT): got command configSet VerticalControl.massDefault 3.304286 millimeter persist 2024-05-22T17:29:30.483Z,1716398970.483 [CommandExec](IMPORTANT): got command restart application 2024-05-22T17:29:31.487Z,1716398971.487 [Supervisor](INFO): Stop Mission called by Supervisor::terminate 2024-05-22T17:29:31.487Z,1716398971.487 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-22T17:29:31.487Z,1716398971.487 [CommandExec](INFO): Uninitializing the command executive. 2024-05-22T17:29:31.487Z,1716398971.487 [CommandExec](INFO): Uninitializing the command scheduler. 2024-05-22T17:29:31.487Z,1716398971.487 [CommandExec ThreadHandler](INFO): Thread cancelled. 2024-05-22T17:29:31.583Z,1716398971.583 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2024-05-22T17:29:31.583Z,1716398971.583 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2024-05-22T17:29:31.583Z,1716398971.583 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2024-05-22T17:29:31.584Z,1716398971.584 [NavChartDb](INFO): Join timeout helper Thread ID is 1301 2024-05-22T17:29:31.895Z,1716398971.895 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-22T17:29:31.895Z,1716398971.895 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2024-05-22T17:29:31.903Z,1716398971.903 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2024-05-22T17:29:31.903Z,1716398971.903 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2024-05-22T17:29:31.903Z,1716398971.903 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1302 2024-05-22T17:29:32.275Z,1716398972.275 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-22T17:29:32.275Z,1716398972.275 [WetLabsBB2FL](INFO): Powering down 2024-05-22T17:29:32.276Z,1716398972.276 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2024-05-22T17:29:32.279Z,1716398972.279 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2024-05-22T17:29:32.279Z,1716398972.279 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2024-05-22T17:29:32.279Z,1716398972.279 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1303 2024-05-22T17:29:33.079Z,1716398973.079 [CTD_Seabird](INFO): Powering down 2024-05-22T17:29:33.096Z,1716398973.096 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-22T17:29:33.101Z,1716398973.101 [CTD_Seabird](INFO): Powering down 2024-05-22T17:29:33.115Z,1716398973.115 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2024-05-22T17:29:33.127Z,1716398973.127 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler 2024-05-22T17:29:33.127Z,1716398973.127 [DAT ThreadHandler](INFO): Thread cancelled. 2024-05-22T17:29:33.127Z,1716398973.127 [DAT](INFO): Join timeout helper Thread ID is 1304 2024-05-22T17:29:33.199Z,1716398973.199 [DAT](INFO): Powering down 2024-05-22T17:29:33.272Z,1716398973.272 [DAT ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-22T17:29:33.272Z,1716398973.272 [DAT](INFO): Powering down 2024-05-22T17:29:33.273Z,1716398973.273 [DAT ThreadHandler](INFO): Thread cancelled. 2024-05-22T17:29:33.291Z,1716398973.291 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2024-05-22T17:29:33.291Z,1716398973.291 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2024-05-22T17:29:33.291Z,1716398973.291 [Radio_Surface](INFO): Join timeout helper Thread ID is 1305 2024-05-22T17:29:33.675Z,1716398973.675 [Radio_Surface](INFO): Powering down 2024-05-22T17:29:33.676Z,1716398973.676 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-22T17:29:33.676Z,1716398973.676 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2024-05-22T17:29:33.680Z,1716398973.680 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2024-05-22T17:29:33.680Z,1716398973.680 [Onboard ThreadHandler](INFO): Thread cancelled. 2024-05-22T17:29:33.680Z,1716398973.680 [Onboard](INFO): Join timeout helper Thread ID is 1306 2024-05-22T17:29:34.511Z,1716398974.511 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2024-05-22T17:29:36.091Z,1716398976.091 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-22T17:29:36.091Z,1716398976.091 [Onboard ThreadHandler](INFO): Thread cancelled. 2024-05-22T17:29:36.100Z,1716398976.100 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2024-05-22T17:29:36.100Z,1716398976.100 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2024-05-22T17:29:36.101Z,1716398976.101 [DataOverHttps](INFO): Join timeout helper Thread ID is 1307