2021-04-19T18:34:20.584Z,1618857260.584 [Supervisor](DEBUG): Initializing supervisor. 2021-04-19T18:34:20.588Z,1618857260.588 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2021-04-19T18:34:20.588Z,1618857260.588 [SyncHandler](INFO): Protected caller Thread ID is 827 2021-04-19T18:34:20.589Z,1618857260.589 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2021-04-19T18:34:20.590Z,1618857260.590 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2021-04-19T18:34:20.590Z,1618857260.590 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 828 2021-04-19T18:34:20.594Z,1618857260.594 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2021-04-19T18:34:20.613Z,1618857260.613 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2021-04-19T18:34:20.614Z,1618857260.614 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2021-04-19T18:34:20.614Z,1618857260.614 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 829 2021-04-19T18:34:20.616Z,1618857260.616 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2021-04-19T18:34:20.617Z,1618857260.617 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2021-04-19T18:34:20.617Z,1618857260.617 [logger ThreadHandler](INFO): Protected caller Thread ID is 830 2021-04-19T18:34:20.621Z,1618857260.621 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2021-04-19T18:34:20.622Z,1618857260.622 [Supervisor](INFO): Looking for Config files in directory: Config/ 2021-04-19T18:34:20.626Z,1618857260.626 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2021-04-19T18:34:20.724Z,1618857260.724 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2021-04-19T18:34:20.726Z,1618857260.726 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2021-04-19T18:34:20.956Z,1618857260.956 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2021-04-19T18:34:20.957Z,1618857260.957 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2021-04-19T18:34:21.190Z,1618857261.190 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2021-04-19T18:34:21.191Z,1618857261.191 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2021-04-19T18:34:21.291Z,1618857261.291 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2021-04-19T18:34:21.292Z,1618857261.292 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2021-04-19T18:34:21.949Z,1618857261.949 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2021-04-19T18:34:21.951Z,1618857261.951 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2021-04-19T18:34:22.389Z,1618857262.389 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2021-04-19T18:34:22.389Z,1618857262.389 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2021-04-19T18:34:22.941Z,1618857262.941 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2021-04-19T18:34:22.943Z,1618857262.943 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2021-04-19T18:34:23.315Z,1618857263.315 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2021-04-19T18:34:23.317Z,1618857263.317 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2021-04-19T18:34:23.666Z,1618857263.666 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2021-04-19T18:34:23.667Z,1618857263.667 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2021-04-19T18:34:24.039Z,1618857264.039 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2021-04-19T18:34:24.041Z,1618857264.041 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2021-04-19T18:34:24.374Z,1618857264.374 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2021-04-19T18:34:24.374Z,1618857264.374 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2021-04-19T18:34:24.983Z,1618857264.983 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2021-04-19T18:34:24.983Z,1618857264.983 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2021-04-19T18:34:25.073Z,1618857265.073 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2021-04-19T18:34:25.152Z,1618857265.152 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2021-04-19T18:34:25.352Z,1618857265.352 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2021-04-19T18:34:25.353Z,1618857265.353 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2021-04-19T18:34:25.572Z,1618857265.572 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2021-04-19T18:34:25.574Z,1618857265.574 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2021-04-19T18:34:25.576Z,1618857265.576 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2021-04-19T18:34:25.662Z,1618857265.662 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2021-04-19T18:34:26.040Z,1618857266.040 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2021-04-19T18:34:26.041Z,1618857266.041 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2021-04-19T18:34:26.141Z,1618857266.141 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2021-04-19T18:34:26.313Z,1618857266.313 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2021-04-19T18:34:26.525Z,1618857266.525 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2021-04-19T18:34:26.614Z,1618857266.614 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2021-04-19T18:34:26.720Z,1618857266.720 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2021-04-19T18:34:26.816Z,1618857266.816 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2021-04-19T18:34:26.994Z,1618857266.994 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2021-04-19T18:34:27.106Z,1618857267.106 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2021-04-19T18:34:27.211Z,1618857267.211 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2021-04-19T18:34:27.221Z,1618857267.221 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2021-04-19T18:34:27.353Z,1618857267.353 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2021-04-19T18:34:27.354Z,1618857267.354 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2021-04-19T18:34:27.509Z,1618857267.509 [BuoyancyServo] Loaded 2021-04-19T18:34:27.510Z,1618857267.510 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2021-04-19T18:34:27.529Z,1618857267.529 [ElevatorServo] Loaded 2021-04-19T18:34:27.529Z,1618857267.529 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2021-04-19T18:34:27.549Z,1618857267.549 [MassServo] Loaded 2021-04-19T18:34:27.549Z,1618857267.549 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2021-04-19T18:34:27.568Z,1618857267.568 [RudderServo] Loaded 2021-04-19T18:34:27.568Z,1618857267.568 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2021-04-19T18:34:27.586Z,1618857267.586 [ThrusterServo] Loaded 2021-04-19T18:34:27.586Z,1618857267.586 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2021-04-19T18:34:27.587Z,1618857267.587 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2021-04-19T18:34:27.587Z,1618857267.587 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2021-04-19T18:34:27.752Z,1618857267.752 [SBIT](DEBUG): Construct Startup Built In Test. 2021-04-19T18:34:27.767Z,1618857267.767 [SBIT] Loaded 2021-04-19T18:34:27.767Z,1618857267.767 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2021-04-19T18:34:27.770Z,1618857267.770 [IBIT](DEBUG): Construct Initiated Built In Test. 2021-04-19T18:34:27.790Z,1618857267.790 [IBIT] Loaded 2021-04-19T18:34:27.790Z,1618857267.790 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2021-04-19T18:34:27.796Z,1618857267.796 [CBIT](DEBUG): Construct Continuous Built In Test. 2021-04-19T18:34:27.997Z,1618857267.997 [CBIT] Loaded 2021-04-19T18:34:27.998Z,1618857267.998 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2021-04-19T18:34:27.998Z,1618857267.998 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2021-04-19T18:34:27.999Z,1618857267.999 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2021-04-19T18:34:28.214Z,1618857268.214 [CTD_Seabird] Loaded 2021-04-19T18:34:28.214Z,1618857268.214 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2021-04-19T18:34:28.215Z,1618857268.215 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406194E0 2021-04-19T18:34:28.216Z,1618857268.216 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 912 2021-04-19T18:34:28.246Z,1618857268.246 [ESPComponent] Loaded 2021-04-19T18:34:28.247Z,1618857268.247 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2021-04-19T18:34:28.265Z,1618857268.265 [PAR_Licor] Loaded 2021-04-19T18:34:28.265Z,1618857268.265 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2021-04-19T18:34:28.295Z,1618857268.295 [WetLabsBB2FL] Loaded 2021-04-19T18:34:28.295Z,1618857268.295 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2021-04-19T18:34:28.297Z,1618857268.297 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406494E0 2021-04-19T18:34:28.297Z,1618857268.297 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 913 2021-04-19T18:34:28.298Z,1618857268.298 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2021-04-19T18:34:28.300Z,1618857268.300 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2021-04-19T18:34:28.357Z,1618857268.357 [DepthRateCalculator] Loaded 2021-04-19T18:34:28.358Z,1618857268.358 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2021-04-19T18:34:28.362Z,1618857268.362 [PitchRateCalculator] Loaded 2021-04-19T18:34:28.363Z,1618857268.363 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2021-04-19T18:34:28.373Z,1618857268.373 [SpeedCalculator] Loaded 2021-04-19T18:34:28.373Z,1618857268.373 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2021-04-19T18:34:28.386Z,1618857268.386 [TempGradientCalculator] Loaded 2021-04-19T18:34:28.387Z,1618857268.387 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2021-04-19T18:34:28.391Z,1618857268.391 [YawRateCalculator] Loaded 2021-04-19T18:34:28.392Z,1618857268.392 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2021-04-19T18:34:28.410Z,1618857268.410 [ElevatorOffsetCalculator] Loaded 2021-04-19T18:34:28.410Z,1618857268.410 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2021-04-19T18:34:28.410Z,1618857268.410 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2021-04-19T18:34:28.412Z,1618857268.412 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2021-04-19T18:34:28.519Z,1618857268.519 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2021-04-19T18:34:28.519Z,1618857268.519 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2021-04-19T18:34:28.561Z,1618857268.561 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2021-04-19T18:34:28.563Z,1618857268.563 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2021-04-19T18:34:28.659Z,1618857268.659 [DeadReckonUsingMultipleVelocitySources] Loaded 2021-04-19T18:34:28.660Z,1618857268.660 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2021-04-19T18:34:28.673Z,1618857268.673 [NavChart] Loaded 2021-04-19T18:34:28.673Z,1618857268.673 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2021-04-19T18:34:28.679Z,1618857268.679 [UniversalFixResidualReporter] Loaded 2021-04-19T18:34:28.679Z,1618857268.679 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2021-04-19T18:34:28.679Z,1618857268.679 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2021-04-19T18:34:28.680Z,1618857268.680 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2021-04-19T18:34:29.769Z,1618857269.769 [AHRS_M2] Loaded 2021-04-19T18:34:29.769Z,1618857269.769 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2021-04-19T18:34:30.466Z,1618857270.466 [BPC1] Loaded 2021-04-19T18:34:30.466Z,1618857270.466 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2021-04-19T18:34:30.608Z,1618857270.608 [DataOverHttps] Loaded 2021-04-19T18:34:30.609Z,1618857270.609 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2021-04-19T18:34:30.610Z,1618857270.610 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409894E0 2021-04-19T18:34:30.610Z,1618857270.610 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 914 2021-04-19T18:34:30.629Z,1618857270.629 [Depth_Keller] Loaded 2021-04-19T18:34:30.629Z,1618857270.629 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2021-04-19T18:34:30.634Z,1618857270.634 [DropWeight] Loaded 2021-04-19T18:34:30.634Z,1618857270.634 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2021-04-19T18:34:30.669Z,1618857270.669 [DVL_micro] Loaded 2021-04-19T18:34:30.669Z,1618857270.669 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2021-04-19T18:34:30.724Z,1618857270.724 [NAL9602] Loaded 2021-04-19T18:34:30.725Z,1618857270.724 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2021-04-19T18:34:30.749Z,1618857270.749 [Onboard] Loaded 2021-04-19T18:34:30.749Z,1618857270.749 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2021-04-19T18:34:30.750Z,1618857270.750 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409B94E0 2021-04-19T18:34:30.751Z,1618857270.751 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 915 2021-04-19T18:34:30.763Z,1618857270.763 [Radio_Surface] Loaded 2021-04-19T18:34:30.764Z,1618857270.764 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2021-04-19T18:34:30.765Z,1618857270.765 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409E94E0 2021-04-19T18:34:30.765Z,1618857270.765 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 916 2021-04-19T18:34:30.846Z,1618857270.846 [DAT] Loaded 2021-04-19T18:34:30.846Z,1618857270.846 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2021-04-19T18:34:30.847Z,1618857270.847 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2021-04-19T18:34:30.847Z,1618857270.847 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2021-04-19T18:34:30.925Z,1618857270.925 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2021-04-19T18:34:30.927Z,1618857270.927 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2021-04-19T18:34:30.995Z,1618857270.995 [VerticalControl](DEBUG): Construct VerticalControl. 2021-04-19T18:34:31.047Z,1618857271.047 [VerticalControl] Loaded 2021-04-19T18:34:31.047Z,1618857271.047 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2021-04-19T18:34:31.050Z,1618857271.050 [HorizontalControl](DEBUG): Construct HorizontalControl. 2021-04-19T18:34:31.084Z,1618857271.084 [HorizontalControl] Loaded 2021-04-19T18:34:31.085Z,1618857271.085 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2021-04-19T18:34:31.087Z,1618857271.087 [SpeedControl](DEBUG): Construct SpeedControl. 2021-04-19T18:34:31.089Z,1618857271.089 [SpeedControl] Loaded 2021-04-19T18:34:31.089Z,1618857271.089 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2021-04-19T18:34:31.092Z,1618857271.092 [LoopControl](DEBUG): Construct LoopControl. 2021-04-19T18:34:31.092Z,1618857271.092 [LoopControl] Loaded 2021-04-19T18:34:31.092Z,1618857271.092 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2021-04-19T18:34:31.093Z,1618857271.093 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2021-04-19T18:34:31.095Z,1618857271.095 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2021-04-19T18:34:31.110Z,1618857271.110 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2021-04-19T18:34:31.111Z,1618857271.111 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2021-04-19T18:34:31.476Z,1618857271.476 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2021-04-19T18:34:31.482Z,1618857271.482 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2021-04-19T18:34:31.485Z,1618857271.485 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2021-04-19T18:34:31.495Z,1618857271.495 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2021-04-19T18:34:31.496Z,1618857271.496 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AEB4E0 2021-04-19T18:34:31.497Z,1618857271.497 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 917 2021-04-19T18:34:31.501Z,1618857271.501 [Supervisor](INFO): Main Thread ID is 822 2021-04-19T18:34:31.501Z,1618857271.501 [Supervisor](DEBUG): Running supervisor. 2021-04-19T18:34:31.502Z,1618857271.502 [CommandLine ThreadHandler](INFO): Handler Thread ID is 918 2021-04-19T18:34:31.504Z,1618857271.504 [controlThread ThreadHandler](INFO): Handler Thread ID is 919 2021-04-19T18:34:31.505Z,1618857271.505 [controlThread](DEBUG): Initializing ControlThread 2021-04-19T18:34:31.506Z,1618857271.506 [SBIT](INFO): Initialize SBIT Component. 2021-04-19T18:34:31.507Z,1618857271.507 [SBIT](IMPORTANT): git: 2021-04-19A 2021-04-19T18:34:31.507Z,1618857271.507 [SBIT](INFO): git hash: 6cfce4cf1db5075d9ce029584b38504190917e0b 2021-04-19T18:34:31.507Z,1618857271.507 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2021-04-19T18:34:31.509Z,1618857271.509 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 Kernel Reported: #1 PREEMPT Fri Mar 5 08:17:40 PST 2021 2021-04-19T18:34:31.510Z,1618857271.510 [SBIT](INFO): Beginning SBIT in 76.000000 seconds. 2021-04-19T18:34:31.511Z,1618857271.511 [IBIT](INFO): Initialize IBIT Component. 2021-04-19T18:34:31.511Z,1618857271.511 [CBIT](DEBUG): Initialize CBIT Component. 2021-04-19T18:34:31.512Z,1618857271.512 [logger ThreadHandler](INFO): Handler Thread ID is 920 2021-04-19T18:34:31.524Z,1618857271.524 [CBIT](DEBUG): Initialized mux pins. 2021-04-19T18:34:31.524Z,1618857271.524 [CBIT](DEBUG): Initializing the watchdog timer. 2021-04-19T18:34:31.532Z,1618857271.532 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 921 2021-04-19T18:34:31.533Z,1618857271.533 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2021-04-19T18:34:31.537Z,1618857271.537 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 923 2021-04-19T18:34:31.540Z,1618857271.540 [WetLabsBB2FL](INFO): Powering up 2021-04-19T18:34:31.542Z,1618857271.542 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 925 2021-04-19T18:34:31.543Z,1618857271.543 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2021-04-19T18:34:31.548Z,1618857271.548 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2021-04-19T18:34:31.549Z,1618857271.549 [CBIT](DEBUG): Initializing heartbeat. 2021-04-19T18:34:31.560Z,1618857271.560 [Onboard ThreadHandler](INFO): Handler Thread ID is 926 2021-04-19T18:34:31.577Z,1618857271.577 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 927 2021-04-19T18:34:31.600Z,1618857271.600 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 928 2021-04-19T18:34:31.609Z,1618857271.609 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2021-04-19T18:34:31.609Z,1618857271.609 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2021-04-19T18:34:31.609Z,1618857271.609 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2021-04-19T18:34:31.609Z,1618857271.609 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2021-04-19T18:34:31.610Z,1618857271.610 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2021-04-19T18:34:31.610Z,1618857271.610 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2021-04-19T18:34:31.610Z,1618857271.610 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2021-04-19T18:34:31.610Z,1618857271.610 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2021-04-19T18:34:31.610Z,1618857271.610 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2021-04-19T18:34:31.610Z,1618857271.610 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2021-04-19T18:34:31.611Z,1618857271.611 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2021-04-19T18:34:31.611Z,1618857271.611 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2021-04-19T18:34:31.611Z,1618857271.611 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2021-04-19T18:34:31.611Z,1618857271.611 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2021-04-19T18:34:31.611Z,1618857271.611 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2021-04-19T18:34:31.611Z,1618857271.611 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2021-04-19T18:34:31.620Z,1618857271.620 [CBIT](DEBUG): Deactivating GF circuits. 2021-04-19T18:34:31.620Z,1618857271.620 [CBIT](DEBUG): Deactivating emergency mode. 2021-04-19T18:34:31.656Z,1618857271.656 [CBIT](DEBUG): Backplane powered. 2021-04-19T18:34:31.660Z,1618857271.660 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2021-04-19T18:34:31.661Z,1618857271.661 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2021-04-19T18:34:31.661Z,1618857271.661 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2021-04-19T18:34:31.661Z,1618857271.661 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2021-04-19T18:34:31.662Z,1618857271.662 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2021-04-19T18:34:31.662Z,1618857271.662 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2021-04-19T18:34:31.663Z,1618857271.663 [NavChart](DEBUG): Initialize NavChart Navigation. 2021-04-19T18:34:31.664Z,1618857271.664 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2021-04-19T18:34:31.670Z,1618857271.670 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2021-04-19T18:34:31.680Z,1618857271.680 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2021-04-19T18:34:31.681Z,1618857271.681 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2021-04-19T18:34:31.681Z,1618857271.681 [LoopControl](DEBUG): Initialize LoopControlComponent. 2021-04-19T18:34:31.682Z,1618857271.682 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2021-04-19T18:34:31.733Z,1618857271.733 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2021-04-19T18:34:31.761Z,1618857271.761 [MissionManager](DEBUG): 2021-04-19T18:34:31.761Z,1618857271.761 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2021-04-19T18:34:31.839Z,1618857271.839 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2021-04-19T18:34:31.861Z,1618857271.861 [Default:A.Wait](DEBUG): Construct Wait. 2021-04-19T18:34:31.863Z,1618857271.863 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2021-04-19T18:34:31.902Z,1618857271.902 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2021-04-19T18:34:31.905Z,1618857271.905 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2021-04-19T18:34:31.919Z,1618857271.919 [Default:E.Execute](DEBUG): Construct Execute. 2021-04-19T18:34:31.923Z,1618857271.923 [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-19T18:34:31.944Z,1618857271.944 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,DAT,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2021-04-19T18:34:31.958Z,1618857271.958 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2021-04-19T18:34:31.984Z,1618857271.984 [Radio_Surface](INFO): Powering up 2021-04-19T18:34:32.072Z,1618857272.072 [Depth_Keller](ERROR): Pressure reading out of range: 1895.684326 decibar 2021-04-19T18:34:32.088Z,1618857272.088 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2021-04-19T18:34:32.088Z,1618857272.088 [DAT](INFO): Powering up 2021-04-19T18:34:32.088Z,1618857272.088 [DAT](DEBUG): Initializing DAT. 2021-04-19T18:34:32.116Z,1618857272.116 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2021-04-19T18:34:32.160Z,1618857272.160 [DepthRateCalculator](ERROR): Depth measurement is not active 2021-04-19T18:34:32.226Z,1618857272.226 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2021-04-19T18:34:32.236Z,1618857272.236 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2021-04-19T18:34:32.237Z,1618857272.237 [ElevatorServo](DEBUG): Initializing EZServoServo. 2021-04-19T18:34:32.244Z,1618857272.244 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2021-04-19T18:34:32.245Z,1618857272.245 [MassServo](DEBUG): Initializing EZServoServo. 2021-04-19T18:34:32.252Z,1618857272.252 [MassServo](DEBUG): Initializing MassServo. 2021-04-19T18:34:32.253Z,1618857272.253 [RudderServo](DEBUG): Initializing EZServoServo. 2021-04-19T18:34:32.260Z,1618857272.260 [RudderServo](DEBUG): Initializing RudderServo. 2021-04-19T18:34:32.261Z,1618857272.261 [ThrusterServo](DEBUG): Initializing EZServoServo. 2021-04-19T18:34:32.268Z,1618857272.268 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2021-04-19T18:34:33.085Z,1618857273.085 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2021-04-19T18:34:33.085Z,1618857273.085 [RudderServo](FAULT): Rudder failed to initialize 2021-04-19T18:34:33.085Z,1618857273.085 [RudderServo] Communications Fault, FailCount= 1 2021-04-19T18:34:33.085Z,1618857273.085 [RudderServo](ERROR): Communications Fault 2021-04-19T18:34:33.188Z,1618857273.188 [CBIT](ERROR): Communications Fault in component: RudderServo 2021-04-19T18:34:33.353Z,1618857273.353 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2021-04-19T18:34:33.353Z,1618857273.353 [RudderServo](INFO): Powering down 2021-04-19T18:34:33.648Z,1618857273.648 [WetLabsBB2FL](INFO): Powering down 2021-04-19T18:34:34.024Z,1618857274.024 [RudderServo](DEBUG): Initializing EZServoServo. 2021-04-19T18:34:34.145Z,1618857274.145 [RudderServo](DEBUG): Initializing RudderServo. 2021-04-19T18:34:34.149Z,1618857274.149 [CBIT](INFO): Clearing failed state for component RudderServo 2021-04-19T18:34:34.149Z,1618857274.149 [RudderServo] No Fault, FailCount= 1 2021-04-19T18:34:46.173Z,1618857286.173 [DAT](INFO): commRate: 800 2021-04-19T18:34:48.562Z,1618857288.562 [DAT](INFO): entering command mode 2021-04-19T18:34:48.971Z,1618857288.971 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:34:49.404Z,1618857289.404 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:34:49.778Z,1618857289.778 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:34:50.174Z,1618857290.174 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:34:50.578Z,1618857290.578 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:34:50.982Z,1618857290.982 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:34:51.386Z,1618857291.386 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:34:51.798Z,1618857291.798 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:34:52.208Z,1618857292.208 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:34:52.608Z,1618857292.608 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:34:53.002Z,1618857293.002 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:34:53.406Z,1618857293.406 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:34:53.810Z,1618857293.810 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:34:54.218Z,1618857294.218 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:34:54.648Z,1618857294.648 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:34:55.022Z,1618857295.022 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:34:55.426Z,1618857295.426 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:34:55.828Z,1618857295.828 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:34:56.235Z,1618857296.235 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:34:56.638Z,1618857296.638 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:34:57.064Z,1618857297.064 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:34:57.442Z,1618857297.442 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:34:57.861Z,1618857297.861 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:34:58.254Z,1618857298.254 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:34:58.654Z,1618857298.654 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:34:59.062Z,1618857299.062 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:34:59.503Z,1618857299.503 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:34:59.866Z,1618857299.866 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:35:00.274Z,1618857300.274 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:35:00.687Z,1618857300.687 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:35:01.082Z,1618857301.082 [NAL9602](INFO): Powering up NAL9602 2021-04-19T18:35:01.088Z,1618857301.088 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:35:01.486Z,1618857301.486 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:35:01.917Z,1618857301.917 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:35:02.308Z,1618857302.308 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:35:02.694Z,1618857302.694 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:35:03.113Z,1618857303.113 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:35:03.506Z,1618857303.506 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:35:03.910Z,1618857303.910 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-19T18:35:03.910Z,1618857303.910 [DAT](FAULT): failed to enter command mode 2021-04-19T18:35:04.335Z,1618857304.335 [DAT](INFO): entering command mode 2021-04-19T18:35:04.761Z,1618857304.761 [DAT](INFO): setting verbose to 3 2021-04-19T18:35:05.123Z,1618857305.123 [DAT](INFO): set verbose to 3 2021-04-19T18:35:05.128Z,1618857305.128 [DAT](INFO): setting DatVerbose to 27440 2021-04-19T18:35:05.540Z,1618857305.540 [DAT](INFO): set DatVerbose to 27440 2021-04-19T18:35:05.540Z,1618857305.540 [DAT](INFO): setting transmit power to 8 2021-04-19T18:35:05.941Z,1618857305.941 [DAT](INFO): set transmit power to 8 2021-04-19T18:35:05.942Z,1618857305.942 [DAT](INFO): setting local address to 4 2021-04-19T18:35:06.335Z,1618857306.335 [DAT](INFO): set local address to 4 2021-04-19T18:35:12.010Z,1618857312.010 [NAL9602](INFO): NAL9602 initialized 2021-04-19T18:35:47.962Z,1618857347.962 [SBIT](IMPORTANT): Beginning Startup BIT 2021-04-19T18:35:47.982Z,1618857347.982 [CBIT](IMPORTANT): Beginning ground fault scan 2021-04-19T18:35:58.921Z,1618857358.921 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): 0.010095 CHAN A1 (24V): 0.000484 CHAN A2 (12V): -0.004957 CHAN A3 (5V): -0.002358 CHAN B0 (3.3V): -0.000939 CHAN B1 (3.15aV): -0.001712 CHAN B2 (3.15bV): -0.001087 CHAN B3 (GND): 0.000180 OPEN: 0.007169 Full Scale Calc: 4.765 mA, -1.589 mA 2021-04-19T18:36:19.513Z,1618857379.513 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-19T18:36:41.735Z,1618857401.735 [SBIT](IMPORTANT): SBIT PASSED 2021-04-19T18:36:41.735Z,1618857401.735 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2021-04-19T18:36:41.736Z,1618857401.736 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count; 2021-04-19T18:36:41.737Z,1618857401.737 [SBIT](IMPORTANT): CBIT.gf24Offset=148.5 microampere; 2021-04-19T18:36:41.737Z,1618857401.737 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=280 cubic_centimeter; 2021-04-19T18:36:41.737Z,1618857401.737 [SBIT](IMPORTANT): VerticalControl.massDefault=14 millimeter; 2021-04-19T18:36:42.093Z,1618857402.093 [MissionManager](IMPORTANT): Started mission Startup 2021-04-19T18:36:42.093Z,1618857402.093 [Startup] Running Loop=1 2021-04-19T18:36:42.094Z,1618857402.094 [Startup](DEBUG): Aggregate::initialize Startup 2021-04-19T18:36:42.094Z,1618857402.094 [Startup:A.GoToSurface] Running Loop=1 2021-04-19T18:36:42.094Z,1618857402.094 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2021-04-19T18:36:42.094Z,1618857402.094 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2021-04-19T18:36:42.095Z,1618857402.095 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2021-04-19T18:36:42.095Z,1618857402.095 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2021-04-19T18:36:42.096Z,1618857402.096 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2021-04-19T18:36:42.096Z,1618857402.096 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2021-04-19T18:36:42.098Z,1618857402.098 [Startup:StartupSatComms] Running Loop=1 2021-04-19T18:36:42.098Z,1618857402.098 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2021-04-19T18:36:42.098Z,1618857402.098 [Startup:StartupSatComms:A] Running Loop=1 2021-04-19T18:36:42.500Z,1618857402.500 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2021-04-19T18:36:45.780Z,1618857405.780 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-19T18:36:59.106Z,1618857419.106 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-19T18:37:07.217Z,1618857427.217 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-19T18:37:12.530Z,1618857432.530 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004972 2021-04-19T18:37:31.821Z,1618857451.821 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2021-04-19T18:37:31.821Z,1618857451.821 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-04-19T18:37:31.831Z,1618857451.831 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-04-19T18:37:32.225Z,1618857452.225 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-04-19T18:37:32.225Z,1618857452.225 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2021-04-19T18:37:39.580Z,1618857459.580 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-19T18:37:42.322Z,1618857462.322 [Startup:StartupSatComms:A](INFO): Timed out from 2021-04-19T18:36:42.1Z 2021-04-19T18:37:42.322Z,1618857462.322 [Startup:StartupSatComms:A] Stopped 2021-04-19T18:37:42.322Z,1618857462.322 [Startup:StartupSatComms:B] Running Loop=1 2021-04-19T18:37:42.715Z,1618857462.715 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2021-04-19T18:37:50.329Z,1618857470.329 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210419T175308/Courier0013.lzma 2021-04-19T18:37:51.330Z,1618857471.330 [DataOverHttps](INFO): Moved sent file to Logs/20210419T175308/Courier0013.lzma.bak 2021-04-19T18:37:51.330Z,1618857471.330 [DataOverHttps](INFO): SBD MOMSN=15586056 2021-04-19T18:38:07.055Z,1618857487.055 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20210419T183420/Courier0000.lzma 2021-04-19T18:38:08.058Z,1618857488.058 [DataOverHttps](INFO): Moved sent file to Logs/20210419T183420/Courier0000.lzma.bak 2021-04-19T18:38:08.058Z,1618857488.058 [DataOverHttps](INFO): SBD MOMSN=15586061 2021-04-19T18:38:23.833Z,1618857503.833 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20210419T175308/Express0014.lzma 2021-04-19T18:38:24.834Z,1618857504.834 [DataOverHttps](INFO): Moved sent file to Logs/20210419T175308/Express0014.lzma.bak 2021-04-19T18:38:24.834Z,1618857504.834 [DataOverHttps](INFO): SBD MOMSN=15586067 2021-04-19T18:38:33.246Z,1618857513.246 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-19T18:38:40.529Z,1618857520.529 [DataOverHttps](INFO): Sending 831 bytes from file Logs/20210419T183420/Express0001.lzma 2021-04-19T18:38:41.530Z,1618857521.530 [DataOverHttps](INFO): Moved sent file to Logs/20210419T183420/Express0001.lzma.bak 2021-04-19T18:38:41.530Z,1618857521.530 [DataOverHttps](INFO): SBD MOMSN=15586073 2021-04-19T18:38:42.498Z,1618857522.498 [Startup:StartupSatComms:B](INFO): Timed out from 2021-04-19T18:37:42.3Z 2021-04-19T18:38:42.499Z,1618857522.499 [Startup:StartupSatComms:B] Stopped 2021-04-19T18:38:42.499Z,1618857522.499 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2021-04-19T18:38:42.499Z,1618857522.499 [Startup:StartupSatComms] Stopped 2021-04-19T18:38:42.499Z,1618857522.499 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2021-04-19T18:38:42.516Z,1618857522.516 [Startup](INFO): Completed Startup 2021-04-19T18:38:42.516Z,1618857522.516 [MissionManager](INFO): Startup is completed. 2021-04-19T18:38:42.516Z,1618857522.516 [MissionManager](INFO): Uninitializing Mission Startup 2021-04-19T18:38:42.516Z,1618857522.516 [Startup] Stopped 2021-04-19T18:38:42.516Z,1618857522.516 [Startup](DEBUG): Aggregate::uninitialize Startup 2021-04-19T18:38:42.516Z,1618857522.516 [Startup:A.GoToSurface] Stopped 2021-04-19T18:38:42.516Z,1618857522.516 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2021-04-19T18:38:42.913Z,1618857522.913 [MissionManager](IMPORTANT): Started mission Default 2021-04-19T18:38:42.913Z,1618857522.913 [Default] Running Loop=1 2021-04-19T18:38:42.914Z,1618857522.914 [Default](DEBUG): Aggregate::initialize Default 2021-04-19T18:38:42.914Z,1618857522.914 [Default:B.GoToSurface] Running Loop=1 2021-04-19T18:38:42.914Z,1618857522.914 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2021-04-19T18:38:42.914Z,1618857522.914 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2021-04-19T18:38:42.914Z,1618857522.914 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2021-04-19T18:38:42.915Z,1618857522.915 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2021-04-19T18:38:42.915Z,1618857522.915 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2021-04-19T18:38:42.915Z,1618857522.915 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2021-04-19T18:38:42.916Z,1618857522.916 [Default:A.Wait] Running Loop=1 2021-04-19T18:38:42.916Z,1618857522.916 [Default:A.Wait](DEBUG): Initialize Wait Component. 2021-04-19T18:38:56.261Z,1618857536.261 [Default:A.Wait](INFO): Done Waiting. 2021-04-19T18:38:56.261Z,1618857536.261 [Default:A.Wait] Stopped 2021-04-19T18:38:56.261Z,1618857536.261 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T18:38:56.643Z,1618857536.643 [Default:CheckIn] Running Loop=1 2021-04-19T18:38:56.643Z,1618857536.643 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T18:38:56.643Z,1618857536.643 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T18:38:57.057Z,1618857537.057 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2021-04-19T18:40:15.399Z,1618857615.399 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-19T18:40:32.825Z,1618857632.825 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2021-04-19T18:40:32.825Z,1618857632.825 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-04-19T18:40:32.835Z,1618857632.835 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-04-19T18:40:33.241Z,1618857633.241 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-04-19T18:40:33.241Z,1618857633.241 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2021-04-19T18:41:17.002Z,1618857677.002 [DVL_micro](ERROR): only read 3 of 4 data items 2021-04-19T18:41:17.003Z,1618857677.003 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.999,+9999.99 2021-04-19T18:41:28.622Z,1618857688.622 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-19T18:41:39.934Z,1618857699.934 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-19T18:42:53.825Z,1618857773.825 [BPC1](ERROR): Battery stick #38 (s/n: 0139) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2021-04-19T18:42:53.825Z,1618857773.825 [BPC1](ERROR): Battery stick #39 (s/n: 00F0) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2021-04-19T18:42:53.826Z,1618857773.826 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5. 2021-04-19T18:42:53.829Z,1618857773.829 [BPC1](INFO): Received data from all battery sticks. 2021-04-19T18:43:33.849Z,1618857813.849 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2021-04-19T18:43:33.849Z,1618857813.849 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-04-19T18:43:33.859Z,1618857813.859 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-04-19T18:43:34.270Z,1618857814.270 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-04-19T18:43:34.270Z,1618857814.270 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2021-04-19T18:43:56.846Z,1618857836.846 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-19T18:38:56.6Z 2021-04-19T18:43:56.847Z,1618857836.847 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T18:43:56.847Z,1618857836.847 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-19T18:43:57.253Z,1618857837.253 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2021-04-19T18:44:03.655Z,1618857843.655 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20210419T183420/Courier0004.lzma 2021-04-19T18:44:04.658Z,1618857844.658 [DataOverHttps](INFO): Moved sent file to Logs/20210419T183420/Courier0004.lzma.bak 2021-04-19T18:44:04.658Z,1618857844.658 [DataOverHttps](INFO): SBD MOMSN=15586107 2021-04-19T18:44:19.119Z,1618857859.119 [DataOverHttps](INFO): Sending 188 bytes from file Logs/20210419T183420/Express0005.lzma 2021-04-19T18:44:20.126Z,1618857860.126 [DataOverHttps](INFO): Moved sent file to Logs/20210419T183420/Express0005.lzma.bak 2021-04-19T18:44:20.126Z,1618857860.126 [DataOverHttps](INFO): SBD MOMSN=15586109 2021-04-19T18:44:21.517Z,1618857861.517 [Default:CheckIn:Read_Iridium] Stopped 2021-04-19T18:44:21.517Z,1618857861.517 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-19T18:44:21.518Z,1618857861.518 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-19T18:45:13.194Z,1618857913.194 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-19T18:45:13.195Z,1618857913.195 [NAL9602] Data Fault, FailCount= 1 2021-04-19T18:45:13.195Z,1618857913.195 [NAL9602](ERROR): Data Fault 2021-04-19T18:45:13.227Z,1618857913.227 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T18:45:13.617Z,1618857913.617 [NAL9602](INFO): Powering down 2021-04-19T18:45:14.428Z,1618857914.428 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T18:45:14.428Z,1618857914.428 [NAL9602] No Fault, FailCount= 1 2021-04-19T18:45:43.911Z,1618857943.911 [NAL9602](INFO): Powering up NAL9602 2021-04-19T18:45:54.811Z,1618857954.811 [NAL9602](INFO): NAL9602 initialized 2021-04-19T18:46:34.812Z,1618857994.812 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2021-04-19T18:46:34.812Z,1618857994.812 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-04-19T18:46:34.822Z,1618857994.822 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-04-19T18:46:35.219Z,1618857995.219 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-04-19T18:46:35.219Z,1618857995.219 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2021-04-19T18:47:49.957Z,1618858069.957 [DVL_micro](ERROR): Failed to parse: :SA,-03.17,-01.66,124.2 2021-04-19T18:49:22.090Z,1618858162.090 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T18:49:22.090Z,1618858162.090 [Default:CheckIn:C.Wait] Stopped 2021-04-19T18:49:22.090Z,1618858162.090 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T18:49:22.090Z,1618858162.090 [Default:CheckIn:D] Running Loop=1 2021-04-19T18:49:22.473Z,1618858162.473 [Default:CheckIn:D] Stopped 2021-04-19T18:49:22.473Z,1618858162.473 [Default:CheckIn:E] Running Loop=1 2021-04-19T18:49:22.870Z,1618858162.870 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.659319 min 2021-04-19T18:49:22.870Z,1618858162.870 [Default:CheckIn:E] Stopped 2021-04-19T18:49:22.870Z,1618858162.870 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T18:49:22.870Z,1618858162.870 [Default:CheckIn] Stopped 2021-04-19T18:49:22.870Z,1618858162.870 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T18:49:22.871Z,1618858162.871 [Default:CheckIn](INFO): Running loop #2 2021-04-19T18:49:22.871Z,1618858162.871 [Default:CheckIn] Running Loop=2 2021-04-19T18:49:22.871Z,1618858162.871 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T18:49:22.871Z,1618858162.871 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T18:49:35.834Z,1618858175.834 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2021-04-19T18:49:35.834Z,1618858175.834 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-04-19T18:49:35.860Z,1618858175.860 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-04-19T18:49:36.246Z,1618858176.246 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-04-19T18:49:36.246Z,1618858176.246 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2021-04-19T18:52:36.821Z,1618858356.821 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2021-04-19T18:52:36.821Z,1618858356.821 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-04-19T18:52:36.839Z,1618858356.839 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-04-19T18:52:37.252Z,1618858357.252 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-04-19T18:52:37.252Z,1618858357.252 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2021-04-19T18:54:15.378Z,1618858455.378 [DVL_micro](ERROR): Failed to parse: :SA,-03.11,-01.59,123.5 2021-04-19T18:54:17.791Z,1618858457.791 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-04-19T18:54:17.792Z,1618858457.792 [DVL_micro](ERROR): Failed to parse: :TS0000000,35.0,+22.0,0000.0,1489.0,000 2021-04-19T18:54:20.209Z,1618858460.209 [DVL_micro](ERROR): No DVL communication! Re-initializing 2021-04-19T18:54:20.210Z,1618858460.210 [DVL_micro] Communications Fault, FailCount= 1 2021-04-19T18:54:20.210Z,1618858460.210 [DVL_micro](ERROR): Communications Fault 2021-04-19T18:54:20.247Z,1618858460.247 [CBIT](ERROR): Communications Fault in component: DVL_micro 2021-04-19T18:54:20.688Z,1618858460.688 [DVL_micro](INFO): Powering down 2021-04-19T18:54:21.451Z,1618858461.451 [CBIT](INFO): Clearing failed state for component DVL_micro 2021-04-19T18:54:21.451Z,1618858461.451 [DVL_micro] No Fault, FailCount= 1 2021-04-19T18:54:23.049Z,1618858463.049 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-19T18:49:22.9Z 2021-04-19T18:54:23.050Z,1618858463.050 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T18:54:23.050Z,1618858463.050 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-19T18:54:30.223Z,1618858470.223 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210419T183420/Courier0007.lzma 2021-04-19T18:54:31.226Z,1618858471.226 [DataOverHttps](INFO): Moved sent file to Logs/20210419T183420/Courier0007.lzma.bak 2021-04-19T18:54:31.226Z,1618858471.226 [DataOverHttps](INFO): SBD MOMSN=15586138 2021-04-19T18:54:46.640Z,1618858486.640 [DataOverHttps](INFO): Sending 182 bytes from file Logs/20210419T183420/Express0008.lzma 2021-04-19T18:54:47.641Z,1618858487.641 [DataOverHttps](INFO): Moved sent file to Logs/20210419T183420/Express0008.lzma.bak 2021-04-19T18:54:47.642Z,1618858487.642 [DataOverHttps](INFO): SBD MOMSN=15586143 2021-04-19T18:54:48.921Z,1618858488.921 [Default:CheckIn:Read_Iridium] Stopped 2021-04-19T18:54:48.922Z,1618858488.922 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-19T18:54:48.922Z,1618858488.922 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-19T18:55:37.800Z,1618858537.800 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2021-04-19T18:55:37.800Z,1618858537.800 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-04-19T18:55:37.811Z,1618858537.811 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-04-19T18:55:38.204Z,1618858538.204 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-04-19T18:55:38.205Z,1618858538.205 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2021-04-19T18:55:57.982Z,1618858557.982 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-19T18:55:57.982Z,1618858557.982 [NAL9602] Data Fault, FailCount= 2 2021-04-19T18:55:57.982Z,1618858557.982 [NAL9602](ERROR): Data Fault 2021-04-19T18:55:57.999Z,1618858557.999 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T18:55:58.383Z,1618858558.383 [NAL9602](INFO): Powering down 2021-04-19T18:55:59.202Z,1618858559.202 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T18:55:59.202Z,1618858559.202 [NAL9602] No Fault, FailCount= 2 2021-04-19T18:56:28.686Z,1618858588.686 [NAL9602](INFO): Powering up NAL9602 2021-04-19T18:56:39.590Z,1618858599.590 [NAL9602](INFO): NAL9602 initialized 2021-04-19T18:56:42.834Z,1618858602.834 [DVL_micro](ERROR): only read 3 of 4 data items 2021-04-19T18:56:42.834Z,1618858602.834 [DVL_micro](ERROR): Failed to parse: :BI,-00001,+0009,+00000,I 2021-04-19T18:58:38.828Z,1618858718.828 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2021-04-19T18:58:38.828Z,1618858718.828 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-04-19T18:58:38.838Z,1618858718.838 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-04-19T18:58:39.231Z,1618858719.231 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-04-19T18:58:39.231Z,1618858719.231 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2021-04-19T18:59:49.481Z,1618858789.481 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T18:59:49.481Z,1618858789.481 [Default:CheckIn:C.Wait] Stopped 2021-04-19T18:59:49.481Z,1618858789.481 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T18:59:49.481Z,1618858789.481 [Default:CheckIn:D] Running Loop=1 2021-04-19T18:59:49.882Z,1618858789.882 [Default:CheckIn:D] Stopped 2021-04-19T18:59:49.883Z,1618858789.883 [Default:CheckIn:E] Running Loop=1 2021-04-19T18:59:50.298Z,1618858790.298 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.116148 min 2021-04-19T18:59:50.298Z,1618858790.298 [Default:CheckIn:E] Stopped 2021-04-19T18:59:50.298Z,1618858790.298 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T18:59:50.298Z,1618858790.298 [Default:CheckIn] Stopped 2021-04-19T18:59:50.298Z,1618858790.298 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T18:59:50.298Z,1618858790.298 [Default:CheckIn](INFO): Running loop #3 2021-04-19T18:59:50.298Z,1618858790.298 [Default:CheckIn] Running Loop=3 2021-04-19T18:59:50.299Z,1618858790.299 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T18:59:50.299Z,1618858790.299 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T19:01:39.786Z,1618858899.786 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9 2021-04-19T19:01:39.786Z,1618858899.786 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-04-19T19:01:39.796Z,1618858899.796 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-04-19T19:01:40.189Z,1618858900.189 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-04-19T19:01:40.189Z,1618858900.189 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9 2021-04-19T19:01:56.073Z,1618858916.073 [CommandLine](IMPORTANT): got command burn on 2021-04-19T19:01:56.073Z,1618858916.073 [CommandLine](IMPORTANT): Activating dropweight wire 2021-04-19T19:02:01.233Z,1618858921.233 [CommandLine](IMPORTANT): got command burn off 2021-04-19T19:02:01.233Z,1618858921.233 [CommandLine](IMPORTANT): Deactivating dropweight wire 2021-04-19T19:03:13.101Z,1618858993.101 [DVL_micro](ERROR): only read 3 of 4 data items 2021-04-19T19:03:13.102Z,1618858993.102 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+99999.99,+9999.99 2021-04-19T19:04:40.758Z,1618859080.758 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10 2021-04-19T19:04:40.758Z,1618859080.758 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-04-19T19:04:40.768Z,1618859080.768 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-04-19T19:04:41.209Z,1618859081.209 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-04-19T19:04:41.209Z,1618859081.209 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10 2021-04-19T19:04:50.462Z,1618859090.462 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-19T18:59:50.3Z 2021-04-19T19:04:50.462Z,1618859090.462 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T19:04:50.462Z,1618859090.462 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-19T19:04:57.635Z,1618859097.635 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210419T183420/Courier0010.lzma 2021-04-19T19:04:58.638Z,1618859098.638 [DataOverHttps](INFO): Moved sent file to Logs/20210419T183420/Courier0010.lzma.bak 2021-04-19T19:04:58.638Z,1618859098.638 [DataOverHttps](INFO): SBD MOMSN=15586179 2021-04-19T19:05:14.168Z,1618859114.168 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20210419T183420/Express0011.lzma 2021-04-19T19:05:15.170Z,1618859115.170 [DataOverHttps](INFO): Moved sent file to Logs/20210419T183420/Express0011.lzma.bak 2021-04-19T19:05:15.170Z,1618859115.170 [DataOverHttps](INFO): SBD MOMSN=15586181 2021-04-19T19:05:16.334Z,1618859116.334 [Default:CheckIn:Read_Iridium] Stopped 2021-04-19T19:05:16.334Z,1618859116.334 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-19T19:05:16.334Z,1618859116.334 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-19T19:06:41.162Z,1618859201.162 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-19T19:06:41.162Z,1618859201.162 [NAL9602] Data Fault, FailCount= 3 2021-04-19T19:06:41.162Z,1618859201.162 [NAL9602](ERROR): Data Fault 2021-04-19T19:06:41.179Z,1618859201.179 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T19:06:41.556Z,1618859201.556 [NAL9602](INFO): Powering down 2021-04-19T19:06:42.386Z,1618859202.386 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T19:06:42.386Z,1618859202.386 [NAL9602] No Fault, FailCount= 3 2021-04-19T19:07:11.852Z,1618859231.852 [NAL9602](INFO): Powering up NAL9602 2021-04-19T19:07:22.788Z,1618859242.788 [NAL9602](INFO): NAL9602 initialized 2021-04-19T19:07:41.774Z,1618859261.774 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11 2021-04-19T19:07:41.774Z,1618859261.774 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-04-19T19:07:41.807Z,1618859261.807 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-04-19T19:07:42.186Z,1618859262.186 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-04-19T19:07:42.186Z,1618859262.186 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11 2021-04-19T19:09:18.341Z,1618859358.341 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-04-19T19:09:18.341Z,1618859358.341 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,.1,0000.0,1489.0,000 2021-04-19T19:10:16.918Z,1618859416.918 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T19:10:16.918Z,1618859416.918 [Default:CheckIn:C.Wait] Stopped 2021-04-19T19:10:16.918Z,1618859416.918 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T19:10:16.919Z,1618859416.919 [Default:CheckIn:D] Running Loop=1 2021-04-19T19:10:17.330Z,1618859417.330 [Default:CheckIn:D] Stopped 2021-04-19T19:10:17.330Z,1618859417.330 [Default:CheckIn:E] Running Loop=1 2021-04-19T19:10:17.699Z,1618859417.699 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.573610 min 2021-04-19T19:10:17.699Z,1618859417.699 [Default:CheckIn:E] Stopped 2021-04-19T19:10:17.699Z,1618859417.699 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T19:10:17.699Z,1618859417.699 [Default:CheckIn] Stopped 2021-04-19T19:10:17.699Z,1618859417.699 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T19:10:17.699Z,1618859417.699 [Default:CheckIn](INFO): Running loop #4 2021-04-19T19:10:17.700Z,1618859417.700 [Default:CheckIn] Running Loop=4 2021-04-19T19:10:17.700Z,1618859417.700 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T19:10:17.700Z,1618859417.700 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T19:10:42.746Z,1618859442.746 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12 2021-04-19T19:10:42.746Z,1618859442.746 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-04-19T19:10:42.756Z,1618859442.756 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-04-19T19:10:43.164Z,1618859443.164 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-04-19T19:10:43.165Z,1618859443.165 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12 2021-04-19T19:13:43.740Z,1618859623.740 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13 2021-04-19T19:13:43.740Z,1618859623.740 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-04-19T19:13:43.751Z,1618859623.751 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-04-19T19:13:44.159Z,1618859624.159 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-04-19T19:13:44.159Z,1618859624.159 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13 2021-04-19T19:15:17.873Z,1618859717.873 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-19T19:10:17.7Z 2021-04-19T19:15:17.874Z,1618859717.874 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T19:15:17.874Z,1618859717.874 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-19T19:15:25.295Z,1618859725.295 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210419T183420/Courier0013.lzma 2021-04-19T19:15:26.298Z,1618859726.298 [DataOverHttps](INFO): Moved sent file to Logs/20210419T183420/Courier0013.lzma.bak 2021-04-19T19:15:26.298Z,1618859726.298 [DataOverHttps](INFO): SBD MOMSN=15586265 2021-04-19T19:15:28.782Z,1618859728.782 [DVL_micro](ERROR): only read 3 of 4 data items 2021-04-19T19:15:28.782Z,1618859728.782 [DVL_micro](ERROR): Failed to parse: :BI,+00030,-0209,+00000,I 2021-04-19T19:15:33.660Z,1618859733.660 [DVL_micro](ERROR): Failed to parse: :WI,-00113,-00042,-00167,+00000,A 2021-04-19T19:15:41.779Z,1618859741.779 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20210419T183420/Express0014.lzma 2021-04-19T19:15:42.782Z,1618859742.782 [DataOverHttps](INFO): Moved sent file to Logs/20210419T183420/Express0014.lzma.bak 2021-04-19T19:15:42.782Z,1618859742.782 [DataOverHttps](INFO): SBD MOMSN=15586267 2021-04-19T19:15:44.154Z,1618859744.154 [Default:CheckIn:Read_Iridium] Stopped 2021-04-19T19:15:44.154Z,1618859744.154 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-19T19:15:44.154Z,1618859744.154 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-19T19:16:44.729Z,1618859804.729 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 14 2021-04-19T19:16:44.729Z,1618859804.729 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-04-19T19:16:44.739Z,1618859804.739 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-04-19T19:16:45.184Z,1618859805.184 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-04-19T19:16:45.184Z,1618859805.184 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 14 2021-04-19T19:17:24.314Z,1618859844.314 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-19T19:17:24.314Z,1618859844.314 [NAL9602] Data Fault, FailCount= 4 2021-04-19T19:17:24.314Z,1618859844.314 [NAL9602](ERROR): Data Fault 2021-04-19T19:17:24.330Z,1618859844.330 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T19:17:24.734Z,1618859844.734 [NAL9602](INFO): Powering down 2021-04-19T19:17:25.562Z,1618859845.562 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T19:17:25.562Z,1618859845.562 [NAL9602] No Fault, FailCount= 4 2021-04-19T19:17:55.031Z,1618859875.031 [NAL9602](INFO): Powering up NAL9602 2021-04-19T19:18:05.930Z,1618859885.930 [NAL9602](INFO): NAL9602 initialized 2021-04-19T19:19:45.760Z,1618859985.760 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 15 2021-04-19T19:19:45.760Z,1618859985.760 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-04-19T19:19:45.771Z,1618859985.771 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-04-19T19:19:46.161Z,1618859986.161 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-04-19T19:19:46.161Z,1618859986.161 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 15 2021-04-19T19:20:44.781Z,1618860044.781 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T19:20:44.781Z,1618860044.781 [Default:CheckIn:C.Wait] Stopped 2021-04-19T19:20:44.782Z,1618860044.782 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T19:20:44.782Z,1618860044.782 [Default:CheckIn:D] Running Loop=1 2021-04-19T19:20:45.178Z,1618860045.178 [Default:CheckIn:D] Stopped 2021-04-19T19:20:45.178Z,1618860045.178 [Default:CheckIn:E] Running Loop=1 2021-04-19T19:20:45.558Z,1618860045.558 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.037732 min 2021-04-19T19:20:45.558Z,1618860045.558 [Default:CheckIn:E] Stopped 2021-04-19T19:20:45.558Z,1618860045.558 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T19:20:45.559Z,1618860045.559 [Default:CheckIn] Stopped 2021-04-19T19:20:45.559Z,1618860045.559 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T19:20:45.559Z,1618860045.559 [Default:CheckIn](INFO): Running loop #5 2021-04-19T19:20:45.559Z,1618860045.559 [Default:CheckIn] Running Loop=5 2021-04-19T19:20:45.559Z,1618860045.559 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T19:20:45.559Z,1618860045.559 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T19:21:48.988Z,1618860108.988 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-04-19T19:21:48.988Z,1618860108.988 [DVL_micro](ERROR): Failed to parse: :TS,000000000.0,+22.2,0000.0,1489.0,000 2021-04-19T19:22:46.797Z,1618860166.797 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 16 2021-04-19T19:22:46.797Z,1618860166.797 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-04-19T19:22:46.807Z,1618860166.807 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-04-19T19:22:47.222Z,1618860167.222 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-04-19T19:22:47.222Z,1618860167.222 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 16 2021-04-19T19:25:45.790Z,1618860345.790 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-19T19:20:45.6Z 2021-04-19T19:25:45.790Z,1618860345.790 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T19:25:45.790Z,1618860345.790 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-19T19:25:47.788Z,1618860347.788 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 17 2021-04-19T19:25:47.788Z,1618860347.788 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-04-19T19:25:47.825Z,1618860347.825 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-04-19T19:25:48.260Z,1618860348.260 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-04-19T19:25:48.260Z,1618860348.260 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 17 2021-04-19T19:25:52.579Z,1618860352.579 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210419T183420/Courier0016.lzma 2021-04-19T19:25:53.582Z,1618860353.582 [DataOverHttps](INFO): Moved sent file to Logs/20210419T183420/Courier0016.lzma.bak 2021-04-19T19:25:53.582Z,1618860353.582 [DataOverHttps](INFO): SBD MOMSN=15586298 2021-04-19T19:26:08.991Z,1618860368.991 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20210419T183420/Express0017.lzma 2021-04-19T19:26:09.993Z,1618860369.993 [DataOverHttps](INFO): Moved sent file to Logs/20210419T183420/Express0017.lzma.bak 2021-04-19T19:26:09.994Z,1618860369.994 [DataOverHttps](INFO): SBD MOMSN=15586300 2021-04-19T19:26:11.235Z,1618860371.235 [Default:CheckIn:Read_Iridium] Stopped 2021-04-19T19:26:11.235Z,1618860371.235 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-19T19:26:11.235Z,1618860371.235 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-19T19:28:06.788Z,1618860486.788 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-19T19:28:06.788Z,1618860486.788 [NAL9602] Data Fault, FailCount= 5 2021-04-19T19:28:06.788Z,1618860486.788 [NAL9602](ERROR): Data Fault 2021-04-19T19:28:06.831Z,1618860486.831 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T19:28:06.831Z,1618860486.831 [CBIT](CRITICAL): Data Fault in component: NAL9602 2021-04-19T19:28:07.169Z,1618860487.169 [NAL9602](INFO): Powering down 2021-04-19T19:28:07.184Z,1618860487.184 [CommandLine](FAULT): Scheduling is paused 2021-04-19T19:28:07.185Z,1618860487.185 [CBIT](INFO): Critical error at 20210419T192806 2021-04-19T19:28:07.185Z,1618860487.185 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2021-04-19T19:28:48.780Z,1618860528.780 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 18 2021-04-19T19:28:48.780Z,1618860528.780 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-04-19T19:28:48.806Z,1618860528.806 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-04-19T19:28:49.221Z,1618860529.221 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-04-19T19:28:49.221Z,1618860529.221 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 18 2021-04-19T19:30:07.178Z,1618860607.178 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T19:30:07.178Z,1618860607.178 [NAL9602] No Fault, FailCount= 5 2021-04-19T19:30:07.568Z,1618860607.568 [NAL9602](INFO): Powering up NAL9602 2021-04-19T19:30:18.545Z,1618860618.545 [NAL9602](INFO): NAL9602 initialized 2021-04-19T19:31:11.869Z,1618860671.869 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T19:31:11.870Z,1618860671.870 [Default:CheckIn:C.Wait] Stopped 2021-04-19T19:31:11.870Z,1618860671.870 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T19:31:11.870Z,1618860671.870 [Default:CheckIn:D] Running Loop=1 2021-04-19T19:31:12.264Z,1618860672.264 [Default:CheckIn:D] Stopped 2021-04-19T19:31:12.264Z,1618860672.264 [Default:CheckIn:E] Running Loop=1 2021-04-19T19:31:12.657Z,1618860672.657 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 52.489168 min 2021-04-19T19:31:12.658Z,1618860672.658 [Default:CheckIn:E] Stopped 2021-04-19T19:31:12.658Z,1618860672.658 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T19:31:12.658Z,1618860672.658 [Default:CheckIn] Stopped 2021-04-19T19:31:12.658Z,1618860672.658 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T19:31:12.658Z,1618860672.658 [Default:CheckIn](INFO): Running loop #6 2021-04-19T19:31:12.658Z,1618860672.658 [Default:CheckIn] Running Loop=6 2021-04-19T19:31:12.658Z,1618860672.658 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T19:31:12.658Z,1618860672.658 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T19:31:49.848Z,1618860709.848 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 19 2021-04-19T19:31:49.848Z,1618860709.848 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-04-19T19:31:49.867Z,1618860709.867 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-04-19T19:31:50.255Z,1618860710.255 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-04-19T19:31:50.255Z,1618860710.255 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 19 2021-04-19T19:33:52.005Z,1618860832.005 [CommandLine](IMPORTANT): got command get CBIT.stopDepth 2021-04-19T19:33:52.005Z,1618860832.005 [CommandLine](IMPORTANT): CBIT.stopDepth 265.000000 m 2021-04-19T19:34:39.554Z,1618860879.554 [CommandLine](IMPORTANT): got command get CBIT.abortDepth 2021-04-19T19:34:39.555Z,1618860879.555 [CommandLine](IMPORTANT): CBIT.abortDepth 300.000000 m 2021-04-19T19:34:50.852Z,1618860890.852 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 20 2021-04-19T19:34:50.852Z,1618860890.852 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-04-19T19:34:50.871Z,1618860890.871 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-04-19T19:34:51.269Z,1618860891.269 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-04-19T19:34:51.269Z,1618860891.269 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 20 2021-04-19T19:35:04.960Z,1618860904.960 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-04-19T19:35:04.960Z,1618860904.960 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+22.21489.0,000 2021-04-19T19:36:12.874Z,1618860972.874 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-19T19:31:12.7Z 2021-04-19T19:36:12.874Z,1618860972.874 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T19:36:12.874Z,1618860972.874 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-19T19:36:19.723Z,1618860979.723 [DataOverHttps](INFO): Sending 105 bytes from file Logs/20210419T183420/Courier0019.lzma 2021-04-19T19:36:20.726Z,1618860980.726 [DataOverHttps](INFO): Moved sent file to Logs/20210419T183420/Courier0019.lzma.bak 2021-04-19T19:36:20.726Z,1618860980.726 [DataOverHttps](INFO): SBD MOMSN=15586334 2021-04-19T19:36:36.184Z,1618860996.184 [DataOverHttps](INFO): Sending 251 bytes from file Logs/20210419T183420/Express0020.lzma 2021-04-19T19:36:37.186Z,1618860997.186 [DataOverHttps](INFO): Moved sent file to Logs/20210419T183420/Express0020.lzma.bak 2021-04-19T19:36:37.186Z,1618860997.186 [DataOverHttps](INFO): SBD MOMSN=15586337 2021-04-19T19:36:38.317Z,1618860998.317 [Default:CheckIn:Read_Iridium] Stopped 2021-04-19T19:36:38.317Z,1618860998.317 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-19T19:36:38.317Z,1618860998.317 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-19T19:37:51.832Z,1618861071.832 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 21 2021-04-19T19:37:51.832Z,1618861071.832 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-04-19T19:37:51.843Z,1618861071.843 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-04-19T19:37:52.243Z,1618861072.243 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-04-19T19:37:52.243Z,1618861072.243 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 21 2021-04-19T19:40:20.895Z,1618861220.895 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-19T19:40:20.895Z,1618861220.895 [NAL9602] Data Fault, FailCount= 1 2021-04-19T19:40:20.895Z,1618861220.895 [NAL9602](ERROR): Data Fault 2021-04-19T19:40:20.919Z,1618861220.919 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T19:40:21.299Z,1618861221.299 [NAL9602](INFO): Powering down 2021-04-19T19:40:22.148Z,1618861222.148 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T19:40:22.148Z,1618861222.148 [NAL9602] No Fault, FailCount= 1 2021-04-19T19:40:51.606Z,1618861251.606 [NAL9602](INFO): Powering up NAL9602 2021-04-19T19:40:52.820Z,1618861252.820 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 22 2021-04-19T19:40:52.820Z,1618861252.820 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-04-19T19:40:52.858Z,1618861252.858 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-04-19T19:40:53.235Z,1618861253.235 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-04-19T19:40:53.236Z,1618861253.236 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 22 2021-04-19T19:41:02.515Z,1618861262.515 [NAL9602](INFO): NAL9602 initialized 2021-04-19T19:41:38.877Z,1618861298.877 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T19:41:38.877Z,1618861298.877 [Default:CheckIn:C.Wait] Stopped 2021-04-19T19:41:38.877Z,1618861298.877 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T19:41:38.877Z,1618861298.877 [Default:CheckIn:D] Running Loop=1 2021-04-19T19:41:39.318Z,1618861299.318 [Default:CheckIn:D] Stopped 2021-04-19T19:41:39.319Z,1618861299.319 [Default:CheckIn:E] Running Loop=1 2021-04-19T19:41:39.706Z,1618861299.706 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.940080 min 2021-04-19T19:41:39.706Z,1618861299.706 [Default:CheckIn:E] Stopped 2021-04-19T19:41:39.706Z,1618861299.706 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T19:41:39.706Z,1618861299.706 [Default:CheckIn] Stopped 2021-04-19T19:41:39.707Z,1618861299.707 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T19:41:39.707Z,1618861299.707 [Default:CheckIn](INFO): Running loop #7 2021-04-19T19:41:39.707Z,1618861299.707 [Default:CheckIn] Running Loop=7 2021-04-19T19:41:39.707Z,1618861299.707 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T19:41:39.707Z,1618861299.707 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T19:42:00.294Z,1618861320.294 [DVL_micro](ERROR): Failed to parse: :WI,+00004,+00085,-00273,+00000,A 2021-04-19T19:43:53.828Z,1618861433.828 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 23 2021-04-19T19:43:53.828Z,1618861433.828 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-04-19T19:43:53.838Z,1618861433.838 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-04-19T19:43:54.257Z,1618861434.257 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-04-19T19:43:54.257Z,1618861434.257 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 23 2021-04-19T19:44:34.671Z,1618861474.671 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-19T19:46:22.637Z,1618861582.637 [DataOverHttps](IMPORTANT): SBD MTMSN=20210419T194621 2021-04-19T19:46:24.161Z,1618861584.161 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-19T19:46:25.827Z,1618861585.827 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-19T19:46:29.932Z,1618861589.932 [DataOverHttps](INFO): Received command:restart app 2021-04-19T19:46:30.000Z,1618861590.000 [CommandLine](IMPORTANT): got command restart application 2021-04-19T19:46:31.004Z,1618861591.004 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2021-04-19T19:46:31.004Z,1618861591.004 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-04-19T19:46:31.088Z,1618861591.088 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2021-04-19T19:46:31.088Z,1618861591.088 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-04-19T19:46:31.089Z,1618861591.089 [CommandLine](INFO): Join timeout helper Thread ID is 1007 2021-04-19T19:46:31.089Z,1618861591.089 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2021-04-19T19:46:31.089Z,1618861591.089 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-04-19T19:46:31.090Z,1618861591.090 [NavChartDb](INFO): Join timeout helper Thread ID is 1008 2021-04-19T19:46:31.104Z,1618861591.104 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2021-04-19T19:46:31.104Z,1618861591.104 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-04-19T19:46:31.112Z,1618861591.112 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2021-04-19T19:46:31.112Z,1618861591.112 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-04-19T19:46:31.112Z,1618861591.112 [Radio_Surface](INFO): Join timeout helper Thread ID is 1009 2021-04-19T19:46:31.500Z,1618861591.500 [Radio_Surface](INFO): Powering down 2021-04-19T19:46:31.501Z,1618861591.501 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2021-04-19T19:46:31.501Z,1618861591.501 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-04-19T19:46:31.520Z,1618861591.520 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2021-04-19T19:46:31.520Z,1618861591.520 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-04-19T19:46:31.520Z,1618861591.520 [Onboard](INFO): Join timeout helper Thread ID is 1010 2021-04-19T19:46:31.936Z,1618861591.936 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2021-04-19T19:46:35.176Z,1618861595.176 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2021-04-19T19:46:35.176Z,1618861595.176 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-04-19T19:46:35.196Z,1618861595.196 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2021-04-19T19:46:35.196Z,1618861595.196 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2021-04-19T19:46:35.196Z,1618861595.196 [DataOverHttps](INFO): Join timeout helper Thread ID is 1011 2021-04-19T19:46:35.952Z,1618861595.952 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2021-04-19T19:46:35.952Z,1618861595.952 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2021-04-19T19:46:35.957Z,1618861595.957 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2021-04-19T19:46:35.957Z,1618861595.957 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-04-19T19:46:35.957Z,1618861595.957 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1012 2021-04-19T19:46:36.216Z,1618861596.216 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2021-04-19T19:46:36.216Z,1618861596.216 [WetLabsBB2FL](INFO): Powering down 2021-04-19T19:46:36.217Z,1618861596.217 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-04-19T19:46:36.237Z,1618861596.237 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2021-04-19T19:46:36.237Z,1618861596.237 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-04-19T19:46:36.237Z,1618861596.237 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1013 2021-04-19T19:46:36.616Z,1618861596.616 [CTD_Seabird](INFO): Powering down 2021-04-19T19:46:36.628Z,1618861596.628 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2021-04-19T19:46:36.628Z,1618861596.628 [CTD_Seabird](INFO): Powering down 2021-04-19T19:46:36.640Z,1618861596.640 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-04-19T19:46:36.641Z,1618861596.641 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2021-04-19T19:46:36.641Z,1618861596.641 [logger ThreadHandler](INFO): Thread cancelled. 2021-04-19T19:46:36.642Z,1618861596.642 [logger](INFO): Join timeout helper Thread ID is 1014 2021-04-19T19:46:36.677Z,1618861596.677 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2021-04-19T19:46:36.677Z,1618861596.677 [logger ThreadHandler](INFO): Thread cancelled. 2021-04-19T19:46:36.681Z,1618861596.681 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2021-04-19T19:46:36.681Z,1618861596.681 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-04-19T19:46:36.681Z,1618861596.681 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2021-04-19T19:46:36.681Z,1618861596.681 [controlThread ThreadHandler](INFO): Thread cancelled. 2021-04-19T19:46:36.681Z,1618861596.681 [controlThread](INFO): Join timeout helper Thread ID is 1015 2021-04-19T19:46:37.012Z,1618861597.012 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2021-04-19T19:46:37.012Z,1618861597.012 [controlThread](DEBUG): Uninitializing ControlThread 2021-04-19T19:46:37.014Z,1618861597.014 [AHRS_M2](INFO): Powering down 2021-04-19T19:46:37.156Z,1618861597.156 [DVL_micro](INFO): Powering down 2021-04-19T19:46:37.157Z,1618861597.157 [NAL9602](INFO): Powering down 2021-04-19T19:46:37.158Z,1618861597.158 [DAT](INFO): Powering down 2021-04-19T19:46:37.276Z,1618861597.276 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2021-04-19T19:46:37.277Z,1618861597.277 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2021-04-19T19:46:37.278Z,1618861597.278 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2021-04-19T19:46:37.278Z,1618861597.278 [MissionManager](INFO): Uninitializing Mission Default 2021-04-19T19:46:37.278Z,1618861597.278 [Default] Stopped 2021-04-19T19:46:37.279Z,1618861597.279 [Default](DEBUG): Aggregate::uninitialize Default 2021-04-19T19:46:37.279Z,1618861597.279 [Default:B.GoToSurface] Stopped 2021-04-19T19:46:37.279Z,1618861597.279 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2021-04-19T19:46:37.279Z,1618861597.279 [Default:CheckIn] Stopped 2021-04-19T19:46:37.279Z,1618861597.279 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T19:46:37.279Z,1618861597.279 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T19:46:37.282Z,1618861597.282 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2021-04-19T19:46:37.282Z,1618861597.282 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2021-04-19T19:46:37.282Z,1618861597.282 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2021-04-19T19:46:37.283Z,1618861597.283 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2021-04-19T19:46:37.283Z,1618861597.283 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2021-04-19T19:46:37.283Z,1618861597.283 [BuoyancyServo](INFO): Powering down 2021-04-19T19:46:37.296Z,1618861597.296 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2021-04-19T19:46:37.296Z,1618861597.296 [ElevatorServo](INFO): Powering down 2021-04-19T19:46:37.297Z,1618861597.297 [MassServo](DEBUG): Uninitialize Mass Servo. 2021-04-19T19:46:37.297Z,1618861597.297 [MassServo](INFO): Powering down 2021-04-19T19:46:37.298Z,1618861597.298 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2021-04-19T19:46:37.298Z,1618861597.298 [RudderServo](INFO): Powering down 2021-04-19T19:46:37.299Z,1618861597.299 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2021-04-19T19:46:37.299Z,1618861597.299 [ThrusterServo](INFO): Powering down 2021-04-19T19:46:37.299Z,1618861597.299 [SBIT](DEBUG): Uninitialize SBIT Component. 2021-04-19T19:46:37.300Z,1618861597.300 [IBIT](DEBUG): Uninitialize IBIT Component. 2021-04-19T19:46:37.300Z,1618861597.300 [CBIT](DEBUG): Uninitialize CBIT Component. 2021-04-19T19:46:37.300Z,1618861597.300 [CBIT](DEBUG): Powering off loads. 2021-04-19T19:46:37.312Z,1618861597.312 [CBIT](DEBUG): Disabling WDT. 2021-04-19T19:46:37.324Z,1618861597.324 [CBIT](DEBUG): Opening all GF detection circuits. 2021-04-19T19:46:37.325Z,1618861597.325 [controlThread ThreadHandler](INFO): Thread cancelled. 2021-04-19T19:46:37.369Z,1618861597.369 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-04-19T19:46:37.375Z,1618861597.375 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-04-19T19:46:37.406Z,1618861597.406 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-04-19T19:46:37.407Z,1618861597.407 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-04-19T19:46:37.415Z,1618861597.415 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2021-04-19T19:46:37.503Z,1618861597.503 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-04-19T19:46:37.564Z,1618861597.564 [logger ThreadHandler](INFO): Thread cancelled.