2023-03-15T18:34:26.765Z,1678905266.765 [Supervisor](DEBUG): Initializing supervisor. 2023-03-15T18:34:26.770Z,1678905266.770 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2023-03-15T18:34:26.770Z,1678905266.770 [SyncHandler](INFO): Protected caller Thread ID is 834 2023-03-15T18:34:26.771Z,1678905266.771 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2023-03-15T18:34:26.772Z,1678905266.772 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2023-03-15T18:34:26.772Z,1678905266.772 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 835 2023-03-15T18:34:26.776Z,1678905266.776 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2023-03-15T18:34:26.794Z,1678905266.794 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2023-03-15T18:34:26.795Z,1678905266.795 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2023-03-15T18:34:26.795Z,1678905266.795 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 836 2023-03-15T18:34:26.799Z,1678905266.799 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2023-03-15T18:34:26.800Z,1678905266.800 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2023-03-15T18:34:26.801Z,1678905266.801 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 837 2023-03-15T18:34:26.803Z,1678905266.803 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2023-03-15T18:34:26.804Z,1678905266.804 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2023-03-15T18:34:26.804Z,1678905266.804 [logger ThreadHandler](INFO): Protected caller Thread ID is 838 2023-03-15T18:34:26.808Z,1678905266.808 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2023-03-15T18:34:26.808Z,1678905266.808 [Supervisor](INFO): Looking for Config files in directory: Config/ 2023-03-15T18:34:26.812Z,1678905266.812 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2023-03-15T18:34:27.080Z,1678905267.080 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2023-03-15T18:34:27.082Z,1678905267.082 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2023-03-15T18:34:27.164Z,1678905267.164 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2023-03-15T18:34:27.654Z,1678905267.654 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2023-03-15T18:34:27.656Z,1678905267.656 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2023-03-15T18:34:28.003Z,1678905268.003 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2023-03-15T18:34:28.003Z,1678905268.003 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2023-03-15T18:34:28.101Z,1678905268.101 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2023-03-15T18:34:28.103Z,1678905268.103 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2023-03-15T18:34:28.508Z,1678905268.508 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2023-03-15T18:34:28.510Z,1678905268.510 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2023-03-15T18:34:28.723Z,1678905268.723 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2023-03-15T18:34:28.724Z,1678905268.724 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2023-03-15T18:34:29.233Z,1678905269.233 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2023-03-15T18:34:29.235Z,1678905269.235 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2023-03-15T18:34:29.376Z,1678905269.376 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2023-03-15T18:34:29.376Z,1678905269.376 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2023-03-15T18:34:29.458Z,1678905269.458 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2023-03-15T18:34:30.305Z,1678905270.305 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2023-03-15T18:34:30.714Z,1678905270.714 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2023-03-15T18:34:31.158Z,1678905271.158 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2023-03-15T18:34:31.160Z,1678905271.160 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2023-03-15T18:34:31.354Z,1678905271.354 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2023-03-15T18:34:31.355Z,1678905271.355 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2023-03-15T18:34:31.468Z,1678905271.468 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2023-03-15T18:34:31.468Z,1678905271.468 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2023-03-15T18:34:31.697Z,1678905271.697 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2023-03-15T18:34:31.698Z,1678905271.698 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2023-03-15T18:34:31.943Z,1678905271.943 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2023-03-15T18:34:31.946Z,1678905271.946 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2023-03-15T18:34:31.949Z,1678905271.949 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg 2023-03-15T18:34:32.041Z,1678905272.041 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2023-03-15T18:34:32.128Z,1678905272.128 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2023-03-15T18:34:32.232Z,1678905272.232 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2023-03-15T18:34:32.317Z,1678905272.317 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2023-03-15T18:34:32.417Z,1678905272.417 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2023-03-15T18:34:32.519Z,1678905272.519 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2023-03-15T18:34:32.704Z,1678905272.704 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg 2023-03-15T18:34:32.781Z,1678905272.781 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2023-03-15T18:34:32.931Z,1678905272.931 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2023-03-15T18:34:33.070Z,1678905273.070 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2023-03-15T18:34:33.190Z,1678905273.190 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2023-03-15T18:34:33.462Z,1678905273.462 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2023-03-15T18:34:33.463Z,1678905273.463 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2023-03-15T18:34:33.485Z,1678905273.485 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2023-03-15T18:34:33.558Z,1678905273.558 [VerticalControl](DEBUG): Construct VerticalControl. 2023-03-15T18:34:33.620Z,1678905273.620 [VerticalControl] Loaded 2023-03-15T18:34:33.620Z,1678905273.620 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2023-03-15T18:34:33.623Z,1678905273.623 [HorizontalControl](DEBUG): Construct HorizontalControl. 2023-03-15T18:34:33.666Z,1678905273.666 [HorizontalControl] Loaded 2023-03-15T18:34:33.666Z,1678905273.666 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2023-03-15T18:34:33.669Z,1678905273.669 [SpeedControl](DEBUG): Construct SpeedControl. 2023-03-15T18:34:33.672Z,1678905273.672 [SpeedControl] Loaded 2023-03-15T18:34:33.672Z,1678905273.672 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2023-03-15T18:34:33.675Z,1678905273.675 [LoopControl](DEBUG): Construct LoopControl. 2023-03-15T18:34:33.675Z,1678905273.675 [LoopControl] Loaded 2023-03-15T18:34:33.675Z,1678905273.675 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2023-03-15T18:34:33.676Z,1678905273.676 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2023-03-15T18:34:33.678Z,1678905273.678 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2023-03-15T18:34:33.694Z,1678905273.694 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2023-03-15T18:34:33.694Z,1678905273.694 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2023-03-15T18:34:33.899Z,1678905273.899 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2023-03-15T18:34:33.900Z,1678905273.900 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2023-03-15T18:34:34.096Z,1678905274.096 [BuoyancyServo] Loaded 2023-03-15T18:34:34.096Z,1678905274.096 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2023-03-15T18:34:34.117Z,1678905274.117 [ElevatorServo] Loaded 2023-03-15T18:34:34.117Z,1678905274.117 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2023-03-15T18:34:34.137Z,1678905274.137 [MassServo] Loaded 2023-03-15T18:34:34.137Z,1678905274.137 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2023-03-15T18:34:34.156Z,1678905274.156 [RudderServo] Loaded 2023-03-15T18:34:34.157Z,1678905274.157 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2023-03-15T18:34:34.174Z,1678905274.174 [ThrusterServo] Loaded 2023-03-15T18:34:34.175Z,1678905274.175 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2023-03-15T18:34:34.175Z,1678905274.175 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2023-03-15T18:34:34.176Z,1678905274.176 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2023-03-15T18:34:34.323Z,1678905274.323 [DeadReckonUsingMultipleVelocitySources] Loaded 2023-03-15T18:34:34.323Z,1678905274.323 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2023-03-15T18:34:34.338Z,1678905274.338 [NavChart] Loaded 2023-03-15T18:34:34.338Z,1678905274.338 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2023-03-15T18:34:34.344Z,1678905274.344 [UniversalFixResidualReporter] Loaded 2023-03-15T18:34:34.344Z,1678905274.344 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2023-03-15T18:34:34.344Z,1678905274.344 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2023-03-15T18:34:34.345Z,1678905274.345 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2023-03-15T18:34:34.433Z,1678905274.433 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2023-03-15T18:34:34.434Z,1678905274.434 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2023-03-15T18:34:35.215Z,1678905275.215 [AHRS_M2] Loaded 2023-03-15T18:34:35.215Z,1678905275.215 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2023-03-15T18:34:36.058Z,1678905276.058 [BPC1] Loaded 2023-03-15T18:34:36.058Z,1678905276.058 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2023-03-15T18:34:36.199Z,1678905276.199 [DataOverHttps] Loaded 2023-03-15T18:34:36.200Z,1678905276.200 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2023-03-15T18:34:36.201Z,1678905276.201 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408FD4E0 2023-03-15T18:34:36.201Z,1678905276.201 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 923 2023-03-15T18:34:36.223Z,1678905276.223 [Depth_Keller] Loaded 2023-03-15T18:34:36.223Z,1678905276.223 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2023-03-15T18:34:36.228Z,1678905276.228 [DropWeight] Loaded 2023-03-15T18:34:36.229Z,1678905276.229 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2023-03-15T18:34:36.248Z,1678905276.248 [MultiRay] Loaded 2023-03-15T18:34:36.248Z,1678905276.248 [ComponentRegistry](DEBUG): SyncComponent "MultiRay" handled in the control thread. 2023-03-15T18:34:36.313Z,1678905276.313 [NAL9602] Loaded 2023-03-15T18:34:36.313Z,1678905276.313 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2023-03-15T18:34:36.344Z,1678905276.344 [Onboard] Loaded 2023-03-15T18:34:36.345Z,1678905276.345 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2023-03-15T18:34:36.346Z,1678905276.346 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4092D4E0 2023-03-15T18:34:36.346Z,1678905276.346 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 924 2023-03-15T18:34:36.360Z,1678905276.360 [Power24vConverter] Loaded 2023-03-15T18:34:36.360Z,1678905276.360 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2023-03-15T18:34:36.374Z,1678905276.374 [Radio_Surface] Loaded 2023-03-15T18:34:36.374Z,1678905276.374 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2023-03-15T18:34:36.375Z,1678905276.375 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4095D4E0 2023-03-15T18:34:36.376Z,1678905276.376 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 925 2023-03-15T18:34:36.377Z,1678905276.377 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2023-03-15T18:34:36.378Z,1678905276.378 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2023-03-15T18:34:36.561Z,1678905276.561 [DepthRateCalculator] Loaded 2023-03-15T18:34:36.561Z,1678905276.561 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2023-03-15T18:34:36.566Z,1678905276.566 [PitchRateCalculator] Loaded 2023-03-15T18:34:36.567Z,1678905276.567 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2023-03-15T18:34:36.628Z,1678905276.628 [SpeedCalculator] Loaded 2023-03-15T18:34:36.628Z,1678905276.628 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2023-03-15T18:34:36.636Z,1678905276.636 [YawRateCalculator] Loaded 2023-03-15T18:34:36.636Z,1678905276.636 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2023-03-15T18:34:36.680Z,1678905276.680 [ElevatorOffsetCalculator] Loaded 2023-03-15T18:34:36.681Z,1678905276.681 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2023-03-15T18:34:36.681Z,1678905276.681 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2023-03-15T18:34:36.682Z,1678905276.682 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2023-03-15T18:34:37.561Z,1678905277.561 [CANONSampler] Loaded 2023-03-15T18:34:37.562Z,1678905277.562 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread. 2023-03-15T18:34:37.623Z,1678905277.623 [CTD_Seabird] Loaded 2023-03-15T18:34:37.623Z,1678905277.623 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2023-03-15T18:34:37.625Z,1678905277.625 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A164E0 2023-03-15T18:34:37.625Z,1678905277.625 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 926 2023-03-15T18:34:37.646Z,1678905277.646 [PAR_Licor] Loaded 2023-03-15T18:34:37.646Z,1678905277.646 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2023-03-15T18:34:37.679Z,1678905277.679 [WetLabsBB2FL] Loaded 2023-03-15T18:34:37.679Z,1678905277.679 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2023-03-15T18:34:37.680Z,1678905277.680 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A464E0 2023-03-15T18:34:37.681Z,1678905277.681 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 927 2023-03-15T18:34:37.681Z,1678905277.681 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2023-03-15T18:34:37.682Z,1678905277.682 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2023-03-15T18:34:37.726Z,1678905277.726 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2023-03-15T18:34:37.727Z,1678905277.727 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2023-03-15T18:34:38.132Z,1678905278.132 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2023-03-15T18:34:38.133Z,1678905278.133 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2023-03-15T18:34:38.319Z,1678905278.319 [SBIT](DEBUG): Construct Startup Built In Test. 2023-03-15T18:34:38.329Z,1678905278.329 [SBIT] Loaded 2023-03-15T18:34:38.329Z,1678905278.329 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2023-03-15T18:34:38.332Z,1678905278.332 [IBIT](DEBUG): Construct Initiated Built In Test. 2023-03-15T18:34:38.345Z,1678905278.345 [IBIT] Loaded 2023-03-15T18:34:38.345Z,1678905278.345 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2023-03-15T18:34:38.351Z,1678905278.351 [CBIT](DEBUG): Construct Continuous Built In Test. 2023-03-15T18:34:38.461Z,1678905278.461 [CBIT] Loaded 2023-03-15T18:34:38.461Z,1678905278.461 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2023-03-15T18:34:38.462Z,1678905278.462 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2023-03-15T18:34:38.462Z,1678905278.462 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2023-03-15T18:34:38.600Z,1678905278.600 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2023-03-15T18:34:38.606Z,1678905278.606 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2023-03-15T18:34:38.609Z,1678905278.609 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2023-03-15T18:34:38.620Z,1678905278.620 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2023-03-15T18:34:38.621Z,1678905278.621 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B7E4E0 2023-03-15T18:34:38.621Z,1678905278.621 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 928 2023-03-15T18:34:38.626Z,1678905278.626 [Supervisor](INFO): Main Thread ID is 829 2023-03-15T18:34:38.626Z,1678905278.626 [Supervisor](DEBUG): Running supervisor. 2023-03-15T18:34:38.627Z,1678905278.627 [CommandExec ThreadHandler](INFO): Handler Thread ID is 929 2023-03-15T18:34:38.627Z,1678905278.627 [CommandExec](INFO): Initializing the command executive. 2023-03-15T18:34:38.629Z,1678905278.629 [CommandLine ThreadHandler](INFO): Handler Thread ID is 930 2023-03-15T18:34:38.631Z,1678905278.631 [controlThread ThreadHandler](INFO): Handler Thread ID is 931 2023-03-15T18:34:38.631Z,1678905278.631 [controlThread](DEBUG): Initializing ControlThread 2023-03-15T18:34:38.632Z,1678905278.632 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2023-03-15T18:34:38.634Z,1678905278.634 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2023-03-15T18:34:38.635Z,1678905278.635 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2023-03-15T18:34:38.635Z,1678905278.635 [LoopControl](DEBUG): Initialize LoopControlComponent. 2023-03-15T18:34:38.637Z,1678905278.637 [NavChart](DEBUG): Initialize NavChart Navigation. 2023-03-15T18:34:38.638Z,1678905278.638 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2023-03-15T18:34:38.642Z,1678905278.642 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2023-03-15T18:34:38.642Z,1678905278.642 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2023-03-15T18:34:38.642Z,1678905278.642 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2023-03-15T18:34:38.643Z,1678905278.643 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2023-03-15T18:34:38.643Z,1678905278.643 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2023-03-15T18:34:38.648Z,1678905278.648 [SBIT](INFO): Initialize SBIT Component. 2023-03-15T18:34:38.649Z,1678905278.649 [SBIT](IMPORTANT): git: 2023-03-15 2023-03-15T18:34:38.649Z,1678905278.649 [SBIT](INFO): git hash: da2de14cb6f019879a6d9fecb1092e9917ba982e 2023-03-15T18:34:38.649Z,1678905278.649 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2023-03-15T18:34:38.650Z,1678905278.650 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021 2023-03-15T18:34:38.651Z,1678905278.651 [SBIT](INFO): Beginning SBIT in 51.000000 seconds. 2023-03-15T18:34:38.652Z,1678905278.652 [IBIT](INFO): Initialize IBIT Component. 2023-03-15T18:34:38.653Z,1678905278.653 [CBIT](DEBUG): Initialize CBIT Component. 2023-03-15T18:34:38.654Z,1678905278.654 [logger ThreadHandler](INFO): Handler Thread ID is 932 2023-03-15T18:34:38.664Z,1678905278.664 [CBIT](DEBUG): Initialized mux pins. 2023-03-15T18:34:38.664Z,1678905278.664 [CBIT](DEBUG): Initializing the watchdog timer. 2023-03-15T18:34:38.672Z,1678905278.672 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 933 2023-03-15T18:34:38.673Z,1678905278.673 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2023-03-15T18:34:38.684Z,1678905278.684 [Onboard ThreadHandler](INFO): Handler Thread ID is 934 2023-03-15T18:34:38.688Z,1678905278.688 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2023-03-15T18:34:38.689Z,1678905278.689 [CBIT](DEBUG): Initializing heartbeat. 2023-03-15T18:34:38.705Z,1678905278.705 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 935 2023-03-15T18:34:38.720Z,1678905278.720 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 936 2023-03-15T18:34:38.721Z,1678905278.721 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2023-03-15T18:34:38.725Z,1678905278.725 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 938 2023-03-15T18:34:38.729Z,1678905278.729 [WetLabsBB2FL](INFO): Powering up 2023-03-15T18:34:38.730Z,1678905278.730 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 940 2023-03-15T18:34:38.740Z,1678905278.740 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2023-03-15T18:34:38.740Z,1678905278.740 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2023-03-15T18:34:38.740Z,1678905278.740 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2023-03-15T18:34:38.740Z,1678905278.740 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2023-03-15T18:34:38.741Z,1678905278.741 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2023-03-15T18:34:38.741Z,1678905278.741 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2023-03-15T18:34:38.741Z,1678905278.741 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2023-03-15T18:34:38.741Z,1678905278.741 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2023-03-15T18:34:38.760Z,1678905278.760 [CBIT](DEBUG): Deactivating GF circuits. 2023-03-15T18:34:38.760Z,1678905278.760 [CBIT](DEBUG): Deactivating emergency mode. 2023-03-15T18:34:38.800Z,1678905278.800 [CBIT](DEBUG): Backplane powered. 2023-03-15T18:34:38.801Z,1678905278.801 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml 2023-03-15T18:34:38.829Z,1678905278.829 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2023-03-15T18:34:38.857Z,1678905278.857 [MissionManager](DEBUG): 2023-03-15T18:34:38.858Z,1678905278.858 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml 2023-03-15T18:34:38.936Z,1678905278.936 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2023-03-15T18:34:38.937Z,1678905278.937 [Default:A.Wait](DEBUG): Construct Wait. 2023-03-15T18:34:38.947Z,1678905278.947 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2023-03-15T18:34:38.974Z,1678905278.974 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2023-03-15T18:34:39.009Z,1678905279.009 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2023-03-15T18:34:39.015Z,1678905279.015 [Default:E.Execute](DEBUG): Construct Execute. 2023-03-15T18:34:39.030Z,1678905279.030 [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 2023-03-15T18:34:39.035Z,1678905279.035 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,MultiRay,NAL9602,Power24vConverter,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2023-03-15T18:34:39.076Z,1678905279.076 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2023-03-15T18:34:39.112Z,1678905279.112 [Radio_Surface](INFO): Powering up 2023-03-15T18:34:39.258Z,1678905279.258 [MultiRay](INFO): Powering up MultiRay Lights 2023-03-15T18:34:39.289Z,1678905279.289 [Power24vConverter](INFO): Powering up. 2023-03-15T18:34:39.289Z,1678905279.289 [CANONSampler](INFO): Powering down 2023-03-15T18:34:39.344Z,1678905279.344 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2023-03-15T18:34:39.353Z,1678905279.353 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2023-03-15T18:34:39.354Z,1678905279.354 [ElevatorServo](DEBUG): Initializing EZServoServo. 2023-03-15T18:34:39.360Z,1678905279.360 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2023-03-15T18:34:39.361Z,1678905279.361 [MassServo](DEBUG): Initializing EZServoServo. 2023-03-15T18:34:39.369Z,1678905279.369 [MassServo](DEBUG): Initializing MassServo. 2023-03-15T18:34:39.370Z,1678905279.370 [RudderServo](DEBUG): Initializing EZServoServo. 2023-03-15T18:34:39.376Z,1678905279.376 [RudderServo](DEBUG): Initializing RudderServo. 2023-03-15T18:34:39.377Z,1678905279.377 [ThrusterServo](DEBUG): Initializing EZServoServo. 2023-03-15T18:34:39.384Z,1678905279.384 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2023-03-15T18:34:41.340Z,1678905281.340 [WetLabsBB2FL](INFO): Powering down 2023-03-15T18:35:06.682Z,1678905306.682 [NAL9602](INFO): Powering up NAL9602 2023-03-15T18:35:17.590Z,1678905317.590 [NAL9602](INFO): NAL9602 initialized 2023-03-15T18:35:30.131Z,1678905330.131 [SBIT](IMPORTANT): Beginning Startup BIT 2023-03-15T18:35:30.136Z,1678905330.136 [CBIT](IMPORTANT): Beginning ground fault scan 2023-03-15T18:35:41.479Z,1678905341.479 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan. 2023-03-15T18:35:41.886Z,1678905341.886 [CBIT](IMPORTANT): Beginning ground fault scan 2023-03-15T18:35:47.100Z,1678905347.100 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2023-03-15T18:35:51.926Z,1678905351.926 [Depth_Keller](FAULT): LCB fault: MCLR Reset. 2023-03-15T18:35:51.926Z,1678905351.926 [Depth_Keller] Hardware Fault, FailCount= 1 2023-03-15T18:35:51.926Z,1678905351.926 [Depth_Keller](ERROR): Hardware Fault 2023-03-15T18:35:52.045Z,1678905352.045 [CBIT](ERROR): Hardware Fault in component: Depth_Keller 2023-03-15T18:35:52.045Z,1678905352.045 [CBIT](INFO): Clearing failed state for component Depth_Keller 2023-03-15T18:35:52.045Z,1678905352.045 [Depth_Keller] No Fault, FailCount= 1 2023-03-15T18:35:52.818Z,1678905352.818 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan. 2023-03-15T18:35:53.232Z,1678905353.232 [CBIT](IMPORTANT): Beginning ground fault scan 2023-03-15T18:36:04.091Z,1678905364.091 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan. 2023-03-15T18:36:04.092Z,1678905364.092 [CBIT](IMPORTANT): Ground fault scan returned out of bounds value in succession 3 times. Will re-run scan on normal schedule. 2023-03-15T18:36:24.280Z,1678905384.280 [SBIT](IMPORTANT): SBIT PASSED 2023-03-15T18:36:24.280Z,1678905384.280 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2023-03-15T18:36:24.281Z,1678905384.281 [SBIT](IMPORTANT): AHRS_M2.readAccelerations=0 bool; 2023-03-15T18:36:24.281Z,1678905384.281 [SBIT](IMPORTANT): AHRS_M2.readAngularVelocities=0 bool; 2023-03-15T18:36:24.281Z,1678905384.281 [SBIT](IMPORTANT): AHRS_M2.readMagnetics=0 bool; 2023-03-15T18:36:24.281Z,1678905384.281 [SBIT](IMPORTANT): AMEcho.loadAtStartup=0 bool; 2023-03-15T18:36:24.281Z,1678905384.281 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=10 count; 2023-03-15T18:36:24.282Z,1678905384.282 [SBIT](IMPORTANT): CANONSampler.loadAtStartup=1 bool; 2023-03-15T18:36:24.282Z,1678905384.282 [SBIT](IMPORTANT): CANONSampler.sampleTimeout=10 minute; 2023-03-15T18:36:24.282Z,1678905384.282 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool; 2023-03-15T18:36:24.282Z,1678905384.282 [SBIT](IMPORTANT): DropWeight.loadAtStartup=1 bool; 2023-03-15T18:36:24.282Z,1678905384.282 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=0 bool; 2023-03-15T18:36:24.282Z,1678905384.282 [SBIT](IMPORTANT): Express none CTD_Seabird.bin_median_sea_water_salinity; 2023-03-15T18:36:24.282Z,1678905384.282 [SBIT](IMPORTANT): Express none CTD_Seabird.bin_median_sea_water_temperature; 2023-03-15T18:36:24.282Z,1678905384.282 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water; 2023-03-15T18:36:24.282Z,1678905384.282 [SBIT](IMPORTANT): Express linearApproximation depth 5.000000 meter; 2023-03-15T18:36:24.283Z,1678905384.283 [SBIT](IMPORTANT): Express linearApproximation latitude 0.005000 degree; 2023-03-15T18:36:24.283Z,1678905384.283 [SBIT](IMPORTANT): Express linearApproximation longitude 0.005000 degree; 2023-03-15T18:36:24.283Z,1678905384.283 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=136.139403 cubic_centimeter; 2023-03-15T18:36:24.283Z,1678905384.283 [SBIT](IMPORTANT): VerticalControl.massDefault=-7.840612 millimeter; 2023-03-15T18:36:24.690Z,1678905384.690 [MissionManager](IMPORTANT): Started mission Startup 2023-03-15T18:36:24.691Z,1678905384.691 [Startup] Running Loop=1 2023-03-15T18:36:24.691Z,1678905384.691 [Startup](DEBUG): Aggregate::initialize Startup 2023-03-15T18:36:24.691Z,1678905384.691 [Startup:A.GoToSurface] Running Loop=1 2023-03-15T18:36:24.691Z,1678905384.691 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2023-03-15T18:36:24.691Z,1678905384.691 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2023-03-15T18:36:24.692Z,1678905384.692 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2023-03-15T18:36:24.692Z,1678905384.692 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2023-03-15T18:36:24.693Z,1678905384.693 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2023-03-15T18:36:24.693Z,1678905384.693 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2023-03-15T18:36:24.694Z,1678905384.694 [Startup:StartupSatComms] Running Loop=1 2023-03-15T18:36:24.695Z,1678905384.695 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2023-03-15T18:36:24.695Z,1678905384.695 [Startup:StartupSatComms:A] Running Loop=1 2023-03-15T18:36:25.071Z,1678905385.071 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2023-03-15T18:37:05.478Z,1678905425.478 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004706 2023-03-15T18:37:25.056Z,1678905445.056 [Startup:StartupSatComms:A](INFO): Timed out from 2023-03-15T18:36:24.7Z 2023-03-15T18:37:25.056Z,1678905445.056 [Startup:StartupSatComms:A] Stopped 2023-03-15T18:37:25.056Z,1678905445.056 [Startup:StartupSatComms:B] Running Loop=1 2023-03-15T18:37:25.472Z,1678905445.472 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2023-03-15T18:37:32.377Z,1678905452.377 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20230315T183426/Courier0000.lzma 2023-03-15T18:37:33.379Z,1678905453.379 [DataOverHttps](INFO): Moved sent file to Logs/20230315T183426/Courier0000.lzma.bak 2023-03-15T18:37:33.380Z,1678905453.380 [DataOverHttps](INFO): SBD MOMSN=17517787 2023-03-15T18:37:38.826Z,1678905458.826 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2023-03-15T18:37:38.826Z,1678905458.826 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-03-15T18:37:38.836Z,1678905458.836 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-03-15T18:37:39.235Z,1678905459.235 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-03-15T18:37:39.235Z,1678905459.235 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2023-03-15T18:37:48.943Z,1678905468.943 [DataOverHttps](INFO): Sending 956 bytes from file Logs/20230315T183426/Express0001.lzma 2023-03-15T18:37:49.943Z,1678905469.943 [DataOverHttps](INFO): Moved sent file to Logs/20230315T183426/Express0001.lzma.bak 2023-03-15T18:37:49.943Z,1678905469.943 [DataOverHttps](INFO): SBD MOMSN=17517790 2023-03-15T18:37:51.322Z,1678905471.322 [Startup:StartupSatComms:B] Stopped 2023-03-15T18:37:51.322Z,1678905471.322 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2023-03-15T18:37:51.322Z,1678905471.322 [Startup:StartupSatComms] Stopped 2023-03-15T18:37:51.322Z,1678905471.322 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2023-03-15T18:37:51.323Z,1678905471.323 [Startup](INFO): Completed Startup 2023-03-15T18:37:51.323Z,1678905471.323 [MissionManager](INFO): Startup is completed. 2023-03-15T18:37:51.323Z,1678905471.323 [MissionManager](INFO): Uninitializing Mission Startup 2023-03-15T18:37:51.323Z,1678905471.323 [Startup] Stopped 2023-03-15T18:37:51.323Z,1678905471.323 [Startup](DEBUG): Aggregate::uninitialize Startup 2023-03-15T18:37:51.323Z,1678905471.323 [Startup:A.GoToSurface] Stopped 2023-03-15T18:37:51.323Z,1678905471.323 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2023-03-15T18:37:51.720Z,1678905471.720 [MissionManager](IMPORTANT): Started mission Default 2023-03-15T18:37:51.720Z,1678905471.720 [Default] Running Loop=1 2023-03-15T18:37:51.720Z,1678905471.720 [Default](DEBUG): Aggregate::initialize Default 2023-03-15T18:37:51.720Z,1678905471.720 [Default:B.GoToSurface] Running Loop=1 2023-03-15T18:37:51.720Z,1678905471.720 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2023-03-15T18:37:51.721Z,1678905471.721 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2023-03-15T18:37:51.721Z,1678905471.721 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2023-03-15T18:37:51.721Z,1678905471.721 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2023-03-15T18:37:51.738Z,1678905471.738 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2023-03-15T18:37:51.738Z,1678905471.738 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2023-03-15T18:37:51.738Z,1678905471.738 [Default:A.Wait] Running Loop=1 2023-03-15T18:37:51.738Z,1678905471.738 [Default:A.Wait](DEBUG): Initialize Wait Component. 2023-03-15T18:38:05.052Z,1678905485.052 [Default:A.Wait](INFO): Done Waiting. 2023-03-15T18:38:05.052Z,1678905485.052 [Default:A.Wait] Stopped 2023-03-15T18:38:05.052Z,1678905485.052 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2023-03-15T18:38:05.456Z,1678905485.456 [Default:CheckIn] Running Loop=1 2023-03-15T18:38:05.457Z,1678905485.457 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-15T18:38:05.457Z,1678905485.457 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-15T18:38:05.860Z,1678905485.860 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2023-03-15T18:39:12.508Z,1678905552.508 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2023-03-15T18:39:28.258Z,1678905568.258 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2023-03-15T18:39:43.207Z,1678905583.207 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2023-03-15T18:39:58.154Z,1678905598.154 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2023-03-15T18:40:02.167Z,1678905602.167 [CommandExec](IMPORTANT): got command burn on 2023-03-15T18:40:02.167Z,1678905602.167 [CommandExec](IMPORTANT): Activating dropweight wire 2023-03-15T18:40:13.103Z,1678905613.103 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2023-03-15T18:40:21.191Z,1678905621.191 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-03-15T18:40:28.454Z,1678905628.454 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2023-03-15T18:40:39.778Z,1678905639.778 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2023-03-15T18:40:39.778Z,1678905639.778 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-03-15T18:40:39.798Z,1678905639.798 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-03-15T18:40:40.221Z,1678905640.221 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-03-15T18:40:40.221Z,1678905640.221 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2023-03-15T18:40:43.807Z,1678905643.807 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2023-03-15T18:40:58.754Z,1678905658.754 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2023-03-15T18:41:14.106Z,1678905674.106 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2023-03-15T18:42:08.086Z,1678905728.086 [CommandExec](IMPORTANT): got command burn off 2023-03-15T18:42:08.086Z,1678905728.086 [CommandExec](IMPORTANT): Deactivating dropweight wire 2023-03-15T18:42:22.794Z,1678905742.794 [BPC1](INFO): Calculating totals. Valid battery stick count: 47. Valid reserve battery stick count: 5. 2023-03-15T18:42:22.797Z,1678905742.797 [BPC1](INFO): Received data from all battery sticks. 2023-03-15T18:43:05.623Z,1678905785.623 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-03-15T18:38:05.5Z 2023-03-15T18:43:05.623Z,1678905785.623 [Default:CheckIn:Read_GPS] Stopped 2023-03-15T18:43:05.624Z,1678905785.624 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-15T18:43:06.034Z,1678905786.034 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2023-03-15T18:43:14.965Z,1678905794.965 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20230315T183426/Courier0004.lzma 2023-03-15T18:43:15.968Z,1678905795.968 [DataOverHttps](INFO): Moved sent file to Logs/20230315T183426/Courier0004.lzma.bak 2023-03-15T18:43:15.968Z,1678905795.968 [DataOverHttps](INFO): SBD MOMSN=17517822 2023-03-15T18:43:30.502Z,1678905810.502 [DataOverHttps](INFO): Sending 268 bytes from file Logs/20230315T183426/Express0005.lzma 2023-03-15T18:43:31.503Z,1678905811.503 [DataOverHttps](INFO): Moved sent file to Logs/20230315T183426/Express0005.lzma.bak 2023-03-15T18:43:31.503Z,1678905811.503 [DataOverHttps](INFO): SBD MOMSN=17517824 2023-03-15T18:43:32.723Z,1678905812.723 [Default:CheckIn:Read_Iridium] Stopped 2023-03-15T18:43:32.723Z,1678905812.723 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-15T18:43:32.723Z,1678905812.723 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-15T18:43:40.830Z,1678905820.830 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2023-03-15T18:43:40.830Z,1678905820.830 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-03-15T18:43:40.841Z,1678905820.841 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-03-15T18:43:41.246Z,1678905821.246 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-03-15T18:43:41.246Z,1678905821.246 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2023-03-15T18:44:40.202Z,1678905880.202 [Power24vConverter](INFO): Powering down. 2023-03-15T18:45:19.369Z,1678905919.369 [NAL9602](FAULT): GPS failed to acquire within timeout. 2023-03-15T18:45:19.369Z,1678905919.369 [NAL9602] Data Fault, FailCount= 1 2023-03-15T18:45:19.369Z,1678905919.369 [NAL9602](ERROR): Data Fault 2023-03-15T18:45:19.386Z,1678905919.386 [CBIT](ERROR): Data Fault in component: NAL9602 2023-03-15T18:45:19.779Z,1678905919.779 [NAL9602](INFO): Powering down 2023-03-15T18:45:20.596Z,1678905920.596 [CBIT](INFO): Clearing failed state for component NAL9602 2023-03-15T18:45:20.596Z,1678905920.596 [NAL9602] No Fault, FailCount= 1 2023-03-15T18:45:50.078Z,1678905950.078 [NAL9602](INFO): Powering up NAL9602 2023-03-15T18:46:00.987Z,1678905960.987 [NAL9602](INFO): NAL9602 initialized 2023-03-15T18:46:41.791Z,1678906001.791 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2023-03-15T18:46:41.791Z,1678906001.791 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-03-15T18:46:41.801Z,1678906001.801 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-03-15T18:46:42.212Z,1678906002.212 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-03-15T18:46:42.212Z,1678906002.212 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2023-03-15T18:48:33.328Z,1678906113.328 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-15T18:48:33.328Z,1678906113.328 [Default:CheckIn:C.Wait] Stopped 2023-03-15T18:48:33.328Z,1678906113.328 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-15T18:48:33.328Z,1678906113.328 [Default:CheckIn:D] Running Loop=1 2023-03-15T18:48:33.728Z,1678906113.728 [Default:CheckIn:D] Stopped 2023-03-15T18:48:33.728Z,1678906113.728 [Default:CheckIn:E] Running Loop=1 2023-03-15T18:48:34.112Z,1678906114.112 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.700133 min 2023-03-15T18:48:34.112Z,1678906114.112 [Default:CheckIn:E] Stopped 2023-03-15T18:48:34.112Z,1678906114.112 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-15T18:48:34.112Z,1678906114.112 [Default:CheckIn] Stopped 2023-03-15T18:48:34.113Z,1678906114.113 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-15T18:48:34.113Z,1678906114.113 [Default:CheckIn](INFO): Running loop #2 2023-03-15T18:48:34.113Z,1678906114.113 [Default:CheckIn] Running Loop=2 2023-03-15T18:48:34.113Z,1678906114.113 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-15T18:48:34.113Z,1678906114.113 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-15T18:49:42.797Z,1678906182.797 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2023-03-15T18:49:42.797Z,1678906182.797 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-03-15T18:49:42.808Z,1678906182.808 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-03-15T18:49:43.220Z,1678906183.220 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-03-15T18:49:43.220Z,1678906183.220 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2023-03-15T18:52:43.803Z,1678906363.803 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2023-03-15T18:52:43.803Z,1678906363.803 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-03-15T18:52:43.814Z,1678906363.814 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-03-15T18:52:44.226Z,1678906364.226 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-03-15T18:52:44.226Z,1678906364.226 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2023-03-15T18:53:34.325Z,1678906414.325 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-03-15T18:48:34.1Z 2023-03-15T18:53:34.325Z,1678906414.325 [Default:CheckIn:Read_GPS] Stopped 2023-03-15T18:53:34.325Z,1678906414.325 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-15T18:53:41.853Z,1678906421.853 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230315T183426/Courier0007.lzma 2023-03-15T18:53:42.855Z,1678906422.855 [DataOverHttps](INFO): Moved sent file to Logs/20230315T183426/Courier0007.lzma.bak 2023-03-15T18:53:42.855Z,1678906422.855 [DataOverHttps](INFO): SBD MOMSN=17517833 2023-03-15T18:53:58.257Z,1678906438.257 [DataOverHttps](INFO): Sending 182 bytes from file Logs/20230315T183426/Express0008.lzma 2023-03-15T18:53:59.259Z,1678906439.259 [DataOverHttps](INFO): Moved sent file to Logs/20230315T183426/Express0008.lzma.bak 2023-03-15T18:53:59.259Z,1678906439.259 [DataOverHttps](INFO): SBD MOMSN=17517835 2023-03-15T18:54:00.600Z,1678906440.600 [Default:CheckIn:Read_Iridium] Stopped 2023-03-15T18:54:00.601Z,1678906440.601 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-15T18:54:00.601Z,1678906440.601 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-15T18:55:44.830Z,1678906544.830 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2023-03-15T18:55:44.830Z,1678906544.830 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-03-15T18:55:44.840Z,1678906544.840 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-03-15T18:55:45.227Z,1678906545.227 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-03-15T18:55:45.227Z,1678906545.227 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2023-03-15T18:56:03.394Z,1678906563.394 [NAL9602](FAULT): GPS failed to acquire within timeout. 2023-03-15T18:56:03.394Z,1678906563.394 [NAL9602] Data Fault, FailCount= 2 2023-03-15T18:56:03.394Z,1678906563.394 [NAL9602](ERROR): Data Fault 2023-03-15T18:56:03.452Z,1678906563.452 [CBIT](ERROR): Data Fault in component: NAL9602 2023-03-15T18:56:03.791Z,1678906563.791 [NAL9602](INFO): Powering down 2023-03-15T18:56:04.646Z,1678906564.646 [CBIT](INFO): Clearing failed state for component NAL9602 2023-03-15T18:56:04.646Z,1678906564.646 [NAL9602] No Fault, FailCount= 2 2023-03-15T18:56:34.091Z,1678906594.091 [NAL9602](INFO): Powering up NAL9602 2023-03-15T18:56:38.895Z,1678906598.895 [DataOverHttps](IMPORTANT): SBD MTMSN=20230315T185637 2023-03-15T18:56:44.999Z,1678906604.999 [NAL9602](INFO): NAL9602 initialized 2023-03-15T18:56:46.081Z,1678906606.081 [DataOverHttps](INFO): Received command: ibit 2023-03-15T18:56:46.110Z,1678906606.110 [CommandExec](IMPORTANT): got command ibit 2023-03-15T18:56:46.270Z,1678906606.270 [IBIT](IMPORTANT): Beginning Initiated BIT 2023-03-15T18:56:46.270Z,1678906606.270 [IBIT](IMPORTANT): Beginning control surface checks. 2023-03-15T18:56:46.278Z,1678906606.278 [CBIT](IMPORTANT): Beginning ground fault scan 2023-03-15T18:56:49.127Z,1678906609.127 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes. 2023-03-15T18:56:57.549Z,1678906617.549 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.002602 CHAN A1 (24V) N/A reporting off CHAN A2 (12V): -0.002123 CHAN A3 (5V): -0.001262 CHAN B0 (3.3V): -0.000418 CHAN B1 (3.15aV): 0.000013 CHAN B2 (3.15bV): 0.000166 CHAN B3 (GND): 0.000037 OPEN: -0.000407 Full Scale: +/- 1 mA 2023-03-15T18:57:16.000Z,1678906637.000 [IBIT](FAULT): Rudder: EXPECTED:-15.000000 ACTUAL:-14.729494 2023-03-15T18:57:16.000Z,1678906637.000 [IBIT](FAULT): Control surface position failure. 2023-03-15T18:58:37.328Z,1678906717.328 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired. 2023-03-15T18:58:37.766Z,1678906717.766 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 0.000000 Voltage: 16.611000 2023-03-15T18:58:37.766Z,1678906717.766 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah 2023-03-15T18:58:37.766Z,1678906717.766 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V 2023-03-15T18:58:38.154Z,1678906718.154 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2023-03-15T18:58:38.154Z,1678906718.154 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2023-03-15T18:58:38.155Z,1678906718.155 [IBIT](IMPORTANT): Pressure:9.879791 PSI 2023-03-15T18:58:38.155Z,1678906718.155 [IBIT](IMPORTANT): Humidity:0.830179 % 2023-03-15T18:58:38.558Z,1678906718.558 [IBIT](IMPORTANT): Vehicle Pitch:0.071495 degrees 2023-03-15T18:58:38.558Z,1678906718.558 [IBIT](IMPORTANT): Vehicle Roll:-5.588935 degrees 2023-03-15T18:58:38.558Z,1678906718.558 [IBIT](IMPORTANT): Vehicle Heading:251.313370 degrees 2023-03-15T18:58:38.944Z,1678906718.944 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2023-03-15T18:58:38.945Z,1678906718.945 [IBIT](IMPORTANT): buoyancyNeutral: 136.139404 cc 2023-03-15T18:58:38.945Z,1678906718.945 [IBIT](IMPORTANT): massDefault: -0.784061 cm 2023-03-15T18:58:38.945Z,1678906718.945 [IBIT](IMPORTANT): stopDepth: 250.000000 m 2023-03-15T18:58:38.982Z,1678906718.982 [IBIT](IMPORTANT): abortDepth: 270.000000 m 2023-03-15T18:58:38.982Z,1678906718.982 [IBIT](IMPORTANT): IBIT FAILED 2023-03-15T18:58:45.825Z,1678906725.825 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2023-03-15T18:58:45.825Z,1678906725.825 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-03-15T18:58:45.848Z,1678906725.848 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-03-15T18:58:46.248Z,1678906726.248 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-03-15T18:58:46.248Z,1678906726.248 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2023-03-15T18:59:01.159Z,1678906741.159 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-15T18:59:01.159Z,1678906741.159 [Default:CheckIn:C.Wait] Stopped 2023-03-15T18:59:01.159Z,1678906741.159 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-15T18:59:01.159Z,1678906741.159 [Default:CheckIn:D] Running Loop=1 2023-03-15T18:59:01.591Z,1678906741.591 [Default:CheckIn:D] Stopped 2023-03-15T18:59:01.591Z,1678906741.591 [Default:CheckIn:E] Running Loop=1 2023-03-15T18:59:01.958Z,1678906741.958 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185900.00,A,3648.17310,N,12147.27495,W,0.019,196.80,150323,,,A*70 2023-03-15T18:59:01.961Z,1678906741.961 [NAL9602](INFO): GPS fix at 20230315T185900: (36.802885, -121.787916) 2023-03-15T18:59:01.972Z,1678906741.972 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.164518 min 2023-03-15T18:59:01.972Z,1678906741.972 [Default:CheckIn:E] Stopped 2023-03-15T18:59:01.973Z,1678906741.973 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-15T18:59:01.973Z,1678906741.973 [Default:CheckIn] Stopped 2023-03-15T18:59:01.973Z,1678906741.973 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-15T18:59:01.973Z,1678906741.973 [Default:CheckIn](INFO): Running loop #3 2023-03-15T18:59:01.973Z,1678906741.973 [Default:CheckIn] Running Loop=3 2023-03-15T18:59:01.973Z,1678906741.973 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-15T18:59:01.973Z,1678906741.973 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-15T18:59:04.793Z,1678906744.793 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185903.00,A,3648.17327,N,12147.27501,W,0.058,196.80,150323,,,A*7E 2023-03-15T18:59:04.795Z,1678906744.795 [NAL9602](INFO): GPS fix at 20230315T185903: (36.802888, -121.787917) 2023-03-15T18:59:04.830Z,1678906744.830 [Default:CheckIn:Read_GPS] Stopped 2023-03-15T18:59:04.830Z,1678906744.830 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-15T18:59:12.201Z,1678906752.201 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20230315T183426/Courier0010.lzma 2023-03-15T18:59:13.203Z,1678906753.203 [DataOverHttps](INFO): Moved sent file to Logs/20230315T183426/Courier0010.lzma.bak 2023-03-15T18:59:13.203Z,1678906753.203 [DataOverHttps](INFO): SBD MOMSN=17517841 2023-03-15T18:59:30.086Z,1678906770.086 [DataOverHttps](INFO): Sending 989 bytes from file Logs/20230315T183426/Express0011.lzma 2023-03-15T18:59:31.087Z,1678906771.087 [DataOverHttps](INFO): Moved sent file to Logs/20230315T183426/Express0011.lzma.bak 2023-03-15T18:59:31.087Z,1678906771.087 [DataOverHttps](INFO): SBD MOMSN=17517844 2023-03-15T18:59:32.489Z,1678906772.489 [Default:CheckIn:Read_Iridium] Stopped 2023-03-15T18:59:32.489Z,1678906772.489 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-15T18:59:32.489Z,1678906772.489 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-15T18:59:37.311Z,1678906777.311 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-15T19:04:33.057Z,1678907073.057 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-15T19:04:33.057Z,1678907073.057 [Default:CheckIn:C.Wait] Stopped 2023-03-15T19:04:33.058Z,1678907073.058 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-15T19:04:33.058Z,1678907073.058 [Default:CheckIn:D] Running Loop=1 2023-03-15T19:04:33.452Z,1678907073.452 [Default:CheckIn:D] Stopped 2023-03-15T19:04:33.452Z,1678907073.452 [Default:CheckIn:E] Running Loop=1 2023-03-15T19:04:33.861Z,1678907073.861 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 26.695532 min 2023-03-15T19:04:33.861Z,1678907073.861 [Default:CheckIn:E] Stopped 2023-03-15T19:04:33.861Z,1678907073.861 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-15T19:04:33.861Z,1678907073.861 [Default:CheckIn] Stopped 2023-03-15T19:04:33.861Z,1678907073.861 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-15T19:04:33.861Z,1678907073.861 [Default:CheckIn](INFO): Running loop #4 2023-03-15T19:04:33.861Z,1678907073.861 [Default:CheckIn] Running Loop=4 2023-03-15T19:04:33.861Z,1678907073.861 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-15T19:04:33.862Z,1678907073.862 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-15T19:04:35.889Z,1678907075.889 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190434.00,A,3648.13899,N,12147.23355,W,0.019,83.30,150323,,,A*41 2023-03-15T19:04:35.891Z,1678907075.891 [NAL9602](INFO): GPS fix at 20230315T190434: (36.802317, -121.787226) 2023-03-15T19:04:35.920Z,1678907075.920 [Default:CheckIn:Read_GPS] Stopped 2023-03-15T19:04:35.921Z,1678907075.921 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-15T19:04:43.841Z,1678907083.841 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230315T183426/Courier0015.lzma 2023-03-15T19:04:44.843Z,1678907084.843 [DataOverHttps](INFO): Moved sent file to Logs/20230315T183426/Courier0015.lzma.bak 2023-03-15T19:04:44.843Z,1678907084.843 [DataOverHttps](INFO): SBD MOMSN=17517873 2023-03-15T19:04:47.187Z,1678907087.187 [NAL9602](INFO): SBD MO Status=0, MOMSN=39115, MT Status=0, MTMSN=0 2023-03-15T19:04:47.187Z,1678907087.187 [NAL9602](INFO): No messages in MT queue 2023-03-15T19:05:03.253Z,1678907103.253 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20230315T183426/Express0014.lzma 2023-03-15T19:05:04.255Z,1678907104.255 [DataOverHttps](INFO): Moved sent file to Logs/20230315T183426/Express0014.lzma.bak 2023-03-15T19:05:04.256Z,1678907104.256 [DataOverHttps](INFO): SBD MOMSN=17517876 2023-03-15T19:05:05.416Z,1678907105.416 [Default:CheckIn:Read_Iridium] Stopped 2023-03-15T19:05:05.416Z,1678907105.416 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-15T19:05:05.416Z,1678907105.416 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-15T19:05:17.926Z,1678907117.926 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-15T19:05:43.187Z,1678907143.187 [DataOverHttps](IMPORTANT): SBD MTMSN=20230315T190542 2023-03-15T19:05:50.593Z,1678907150.593 [DataOverHttps](INFO): Received command: ibit 2023-03-15T19:05:50.682Z,1678907150.682 [CommandExec](IMPORTANT): got command ibit 2023-03-15T19:05:50.700Z,1678907150.700 [IBIT](IMPORTANT): Beginning Initiated BIT 2023-03-15T19:05:50.700Z,1678907150.700 [IBIT](IMPORTANT): Beginning control surface checks. 2023-03-15T19:05:50.703Z,1678907150.703 [CBIT](IMPORTANT): Beginning ground fault scan 2023-03-15T19:05:52.269Z,1678907152.269 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190550.00,A,3648.13999,N,12147.23400,W,0.078,83.30,150323,,,A*43 2023-03-15T19:05:52.271Z,1678907152.271 [NAL9602](INFO): GPS fix at 20230315T190550: (36.802333, -121.787233) 2023-03-15T19:05:53.570Z,1678907153.570 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes. 2023-03-15T19:06:01.615Z,1678907161.615 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.002425 CHAN A1 (24V) N/A reporting off CHAN A2 (12V): -0.002253 CHAN A3 (5V): -0.001753 CHAN B0 (3.3V): 0.000023 CHAN B1 (3.15aV): -0.000149 CHAN B2 (3.15bV): 0.000211 CHAN B3 (GND): 0.000444 OPEN: -0.000650 Full Scale: +/- 1 mA 2023-03-15T19:06:14.491Z,1678907174.491 [NAL9602](INFO): SBD MO Status=2, MOMSN=39116, MT Status=2, MTMSN=0 2023-03-15T19:06:14.492Z,1678907174.492 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-15T19:06:19.784Z,1678907179.784 [PAR_Licor](FAULT): LCB fault: MCLR Reset. 2023-03-15T19:06:19.785Z,1678907179.785 [PAR_Licor] Hardware Fault, FailCount= 1 2023-03-15T19:06:19.785Z,1678907179.785 [PAR_Licor](ERROR): Hardware Fault 2023-03-15T19:06:19.882Z,1678907179.882 [CBIT](ERROR): Hardware Fault in component: PAR_Licor 2023-03-15T19:06:19.882Z,1678907179.882 [CBIT](INFO): Clearing failed state for component PAR_Licor 2023-03-15T19:06:19.882Z,1678907179.882 [PAR_Licor] No Fault, FailCount= 1 2023-03-15T19:06:21.825Z,1678907181.825 [NAL9602](INFO): SBD MO Status=0, MOMSN=39116, MT Status=0, MTMSN=0 2023-03-15T19:06:21.825Z,1678907181.825 [NAL9602](INFO): No messages in MT queue 2023-03-15T19:06:22.651Z,1678907182.651 [PAR_Licor](FAULT): LCB fault: MCLR Reset. 2023-03-15T19:06:22.651Z,1678907182.651 [PAR_Licor] Hardware Fault, FailCount= 1 2023-03-15T19:06:22.651Z,1678907182.651 [PAR_Licor](ERROR): Hardware Fault 2023-03-15T19:06:22.747Z,1678907182.747 [CBIT](ERROR): Hardware Fault in component: PAR_Licor 2023-03-15T19:06:22.747Z,1678907182.747 [CBIT](INFO): Clearing failed state for component PAR_Licor 2023-03-15T19:06:22.747Z,1678907182.747 [PAR_Licor] No Fault, FailCount= 1 2023-03-15T19:06:23.025Z,1678907183.025 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190621.00,A,3648.13951,N,12147.23424,W,0.039,83.30,150323,,,A*41 2023-03-15T19:06:23.027Z,1678907183.027 [NAL9602](INFO): GPS fix at 20230315T190621: (36.802325, -121.787237) 2023-03-15T19:06:25.853Z,1678907185.853 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190624.00,A,3648.13906,N,12147.23439,W,0.019,83.30,150323,,,A*48 2023-03-15T19:06:25.855Z,1678907185.855 [NAL9602](INFO): GPS fix at 20230315T190624: (36.802318, -121.787240) 2023-03-15T19:06:29.085Z,1678907189.085 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190627.00,A,3648.13888,N,12147.23450,W,0.019,83.30,150323,,,A*43 2023-03-15T19:06:29.087Z,1678907189.087 [NAL9602](INFO): GPS fix at 20230315T190627: (36.802315, -121.787242) 2023-03-15T19:06:31.912Z,1678907191.912 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190630.00,A,3648.13895,N,12147.23461,W,0.039,83.30,150323,,,A*49 2023-03-15T19:06:31.914Z,1678907191.914 [NAL9602](INFO): GPS fix at 20230315T190630: (36.802316, -121.787244) 2023-03-15T19:06:35.149Z,1678907195.149 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190633.00,A,3648.13909,N,12147.23465,W,0.019,83.30,150323,,,A*48 2023-03-15T19:06:35.151Z,1678907195.151 [NAL9602](INFO): GPS fix at 20230315T190633: (36.802318, -121.787244) 2023-03-15T19:06:36.783Z,1678907196.783 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 3 Latitude: 36.802319 Longitude: -121.787247 2023-03-15T19:06:37.183Z,1678907197.183 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 0.000000 Voltage: 16.611000 2023-03-15T19:06:37.183Z,1678907197.183 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah 2023-03-15T19:06:37.184Z,1678907197.184 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V 2023-03-15T19:06:37.596Z,1678907197.596 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2023-03-15T19:06:37.596Z,1678907197.596 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2023-03-15T19:06:37.597Z,1678907197.597 [IBIT](IMPORTANT): Pressure:9.889088 PSI 2023-03-15T19:06:37.597Z,1678907197.597 [IBIT](IMPORTANT): Humidity:0.854596 % 2023-03-15T19:06:37.986Z,1678907197.986 [IBIT](IMPORTANT): Vehicle Pitch:-0.806256 degrees 2023-03-15T19:06:37.986Z,1678907197.986 [IBIT](IMPORTANT): Vehicle Roll:-4.966990 degrees 2023-03-15T19:06:37.986Z,1678907197.986 [IBIT](IMPORTANT): Vehicle Heading:190.401184 degrees 2023-03-15T19:06:38.396Z,1678907198.396 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2023-03-15T19:06:38.397Z,1678907198.397 [IBIT](IMPORTANT): buoyancyNeutral: 136.139404 cc 2023-03-15T19:06:38.397Z,1678907198.397 [IBIT](IMPORTANT): massDefault: -0.784061 cm 2023-03-15T19:06:38.398Z,1678907198.398 [IBIT](IMPORTANT): stopDepth: 250.000000 m 2023-03-15T19:06:38.398Z,1678907198.398 [IBIT](IMPORTANT): abortDepth: 270.000000 m 2023-03-15T19:06:38.398Z,1678907198.398 [IBIT](IMPORTANT): IBIT PASSED 2023-03-15T19:07:07.518Z,1678907227.518 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-15T19:10:05.824Z,1678907405.824 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-15T19:10:05.824Z,1678907405.824 [Default:CheckIn:C.Wait] Stopped 2023-03-15T19:10:05.824Z,1678907405.824 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-15T19:10:05.824Z,1678907405.824 [Default:CheckIn:D] Running Loop=1 2023-03-15T19:10:06.226Z,1678907406.226 [Default:CheckIn:D] Stopped 2023-03-15T19:10:06.226Z,1678907406.226 [Default:CheckIn:E] Running Loop=1 2023-03-15T19:10:06.626Z,1678907406.626 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.241768 min 2023-03-15T19:10:06.626Z,1678907406.626 [Default:CheckIn:E] Stopped 2023-03-15T19:10:06.626Z,1678907406.626 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-15T19:10:06.626Z,1678907406.626 [Default:CheckIn] Stopped 2023-03-15T19:10:06.626Z,1678907406.626 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-15T19:10:06.627Z,1678907406.627 [Default:CheckIn](INFO): Running loop #5 2023-03-15T19:10:06.627Z,1678907406.627 [Default:CheckIn] Running Loop=5 2023-03-15T19:10:06.627Z,1678907406.627 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-15T19:10:06.627Z,1678907406.627 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-15T19:10:08.643Z,1678907408.643 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191006.00,A,3648.14231,N,12147.23307,W,0.039,83.30,150323,,,A*4F 2023-03-15T19:10:08.645Z,1678907408.645 [NAL9602](INFO): GPS fix at 20230315T191006: (36.802372, -121.787218) 2023-03-15T19:10:08.662Z,1678907408.662 [Default:CheckIn:Read_GPS] Stopped 2023-03-15T19:10:08.662Z,1678907408.662 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-15T19:10:16.029Z,1678907416.029 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230315T183426/Courier0019.lzma 2023-03-15T19:10:17.031Z,1678907417.031 [DataOverHttps](INFO): Moved sent file to Logs/20230315T183426/Courier0019.lzma.bak 2023-03-15T19:10:17.032Z,1678907417.032 [DataOverHttps](INFO): SBD MOMSN=17517883 2023-03-15T19:10:23.632Z,1678907423.632 [NAL9602](INFO): SBD MO Status=0, MOMSN=39117, MT Status=0, MTMSN=0 2023-03-15T19:10:23.633Z,1678907423.633 [NAL9602](INFO): No messages in MT queue 2023-03-15T19:10:35.315Z,1678907435.315 [DataOverHttps](INFO): Sending 837 bytes from file Logs/20230315T183426/Express0020.lzma 2023-03-15T19:10:36.315Z,1678907436.315 [DataOverHttps](INFO): Moved sent file to Logs/20230315T183426/Express0020.lzma.bak 2023-03-15T19:10:36.315Z,1678907436.315 [DataOverHttps](INFO): SBD MOMSN=17517886 2023-03-15T19:10:54.387Z,1678907454.387 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-15T19:10:54.810Z,1678907454.810 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20230315T183426/Express0023.lzma 2023-03-15T19:10:55.812Z,1678907455.812 [DataOverHttps](INFO): Moved sent file to Logs/20230315T183426/Express0023.lzma.bak 2023-03-15T19:10:55.812Z,1678907455.812 [DataOverHttps](INFO): SBD MOMSN=17517914 2023-03-15T19:10:56.829Z,1678907456.829 [Default:CheckIn:Read_Iridium] Stopped 2023-03-15T19:10:56.829Z,1678907456.829 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-15T19:10:56.829Z,1678907456.829 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-15T19:13:06.371Z,1678907586.371 [DataOverHttps](IMPORTANT): SBD MTMSN=20230315T191305 2023-03-15T19:13:13.737Z,1678907593.737 [DataOverHttps](INFO): Received command: failc 2023-03-15T19:13:13.750Z,1678907593.750 [CommandExec](IMPORTANT): got command failComponent 2023-03-15T19:13:13.750Z,1678907593.750 [CommandExec](IMPORTANT): Failed components: 2023-03-15T19:13:13.750Z,1678907593.750 [CommandExec](IMPORTANT): No failed Components. 2023-03-15T19:15:57.407Z,1678907757.407 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-15T19:15:57.408Z,1678907757.408 [Default:CheckIn:C.Wait] Stopped 2023-03-15T19:15:57.408Z,1678907757.408 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-15T19:15:57.408Z,1678907757.408 [Default:CheckIn:D] Running Loop=1 2023-03-15T19:15:57.813Z,1678907757.813 [Default:CheckIn:D] Stopped 2023-03-15T19:15:57.813Z,1678907757.813 [Default:CheckIn:E] Running Loop=1 2023-03-15T19:15:58.219Z,1678907758.219 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 38.101542 min 2023-03-15T19:15:58.219Z,1678907758.219 [Default:CheckIn:E] Stopped 2023-03-15T19:15:58.219Z,1678907758.219 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-15T19:15:58.219Z,1678907758.219 [Default:CheckIn] Stopped 2023-03-15T19:15:58.220Z,1678907758.220 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-15T19:15:58.220Z,1678907758.220 [Default:CheckIn](INFO): Running loop #6 2023-03-15T19:15:58.220Z,1678907758.220 [Default:CheckIn] Running Loop=6 2023-03-15T19:15:58.220Z,1678907758.220 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-15T19:15:58.220Z,1678907758.220 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-15T19:16:00.233Z,1678907760.233 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191559.00,A,3648.13987,N,12147.23312,W,0.019,83.30,150323,,,A*47 2023-03-15T19:16:00.245Z,1678907760.245 [NAL9602](INFO): GPS fix at 20230315T191559: (36.802331, -121.787219) 2023-03-15T19:16:00.256Z,1678907760.256 [Default:CheckIn:Read_GPS] Stopped 2023-03-15T19:16:00.256Z,1678907760.256 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-15T19:16:07.741Z,1678907767.741 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230315T183426/Courier0025.lzma 2023-03-15T19:16:08.743Z,1678907768.743 [DataOverHttps](INFO): Moved sent file to Logs/20230315T183426/Courier0025.lzma.bak 2023-03-15T19:16:08.743Z,1678907768.743 [DataOverHttps](INFO): SBD MOMSN=17517919 2023-03-15T19:16:17.197Z,1678907777.197 [NAL9602](INFO): SBD MO Status=0, MOMSN=39118, MT Status=0, MTMSN=0 2023-03-15T19:16:17.197Z,1678907777.197 [NAL9602](INFO): No messages in MT queue 2023-03-15T19:16:27.229Z,1678907787.229 [DataOverHttps](INFO): Sending 219 bytes from file Logs/20230315T183426/Express0026.lzma 2023-03-15T19:16:28.231Z,1678907788.231 [DataOverHttps](INFO): Moved sent file to Logs/20230315T183426/Express0026.lzma.bak 2023-03-15T19:16:28.231Z,1678907788.231 [DataOverHttps](INFO): SBD MOMSN=17517923 2023-03-15T19:16:44.077Z,1678907804.077 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20230315T183426/Express0029.lzma 2023-03-15T19:16:45.079Z,1678907805.079 [DataOverHttps](INFO): Moved sent file to Logs/20230315T183426/Express0029.lzma.bak 2023-03-15T19:16:45.079Z,1678907805.079 [DataOverHttps](INFO): SBD MOMSN=17517930 2023-03-15T19:16:46.391Z,1678907806.391 [Default:CheckIn:Read_Iridium] Stopped 2023-03-15T19:16:46.391Z,1678907806.391 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-15T19:16:46.391Z,1678907806.391 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-15T19:16:47.948Z,1678907807.948 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-15T19:21:46.814Z,1678908106.814 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-15T19:21:46.814Z,1678908106.814 [Default:CheckIn:C.Wait] Stopped 2023-03-15T19:21:46.814Z,1678908106.814 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-15T19:21:46.814Z,1678908106.814 [Default:CheckIn:D] Running Loop=1 2023-03-15T19:21:47.188Z,1678908107.188 [Default:CheckIn:D] Stopped 2023-03-15T19:21:47.188Z,1678908107.188 [Default:CheckIn:E] Running Loop=1 2023-03-15T19:21:47.589Z,1678908107.589 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.924471 min 2023-03-15T19:21:47.589Z,1678908107.589 [Default:CheckIn:E] Stopped 2023-03-15T19:21:47.589Z,1678908107.589 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-15T19:21:47.589Z,1678908107.589 [Default:CheckIn] Stopped 2023-03-15T19:21:47.589Z,1678908107.589 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-15T19:21:47.589Z,1678908107.589 [Default:CheckIn](INFO): Running loop #7 2023-03-15T19:21:47.589Z,1678908107.589 [Default:CheckIn] Running Loop=7 2023-03-15T19:21:47.590Z,1678908107.590 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-15T19:21:47.590Z,1678908107.590 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-15T19:21:49.609Z,1678908109.609 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192148.00,A,3648.14094,N,12147.23157,W,0.039,83.30,150323,,,A*4D 2023-03-15T19:21:49.611Z,1678908109.611 [NAL9602](INFO): GPS fix at 20230315T192148: (36.802349, -121.787193) 2023-03-15T19:21:49.622Z,1678908109.622 [Default:CheckIn:Read_GPS] Stopped 2023-03-15T19:21:49.622Z,1678908109.622 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-15T19:21:56.633Z,1678908116.633 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230315T183426/Courier0031.lzma 2023-03-15T19:21:57.635Z,1678908117.635 [DataOverHttps](INFO): Moved sent file to Logs/20230315T183426/Courier0031.lzma.bak 2023-03-15T19:21:57.635Z,1678908117.635 [DataOverHttps](INFO): SBD MOMSN=17517933 2023-03-15T19:22:04.151Z,1678908124.151 [NAL9602](INFO): SBD MO Status=0, MOMSN=39119, MT Status=0, MTMSN=0 2023-03-15T19:22:04.151Z,1678908124.151 [NAL9602](INFO): No messages in MT queue 2023-03-15T19:22:13.389Z,1678908133.389 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230315T183426/Express0032.lzma 2023-03-15T19:22:14.392Z,1678908134.392 [DataOverHttps](INFO): Moved sent file to Logs/20230315T183426/Express0032.lzma.bak 2023-03-15T19:22:14.392Z,1678908134.392 [DataOverHttps](INFO): SBD MOMSN=17517936 2023-03-15T19:22:15.464Z,1678908135.464 [Default:CheckIn:Read_Iridium] Stopped 2023-03-15T19:22:15.464Z,1678908135.464 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-15T19:22:15.464Z,1678908135.464 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-15T19:22:34.894Z,1678908154.894 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-15T19:27:15.957Z,1678908435.957 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-15T19:27:15.957Z,1678908435.957 [Default:CheckIn:C.Wait] Stopped 2023-03-15T19:27:15.957Z,1678908435.957 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-15T19:27:15.957Z,1678908435.957 [Default:CheckIn:D] Running Loop=1 2023-03-15T19:27:16.353Z,1678908436.353 [Default:CheckIn:D] Stopped 2023-03-15T19:27:16.353Z,1678908436.353 [Default:CheckIn:E] Running Loop=1 2023-03-15T19:27:16.761Z,1678908436.761 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 49.410547 min 2023-03-15T19:27:16.761Z,1678908436.761 [Default:CheckIn:E] Stopped 2023-03-15T19:27:16.765Z,1678908436.765 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-15T19:27:16.766Z,1678908436.766 [Default:CheckIn] Stopped 2023-03-15T19:27:16.766Z,1678908436.766 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-15T19:27:16.766Z,1678908436.766 [Default:CheckIn](INFO): Running loop #8 2023-03-15T19:27:16.766Z,1678908436.766 [Default:CheckIn] Running Loop=8 2023-03-15T19:27:16.766Z,1678908436.766 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-15T19:27:16.766Z,1678908436.766 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-15T19:27:18.766Z,1678908438.766 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192718.00,A,3648.14413,N,12147.23252,W,0.058,83.30,150323,,,A*44 2023-03-15T19:27:18.768Z,1678908438.768 [NAL9602](INFO): GPS fix at 20230315T192718: (36.802402, -121.787209) 2023-03-15T19:27:18.780Z,1678908438.780 [Default:CheckIn:Read_GPS] Stopped 2023-03-15T19:27:18.780Z,1678908438.780 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-15T19:27:25.741Z,1678908445.741 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230315T183426/Courier0034.lzma 2023-03-15T19:27:26.743Z,1678908446.743 [DataOverHttps](INFO): Moved sent file to Logs/20230315T183426/Courier0034.lzma.bak 2023-03-15T19:27:26.743Z,1678908446.743 [DataOverHttps](INFO): SBD MOMSN=17517940 2023-03-15T19:27:42.501Z,1678908462.501 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230315T183426/Express0035.lzma 2023-03-15T19:27:43.504Z,1678908463.504 [DataOverHttps](INFO): Moved sent file to Logs/20230315T183426/Express0035.lzma.bak 2023-03-15T19:27:43.504Z,1678908463.504 [DataOverHttps](INFO): SBD MOMSN=17517943 2023-03-15T19:27:43.812Z,1678908463.812 [NAL9602](INFO): SBD MO Status=0, MOMSN=39120, MT Status=0, MTMSN=0 2023-03-15T19:27:43.813Z,1678908463.813 [NAL9602](INFO): No messages in MT queue 2023-03-15T19:27:44.628Z,1678908464.628 [Default:CheckIn:Read_Iridium] Stopped 2023-03-15T19:27:44.628Z,1678908464.628 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-15T19:27:44.628Z,1678908464.628 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-15T19:28:14.519Z,1678908494.519 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-15T19:32:45.113Z,1678908765.113 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-15T19:32:45.113Z,1678908765.113 [Default:CheckIn:C.Wait] Stopped 2023-03-15T19:32:45.113Z,1678908765.113 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-15T19:32:45.113Z,1678908765.113 [Default:CheckIn:D] Running Loop=1 2023-03-15T19:32:45.512Z,1678908765.512 [Default:CheckIn:D] Stopped 2023-03-15T19:32:45.512Z,1678908765.512 [Default:CheckIn:E] Running Loop=1 2023-03-15T19:32:45.925Z,1678908765.925 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 54.896537 min 2023-03-15T19:32:45.925Z,1678908765.925 [Default:CheckIn:E] Stopped 2023-03-15T19:32:45.925Z,1678908765.925 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-15T19:32:45.925Z,1678908765.925 [Default:CheckIn] Stopped 2023-03-15T19:32:45.925Z,1678908765.925 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-15T19:32:45.925Z,1678908765.925 [Default:CheckIn](INFO): Running loop #9 2023-03-15T19:32:45.926Z,1678908765.926 [Default:CheckIn] Running Loop=9 2023-03-15T19:32:45.926Z,1678908765.926 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-15T19:32:45.926Z,1678908765.926 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-15T19:32:47.928Z,1678908767.928 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193247.00,A,3648.13963,N,12147.20877,W,0.039,61.22,150323,,,D*44 2023-03-15T19:32:47.931Z,1678908767.931 [NAL9602](INFO): GPS fix at 20230315T193247: (36.802327, -121.786813) 2023-03-15T19:32:47.978Z,1678908767.978 [Default:CheckIn:Read_GPS] Stopped 2023-03-15T19:32:47.978Z,1678908767.978 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-15T19:32:57.849Z,1678908777.849 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230315T183426/Courier0037.lzma 2023-03-15T19:32:58.851Z,1678908778.851 [DataOverHttps](INFO): Moved sent file to Logs/20230315T183426/Courier0037.lzma.bak 2023-03-15T19:32:58.851Z,1678908778.851 [DataOverHttps](INFO): SBD MOMSN=17517947 2023-03-15T19:33:14.633Z,1678908794.633 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230315T183426/Express0038.lzma 2023-03-15T19:33:15.636Z,1678908795.636 [DataOverHttps](INFO): Moved sent file to Logs/20230315T183426/Express0038.lzma.bak 2023-03-15T19:33:15.636Z,1678908795.636 [DataOverHttps](INFO): SBD MOMSN=17517950 2023-03-15T19:33:16.695Z,1678908796.695 [Default:CheckIn:Read_Iridium] Stopped 2023-03-15T19:33:16.695Z,1678908796.695 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-15T19:33:16.695Z,1678908796.695 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-15T19:33:21.528Z,1678908801.528 [NAL9602](INFO): SBD MO Status=0, MOMSN=39121, MT Status=0, MTMSN=0 2023-03-15T19:33:21.528Z,1678908801.528 [NAL9602](INFO): No messages in MT queue 2023-03-15T19:33:52.231Z,1678908832.231 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-15T19:38:17.488Z,1678909097.488 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-15T19:38:17.488Z,1678909097.488 [Default:CheckIn:C.Wait] Stopped 2023-03-15T19:38:17.488Z,1678909097.488 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-15T19:38:17.488Z,1678909097.488 [Default:CheckIn:D] Running Loop=1 2023-03-15T19:38:17.863Z,1678909097.863 [Default:CheckIn:D] Stopped 2023-03-15T19:38:17.863Z,1678909097.863 [Default:CheckIn:E] Running Loop=1 2023-03-15T19:38:18.265Z,1678909098.265 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 60.435710 min 2023-03-15T19:38:18.266Z,1678909098.266 [Default:CheckIn:E] Stopped 2023-03-15T19:38:18.266Z,1678909098.266 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-15T19:38:18.266Z,1678909098.266 [Default:CheckIn] Stopped 2023-03-15T19:38:18.266Z,1678909098.266 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-15T19:38:18.266Z,1678909098.266 [Default:CheckIn](INFO): Running loop #10 2023-03-15T19:38:18.266Z,1678909098.266 [Default:CheckIn] Running Loop=10 2023-03-15T19:38:18.266Z,1678909098.266 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-15T19:38:18.266Z,1678909098.266 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-15T19:38:20.276Z,1678909100.276 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193819.00,A,3648.13867,N,12147.20717,W,0.136,102.37,150323,,,D*77 2023-03-15T19:38:20.278Z,1678909100.278 [NAL9602](INFO): GPS fix at 20230315T193819: (36.802311, -121.786786) 2023-03-15T19:38:20.289Z,1678909100.289 [Default:CheckIn:Read_GPS] Stopped 2023-03-15T19:38:20.289Z,1678909100.289 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-15T19:38:30.457Z,1678909110.457 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230315T183426/Courier0040.lzma 2023-03-15T19:38:31.459Z,1678909111.459 [DataOverHttps](INFO): Moved sent file to Logs/20230315T183426/Courier0040.lzma.bak 2023-03-15T19:38:31.459Z,1678909111.459 [DataOverHttps](INFO): SBD MOMSN=17517954 2023-03-15T19:38:47.157Z,1678909127.157 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230315T183426/Express0041.lzma 2023-03-15T19:38:48.160Z,1678909128.160 [DataOverHttps](INFO): Moved sent file to Logs/20230315T183426/Express0041.lzma.bak 2023-03-15T19:38:48.160Z,1678909128.160 [DataOverHttps](INFO): SBD MOMSN=17517957 2023-03-15T19:38:49.434Z,1678909129.434 [Default:CheckIn:Read_Iridium] Stopped 2023-03-15T19:38:49.434Z,1678909129.434 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-15T19:38:49.434Z,1678909129.434 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-15T19:38:56.352Z,1678909136.352 [NAL9602](INFO): SBD MO Status=2, MOMSN=39122, MT Status=2, MTMSN=0 2023-03-15T19:38:56.353Z,1678909136.353 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-15T19:39:24.621Z,1678909164.621 [NAL9602](INFO): SBD MO Status=2, MOMSN=39122, MT Status=2, MTMSN=0 2023-03-15T19:39:24.621Z,1678909164.621 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-15T19:39:39.168Z,1678909179.168 [NAL9602](INFO): SBD MO Status=0, MOMSN=39122, MT Status=0, MTMSN=0 2023-03-15T19:39:39.169Z,1678909179.168 [NAL9602](INFO): No messages in MT queue 2023-03-15T19:40:09.871Z,1678909209.871 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-15T19:40:18.352Z,1678909218.352 [PAR_Licor](FAULT): LCB fault: MCLR Reset. 2023-03-15T19:40:18.352Z,1678909218.352 [PAR_Licor] Hardware Fault, FailCount= 1 2023-03-15T19:40:18.352Z,1678909218.352 [PAR_Licor](ERROR): Hardware Fault 2023-03-15T19:40:18.379Z,1678909218.379 [CBIT](ERROR): Hardware Fault in component: PAR_Licor 2023-03-15T19:40:18.379Z,1678909218.379 [CBIT](INFO): Clearing failed state for component PAR_Licor 2023-03-15T19:40:18.379Z,1678909218.379 [PAR_Licor] No Fault, FailCount= 1 2023-03-15T19:43:50.136Z,1678909430.136 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-15T19:43:50.137Z,1678909430.137 [Default:CheckIn:C.Wait] Stopped 2023-03-15T19:43:50.137Z,1678909430.137 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-15T19:43:50.137Z,1678909430.137 [Default:CheckIn:D] Running Loop=1 2023-03-15T19:43:50.537Z,1678909430.537 [Default:CheckIn:D] Stopped 2023-03-15T19:43:50.537Z,1678909430.537 [Default:CheckIn:E] Running Loop=1 2023-03-15T19:43:50.981Z,1678909430.981 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 65.980282 min 2023-03-15T19:43:50.981Z,1678909430.981 [Default:CheckIn:E] Stopped 2023-03-15T19:43:50.981Z,1678909430.981 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-15T19:43:50.981Z,1678909430.981 [Default:CheckIn] Stopped 2023-03-15T19:43:50.981Z,1678909430.981 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-15T19:43:50.981Z,1678909430.981 [Default:CheckIn](INFO): Running loop #11 2023-03-15T19:43:50.981Z,1678909430.981 [Default:CheckIn] Running Loop=11 2023-03-15T19:43:50.982Z,1678909430.982 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-15T19:43:50.982Z,1678909430.982 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-15T19:43:52.961Z,1678909432.961 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194352.00,A,3648.39647,N,12147.11592,W,5.637,359.51,150323,,,D*72 2023-03-15T19:43:52.963Z,1678909432.963 [NAL9602](INFO): GPS fix at 20230315T194352: (36.806608, -121.785265) 2023-03-15T19:43:52.973Z,1678909432.973 [Default:CheckIn:Read_GPS] Stopped 2023-03-15T19:43:52.973Z,1678909432.973 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-15T19:44:00.169Z,1678909440.169 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230315T183426/Courier0043.lzma 2023-03-15T19:44:01.172Z,1678909441.172 [DataOverHttps](INFO): Moved sent file to Logs/20230315T183426/Courier0043.lzma.bak 2023-03-15T19:44:01.172Z,1678909441.172 [DataOverHttps](INFO): SBD MOMSN=17517962 2023-03-15T19:44:17.213Z,1678909457.213 [DataOverHttps](INFO): Sending 160 bytes from file Logs/20230315T183426/Express0044.lzma 2023-03-15T19:44:18.216Z,1678909458.216 [DataOverHttps](INFO): Moved sent file to Logs/20230315T183426/Express0044.lzma.bak 2023-03-15T19:44:18.216Z,1678909458.216 [DataOverHttps](INFO): SBD MOMSN=17517965 2023-03-15T19:44:19.630Z,1678909459.630 [Default:CheckIn:Read_Iridium] Stopped 2023-03-15T19:44:19.631Z,1678909459.631 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-15T19:44:19.631Z,1678909459.631 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-15T19:44:30.164Z,1678909470.164 [NAL9602](INFO): SBD MO Status=2, MOMSN=39123, MT Status=2, MTMSN=0 2023-03-15T19:44:30.164Z,1678909470.164 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-15T19:45:11.399Z,1678909511.399 [NAL9602](INFO): SBD MO Status=0, MOMSN=39123, MT Status=0, MTMSN=0 2023-03-15T19:45:11.399Z,1678909511.399 [NAL9602](INFO): No messages in MT queue 2023-03-15T19:45:42.106Z,1678909542.106 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-15T19:47:21.110Z,1678909641.110 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-03-15T19:47:22.723Z,1678909642.723 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2023-03-15T19:47:26.359Z,1678909646.359 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2023-03-15T19:47:38.479Z,1678909658.479 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2023-03-15T19:47:53.832Z,1678909673.832 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2023-03-15T19:48:09.590Z,1678909689.590 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2023-03-15T19:48:24.536Z,1678909704.536 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2023-03-15T19:48:39.484Z,1678909719.484 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2023-03-15T19:48:54.432Z,1678909734.432 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2023-03-15T19:49:09.784Z,1678909749.784 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2023-03-15T19:49:20.321Z,1678909760.321 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-15T19:49:20.321Z,1678909760.321 [Default:CheckIn:C.Wait] Stopped 2023-03-15T19:49:20.321Z,1678909760.321 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-15T19:49:20.321Z,1678909760.321 [Default:CheckIn:D] Running Loop=1 2023-03-15T19:49:20.707Z,1678909760.707 [Default:CheckIn:D] Stopped 2023-03-15T19:49:20.707Z,1678909760.707 [Default:CheckIn:E] Running Loop=1 2023-03-15T19:49:21.147Z,1678909761.147 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 71.483122 min 2023-03-15T19:49:21.147Z,1678909761.147 [Default:CheckIn:E] Stopped 2023-03-15T19:49:21.147Z,1678909761.147 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-15T19:49:21.147Z,1678909761.147 [Default:CheckIn] Stopped 2023-03-15T19:49:21.147Z,1678909761.147 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-15T19:49:21.147Z,1678909761.147 [Default:CheckIn](INFO): Running loop #12 2023-03-15T19:49:21.147Z,1678909761.147 [Default:CheckIn] Running Loop=12 2023-03-15T19:49:21.148Z,1678909761.148 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-15T19:49:21.148Z,1678909761.148 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-15T19:49:23.129Z,1678909763.129 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194922.00,A,3648.49526,N,12148.25286,W,17.028,295.71,150323,,,D*4E 2023-03-15T19:49:23.131Z,1678909763.131 [NAL9602](INFO): GPS fix at 20230315T194922: (36.808254, -121.804214) 2023-03-15T19:49:23.141Z,1678909763.141 [Default:CheckIn:Read_GPS] Stopped 2023-03-15T19:49:23.141Z,1678909763.141 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-15T19:49:25.541Z,1678909765.541 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2023-03-15T19:49:30.533Z,1678909770.533 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230315T183426/Courier0046.lzma 2023-03-15T19:49:31.535Z,1678909771.535 [DataOverHttps](INFO): Moved sent file to Logs/20230315T183426/Courier0046.lzma.bak 2023-03-15T19:49:31.536Z,1678909771.536 [DataOverHttps](INFO): SBD MOMSN=17517970 2023-03-15T19:49:46.958Z,1678909786.958 [BPC1](INFO): Calculating totals. Valid battery stick count: 52. Valid reserve battery stick count: 5. 2023-03-15T19:49:46.961Z,1678909786.961 [BPC1](INFO): Received data from all battery sticks. 2023-03-15T19:49:47.401Z,1678909787.401 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20230315T183426/Express0047.lzma 2023-03-15T19:49:48.403Z,1678909788.403 [DataOverHttps](INFO): Moved sent file to Logs/20230315T183426/Express0047.lzma.bak 2023-03-15T19:49:48.404Z,1678909788.404 [DataOverHttps](INFO): SBD MOMSN=17517973 2023-03-15T19:49:49.812Z,1678909789.812 [Default:CheckIn:Read_Iridium] Stopped 2023-03-15T19:49:49.813Z,1678909789.813 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-15T19:49:49.813Z,1678909789.813 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-15T19:49:53.016Z,1678909793.016 [NAL9602](INFO): SBD MO Status=2, MOMSN=39124, MT Status=2, MTMSN=0 2023-03-15T19:49:53.016Z,1678909793.016 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-15T19:50:09.581Z,1678909809.581 [NAL9602](INFO): SBD MO Status=0, MOMSN=39124, MT Status=0, MTMSN=0 2023-03-15T19:50:09.581Z,1678909809.581 [NAL9602](INFO): No messages in MT queue 2023-03-15T19:50:40.317Z,1678909840.317 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-15T19:53:29.551Z,1678910009.551 [DataOverHttps](IMPORTANT): SBD MTMSN=20230315T195328 2023-03-15T19:53:36.977Z,1678910016.977 [DataOverHttps](INFO): Received command: restart logs