2021-04-11T17:42:52.058Z,1618162972.058 [Supervisor](DEBUG): Initializing supervisor. 2021-04-11T17:42:52.073Z,1618162972.073 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2021-04-11T17:42:52.073Z,1618162972.073 [SyncHandler](INFO): Protected caller Thread ID is 820 2021-04-11T17:42:52.074Z,1618162972.074 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2021-04-11T17:42:52.085Z,1618162972.085 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2021-04-11T17:42:52.085Z,1618162972.085 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 821 2021-04-11T17:42:52.089Z,1618162972.089 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2021-04-11T17:42:52.128Z,1618162972.128 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2021-04-11T17:42:52.141Z,1618162972.141 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2021-04-11T17:42:52.141Z,1618162972.141 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 822 2021-04-11T17:42:52.143Z,1618162972.143 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2021-04-11T17:42:52.153Z,1618162972.153 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2021-04-11T17:42:52.153Z,1618162972.153 [logger ThreadHandler](INFO): Protected caller Thread ID is 823 2021-04-11T17:42:52.157Z,1618162972.157 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2021-04-11T17:42:52.157Z,1618162972.157 [Supervisor](INFO): Looking for Config files in directory: Config/ 2021-04-11T17:42:52.171Z,1618162972.171 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2021-04-11T17:42:52.868Z,1618162972.868 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2021-04-11T17:42:52.870Z,1618162972.870 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2021-04-11T17:42:53.808Z,1618162973.808 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2021-04-11T17:42:53.810Z,1618162973.810 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2021-04-11T17:42:53.913Z,1618162973.913 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2021-04-11T17:42:53.914Z,1618162973.914 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2021-04-11T17:42:54.438Z,1618162974.438 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2021-04-11T17:42:54.440Z,1618162974.440 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2021-04-11T17:42:54.540Z,1618162974.540 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2021-04-11T17:42:54.541Z,1618162974.541 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2021-04-11T17:42:54.906Z,1618162974.906 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2021-04-11T17:42:55.302Z,1618162975.302 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2021-04-11T17:42:55.304Z,1618162975.304 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2021-04-11T17:42:55.454Z,1618162975.454 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2021-04-11T17:42:55.454Z,1618162975.454 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2021-04-11T17:42:55.581Z,1618162975.581 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2021-04-11T17:42:55.582Z,1618162975.582 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2021-04-11T17:42:55.817Z,1618162975.817 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2021-04-11T17:42:55.818Z,1618162975.818 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2021-04-11T17:42:56.267Z,1618162976.267 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2021-04-11T17:42:56.269Z,1618162976.269 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2021-04-11T17:42:56.637Z,1618162976.637 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2021-04-11T17:42:56.639Z,1618162976.639 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2021-04-11T17:42:56.719Z,1618162976.719 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2021-04-11T17:42:56.918Z,1618162976.918 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2021-04-11T17:42:56.919Z,1618162976.919 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2021-04-11T17:42:57.132Z,1618162977.132 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2021-04-11T17:42:57.133Z,1618162977.133 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2021-04-11T17:42:57.384Z,1618162977.384 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2021-04-11T17:42:57.386Z,1618162977.386 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-brizo/ 2021-04-11T17:42:57.389Z,1618162977.389 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Control.cfg 2021-04-11T17:42:57.488Z,1618162977.488 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Sensor.cfg 2021-04-11T17:42:57.635Z,1618162977.635 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Simulator.cfg 2021-04-11T17:42:57.721Z,1618162977.721 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/secure.cfg 2021-04-11T17:42:57.805Z,1618162977.805 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Servo.cfg 2021-04-11T17:42:57.915Z,1618162977.915 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/vehicle.cfg 2021-04-11T17:42:58.100Z,1618162978.100 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Battery.cfg 2021-04-11T17:42:58.356Z,1618162978.356 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2021-04-11T17:42:58.357Z,1618162978.357 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Science.cfg 2021-04-11T17:42:58.480Z,1618162978.480 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/logger.cfg 2021-04-11T17:42:58.577Z,1618162978.577 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/BIT.cfg 2021-04-11T17:42:58.685Z,1618162978.685 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Navigation.cfg 2021-04-11T17:42:58.780Z,1618162978.780 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2021-04-11T17:42:58.794Z,1618162978.794 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2021-04-11T17:42:58.901Z,1618162978.901 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2021-04-11T17:42:58.903Z,1618162978.903 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2021-04-11T17:42:58.919Z,1618162978.919 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2021-04-11T17:42:58.921Z,1618162978.921 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2021-04-11T17:42:58.978Z,1618162978.978 [DepthRateCalculator] Loaded 2021-04-11T17:42:58.978Z,1618162978.978 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2021-04-11T17:42:58.983Z,1618162978.983 [PitchRateCalculator] Loaded 2021-04-11T17:42:58.983Z,1618162978.983 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2021-04-11T17:42:58.994Z,1618162978.994 [SpeedCalculator] Loaded 2021-04-11T17:42:58.994Z,1618162978.994 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2021-04-11T17:42:59.007Z,1618162979.007 [TempGradientCalculator] Loaded 2021-04-11T17:42:59.007Z,1618162979.007 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2021-04-11T17:42:59.012Z,1618162979.012 [YawRateCalculator] Loaded 2021-04-11T17:42:59.012Z,1618162979.012 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2021-04-11T17:42:59.032Z,1618162979.032 [ElevatorOffsetCalculator] Loaded 2021-04-11T17:42:59.032Z,1618162979.032 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2021-04-11T17:42:59.033Z,1618162979.033 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2021-04-11T17:42:59.033Z,1618162979.033 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2021-04-11T17:42:59.101Z,1618162979.101 [VerticalControl](DEBUG): Construct VerticalControl. 2021-04-11T17:42:59.157Z,1618162979.157 [VerticalControl] Loaded 2021-04-11T17:42:59.157Z,1618162979.157 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2021-04-11T17:42:59.159Z,1618162979.159 [HorizontalControl](DEBUG): Construct HorizontalControl. 2021-04-11T17:42:59.196Z,1618162979.196 [HorizontalControl] Loaded 2021-04-11T17:42:59.196Z,1618162979.196 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2021-04-11T17:42:59.199Z,1618162979.199 [SpeedControl](DEBUG): Construct SpeedControl. 2021-04-11T17:42:59.201Z,1618162979.201 [SpeedControl] Loaded 2021-04-11T17:42:59.202Z,1618162979.202 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2021-04-11T17:42:59.204Z,1618162979.204 [LoopControl](DEBUG): Construct LoopControl. 2021-04-11T17:42:59.205Z,1618162979.205 [LoopControl] Loaded 2021-04-11T17:42:59.205Z,1618162979.205 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2021-04-11T17:42:59.205Z,1618162979.205 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2021-04-11T17:42:59.206Z,1618162979.206 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2021-04-11T17:42:59.302Z,1618162979.302 [DeadReckonUsingMultipleVelocitySources] Loaded 2021-04-11T17:42:59.302Z,1618162979.302 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2021-04-11T17:42:59.314Z,1618162979.314 [NavChart] Loaded 2021-04-11T17:42:59.315Z,1618162979.315 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2021-04-11T17:42:59.320Z,1618162979.320 [UniversalFixResidualReporter] Loaded 2021-04-11T17:42:59.320Z,1618162979.320 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2021-04-11T17:42:59.321Z,1618162979.321 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2021-04-11T17:42:59.323Z,1618162979.323 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2021-04-11T17:42:59.447Z,1618162979.447 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2021-04-11T17:42:59.448Z,1618162979.448 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2021-04-11T17:43:00.322Z,1618162980.322 [AHRS_M2] Loaded 2021-04-11T17:43:00.322Z,1618162980.322 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2021-04-11T17:43:00.695Z,1618162980.695 [BackseatComponent] Loaded 2021-04-11T17:43:00.695Z,1618162980.695 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2021-04-11T17:43:00.698Z,1618162980.698 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408674E0 2021-04-11T17:43:00.698Z,1618162980.698 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 905 2021-04-11T17:43:00.701Z,1618162980.701 [LcmUniversalReporter] Loaded 2021-04-11T17:43:00.701Z,1618162980.701 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2021-04-11T17:43:01.459Z,1618162981.459 [BPC1] Loaded 2021-04-11T17:43:01.460Z,1618162981.460 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2021-04-11T17:43:01.607Z,1618162981.607 [DataOverHttps] Loaded 2021-04-11T17:43:01.607Z,1618162981.607 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2021-04-11T17:43:01.608Z,1618162981.608 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408974E0 2021-04-11T17:43:01.608Z,1618162981.608 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 906 2021-04-11T17:43:01.627Z,1618162981.627 [Depth_Keller] Loaded 2021-04-11T17:43:01.628Z,1618162981.628 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2021-04-11T17:43:01.632Z,1618162981.632 [DropWeight] Loaded 2021-04-11T17:43:01.632Z,1618162981.632 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2021-04-11T17:43:01.666Z,1618162981.666 [DVL_micro] Loaded 2021-04-11T17:43:01.666Z,1618162981.666 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2021-04-11T17:43:01.722Z,1618162981.722 [NAL9602] Loaded 2021-04-11T17:43:01.723Z,1618162981.723 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2021-04-11T17:43:01.750Z,1618162981.750 [Onboard] Loaded 2021-04-11T17:43:01.751Z,1618162981.751 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2021-04-11T17:43:01.752Z,1618162981.752 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408C74E0 2021-04-11T17:43:01.752Z,1618162981.752 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 907 2021-04-11T17:43:01.764Z,1618162981.764 [Radio_Surface] Loaded 2021-04-11T17:43:01.765Z,1618162981.765 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2021-04-11T17:43:01.766Z,1618162981.766 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408F74E0 2021-04-11T17:43:01.766Z,1618162981.766 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 908 2021-04-11T17:43:01.844Z,1618162981.844 [DAT] Loaded 2021-04-11T17:43:01.845Z,1618162981.845 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2021-04-11T17:43:01.845Z,1618162981.845 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2021-04-11T17:43:01.846Z,1618162981.846 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2021-04-11T17:43:01.976Z,1618162981.976 [BuoyancyServo] Loaded 2021-04-11T17:43:01.976Z,1618162981.976 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2021-04-11T17:43:01.995Z,1618162981.995 [ElevatorServo] Loaded 2021-04-11T17:43:01.995Z,1618162981.995 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2021-04-11T17:43:02.013Z,1618162982.013 [MassServo] Loaded 2021-04-11T17:43:02.014Z,1618162982.014 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2021-04-11T17:43:02.031Z,1618162982.031 [RudderServo] Loaded 2021-04-11T17:43:02.031Z,1618162982.031 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2021-04-11T17:43:02.048Z,1618162982.048 [ThrusterServo] Loaded 2021-04-11T17:43:02.048Z,1618162982.048 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2021-04-11T17:43:02.049Z,1618162982.049 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2021-04-11T17:43:02.049Z,1618162982.049 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2021-04-11T17:43:02.125Z,1618162982.125 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2021-04-11T17:43:02.126Z,1618162982.126 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2021-04-11T17:43:02.168Z,1618162982.168 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2021-04-11T17:43:02.169Z,1618162982.169 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2021-04-11T17:43:02.523Z,1618162982.523 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2021-04-11T17:43:02.523Z,1618162982.523 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2021-04-11T17:43:02.737Z,1618162982.737 [CTD_Seabird] Loaded 2021-04-11T17:43:02.738Z,1618162982.738 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2021-04-11T17:43:02.739Z,1618162982.739 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A7F4E0 2021-04-11T17:43:02.739Z,1618162982.739 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 909 2021-04-11T17:43:02.770Z,1618162982.770 [ESPComponent] Loaded 2021-04-11T17:43:02.770Z,1618162982.770 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2021-04-11T17:43:02.789Z,1618162982.789 [PAR_Licor] Loaded 2021-04-11T17:43:02.789Z,1618162982.789 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2021-04-11T17:43:02.820Z,1618162982.820 [WetLabsBB2FL] Loaded 2021-04-11T17:43:02.820Z,1618162982.820 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2021-04-11T17:43:02.821Z,1618162982.821 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AAF4E0 2021-04-11T17:43:02.821Z,1618162982.821 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 910 2021-04-11T17:43:02.822Z,1618162982.822 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2021-04-11T17:43:02.823Z,1618162982.823 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2021-04-11T17:43:03.031Z,1618162983.031 [SBIT](DEBUG): Construct Startup Built In Test. 2021-04-11T17:43:03.040Z,1618162983.040 [SBIT] Loaded 2021-04-11T17:43:03.040Z,1618162983.040 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2021-04-11T17:43:03.043Z,1618162983.043 [IBIT](DEBUG): Construct Initiated Built In Test. 2021-04-11T17:43:03.056Z,1618162983.056 [IBIT] Loaded 2021-04-11T17:43:03.056Z,1618162983.056 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2021-04-11T17:43:03.062Z,1618162983.062 [CBIT](DEBUG): Construct Continuous Built In Test. 2021-04-11T17:43:03.161Z,1618162983.161 [CBIT] Loaded 2021-04-11T17:43:03.161Z,1618162983.161 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2021-04-11T17:43:03.161Z,1618162983.161 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2021-04-11T17:43:03.167Z,1618162983.167 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2021-04-11T17:43:03.170Z,1618162983.170 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2021-04-11T17:43:03.180Z,1618162983.180 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2021-04-11T17:43:03.181Z,1618162983.181 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B1B4E0 2021-04-11T17:43:03.181Z,1618162983.181 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 912 2021-04-11T17:43:03.186Z,1618162983.186 [Supervisor](INFO): Main Thread ID is 816 2021-04-11T17:43:03.186Z,1618162983.186 [Supervisor](DEBUG): Running supervisor. 2021-04-11T17:43:03.187Z,1618162983.187 [CommandLine ThreadHandler](INFO): Handler Thread ID is 913 2021-04-11T17:43:03.189Z,1618162983.189 [controlThread ThreadHandler](INFO): Handler Thread ID is 914 2021-04-11T17:43:03.190Z,1618162983.190 [controlThread](DEBUG): Initializing ControlThread 2021-04-11T17:43:03.190Z,1618162983.190 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2021-04-11T17:43:03.191Z,1618162983.191 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2021-04-11T17:43:03.191Z,1618162983.191 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2021-04-11T17:43:03.191Z,1618162983.191 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2021-04-11T17:43:03.192Z,1618162983.192 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2021-04-11T17:43:03.192Z,1618162983.192 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2021-04-11T17:43:03.193Z,1618162983.193 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2021-04-11T17:43:03.195Z,1618162983.195 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2021-04-11T17:43:03.196Z,1618162983.196 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2021-04-11T17:43:03.196Z,1618162983.196 [LoopControl](DEBUG): Initialize LoopControlComponent. 2021-04-11T17:43:03.197Z,1618162983.197 [NavChart](DEBUG): Initialize NavChart Navigation. 2021-04-11T17:43:03.197Z,1618162983.197 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2021-04-11T17:43:03.209Z,1618162983.209 [SBIT](INFO): Initialize SBIT Component. 2021-04-11T17:43:03.210Z,1618162983.210 [SBIT](IMPORTANT): git: 2021-04-08-1-g2cf736d20 2021-04-11T17:43:03.210Z,1618162983.210 [SBIT](INFO): git hash: 2cf736d2050aa38b8c70bc5b54d41b1e0a6791a1 2021-04-11T17:43:03.210Z,1618162983.210 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2021-04-11T17:43:03.210Z,1618162983.210 [SBIT](IMPORTANT): Kernel Version:#1 PREEMPT Tue Sep 24 11:12:27 PDT 2019 2021-04-11T17:43:03.212Z,1618162983.212 [SBIT](INFO): Beginning SBIT in 22.000000 seconds. 2021-04-11T17:43:03.212Z,1618162983.212 [IBIT](INFO): Initialize IBIT Component. 2021-04-11T17:43:03.213Z,1618162983.213 [logger ThreadHandler](INFO): Handler Thread ID is 915 2021-04-11T17:43:03.229Z,1618162983.229 [CBIT](DEBUG): Initialize CBIT Component. 2021-04-11T17:43:03.237Z,1618162983.237 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 916 2021-04-11T17:43:03.241Z,1618162983.241 [CBIT](DEBUG): Initialized mux pins. 2021-04-11T17:43:03.241Z,1618162983.241 [CBIT](DEBUG): Initializing the watchdog timer. 2021-04-11T17:43:03.249Z,1618162983.249 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 917 2021-04-11T17:43:03.250Z,1618162983.250 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2021-04-11T17:43:03.261Z,1618162983.261 [Onboard ThreadHandler](INFO): Handler Thread ID is 918 2021-04-11T17:43:03.265Z,1618162983.265 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2021-04-11T17:43:03.266Z,1618162983.266 [CBIT](DEBUG): Initializing heartbeat. 2021-04-11T17:43:03.293Z,1618162983.293 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 919 2021-04-11T17:43:03.301Z,1618162983.301 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 920 2021-04-11T17:43:03.302Z,1618162983.302 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2021-04-11T17:43:03.306Z,1618162983.306 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 922 2021-04-11T17:43:03.309Z,1618162983.309 [WetLabsBB2FL](INFO): Powering up 2021-04-11T17:43:03.310Z,1618162983.310 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 924 2021-04-11T17:43:03.319Z,1618162983.319 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2021-04-11T17:43:03.320Z,1618162983.320 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2021-04-11T17:43:03.320Z,1618162983.320 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2021-04-11T17:43:03.320Z,1618162983.320 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2021-04-11T17:43:03.320Z,1618162983.320 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2021-04-11T17:43:03.320Z,1618162983.320 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2021-04-11T17:43:03.320Z,1618162983.320 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2021-04-11T17:43:03.321Z,1618162983.321 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2021-04-11T17:43:03.321Z,1618162983.321 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2021-04-11T17:43:03.321Z,1618162983.321 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2021-04-11T17:43:03.321Z,1618162983.321 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2021-04-11T17:43:03.321Z,1618162983.321 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2021-04-11T17:43:03.322Z,1618162983.322 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2021-04-11T17:43:03.322Z,1618162983.322 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2021-04-11T17:43:03.322Z,1618162983.322 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2021-04-11T17:43:03.322Z,1618162983.322 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2021-04-11T17:43:03.337Z,1618162983.337 [CBIT](DEBUG): Deactivating GF circuits. 2021-04-11T17:43:03.337Z,1618162983.337 [CBIT](DEBUG): Deactivating emergency mode. 2021-04-11T17:43:03.373Z,1618162983.373 [CBIT](DEBUG): Backplane powered. 2021-04-11T17:43:03.374Z,1618162983.374 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2021-04-11T17:43:03.409Z,1618162983.409 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2021-04-11T17:43:03.420Z,1618162983.420 [MissionManager](DEBUG): 2021-04-11T17:43:03.420Z,1618162983.420 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2021-04-11T17:43:03.491Z,1618162983.491 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2021-04-11T17:43:03.492Z,1618162983.492 [Default:A.Wait](DEBUG): Construct Wait. 2021-04-11T17:43:03.530Z,1618162983.530 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2021-04-11T17:43:03.566Z,1618162983.566 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2021-04-11T17:43:03.568Z,1618162983.568 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2021-04-11T17:43:03.590Z,1618162983.590 [Default:E.Execute](DEBUG): Construct Execute. 2021-04-11T17:43:03.606Z,1618162983.606 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2021-04-11T17:43:03.611Z,1618162983.611 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,DAT,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2021-04-11T17:43:03.621Z,1618162983.621 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2021-04-11T17:43:03.697Z,1618162983.697 [Radio_Surface](INFO): Powering up 2021-04-11T17:43:03.904Z,1618162983.904 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2021-04-11T17:43:03.904Z,1618162983.904 [DAT](INFO): Powering up 2021-04-11T17:43:03.905Z,1618162983.905 [DAT](DEBUG): Initializing DAT. 2021-04-11T17:43:03.984Z,1618162983.984 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2021-04-11T17:43:03.985Z,1618162983.985 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2021-04-11T17:43:04.017Z,1618162984.017 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2021-04-11T17:43:04.018Z,1618162984.018 [ElevatorServo](DEBUG): Initializing EZServoServo. 2021-04-11T17:43:04.033Z,1618162984.033 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2021-04-11T17:43:04.034Z,1618162984.034 [MassServo](DEBUG): Initializing EZServoServo. 2021-04-11T17:43:04.045Z,1618162984.045 [MassServo](DEBUG): Initializing MassServo. 2021-04-11T17:43:04.046Z,1618162984.046 [RudderServo](DEBUG): Initializing EZServoServo. 2021-04-11T17:43:04.057Z,1618162984.057 [RudderServo](DEBUG): Initializing RudderServo. 2021-04-11T17:43:04.058Z,1618162984.058 [ThrusterServo](DEBUG): Initializing EZServoServo. 2021-04-11T17:43:04.069Z,1618162984.069 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2021-04-11T17:43:05.921Z,1618162985.921 [WetLabsBB2FL](INFO): Powering down 2021-04-11T17:43:17.929Z,1618162997.929 [DAT](INFO): commRate: 800 2021-04-11T17:43:19.943Z,1618162999.943 [DAT](INFO): entering command mode 2021-04-11T17:43:20.347Z,1618163000.347 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:20.751Z,1618163000.751 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:21.155Z,1618163001.155 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:21.584Z,1618163001.584 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:21.963Z,1618163001.963 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:22.367Z,1618163002.367 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:22.771Z,1618163002.771 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:23.179Z,1618163003.179 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:23.579Z,1618163003.579 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:23.992Z,1618163003.992 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:24.388Z,1618163004.388 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:24.791Z,1618163004.791 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:25.195Z,1618163005.195 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:25.599Z,1618163005.599 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:25.645Z,1618163005.645 [SBIT](IMPORTANT): Beginning Startup BIT 2021-04-11T17:43:25.653Z,1618163005.653 [CBIT](IMPORTANT): Beginning ground fault scan 2021-04-11T17:43:26.003Z,1618163006.003 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:26.416Z,1618163006.416 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:26.816Z,1618163006.816 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:27.215Z,1618163007.215 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:27.627Z,1618163007.627 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:28.023Z,1618163008.023 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:28.443Z,1618163008.443 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:28.845Z,1618163008.845 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:29.245Z,1618163009.245 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:29.639Z,1618163009.639 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:30.056Z,1618163010.056 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:30.447Z,1618163010.447 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:30.851Z,1618163010.851 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:31.255Z,1618163011.255 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:31.676Z,1618163011.676 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:32.063Z,1618163012.063 [NAL9602](INFO): Powering up NAL9602 2021-04-11T17:43:32.064Z,1618163012.064 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:32.467Z,1618163012.467 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:32.871Z,1618163012.871 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:33.280Z,1618163013.280 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:33.679Z,1618163013.679 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:34.093Z,1618163014.093 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:34.487Z,1618163014.487 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:34.899Z,1618163014.899 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:35.295Z,1618163015.295 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:43:35.295Z,1618163015.295 [DAT](FAULT): failed to enter command mode 2021-04-11T17:43:35.699Z,1618163015.699 [DAT](INFO): entering command mode 2021-04-11T17:43:36.112Z,1618163016.112 [DAT](INFO): setting verbose to 3 2021-04-11T17:43:36.513Z,1618163016.513 [DAT](INFO): set verbose to 3 2021-04-11T17:43:36.513Z,1618163016.513 [DAT](INFO): setting DatVerbose to 27440 2021-04-11T17:43:36.612Z,1618163016.612 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.001902 CHAN A1 (24V): -0.002126 CHAN A2 (12V): -0.000071 CHAN A3 (5V): 0.000826 CHAN B0 (3.3V): -0.000070 CHAN B1 (3.15aV): 0.001284 CHAN B2 (3.15bV): -0.000283 CHAN B3 (GND): 0.000847 OPEN: -0.004591 Full Scale Calc: 4.765 mA, -1.589 mA 2021-04-11T17:43:36.926Z,1618163016.926 [DAT](INFO): set DatVerbose to 27440 2021-04-11T17:43:36.926Z,1618163016.926 [DAT](INFO): setting transmit power to 8 2021-04-11T17:43:37.316Z,1618163017.316 [DAT](INFO): set transmit power to 8 2021-04-11T17:43:37.316Z,1618163017.316 [DAT](INFO): setting local address to 8 2021-04-11T17:43:37.726Z,1618163017.726 [DAT](INFO): set local address to 8 2021-04-11T17:43:42.971Z,1618163022.971 [NAL9602](INFO): NAL9602 initialized 2021-04-11T17:44:19.770Z,1618163059.770 [SBIT](IMPORTANT): SBIT PASSED 2021-04-11T17:44:19.770Z,1618163059.770 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2021-04-11T17:44:19.771Z,1618163059.771 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count; 2021-04-11T17:44:19.771Z,1618163059.771 [SBIT](IMPORTANT): BackseatComponent.loadAtStartup=1 bool; 2021-04-11T17:44:19.771Z,1618163059.771 [SBIT](IMPORTANT): BackseatComponent.simulateHardware=1 bool; 2021-04-11T17:44:19.771Z,1618163059.771 [SBIT](IMPORTANT): DAT.sbdAddress=-1 enum; 2021-04-11T17:44:19.771Z,1618163059.771 [SBIT](IMPORTANT): DAT.surfaceThreshold=-0.5 meter; 2021-04-11T17:44:19.772Z,1618163059.772 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=1 bool; 2021-04-11T17:44:19.772Z,1618163059.772 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=1 minute; 2021-04-11T17:44:19.772Z,1618163059.772 [SBIT](IMPORTANT): ESPComponent.simulateHardware=1 bool; 2021-04-11T17:44:19.772Z,1618163059.772 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=194.169302 cubic_centimeter; 2021-04-11T17:44:19.772Z,1618163059.772 [SBIT](IMPORTANT): VerticalControl.massDefault=-0.743969 millimeter; 2021-04-11T17:44:20.163Z,1618163060.163 [MissionManager](IMPORTANT): Started mission Startup 2021-04-11T17:44:20.164Z,1618163060.164 [Startup] Running Loop=1 2021-04-11T17:44:20.164Z,1618163060.164 [Startup](DEBUG): Aggregate::initialize Startup 2021-04-11T17:44:20.164Z,1618163060.164 [Startup:A.GoToSurface] Running Loop=1 2021-04-11T17:44:20.164Z,1618163060.164 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2021-04-11T17:44:20.164Z,1618163060.164 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2021-04-11T17:44:20.165Z,1618163060.165 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2021-04-11T17:44:20.165Z,1618163060.165 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2021-04-11T17:44:20.166Z,1618163060.166 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2021-04-11T17:44:20.166Z,1618163060.166 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2021-04-11T17:44:20.168Z,1618163060.168 [Startup:StartupSatComms] Running Loop=1 2021-04-11T17:44:20.168Z,1618163060.168 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2021-04-11T17:44:20.168Z,1618163060.168 [Startup:StartupSatComms:A] Running Loop=1 2021-04-11T17:44:20.559Z,1618163060.559 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2021-04-11T17:44:31.503Z,1618163071.503 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-11T17:45:14.756Z,1618163114.756 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-11T17:45:20.371Z,1618163120.371 [Startup:StartupSatComms:A](INFO): Timed out from 2021-04-11T17:44:20.2Z 2021-04-11T17:45:20.371Z,1618163120.371 [Startup:StartupSatComms:A] Stopped 2021-04-11T17:45:20.372Z,1618163120.372 [Startup:StartupSatComms:B] Running Loop=1 2021-04-11T17:45:20.760Z,1618163120.760 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2021-04-11T17:45:27.087Z,1618163127.087 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005001 2021-04-11T17:45:27.665Z,1618163127.665 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-11T17:45:34.358Z,1618163134.358 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210411T171644/Courier0010.lzma 2021-04-11T17:45:35.359Z,1618163135.359 [DataOverHttps](INFO): Moved sent file to Logs/20210411T171644/Courier0010.lzma.bak 2021-04-11T17:45:35.359Z,1618163135.359 [DataOverHttps](INFO): SBD MOMSN=15558437 2021-04-11T17:45:44.218Z,1618163144.218 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-11T17:45:51.797Z,1618163151.797 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20210411T174252/Courier0000.lzma 2021-04-11T17:45:52.799Z,1618163152.799 [DataOverHttps](INFO): Moved sent file to Logs/20210411T174252/Courier0000.lzma.bak 2021-04-11T17:45:52.799Z,1618163152.799 [DataOverHttps](INFO): SBD MOMSN=15558439 2021-04-11T17:45:55.984Z,1618163155.984 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-11T17:46:03.578Z,1618163163.578 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2021-04-11T17:46:03.578Z,1618163163.578 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-04-11T17:46:03.589Z,1618163163.589 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-04-11T17:46:03.999Z,1618163163.999 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-04-11T17:46:03.999Z,1618163163.999 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2021-04-11T17:46:08.522Z,1618163168.522 [DataOverHttps](INFO): Sending 127 bytes from file Logs/20210411T171644/Express0011.lzma 2021-04-11T17:46:09.523Z,1618163169.523 [DataOverHttps](INFO): Moved sent file to Logs/20210411T171644/Express0011.lzma.bak 2021-04-11T17:46:09.523Z,1618163169.523 [DataOverHttps](INFO): SBD MOMSN=15558442 2021-04-11T17:46:20.551Z,1618163180.551 [Startup:StartupSatComms:B](INFO): Timed out from 2021-04-11T17:45:20.4Z 2021-04-11T17:46:20.552Z,1618163180.552 [Startup:StartupSatComms:B] Stopped 2021-04-11T17:46:20.552Z,1618163180.552 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2021-04-11T17:46:20.552Z,1618163180.552 [Startup:StartupSatComms] Stopped 2021-04-11T17:46:20.552Z,1618163180.552 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2021-04-11T17:46:20.553Z,1618163180.553 [Startup](INFO): Completed Startup 2021-04-11T17:46:20.553Z,1618163180.553 [MissionManager](INFO): Startup is completed. 2021-04-11T17:46:20.553Z,1618163180.553 [MissionManager](INFO): Uninitializing Mission Startup 2021-04-11T17:46:20.553Z,1618163180.553 [Startup] Stopped 2021-04-11T17:46:20.553Z,1618163180.553 [Startup](DEBUG): Aggregate::uninitialize Startup 2021-04-11T17:46:20.554Z,1618163180.554 [Startup:A.GoToSurface] Stopped 2021-04-11T17:46:20.554Z,1618163180.554 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2021-04-11T17:46:20.974Z,1618163180.974 [MissionManager](IMPORTANT): Started mission Default 2021-04-11T17:46:20.974Z,1618163180.974 [Default] Running Loop=1 2021-04-11T17:46:20.974Z,1618163180.974 [Default](DEBUG): Aggregate::initialize Default 2021-04-11T17:46:20.974Z,1618163180.974 [Default:B.GoToSurface] Running Loop=1 2021-04-11T17:46:20.975Z,1618163180.975 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2021-04-11T17:46:20.975Z,1618163180.975 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2021-04-11T17:46:20.975Z,1618163180.975 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2021-04-11T17:46:20.975Z,1618163180.975 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2021-04-11T17:46:20.976Z,1618163180.976 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2021-04-11T17:46:20.976Z,1618163180.976 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2021-04-11T17:46:20.976Z,1618163180.976 [Default:A.Wait] Running Loop=1 2021-04-11T17:46:20.976Z,1618163180.976 [Default:A.Wait](DEBUG): Initialize Wait Component. 2021-04-11T17:46:22.219Z,1618163182.219 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-11T17:46:25.099Z,1618163185.099 [DataOverHttps](INFO): Sending 933 bytes from file Logs/20210411T174252/Express0001.lzma 2021-04-11T17:46:26.098Z,1618163186.098 [DataOverHttps](INFO): Moved sent file to Logs/20210411T174252/Express0001.lzma.bak 2021-04-11T17:46:26.099Z,1618163186.099 [DataOverHttps](INFO): SBD MOMSN=15558446 2021-04-11T17:46:34.292Z,1618163194.292 [Default:A.Wait](INFO): Done Waiting. 2021-04-11T17:46:34.292Z,1618163194.292 [Default:A.Wait] Stopped 2021-04-11T17:46:34.292Z,1618163194.292 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2021-04-11T17:46:34.707Z,1618163194.707 [Default:CheckIn] Running Loop=1 2021-04-11T17:46:34.707Z,1618163194.707 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-11T17:46:34.707Z,1618163194.707 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-11T17:46:35.182Z,1618163195.182 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2021-04-11T17:47:08.265Z,1618163228.265 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-11T17:47:20.780Z,1618163240.780 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-11T17:47:38.537Z,1618163258.537 [DVL_micro](ERROR): only read 3 of 4 data items 2021-04-11T17:47:38.537Z,1618163258.537 [DVL_micro](ERROR): Failed to parse: :BI,-00030,-00138,+0010,I 2021-04-11T17:47:51.084Z,1618163271.084 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-11T17:48:33.120Z,1618163313.120 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-11T17:48:45.978Z,1618163325.978 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-11T17:49:01.382Z,1618163341.382 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-11T17:49:04.597Z,1618163344.597 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2021-04-11T17:49:04.597Z,1618163344.597 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-04-11T17:49:04.608Z,1618163344.608 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-04-11T17:49:05.011Z,1618163345.011 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-04-11T17:49:05.012Z,1618163345.012 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2021-04-11T17:49:11.879Z,1618163351.879 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-11T17:49:29.661Z,1618163369.661 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-11T17:49:36.514Z,1618163376.514 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-11T17:50:02.813Z,1618163402.813 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-11T17:50:03.948Z,1618163403.948 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-04-11T17:50:03.948Z,1618163403.948 [DVL_micro](ERROR): Failed to parse: :TS0000000,35.0,+19.4,0000.0,1489.0,000 2021-04-11T17:50:25.410Z,1618163425.410 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-11T17:50:27.419Z,1618163427.419 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-11T17:50:36.800Z,1618163436.800 [CommandLine](IMPORTANT): got command run ./Missions/send_rep_test.xml 2021-04-11T17:50:36.800Z,1618163436.800 [MissionManager](INFO): Loading Mission: ./Missions/send_rep_test.xml 2021-04-11T17:50:36.896Z,1618163436.896 [MissionManager](INFO): DefineArg esp_sample_at_depth.SendRepeat = 2.000000 count 2021-04-11T17:50:36.903Z,1618163436.903 [MissionManager](INFO): DefineOutput esp_sample_at_depth.CntSamples = 1.000000 count 2021-04-11T17:50:37.020Z,1618163437.020 [esp_sample_at_depth:SendRep:C.Wait](DEBUG): Construct Wait. 2021-04-11T17:50:37.038Z,1618163437.038 [MissionManager](DEBUG): This mission takes ESP samples at the designated depth. 2 Count of water samples (initilized to 1). 1 CntSamples = ESPComponent.sample_number = ESPComponent.cartridge = Science:ESPComponent.sampleVolume = Universal:depth = Universal:sea_water_temperature = Universal:mass_concentration_of_chlorophyll_in_sea_water = 1 10 2021-04-11T17:50:37.040Z,1618163437.040 [CommandLine](IMPORTANT): Running ./Missions/send_rep_test.xml 2021-04-11T17:50:37.127Z,1618163437.127 [Default] Stopped 2021-04-11T17:50:37.127Z,1618163437.127 [Default](DEBUG): Aggregate::uninitialize Default 2021-04-11T17:50:37.127Z,1618163437.127 [Default:B.GoToSurface] Stopped 2021-04-11T17:50:37.127Z,1618163437.127 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2021-04-11T17:50:37.127Z,1618163437.127 [Default:CheckIn] Stopped 2021-04-11T17:50:37.128Z,1618163437.128 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-11T17:50:37.128Z,1618163437.128 [Default:CheckIn:Read_GPS] Stopped 2021-04-11T17:50:37.128Z,1618163437.128 [MissionManager](IMPORTANT): Started mission esp_sample_at_depth 2021-04-11T17:50:37.128Z,1618163437.128 [esp_sample_at_depth] Running Loop=1 2021-04-11T17:50:37.128Z,1618163437.128 [esp_sample_at_depth](DEBUG): Aggregate::initialize esp_sample_at_depth 2021-04-11T17:50:37.128Z,1618163437.128 [esp_sample_at_depth:SendRep] Running Loop=1 2021-04-11T17:50:37.128Z,1618163437.128 [esp_sample_at_depth:SendRep](DEBUG): Aggregate::initialize esp_sample_at_depth:SendRep 2021-04-11T17:50:37.137Z,1618163437.137 [esp_sample_at_depth:SendRep:ReportSample] Running Loop=1 2021-04-11T17:50:37.137Z,1618163437.137 [esp_sample_at_depth:SendRep:ReportSample](DEBUG): Aggregate::initialize esp_sample_at_depth:SendRep:ReportSample 2021-04-11T17:50:37.137Z,1618163437.137 [esp_sample_at_depth:SendDataTo1Modem] Running Loop=1 2021-04-11T17:50:37.137Z,1618163437.137 [esp_sample_at_depth:SendDataTo1Modem](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem 2021-04-11T17:50:37.137Z,1618163437.137 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem] Running Loop=1 2021-04-11T17:50:37.137Z,1618163437.137 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem 2021-04-11T17:50:37.138Z,1618163437.138 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples] Running Loop=1 2021-04-11T17:50:37.138Z,1618163437.138 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples 2021-04-11T17:50:37.138Z,1618163437.138 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:A] Running Loop=1 2021-04-11T17:50:37.138Z,1618163437.138 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:A](IMPORTANT): CntSamples = 1.000000 count 2021-04-11T17:50:37.138Z,1618163437.138 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:A] Stopped 2021-04-11T17:50:37.139Z,1618163437.139 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:B] Running Loop=1 2021-04-11T17:50:37.502Z,1618163437.502 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:B](INFO): Queuing up send data for esp_sample_at_depth.CntSamples. 2021-04-11T17:50:37.502Z,1618163437.502 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:B](INFO): Inserting _.LRAUVcntSamples to buffer. 2021-04-11T17:50:37.502Z,1618163437.502 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:B] Stopped 2021-04-11T17:50:37.502Z,1618163437.502 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples](INFO): Completed esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples 2021-04-11T17:50:37.502Z,1618163437.502 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples] Stopped 2021-04-11T17:50:37.503Z,1618163437.503 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples 2021-04-11T17:50:37.503Z,1618163437.503 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber] Running Loop=1 2021-04-11T17:50:37.503Z,1618163437.503 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber 2021-04-11T17:50:37.503Z,1618163437.503 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber:A] Running Loop=1 2021-04-11T17:50:37.901Z,1618163437.901 [DAT](INFO): modem://6: set _.LRAUVcntSamples 1.000000 count 2021-04-11T17:50:37.901Z,1618163437.901 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-04-11T17:50:37.913Z,1618163437.913 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber] Stopped 2021-04-11T17:50:37.913Z,1618163437.913 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber 2021-04-11T17:50:37.913Z,1618163437.913 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleNumber:A] Stopped 2021-04-11T17:50:37.914Z,1618163437.914 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType] Running Loop=1 2021-04-11T17:50:37.914Z,1618163437.914 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType 2021-04-11T17:50:37.914Z,1618163437.914 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType:A] Running Loop=1 2021-04-11T17:50:38.284Z,1618163438.284 [DAT](INFO): entering command mode 2021-04-11T17:50:38.307Z,1618163438.307 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType] Stopped 2021-04-11T17:50:38.307Z,1618163438.307 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType 2021-04-11T17:50:38.308Z,1618163438.308 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPCartridgeType:A] Stopped 2021-04-11T17:50:38.308Z,1618163438.308 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume] Running Loop=1 2021-04-11T17:50:38.308Z,1618163438.308 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume 2021-04-11T17:50:38.308Z,1618163438.308 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume:A] Running Loop=1 2021-04-11T17:50:38.694Z,1618163438.694 [DAT](INFO): commRate: 800 2021-04-11T17:50:38.711Z,1618163438.711 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume:A](ERROR): data element is not active. 2021-04-11T17:50:38.711Z,1618163438.711 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume:A](IMPORTANT): Science:ESPComponent.sampleVolume = nan ml 2021-04-11T17:50:38.711Z,1618163438.711 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume:A] Stopped 2021-04-11T17:50:38.711Z,1618163438.711 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume:B] Running Loop=1 2021-04-11T17:50:39.123Z,1618163439.123 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume:B](INFO): Queuing up send data for ESPComponent.sampleVolume. 2021-04-11T17:50:39.123Z,1618163439.123 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume:B](INFO): Inserting _.ESPsampleVolume to buffer. 2021-04-11T17:50:39.123Z,1618163439.123 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume:B] Stopped 2021-04-11T17:50:39.123Z,1618163439.123 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume](INFO): Completed esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume 2021-04-11T17:50:39.123Z,1618163439.123 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume] Stopped 2021-04-11T17:50:39.124Z,1618163439.124 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataESPSampleVolume 2021-04-11T17:50:39.124Z,1618163439.124 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth] Running Loop=1 2021-04-11T17:50:39.124Z,1618163439.124 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth 2021-04-11T17:50:39.124Z,1618163439.124 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth:A] Running Loop=1 2021-04-11T17:50:39.668Z,1618163439.668 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth:A](IMPORTANT): Universal:depth = 0.231765 m 2021-04-11T17:50:39.668Z,1618163439.668 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth:A] Stopped 2021-04-11T17:50:39.668Z,1618163439.668 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth:B] Running Loop=1 2021-04-11T17:50:39.967Z,1618163439.967 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth:B](INFO): Queuing up send data for depth. 2021-04-11T17:50:39.967Z,1618163439.967 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth:B](INFO): Inserting _.sampleDepth to buffer. 2021-04-11T17:50:39.967Z,1618163439.967 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth:B] Stopped 2021-04-11T17:50:39.967Z,1618163439.967 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth](INFO): Completed esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth 2021-04-11T17:50:39.967Z,1618163439.967 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth] Stopped 2021-04-11T17:50:39.967Z,1618163439.967 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleDepth 2021-04-11T17:50:39.968Z,1618163439.968 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp] Running Loop=1 2021-04-11T17:50:39.968Z,1618163439.968 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp 2021-04-11T17:50:39.968Z,1618163439.968 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp:A] Running Loop=1 2021-04-11T17:50:40.444Z,1618163440.444 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp:A](ERROR): data element is not active. 2021-04-11T17:50:40.444Z,1618163440.444 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp:A](IMPORTANT): Universal:sea_water_temperature = nan degC 2021-04-11T17:50:40.444Z,1618163440.444 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp:A] Stopped 2021-04-11T17:50:40.444Z,1618163440.444 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp:B] Running Loop=1 2021-04-11T17:50:40.716Z,1618163440.716 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:40.759Z,1618163440.759 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp:B](ERROR): Failed to send data. sea_water_temperature has no value. 2021-04-11T17:50:40.759Z,1618163440.759 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp:B] Stopped 2021-04-11T17:50:40.759Z,1618163440.759 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp](INFO): Completed esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp 2021-04-11T17:50:40.759Z,1618163440.759 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp] Stopped 2021-04-11T17:50:40.759Z,1618163440.759 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleTemp 2021-04-11T17:50:40.759Z,1618163440.759 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl] Running Loop=1 2021-04-11T17:50:40.759Z,1618163440.759 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl 2021-04-11T17:50:40.760Z,1618163440.760 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl:A] Running Loop=1 2021-04-11T17:50:41.144Z,1618163441.144 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:41.159Z,1618163441.159 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl:A](ERROR): data element is not active. 2021-04-11T17:50:41.159Z,1618163441.159 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl:A](IMPORTANT): Universal:mass_concentration_of_chlorophyll_in_sea_water = nan ug/l 2021-04-11T17:50:41.159Z,1618163441.159 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl:A] Stopped 2021-04-11T17:50:41.160Z,1618163441.160 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl:B] Running Loop=1 2021-04-11T17:50:41.537Z,1618163441.537 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:41.545Z,1618163441.545 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl:B](ERROR): Failed to send data. mass_concentration_of_chlorophyll_in_sea_water has no value. 2021-04-11T17:50:41.546Z,1618163441.546 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl:B] Stopped 2021-04-11T17:50:41.546Z,1618163441.546 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl](INFO): Completed esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl 2021-04-11T17:50:41.546Z,1618163441.546 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl] Stopped 2021-04-11T17:50:41.546Z,1618163441.546 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataSampleChl 2021-04-11T17:50:41.546Z,1618163441.546 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem](INFO): Completed esp_sample_at_depth:SendDataTo1Modem:SendDataToModem 2021-04-11T17:50:41.546Z,1618163441.546 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem] Stopped 2021-04-11T17:50:41.546Z,1618163441.546 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem 2021-04-11T17:50:41.546Z,1618163441.546 [esp_sample_at_depth:SendDataTo1Modem](INFO): Completed esp_sample_at_depth:SendDataTo1Modem 2021-04-11T17:50:41.547Z,1618163441.547 [esp_sample_at_depth:SendDataTo1Modem] Stopped 2021-04-11T17:50:41.547Z,1618163441.547 [esp_sample_at_depth:SendDataTo1Modem](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendDataTo1Modem 2021-04-11T17:50:41.939Z,1618163441.939 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:41.947Z,1618163441.947 [esp_sample_at_depth:SendRep:ReportSample](INFO): Completed esp_sample_at_depth:SendRep:ReportSample 2021-04-11T17:50:41.947Z,1618163441.947 [esp_sample_at_depth:SendRep:ReportSample] Stopped 2021-04-11T17:50:41.947Z,1618163441.947 [esp_sample_at_depth:SendRep:ReportSample](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendRep:ReportSample 2021-04-11T17:50:41.948Z,1618163441.948 [esp_sample_at_depth:SendRep:B] Running Loop=1 2021-04-11T17:50:42.346Z,1618163442.346 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:42.371Z,1618163442.371 [esp_sample_at_depth:SendRep:B] Stopped 2021-04-11T17:50:42.371Z,1618163442.371 [esp_sample_at_depth:SendRep:C.Wait] Running Loop=1 2021-04-11T17:50:42.371Z,1618163442.371 [esp_sample_at_depth:SendRep:C.Wait](DEBUG): Initialize Wait Component. 2021-04-11T17:50:42.745Z,1618163442.745 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:43.153Z,1618163443.153 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:43.540Z,1618163443.540 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:43.944Z,1618163443.944 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:44.344Z,1618163444.344 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:44.767Z,1618163444.767 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:45.156Z,1618163445.156 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:45.565Z,1618163445.565 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-11T17:50:45.594Z,1618163445.594 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:45.989Z,1618163445.989 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:46.397Z,1618163446.397 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:46.768Z,1618163446.768 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:47.185Z,1618163447.185 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:47.581Z,1618163447.581 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:47.984Z,1618163447.984 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:48.402Z,1618163448.402 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:48.805Z,1618163448.805 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:49.212Z,1618163449.212 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:49.621Z,1618163449.621 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:49.000Z,1618163450.000 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:50.404Z,1618163450.404 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:50.818Z,1618163450.818 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:51.223Z,1618163451.223 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:51.634Z,1618163451.634 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:52.069Z,1618163452.069 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:52.445Z,1618163452.445 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:52.835Z,1618163452.835 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:52.843Z,1618163452.843 [esp_sample_at_depth:SendRep:C.Wait](INFO): Done Waiting. 2021-04-11T17:50:52.843Z,1618163452.843 [esp_sample_at_depth:SendRep:C.Wait] Stopped 2021-04-11T17:50:52.844Z,1618163452.844 [esp_sample_at_depth:SendRep:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-11T17:50:52.844Z,1618163452.844 [esp_sample_at_depth:SendRep](INFO): Completed esp_sample_at_depth:SendRep 2021-04-11T17:50:52.844Z,1618163452.844 [esp_sample_at_depth:SendRep] Stopped 2021-04-11T17:50:52.844Z,1618163452.844 [esp_sample_at_depth:SendRep](DEBUG): Aggregate::uninitialize esp_sample_at_depth:SendRep 2021-04-11T17:50:52.844Z,1618163452.844 [esp_sample_at_depth:SendRep](INFO): Running loop #2 2021-04-11T17:50:52.844Z,1618163452.844 [esp_sample_at_depth:SendRep] Running Loop=2 2021-04-11T17:50:52.844Z,1618163452.844 [esp_sample_at_depth:SendRep](DEBUG): Aggregate::initialize esp_sample_at_depth:SendRep 2021-04-11T17:50:52.844Z,1618163452.844 [esp_sample_at_depth:SendRep:ReportSample] Running Loop=1 2021-04-11T17:50:52.845Z,1618163452.845 [esp_sample_at_depth:SendRep:ReportSample](DEBUG): Aggregate::initialize esp_sample_at_depth:SendRep:ReportSample 2021-04-11T17:50:53.236Z,1618163453.236 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:53.255Z,1618163453.255 [esp_sample_at_depth:SendDataTo1Modem] Running Loop=1 2021-04-11T17:50:53.255Z,1618163453.255 [esp_sample_at_depth:SendDataTo1Modem](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem 2021-04-11T17:50:53.256Z,1618163453.256 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem] Running Loop=1 2021-04-11T17:50:53.256Z,1618163453.256 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem 2021-04-11T17:50:53.256Z,1618163453.256 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples] Running Loop=1 2021-04-11T17:50:53.256Z,1618163453.256 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples](DEBUG): Aggregate::initialize esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples 2021-04-11T17:50:53.256Z,1618163453.256 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:A] Running Loop=1 2021-04-11T17:50:53.257Z,1618163453.257 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:A](IMPORTANT): CntSamples = 2.000000 count 2021-04-11T17:50:53.257Z,1618163453.257 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:A] Stopped 2021-04-11T17:50:53.257Z,1618163453.257 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:B] Running Loop=1 2021-04-11T17:50:53.637Z,1618163453.637 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-11T17:50:53.639Z,1618163453.639 [DAT](FAULT): failed to enter command mode 2021-04-11T17:50:53.640Z,1618163453.640 [DAT](ERROR): Failure setting remote address to 6 2021-04-11T17:50:53.695Z,1618163453.695 [esp_sample_at_depth:SendDataTo1Modem:SendDataToModem:SendDataCntSamples:B](INFO): Queuing up send data for esp_sample_at_depth.CntSamples. 2021-04-11T17:50:53.921Z,1618163453.921 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2021-04-11T17:50:53.921Z,1618163453.921 [MissionManager] Software Fault, FailCount= 1 2021-04-11T17:50:53.922Z,1618163453.922 [MissionManager](ERROR): Software Fault 2021-04-11T17:50:53.000Z,1618163454.000 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2021-04-11T17:50:54.081Z,1618163454.081 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2021-04-11T17:50:54.118Z,1618163454.118 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2021-04-11T17:50:54.149Z,1618163454.149 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2021-04-11T17:50:54.244Z,1618163454.244 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2021-04-11T17:50:54.343Z,1618163454.343 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2021-04-11T17:50:54.448Z,1618163454.448 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2021-04-11T17:50:54.571Z,1618163454.571 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2021-04-11T17:50:54.658Z,1618163454.658 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2021-04-11T17:50:54.714Z,1618163454.714 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2021-04-11T17:50:55.180Z,1618163455.180 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2021-04-11T17:50:55.290Z,1618163455.290 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2021-04-11T17:50:55.343Z,1618163455.343 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2021-04-11T17:50:55.565Z,1618163455.565 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2021-04-11T17:50:55.639Z,1618163455.639 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2021-04-11T17:50:55.996Z,1618163455.996 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2021-04-11T17:50:56.075Z,1618163456.075 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2021-04-11T17:50:56.380Z,1618163456.380 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2021-04-11T17:50:56.459Z,1618163456.459 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2021-04-11T17:50:57.067Z,1618163457.067 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2021-04-11T17:50:57.153Z,1618163457.153 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2021-04-11T17:50:57.420Z,1618163457.420 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2021-04-11T17:50:57.499Z,1618163457.499 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2021-04-11T17:50:57.807Z,1618163457.807 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2021-04-11T17:50:57.889Z,1618163457.889 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2021-04-11T17:50:58.235Z,1618163458.235 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2021-04-11T17:50:58.623Z,1618163458.623 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2021-04-11T17:50:58.739Z,1618163458.739 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2021-04-11T17:50:59.240Z,1618163459.240 [MissionManager](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)