2021-11-09T19:29:39.655Z,1636486179.655 [Supervisor](DEBUG): Initializing supervisor. 2021-11-09T19:29:39.660Z,1636486179.660 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2021-11-09T19:29:39.661Z,1636486179.661 [SyncHandler](INFO): Protected caller Thread ID is 833 2021-11-09T19:29:39.661Z,1636486179.661 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2021-11-09T19:29:39.662Z,1636486179.662 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2021-11-09T19:29:39.662Z,1636486179.662 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 834 2021-11-09T19:29:39.666Z,1636486179.666 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2021-11-09T19:29:39.685Z,1636486179.685 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2021-11-09T19:29:39.686Z,1636486179.686 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2021-11-09T19:29:39.686Z,1636486179.686 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 835 2021-11-09T19:29:39.690Z,1636486179.690 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2021-11-09T19:29:39.691Z,1636486179.691 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2021-11-09T19:29:39.692Z,1636486179.692 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 836 2021-11-09T19:29:39.694Z,1636486179.694 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2021-11-09T19:29:39.695Z,1636486179.695 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2021-11-09T19:29:39.695Z,1636486179.695 [logger ThreadHandler](INFO): Protected caller Thread ID is 837 2021-11-09T19:29:39.699Z,1636486179.699 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2021-11-09T19:29:39.699Z,1636486179.699 [Supervisor](INFO): Looking for Config files in directory: Config/ 2021-11-09T19:29:39.704Z,1636486179.704 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2021-11-09T19:29:40.147Z,1636486180.147 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2021-11-09T19:29:40.147Z,1636486180.147 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2021-11-09T19:29:40.292Z,1636486180.292 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2021-11-09T19:29:40.294Z,1636486180.294 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2021-11-09T19:29:40.376Z,1636486180.376 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2021-11-09T19:29:40.587Z,1636486180.587 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2021-11-09T19:29:40.587Z,1636486180.587 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2021-11-09T19:29:40.668Z,1636486180.668 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2021-11-09T19:29:40.763Z,1636486180.763 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2021-11-09T19:29:40.764Z,1636486180.764 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2021-11-09T19:29:41.110Z,1636486181.110 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2021-11-09T19:29:41.111Z,1636486181.111 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2021-11-09T19:29:41.236Z,1636486181.236 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2021-11-09T19:29:41.238Z,1636486181.238 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2021-11-09T19:29:41.755Z,1636486181.755 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2021-11-09T19:29:41.756Z,1636486181.756 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2021-11-09T19:29:41.952Z,1636486181.952 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2021-11-09T19:29:41.953Z,1636486181.953 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2021-11-09T19:29:42.319Z,1636486182.319 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2021-11-09T19:29:42.321Z,1636486182.321 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2021-11-09T19:29:42.565Z,1636486182.565 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2021-11-09T19:29:42.566Z,1636486182.566 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2021-11-09T19:29:42.675Z,1636486182.675 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2021-11-09T19:29:42.677Z,1636486182.677 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2021-11-09T19:29:43.702Z,1636486183.702 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2021-11-09T19:29:43.936Z,1636486183.936 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2021-11-09T19:29:44.502Z,1636486184.502 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2021-11-09T19:29:44.504Z,1636486184.504 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2021-11-09T19:29:44.717Z,1636486184.717 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2021-11-09T19:29:44.719Z,1636486184.719 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/ 2021-11-09T19:29:44.723Z,1636486184.723 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg 2021-11-09T19:29:44.914Z,1636486184.914 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg 2021-11-09T19:29:44.997Z,1636486184.997 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg 2021-11-09T19:29:45.131Z,1636486185.131 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg 2021-11-09T19:29:45.217Z,1636486185.217 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg 2021-11-09T19:29:45.478Z,1636486185.478 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2021-11-09T19:29:45.479Z,1636486185.479 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg 2021-11-09T19:29:45.582Z,1636486185.582 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg 2021-11-09T19:29:45.692Z,1636486185.692 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg 2021-11-09T19:29:45.786Z,1636486185.786 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg 2021-11-09T19:29:45.927Z,1636486185.927 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg 2021-11-09T19:29:46.025Z,1636486186.025 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg 2021-11-09T19:29:46.117Z,1636486186.117 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2021-11-09T19:29:46.133Z,1636486186.133 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2021-11-09T19:29:46.151Z,1636486186.151 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2021-11-09T19:29:46.151Z,1636486186.151 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2021-11-09T19:29:46.271Z,1636486186.271 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2021-11-09T19:29:46.271Z,1636486186.271 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2021-11-09T19:29:46.343Z,1636486186.343 [VerticalControl](DEBUG): Construct VerticalControl. 2021-11-09T19:29:46.407Z,1636486186.407 [VerticalControl] Loaded 2021-11-09T19:29:46.407Z,1636486186.407 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2021-11-09T19:29:46.410Z,1636486186.410 [HorizontalControl](DEBUG): Construct HorizontalControl. 2021-11-09T19:29:46.449Z,1636486186.449 [HorizontalControl] Loaded 2021-11-09T19:29:46.449Z,1636486186.449 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2021-11-09T19:29:46.452Z,1636486186.452 [SpeedControl](DEBUG): Construct SpeedControl. 2021-11-09T19:29:46.455Z,1636486186.455 [SpeedControl] Loaded 2021-11-09T19:29:46.455Z,1636486186.455 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2021-11-09T19:29:46.458Z,1636486186.458 [LoopControl](DEBUG): Construct LoopControl. 2021-11-09T19:29:46.458Z,1636486186.458 [LoopControl] Loaded 2021-11-09T19:29:46.458Z,1636486186.458 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2021-11-09T19:29:46.459Z,1636486186.459 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2021-11-09T19:29:46.459Z,1636486186.459 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2021-11-09T19:29:46.640Z,1636486186.640 [BuoyancyServo] Loaded 2021-11-09T19:29:46.641Z,1636486186.641 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2021-11-09T19:29:46.660Z,1636486186.660 [ElevatorServo] Loaded 2021-11-09T19:29:46.660Z,1636486186.660 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2021-11-09T19:29:46.678Z,1636486186.678 [MassServo] Loaded 2021-11-09T19:29:46.679Z,1636486186.679 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2021-11-09T19:29:46.697Z,1636486186.697 [RudderServo] Loaded 2021-11-09T19:29:46.697Z,1636486186.697 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2021-11-09T19:29:46.713Z,1636486186.713 [ThrusterHE] Loaded 2021-11-09T19:29:46.713Z,1636486186.713 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2021-11-09T19:29:46.713Z,1636486186.713 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2021-11-09T19:29:46.714Z,1636486186.714 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2021-11-09T19:29:46.775Z,1636486186.775 [DepthRateCalculator] Loaded 2021-11-09T19:29:46.775Z,1636486186.775 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2021-11-09T19:29:46.780Z,1636486186.780 [PitchRateCalculator] Loaded 2021-11-09T19:29:46.780Z,1636486186.780 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2021-11-09T19:29:46.790Z,1636486186.790 [SpeedCalculator] Loaded 2021-11-09T19:29:46.791Z,1636486186.791 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2021-11-09T19:29:46.804Z,1636486186.804 [TempGradientCalculator] Loaded 2021-11-09T19:29:46.805Z,1636486186.805 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2021-11-09T19:29:46.809Z,1636486186.809 [YawRateCalculator] Loaded 2021-11-09T19:29:46.809Z,1636486186.809 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2021-11-09T19:29:46.827Z,1636486186.827 [ElevatorOffsetCalculator] Loaded 2021-11-09T19:29:46.827Z,1636486186.827 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2021-11-09T19:29:46.828Z,1636486186.828 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2021-11-09T19:29:46.828Z,1636486186.828 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2021-11-09T19:29:46.927Z,1636486186.927 [DeadReckonUsingMultipleVelocitySources] Loaded 2021-11-09T19:29:46.928Z,1636486186.928 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2021-11-09T19:29:46.941Z,1636486186.941 [NavChart] Loaded 2021-11-09T19:29:46.941Z,1636486186.941 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2021-11-09T19:29:46.947Z,1636486186.947 [UniversalFixResidualReporter] Loaded 2021-11-09T19:29:46.947Z,1636486186.947 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2021-11-09T19:29:46.948Z,1636486186.948 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2021-11-09T19:29:46.949Z,1636486186.949 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2021-11-09T19:29:47.637Z,1636486187.637 [AHRS_M2] Loaded 2021-11-09T19:29:47.637Z,1636486187.637 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2021-11-09T19:29:47.885Z,1636486187.885 [BackseatComponent] Loaded 2021-11-09T19:29:47.886Z,1636486187.886 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2021-11-09T19:29:47.887Z,1636486187.887 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408A64E0 2021-11-09T19:29:47.887Z,1636486187.887 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 919 2021-11-09T19:29:47.890Z,1636486187.890 [LcmUniversalReporter] Loaded 2021-11-09T19:29:47.890Z,1636486187.890 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2021-11-09T19:29:48.688Z,1636486188.688 [BPC1] Loaded 2021-11-09T19:29:48.689Z,1636486188.689 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2021-11-09T19:29:48.838Z,1636486188.838 [DataOverHttps] Loaded 2021-11-09T19:29:48.838Z,1636486188.838 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2021-11-09T19:29:48.839Z,1636486188.839 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408D64E0 2021-11-09T19:29:48.839Z,1636486188.839 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 920 2021-11-09T19:29:48.859Z,1636486188.859 [Depth_Keller] Loaded 2021-11-09T19:29:48.859Z,1636486188.859 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2021-11-09T19:29:48.864Z,1636486188.864 [DropWeight] Loaded 2021-11-09T19:29:48.864Z,1636486188.864 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2021-11-09T19:29:48.924Z,1636486188.924 [NAL9602] Loaded 2021-11-09T19:29:48.924Z,1636486188.924 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2021-11-09T19:29:48.953Z,1636486188.953 [Onboard] Loaded 2021-11-09T19:29:48.954Z,1636486188.954 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2021-11-09T19:29:48.955Z,1636486188.955 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409064E0 2021-11-09T19:29:48.955Z,1636486188.955 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 921 2021-11-09T19:29:48.968Z,1636486188.968 [Power24vConverter] Loaded 2021-11-09T19:29:48.969Z,1636486188.969 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2021-11-09T19:29:48.982Z,1636486188.982 [Radio_Surface] Loaded 2021-11-09T19:29:48.982Z,1636486188.982 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2021-11-09T19:29:48.983Z,1636486188.983 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409364E0 2021-11-09T19:29:48.984Z,1636486188.984 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 922 2021-11-09T19:29:49.187Z,1636486189.187 [DAT] Loaded 2021-11-09T19:29:49.188Z,1636486189.188 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2021-11-09T19:29:49.210Z,1636486189.210 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2021-11-09T19:29:49.211Z,1636486189.211 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2021-11-09T19:29:50.065Z,1636486190.065 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2021-11-09T19:29:50.066Z,1636486190.066 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2021-11-09T19:29:50.199Z,1636486190.199 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2021-11-09T19:29:50.201Z,1636486190.201 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2021-11-09T19:29:50.244Z,1636486190.244 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2021-11-09T19:29:50.245Z,1636486190.245 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2021-11-09T19:29:50.471Z,1636486190.471 [CTD_Seabird] Loaded 2021-11-09T19:29:50.471Z,1636486190.471 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2021-11-09T19:29:50.472Z,1636486190.472 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A564E0 2021-11-09T19:29:50.473Z,1636486190.473 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 923 2021-11-09T19:29:50.493Z,1636486190.493 [PAR_Licor] Loaded 2021-11-09T19:29:50.493Z,1636486190.493 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2021-11-09T19:29:50.525Z,1636486190.525 [WetLabsBB2FL] Loaded 2021-11-09T19:29:50.526Z,1636486190.526 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2021-11-09T19:29:50.527Z,1636486190.527 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A864E0 2021-11-09T19:29:50.527Z,1636486190.527 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 924 2021-11-09T19:29:50.528Z,1636486190.528 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2021-11-09T19:29:50.528Z,1636486190.528 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2021-11-09T19:29:50.908Z,1636486190.908 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2021-11-09T19:29:50.910Z,1636486190.910 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2021-11-09T19:29:51.084Z,1636486191.084 [SBIT](DEBUG): Construct Startup Built In Test. 2021-11-09T19:29:51.094Z,1636486191.094 [SBIT] Loaded 2021-11-09T19:29:51.094Z,1636486191.094 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2021-11-09T19:29:51.097Z,1636486191.097 [IBIT](DEBUG): Construct Initiated Built In Test. 2021-11-09T19:29:51.110Z,1636486191.110 [IBIT] Loaded 2021-11-09T19:29:51.110Z,1636486191.110 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2021-11-09T19:29:51.116Z,1636486191.116 [CBIT](DEBUG): Construct Continuous Built In Test. 2021-11-09T19:29:51.220Z,1636486191.220 [CBIT] Loaded 2021-11-09T19:29:51.221Z,1636486191.221 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2021-11-09T19:29:51.221Z,1636486191.221 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2021-11-09T19:29:51.227Z,1636486191.227 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2021-11-09T19:29:51.230Z,1636486191.230 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2021-11-09T19:29:51.241Z,1636486191.241 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2021-11-09T19:29:51.242Z,1636486191.242 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B6D4E0 2021-11-09T19:29:51.242Z,1636486191.242 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 925 2021-11-09T19:29:51.247Z,1636486191.247 [Supervisor](INFO): Main Thread ID is 829 2021-11-09T19:29:51.247Z,1636486191.247 [Supervisor](DEBUG): Running supervisor. 2021-11-09T19:29:51.248Z,1636486191.248 [CommandExec ThreadHandler](INFO): Handler Thread ID is 926 2021-11-09T19:29:51.248Z,1636486191.248 [CommandExec](INFO): Initializing the command executive. 2021-11-09T19:29:51.250Z,1636486191.250 [CommandLine ThreadHandler](INFO): Handler Thread ID is 927 2021-11-09T19:29:51.252Z,1636486191.252 [controlThread ThreadHandler](INFO): Handler Thread ID is 928 2021-11-09T19:29:51.252Z,1636486191.252 [controlThread](DEBUG): Initializing ControlThread 2021-11-09T19:29:51.253Z,1636486191.253 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2021-11-09T19:29:51.255Z,1636486191.255 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2021-11-09T19:29:51.256Z,1636486191.256 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2021-11-09T19:29:51.256Z,1636486191.256 [LoopControl](DEBUG): Initialize LoopControlComponent. 2021-11-09T19:29:51.258Z,1636486191.258 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2021-11-09T19:29:51.258Z,1636486191.258 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2021-11-09T19:29:51.258Z,1636486191.258 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2021-11-09T19:29:51.259Z,1636486191.259 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2021-11-09T19:29:51.259Z,1636486191.259 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2021-11-09T19:29:51.260Z,1636486191.260 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2021-11-09T19:29:51.261Z,1636486191.261 [NavChart](DEBUG): Initialize NavChart Navigation. 2021-11-09T19:29:51.262Z,1636486191.262 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2021-11-09T19:29:51.268Z,1636486191.268 [SBIT](INFO): Initialize SBIT Component. 2021-11-09T19:29:51.269Z,1636486191.269 [SBIT](IMPORTANT): git: 2021-11-09 2021-11-09T19:29:51.269Z,1636486191.269 [SBIT](INFO): git hash: 235ad51f9df6aba2b8b5ed692903eef5eaec5ce6 2021-11-09T19:29:51.269Z,1636486191.269 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2021-11-09T19:29:51.270Z,1636486191.270 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018 Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021 2021-11-09T19:29:51.272Z,1636486191.272 [SBIT](INFO): Beginning SBIT in 61.000000 seconds. 2021-11-09T19:29:51.272Z,1636486191.272 [IBIT](INFO): Initialize IBIT Component. 2021-11-09T19:29:51.273Z,1636486191.273 [CBIT](DEBUG): Initialize CBIT Component. 2021-11-09T19:29:51.274Z,1636486191.274 [logger ThreadHandler](INFO): Handler Thread ID is 929 2021-11-09T19:29:51.284Z,1636486191.284 [CBIT](DEBUG): Initialized mux pins. 2021-11-09T19:29:51.284Z,1636486191.284 [CBIT](DEBUG): Initializing the watchdog timer. 2021-11-09T19:29:51.292Z,1636486191.292 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 930 2021-11-09T19:29:51.304Z,1636486191.304 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 931 2021-11-09T19:29:51.305Z,1636486191.305 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2021-11-09T19:29:51.308Z,1636486191.308 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2021-11-09T19:29:51.308Z,1636486191.308 [CBIT](DEBUG): Initializing heartbeat. 2021-11-09T19:29:51.316Z,1636486191.316 [Onboard ThreadHandler](INFO): Handler Thread ID is 932 2021-11-09T19:29:51.338Z,1636486191.338 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 933 2021-11-09T19:29:51.356Z,1636486191.356 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 934 2021-11-09T19:29:51.357Z,1636486191.357 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2021-11-09T19:29:51.361Z,1636486191.361 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 936 2021-11-09T19:29:51.364Z,1636486191.364 [WetLabsBB2FL](INFO): Powering up 2021-11-09T19:29:51.365Z,1636486191.365 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 938 2021-11-09T19:29:51.373Z,1636486191.373 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2021-11-09T19:29:51.374Z,1636486191.374 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2021-11-09T19:29:51.374Z,1636486191.374 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2021-11-09T19:29:51.374Z,1636486191.374 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2021-11-09T19:29:51.374Z,1636486191.374 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2021-11-09T19:29:51.374Z,1636486191.374 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2021-11-09T19:29:51.375Z,1636486191.375 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2021-11-09T19:29:51.375Z,1636486191.375 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2021-11-09T19:29:51.375Z,1636486191.375 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2021-11-09T19:29:51.375Z,1636486191.375 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2021-11-09T19:29:51.375Z,1636486191.375 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2021-11-09T19:29:51.375Z,1636486191.375 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2021-11-09T19:29:51.376Z,1636486191.376 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2021-11-09T19:29:51.376Z,1636486191.376 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2021-11-09T19:29:51.376Z,1636486191.376 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2021-11-09T19:29:51.376Z,1636486191.376 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2021-11-09T19:29:51.380Z,1636486191.380 [CBIT](DEBUG): Deactivating GF circuits. 2021-11-09T19:29:51.380Z,1636486191.380 [CBIT](DEBUG): Deactivating emergency mode. 2021-11-09T19:29:51.416Z,1636486191.416 [CBIT](DEBUG): Backplane powered. 2021-11-09T19:29:51.417Z,1636486191.417 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2021-11-09T19:29:51.444Z,1636486191.444 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2021-11-09T19:29:51.472Z,1636486191.472 [MissionManager](DEBUG): 2021-11-09T19:29:51.473Z,1636486191.473 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2021-11-09T19:29:51.552Z,1636486191.552 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2021-11-09T19:29:51.553Z,1636486191.553 [Default:A.Wait](DEBUG): Construct Wait. 2021-11-09T19:29:51.555Z,1636486191.555 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2021-11-09T19:29:51.599Z,1636486191.599 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2021-11-09T19:29:51.602Z,1636486191.602 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2021-11-09T19:29:51.630Z,1636486191.630 [Default:E.Execute](DEBUG): Construct Execute. 2021-11-09T19:29:51.657Z,1636486191.657 [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-11-09T19:29:51.672Z,1636486191.672 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,DAT,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2021-11-09T19:29:51.680Z,1636486191.680 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2021-11-09T19:29:51.752Z,1636486191.752 [Radio_Surface](INFO): Powering up 2021-11-09T19:29:51.826Z,1636486191.826 [Power24vConverter](INFO): Powering up. 2021-11-09T19:29:51.827Z,1636486191.827 [DAT](INFO): Powering up 2021-11-09T19:29:51.827Z,1636486191.827 [DAT](DEBUG): Initializing DAT. 2021-11-09T19:29:51.934Z,1636486191.934 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2021-11-09T19:29:51.941Z,1636486191.941 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2021-11-09T19:29:51.942Z,1636486191.942 [ElevatorServo](DEBUG): Initializing EZServoServo. 2021-11-09T19:29:51.948Z,1636486191.948 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2021-11-09T19:29:51.949Z,1636486191.949 [MassServo](DEBUG): Initializing EZServoServo. 2021-11-09T19:29:51.960Z,1636486191.960 [MassServo](DEBUG): Initializing MassServo. 2021-11-09T19:29:51.961Z,1636486191.961 [RudderServo](DEBUG): Initializing EZServoServo. 2021-11-09T19:29:51.968Z,1636486191.968 [RudderServo](DEBUG): Initializing RudderServo. 2021-11-09T19:29:51.969Z,1636486191.969 [ThrusterHE](DEBUG): Initializing EZServoServo. 2021-11-09T19:29:51.976Z,1636486191.976 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2021-11-09T19:29:52.824Z,1636486192.824 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2021-11-09T19:29:52.824Z,1636486192.824 [RudderServo](FAULT): Rudder failed to initialize 2021-11-09T19:29:52.824Z,1636486192.824 [RudderServo] Communications Fault, FailCount= 1 2021-11-09T19:29:52.824Z,1636486192.824 [RudderServo](ERROR): Communications Fault 2021-11-09T19:29:52.829Z,1636486192.829 [CBIT](ERROR): Communications Fault in component: RudderServo 2021-11-09T19:29:53.073Z,1636486193.073 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2021-11-09T19:29:53.073Z,1636486193.073 [RudderServo](INFO): Powering down 2021-11-09T19:29:53.472Z,1636486193.472 [WetLabsBB2FL](INFO): Powering down 2021-11-09T19:29:53.721Z,1636486193.721 [RudderServo](DEBUG): Initializing EZServoServo. 2021-11-09T19:29:53.841Z,1636486193.841 [RudderServo](DEBUG): Initializing RudderServo. 2021-11-09T19:29:53.845Z,1636486193.845 [CBIT](INFO): Clearing failed state for component RudderServo 2021-11-09T19:29:53.845Z,1636486193.845 [RudderServo] No Fault, FailCount= 1 2021-11-09T19:30:19.169Z,1636486219.169 [NAL9602](INFO): Powering up NAL9602 2021-11-09T19:30:30.086Z,1636486230.086 [NAL9602](INFO): NAL9602 initialized 2021-11-09T19:30:51.898Z,1636486251.898 [DAT](FAULT): failed to initialize, no bytes available on serial interface 2021-11-09T19:30:51.899Z,1636486251.899 [DAT] Communications Fault, FailCount= 1 2021-11-09T19:30:51.899Z,1636486251.899 [DAT](ERROR): Communications Fault 2021-11-09T19:30:51.933Z,1636486251.933 [CBIT](ERROR): Communications Fault in component: DAT 2021-11-09T19:30:52.323Z,1636486252.323 [DAT](INFO): Powering down 2021-11-09T19:30:52.763Z,1636486252.763 [SBIT](IMPORTANT): Beginning Startup BIT 2021-11-09T19:30:52.768Z,1636486252.768 [CBIT](IMPORTANT): Beginning ground fault scan 2021-11-09T19:30:53.197Z,1636486253.197 [CBIT](INFO): Clearing failed state for component DAT 2021-11-09T19:30:53.197Z,1636486253.197 [DAT] No Fault, FailCount= 1 2021-11-09T19:30:55.534Z,1636486255.534 [DAT](INFO): Powering up 2021-11-09T19:30:55.534Z,1636486255.534 [DAT](DEBUG): Initializing DAT. 2021-11-09T19:31:03.645Z,1636486263.645 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.005722 CHAN A1 (24V): 0.009604 CHAN A2 (12V): -0.004448 CHAN A3 (5V): -0.002415 CHAN B0 (3.3V): -0.000252 CHAN B1 (3.15aV): -0.001534 CHAN B2 (3.15bV): -0.001314 CHAN B3 (GND): 0.001079 OPEN: 0.006376 Full Scale: +/- 1 mA 2021-11-09T19:31:46.904Z,1636486306.904 [SBIT](IMPORTANT): SBIT PASSED 2021-11-09T19:31:46.905Z,1636486306.905 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2021-11-09T19:31:46.905Z,1636486306.905 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=32 count; 2021-11-09T19:31:46.906Z,1636486306.906 [SBIT](IMPORTANT): BPC1.batterySamplingInterval=1 hour; 2021-11-09T19:31:46.906Z,1636486306.906 [SBIT](IMPORTANT): BackseatComponent.loadAtStartup=1 bool; 2021-11-09T19:31:46.906Z,1636486306.906 [SBIT](IMPORTANT): CBIT.gf24Offset=-18.106 microampere; 2021-11-09T19:31:46.906Z,1636486306.906 [SBIT](IMPORTANT): CBIT.stopDepth=295 meter; 2021-11-09T19:31:46.906Z,1636486306.906 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water; 2021-11-09T19:31:46.906Z,1636486306.906 [SBIT](IMPORTANT): PAR_Licor.parCal=1.38207 none; 2021-11-09T19:31:46.906Z,1636486306.906 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=233.479799 cubic_centimeter; 2021-11-09T19:31:46.907Z,1636486306.907 [SBIT](IMPORTANT): VerticalControl.massDefault=10.270247 millimeter; 2021-11-09T19:31:47.274Z,1636486307.274 [MissionManager](IMPORTANT): Started mission Startup 2021-11-09T19:31:47.275Z,1636486307.275 [Startup] Running Loop=1 2021-11-09T19:31:47.275Z,1636486307.275 [Startup](DEBUG): Aggregate::initialize Startup 2021-11-09T19:31:47.275Z,1636486307.275 [Startup:A.GoToSurface] Running Loop=1 2021-11-09T19:31:47.275Z,1636486307.275 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2021-11-09T19:31:47.276Z,1636486307.276 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2021-11-09T19:31:47.276Z,1636486307.276 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2021-11-09T19:31:47.276Z,1636486307.276 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2021-11-09T19:31:47.277Z,1636486307.277 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2021-11-09T19:31:47.277Z,1636486307.277 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2021-11-09T19:31:47.279Z,1636486307.279 [Startup:StartupSatComms] Running Loop=1 2021-11-09T19:31:47.279Z,1636486307.279 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2021-11-09T19:31:47.279Z,1636486307.279 [Startup:StartupSatComms:A] Running Loop=1 2021-11-09T19:31:47.672Z,1636486307.672 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2021-11-09T19:31:55.735Z,1636486315.735 [DAT](FAULT): failed to initialize, no bytes available on serial interface 2021-11-09T19:31:55.735Z,1636486315.735 [DAT] Communications Fault, FailCount= 2 2021-11-09T19:31:55.735Z,1636486315.735 [DAT](ERROR): Communications Fault 2021-11-09T19:31:55.775Z,1636486315.775 [CBIT](ERROR): Communications Fault in component: DAT 2021-11-09T19:31:56.149Z,1636486316.149 [DAT](INFO): Powering down 2021-11-09T19:31:56.993Z,1636486316.993 [CBIT](INFO): Clearing failed state for component DAT 2021-11-09T19:31:56.993Z,1636486316.993 [DAT] No Fault, FailCount= 2 2021-11-09T19:31:59.410Z,1636486319.410 [DAT](INFO): Powering up 2021-11-09T19:31:59.410Z,1636486319.410 [DAT](DEBUG): Initializing DAT. 2021-11-09T19:32:47.452Z,1636486367.452 [Startup:StartupSatComms:A](INFO): Timed out from 2021-11-09T19:31:47.3Z 2021-11-09T19:32:47.453Z,1636486367.453 [Startup:StartupSatComms:A] Stopped 2021-11-09T19:32:47.453Z,1636486367.453 [Startup:StartupSatComms:B] Running Loop=1 2021-11-09T19:32:47.867Z,1636486367.867 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2021-11-09T19:32:51.523Z,1636486371.523 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2021-11-09T19:32:51.523Z,1636486371.523 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-09T19:32:51.534Z,1636486371.534 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-09T19:32:51.982Z,1636486371.982 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-09T19:32:51.982Z,1636486371.982 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2021-11-09T19:32:52.285Z,1636486372.285 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-11-09T19:32:59.563Z,1636486379.563 [DAT](FAULT): failed to initialize, no bytes available on serial interface 2021-11-09T19:32:59.563Z,1636486379.563 [DAT] Communications Fault, FailCount= 3 2021-11-09T19:32:59.563Z,1636486379.563 [DAT](ERROR): Communications Fault 2021-11-09T19:32:59.606Z,1636486379.606 [CBIT](ERROR): Communications Fault in component: DAT 2021-11-09T19:32:59.980Z,1636486379.980 [DAT](INFO): Powering down 2021-11-09T19:33:00.832Z,1636486380.832 [CBIT](INFO): Clearing failed state for component DAT 2021-11-09T19:33:00.832Z,1636486380.832 [DAT] No Fault, FailCount= 3 2021-11-09T19:33:03.198Z,1636486383.198 [DAT](INFO): Powering up 2021-11-09T19:33:03.199Z,1636486383.199 [DAT](DEBUG): Initializing DAT. 2021-11-09T19:33:05.621Z,1636486385.621 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-11-09T19:33:18.949Z,1636486398.949 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-11-09T19:33:27.989Z,1636486407.989 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004200 2021-11-09T19:33:32.874Z,1636486412.874 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-11-09T19:33:35.392Z,1636486415.392 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20211109T191800/Courier0007.lzma 2021-11-09T19:33:36.393Z,1636486416.393 [DataOverHttps](INFO): Moved sent file to Logs/20211109T191800/Courier0007.lzma.bak 2021-11-09T19:33:36.393Z,1636486416.393 [DataOverHttps](INFO): SBD MOMSN=16224495 2021-11-09T19:33:46.610Z,1636486426.610 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-11-09T19:33:47.530Z,1636486427.530 [Startup:StartupSatComms:B](INFO): Timed out from 2021-11-09T19:32:47.5Z 2021-11-09T19:33:47.530Z,1636486427.530 [Startup:StartupSatComms:B] Stopped 2021-11-09T19:33:47.546Z,1636486427.546 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2021-11-09T19:33:47.546Z,1636486427.546 [Startup:StartupSatComms] Stopped 2021-11-09T19:33:47.547Z,1636486427.547 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2021-11-09T19:33:47.548Z,1636486427.548 [Startup](INFO): Completed Startup 2021-11-09T19:33:47.548Z,1636486427.548 [MissionManager](INFO): Startup is completed. 2021-11-09T19:33:47.548Z,1636486427.548 [MissionManager](INFO): Uninitializing Mission Startup 2021-11-09T19:33:47.548Z,1636486427.548 [Startup] Stopped 2021-11-09T19:33:47.548Z,1636486427.548 [Startup](DEBUG): Aggregate::uninitialize Startup 2021-11-09T19:33:47.548Z,1636486427.548 [Startup:A.GoToSurface] Stopped 2021-11-09T19:33:47.548Z,1636486427.548 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2021-11-09T19:33:47.914Z,1636486427.914 [MissionManager](IMPORTANT): Started mission Default 2021-11-09T19:33:47.914Z,1636486427.914 [Default] Running Loop=1 2021-11-09T19:33:47.914Z,1636486427.914 [Default](DEBUG): Aggregate::initialize Default 2021-11-09T19:33:47.914Z,1636486427.914 [Default:B.GoToSurface] Running Loop=1 2021-11-09T19:33:47.914Z,1636486427.914 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2021-11-09T19:33:47.915Z,1636486427.915 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2021-11-09T19:33:47.916Z,1636486427.916 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2021-11-09T19:33:47.916Z,1636486427.916 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2021-11-09T19:33:47.916Z,1636486427.916 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2021-11-09T19:33:47.917Z,1636486427.917 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2021-11-09T19:33:47.917Z,1636486427.917 [Default:A.Wait] Running Loop=1 2021-11-09T19:33:47.917Z,1636486427.917 [Default:A.Wait](DEBUG): Initialize Wait Component. 2021-11-09T19:33:52.098Z,1636486432.098 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20211109T192939/Courier0000.lzma 2021-11-09T19:33:53.100Z,1636486433.100 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Courier0000.lzma.bak 2021-11-09T19:33:53.101Z,1636486433.101 [DataOverHttps](INFO): SBD MOMSN=16224497 2021-11-09T19:33:59.943Z,1636486439.943 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-11-09T19:34:01.197Z,1636486441.197 [Default:A.Wait](INFO): Done Waiting. 2021-11-09T19:34:01.197Z,1636486441.197 [Default:A.Wait] Stopped 2021-11-09T19:34:01.197Z,1636486441.197 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2021-11-09T19:34:01.586Z,1636486441.586 [Default:CheckIn] Running Loop=1 2021-11-09T19:34:01.586Z,1636486441.586 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-09T19:34:01.586Z,1636486441.586 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-09T19:34:01.997Z,1636486441.997 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2021-11-09T19:34:03.607Z,1636486443.607 [DAT](FAULT): failed to initialize, no bytes available on serial interface 2021-11-09T19:34:03.608Z,1636486443.608 [DAT] Communications Fault, FailCount= 4 2021-11-09T19:34:03.608Z,1636486443.608 [DAT](ERROR): Communications Fault 2021-11-09T19:34:03.656Z,1636486443.656 [CBIT](ERROR): Communications Fault in component: DAT 2021-11-09T19:34:04.003Z,1636486444.003 [DAT](INFO): Powering down 2021-11-09T19:34:04.814Z,1636486444.814 [CBIT](INFO): Clearing failed state for component DAT 2021-11-09T19:34:04.814Z,1636486444.814 [DAT] No Fault, FailCount= 4 2021-11-09T19:34:07.223Z,1636486447.223 [DAT](INFO): Powering up 2021-11-09T19:34:07.224Z,1636486447.224 [DAT](DEBUG): Initializing DAT. 2021-11-09T19:34:13.687Z,1636486453.687 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-11-09T19:34:22.328Z,1636486462.328 [CommandExec](IMPORTANT): got command strobe off 2021-11-09T19:34:22.328Z,1636486462.328 [CommandExec](IMPORTANT): Deactivating strobe 2021-11-09T19:34:25.035Z,1636486465.035 [CommandExec](IMPORTANT): got command failComponent 2021-11-09T19:34:25.036Z,1636486465.036 [CommandExec](IMPORTANT): Failed components: 2021-11-09T19:34:25.036Z,1636486465.036 [CommandExec](IMPORTANT): No failed Components. 2021-11-09T19:34:27.080Z,1636486467.080 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-11-09T19:34:40.908Z,1636486480.908 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-11-09T19:34:54.611Z,1636486494.611 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-11-09T19:35:07.602Z,1636486507.602 [DAT](FAULT): failed to initialize, no bytes available on serial interface 2021-11-09T19:35:07.602Z,1636486507.602 [DAT] Communications Fault, FailCount= 5 2021-11-09T19:35:07.602Z,1636486507.602 [DAT](ERROR): Communications Fault 2021-11-09T19:35:07.680Z,1636486507.680 [CBIT](ERROR): Communications Fault in component: DAT 2021-11-09T19:35:07.886Z,1636486507.886 [BPC1](INFO): Calculating totals. Valid battery stick count: 28. Valid reserve battery stick count: 4. 2021-11-09T19:35:07.889Z,1636486507.889 [BPC1](INFO): Received data from all battery sticks. 2021-11-09T19:35:07.905Z,1636486507.905 [DAT](INFO): Powering down 2021-11-09T19:35:08.731Z,1636486508.731 [CBIT](INFO): Clearing failed state for component DAT 2021-11-09T19:35:08.731Z,1636486508.731 [DAT] No Fault, FailCount= 5 2021-11-09T19:35:11.132Z,1636486511.132 [DAT](INFO): Powering up 2021-11-09T19:35:11.133Z,1636486511.133 [DAT](DEBUG): Initializing DAT. 2021-11-09T19:35:33.331Z,1636486533.331 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-11-09T19:35:52.345Z,1636486552.345 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2021-11-09T19:35:52.345Z,1636486552.345 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-09T19:35:52.356Z,1636486552.356 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-09T19:35:52.764Z,1636486552.764 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-09T19:35:52.765Z,1636486552.765 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2021-11-09T19:36:11.313Z,1636486571.313 [DAT](FAULT): failed to initialize, no bytes available on serial interface 2021-11-09T19:36:11.313Z,1636486571.313 [DAT] Communications Fault, FailCount= 6 2021-11-09T19:36:11.314Z,1636486571.314 [DAT](ERROR): Communications Fault 2021-11-09T19:36:11.359Z,1636486571.359 [CBIT](ERROR): Communications Fault in component: DAT 2021-11-09T19:36:11.714Z,1636486571.714 [DAT](INFO): Powering down 2021-11-09T19:36:12.556Z,1636486572.556 [CBIT](INFO): Clearing failed state for component DAT 2021-11-09T19:36:12.557Z,1636486572.557 [DAT] No Fault, FailCount= 6 2021-11-09T19:36:14.949Z,1636486574.949 [DAT](INFO): Powering up 2021-11-09T19:36:14.949Z,1636486574.949 [DAT](DEBUG): Initializing DAT. 2021-11-09T19:37:15.204Z,1636486635.204 [DAT](FAULT): failed to initialize, no bytes available on serial interface 2021-11-09T19:37:15.204Z,1636486635.204 [DAT] Communications Fault, FailCount= 7 2021-11-09T19:37:15.204Z,1636486635.204 [DAT](ERROR): Communications Fault 2021-11-09T19:37:15.222Z,1636486635.222 [CBIT](ERROR): Communications Fault in component: DAT 2021-11-09T19:37:15.607Z,1636486635.607 [DAT](INFO): Powering down 2021-11-09T19:37:16.465Z,1636486636.465 [CBIT](INFO): Clearing failed state for component DAT 2021-11-09T19:37:16.465Z,1636486636.465 [DAT] No Fault, FailCount= 7 2021-11-09T19:37:18.833Z,1636486638.833 [DAT](INFO): Powering up 2021-11-09T19:37:18.834Z,1636486638.834 [DAT](DEBUG): Initializing DAT. 2021-11-09T19:38:19.033Z,1636486699.033 [DAT](FAULT): failed to initialize, no bytes available on serial interface 2021-11-09T19:38:19.034Z,1636486699.034 [DAT] Communications Fault, FailCount= 8 2021-11-09T19:38:19.034Z,1636486699.034 [DAT](ERROR): Communications Fault 2021-11-09T19:38:19.051Z,1636486699.051 [CBIT](ERROR): Communications Fault in component: DAT 2021-11-09T19:38:19.051Z,1636486699.051 [CBIT](FAULT): Communications Fault in component: DAT 2021-11-09T19:38:19.447Z,1636486699.447 [DAT](INFO): Powering down 2021-11-09T19:38:53.412Z,1636486733.412 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2021-11-09T19:38:53.412Z,1636486733.412 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-09T19:38:53.423Z,1636486733.423 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-09T19:38:53.826Z,1636486733.826 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-09T19:38:53.826Z,1636486733.826 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2021-11-09T19:39:01.898Z,1636486741.898 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-11-09T19:34:01.6Z 2021-11-09T19:39:01.899Z,1636486741.899 [Default:CheckIn:Read_GPS] Stopped 2021-11-09T19:39:01.899Z,1636486741.899 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-09T19:39:02.314Z,1636486742.314 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2021-11-09T19:39:09.418Z,1636486749.418 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20211109T192939/Courier0004.lzma 2021-11-09T19:39:10.420Z,1636486750.420 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Courier0004.lzma.bak 2021-11-09T19:39:10.421Z,1636486750.421 [DataOverHttps](INFO): SBD MOMSN=16224521 2021-11-09T19:39:25.888Z,1636486765.888 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20211109T191800/Express0008.lzma 2021-11-09T19:39:26.889Z,1636486766.889 [DataOverHttps](INFO): Moved sent file to Logs/20211109T191800/Express0008.lzma.bak 2021-11-09T19:39:26.889Z,1636486766.889 [DataOverHttps](INFO): SBD MOMSN=16224523 2021-11-09T19:39:42.360Z,1636486782.360 [DataOverHttps](INFO): Sending 965 bytes from file Logs/20211109T192939/Express0001.lzma 2021-11-09T19:39:43.361Z,1636486783.361 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Express0001.lzma.bak 2021-11-09T19:39:43.361Z,1636486783.361 [DataOverHttps](INFO): SBD MOMSN=16224528 2021-11-09T19:39:52.798Z,1636486792.798 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193952.00,A,3648.16957,N,12147.27159,W,0.175,0.00,091121,,,A*7C 2021-11-09T19:39:52.807Z,1636486792.807 [NAL9602](INFO): GPS fix at 20211109T193952: (36.802826, -121.787860) 2021-11-09T19:39:59.868Z,1636486799.868 [CommandExec](IMPORTANT): got command ibit 2021-11-09T19:40:00.111Z,1636486800.111 [IBIT](IMPORTANT): Beginning Initiated BIT 2021-11-09T19:40:00.111Z,1636486800.111 [IBIT](IMPORTANT): Beginning control surface checks. 2021-11-09T19:40:00.150Z,1636486800.150 [CBIT](IMPORTANT): Beginning ground fault scan 2021-11-09T19:40:01.674Z,1636486801.674 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194001.00,A,3648.16883,N,12147.27273,W,0.214,0.00,091121,,,A*73 2021-11-09T19:40:01.677Z,1636486801.677 [NAL9602](INFO): GPS fix at 20211109T194001: (36.802814, -121.787879) 2021-11-09T19:40:02.227Z,1636486802.227 [DataOverHttps](INFO): Sending 385 bytes from file Logs/20211109T192939/Express0005.lzma 2021-11-09T19:40:03.229Z,1636486803.229 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Express0005.lzma.bak 2021-11-09T19:40:03.229Z,1636486803.229 [DataOverHttps](INFO): SBD MOMSN=16224551 2021-11-09T19:40:04.906Z,1636486804.906 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194004.00,A,3648.16904,N,12147.27272,W,0.214,0.00,091121,,,A*79 2021-11-09T19:40:04.908Z,1636486804.908 [NAL9602](INFO): GPS fix at 20211109T194004: (36.802817, -121.787879) 2021-11-09T19:40:07.738Z,1636486807.738 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194007.00,A,3648.16916,N,12147.27281,W,1.186,0.00,091121,,,A*7C 2021-11-09T19:40:07.745Z,1636486807.745 [NAL9602](INFO): GPS fix at 20211109T194007: (36.802819, -121.787880) 2021-11-09T19:40:10.977Z,1636486810.977 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194010.00,A,3648.16933,N,12147.27299,W,0.797,0.00,091121,,,A*73 2021-11-09T19:40:10.979Z,1636486810.979 [NAL9602](INFO): GPS fix at 20211109T194010: (36.802822, -121.787883) 2021-11-09T19:40:11.003Z,1636486811.003 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.006346 CHAN A1 (24V): -0.005928 CHAN A2 (12V): -0.003977 CHAN A3 (5V): -0.001912 CHAN B0 (3.3V): -0.001117 CHAN B1 (3.15aV): -0.000903 CHAN B2 (3.15bV): -0.001532 CHAN B3 (GND): -0.000035 OPEN: 0.004465 Full Scale: +/- 1 mA 2021-11-09T19:40:13.804Z,1636486813.804 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194013.00,A,3648.16955,N,12147.27318,W,0.330,0.00,091121,,,A*71 2021-11-09T19:40:13.806Z,1636486813.806 [NAL9602](INFO): GPS fix at 20211109T194013: (36.802826, -121.787886) 2021-11-09T19:40:16.626Z,1636486816.626 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194015.00,A,3648.16960,N,12147.27335,W,0.544,0.00,091121,,,A*7B 2021-11-09T19:40:16.629Z,1636486816.629 [NAL9602](INFO): GPS fix at 20211109T194015: (36.802827, -121.787889) 2021-11-09T19:40:19.862Z,1636486819.862 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194019.00,A,3648.16942,N,12147.27344,W,0.272,0.00,091121,,,A*73 2021-11-09T19:40:19.869Z,1636486819.869 [NAL9602](INFO): GPS fix at 20211109T194019: (36.802824, -121.787891) 2021-11-09T19:40:22.686Z,1636486822.686 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194022.00,A,3648.16935,N,12147.27353,W,0.117,0.00,091121,,,A*7D 2021-11-09T19:40:22.693Z,1636486822.693 [NAL9602](INFO): GPS fix at 20211109T194022: (36.802822, -121.787892) 2021-11-09T19:40:25.924Z,1636486825.924 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194025.00,A,3648.16934,N,12147.27370,W,0.253,0.00,091121,,,A*79 2021-11-09T19:40:25.926Z,1636486825.926 [NAL9602](INFO): GPS fix at 20211109T194025: (36.802822, -121.787895) 2021-11-09T19:40:28.751Z,1636486828.751 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194028.00,A,3648.16939,N,12147.27389,W,0.428,0.00,091121,,,A*75 2021-11-09T19:40:28.753Z,1636486828.753 [NAL9602](INFO): GPS fix at 20211109T194028: (36.802823, -121.787898) 2021-11-09T19:40:31.974Z,1636486831.974 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194031.00,A,3648.16942,N,12147.27427,W,0.078,0.00,091121,,,A*73 2021-11-09T19:40:31.995Z,1636486831.995 [NAL9602](INFO): GPS fix at 20211109T194031: (36.802824, -121.787904) 2021-11-09T19:40:34.807Z,1636486834.807 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194034.00,A,3648.16912,N,12147.27459,W,0.136,0.00,091121,,,A*71 2021-11-09T19:40:34.809Z,1636486834.809 [NAL9602](INFO): GPS fix at 20211109T194034: (36.802819, -121.787910) 2021-11-09T19:40:38.046Z,1636486838.046 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194037.00,A,3648.16901,N,12147.27482,W,0.505,0.00,091121,,,A*72 2021-11-09T19:40:38.053Z,1636486838.053 [NAL9602](INFO): GPS fix at 20211109T194037: (36.802817, -121.787914) 2021-11-09T19:40:40.862Z,1636486840.862 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194040.00,A,3648.16885,N,12147.27519,W,0.253,0.00,091121,,,A*78 2021-11-09T19:40:40.865Z,1636486840.865 [NAL9602](INFO): GPS fix at 20211109T194040: (36.802814, -121.787920) 2021-11-09T19:40:43.710Z,1636486843.710 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194043.00,A,3648.16861,N,12147.27539,W,0.117,0.00,091121,,,A*70 2021-11-09T19:40:43.712Z,1636486843.712 [NAL9602](INFO): GPS fix at 20211109T194043: (36.802810, -121.787923) 2021-11-09T19:40:46.950Z,1636486846.950 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194046.00,A,3648.16823,N,12147.27561,W,0.175,0.00,091121,,,A*7A 2021-11-09T19:40:46.953Z,1636486846.953 [NAL9602](INFO): GPS fix at 20211109T194046: (36.802804, -121.787927) 2021-11-09T19:40:49.806Z,1636486849.806 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194049.00,A,3648.16798,N,12147.27574,W,0.117,0.00,091121,,,A*7A 2021-11-09T19:40:49.815Z,1636486849.815 [NAL9602](INFO): GPS fix at 20211109T194049: (36.802800, -121.787929) 2021-11-09T19:40:52.666Z,1636486852.666 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194051.00,A,3648.16789,N,12147.27592,W,0.058,0.00,091121,,,A*71 2021-11-09T19:40:52.669Z,1636486852.669 [NAL9602](INFO): GPS fix at 20211109T194051: (36.802798, -121.787932) 2021-11-09T19:40:53.519Z,1636486853.519 [Power24vConverter](INFO): Powering down. 2021-11-09T19:40:55.922Z,1636486855.922 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194055.00,A,3648.16775,N,12147.27627,W,0.078,0.00,091121,,,A*79 2021-11-09T19:40:55.925Z,1636486855.925 [NAL9602](INFO): GPS fix at 20211109T194055: (36.802796, -121.787938) 2021-11-09T19:40:58.750Z,1636486858.750 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194058.00,A,3648.16766,N,12147.27661,W,0.175,0.00,091121,,,A*78 2021-11-09T19:40:58.762Z,1636486858.762 [NAL9602](INFO): GPS fix at 20211109T194058: (36.802794, -121.787943) 2021-11-09T19:41:01.984Z,1636486861.984 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194101.00,A,3648.16742,N,12147.27695,W,0.292,0.00,091121,,,A*72 2021-11-09T19:41:01.987Z,1636486861.987 [NAL9602](INFO): GPS fix at 20211109T194101: (36.802790, -121.787949) 2021-11-09T19:41:04.810Z,1636486864.810 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194104.00,A,3648.16732,N,12147.27740,W,0.019,0.00,091121,,,A*78 2021-11-09T19:41:04.817Z,1636486864.817 [NAL9602](INFO): GPS fix at 20211109T194104: (36.802789, -121.787957) 2021-11-09T19:41:08.038Z,1636486868.038 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194107.00,A,3648.16715,N,12147.27788,W,0.214,0.00,091121,,,A*75 2021-11-09T19:41:08.040Z,1636486868.040 [NAL9602](INFO): GPS fix at 20211109T194107: (36.802786, -121.787965) 2021-11-09T19:41:10.866Z,1636486870.866 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194110.00,A,3648.16705,N,12147.27821,W,0.097,0.00,091121,,,A*77 2021-11-09T19:41:10.869Z,1636486870.869 [NAL9602](INFO): GPS fix at 20211109T194110: (36.802784, -121.787970) 2021-11-09T19:41:13.694Z,1636486873.694 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194113.00,A,3648.16682,N,12147.27836,W,0.350,0.00,091121,,,A*74 2021-11-09T19:41:13.697Z,1636486873.697 [NAL9602](INFO): GPS fix at 20211109T194113: (36.802780, -121.787973) 2021-11-09T19:41:16.930Z,1636486876.930 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194116.00,A,3648.16694,N,12147.27854,W,0.136,0.00,091121,,,A*70 2021-11-09T19:41:16.944Z,1636486876.944 [NAL9602](INFO): GPS fix at 20211109T194116: (36.802782, -121.787976) 2021-11-09T19:41:19.758Z,1636486879.758 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194119.00,A,3648.16751,N,12147.27843,W,0.505,0.00,091121,,,A*75 2021-11-09T19:41:19.765Z,1636486879.765 [NAL9602](INFO): GPS fix at 20211109T194119: (36.802792, -121.787974) 2021-11-09T19:41:22.987Z,1636486882.987 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194122.00,A,3648.16730,N,12147.27873,W,0.389,0.00,091121,,,A*7B 2021-11-09T19:41:22.989Z,1636486882.989 [NAL9602](INFO): GPS fix at 20211109T194122: (36.802788, -121.787979) 2021-11-09T19:41:25.818Z,1636486885.818 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194125.00,A,3648.16693,N,12147.27830,W,0.272,0.00,091121,,,A*76 2021-11-09T19:41:25.821Z,1636486885.821 [NAL9602](INFO): GPS fix at 20211109T194125: (36.802782, -121.787972) 2021-11-09T19:41:29.063Z,1636486889.063 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194128.00,A,3648.16682,N,12147.27861,W,0.564,0.00,091121,,,A*7F 2021-11-09T19:41:29.065Z,1636486889.065 [NAL9602](INFO): GPS fix at 20211109T194128: (36.802780, -121.787977) 2021-11-09T19:41:31.882Z,1636486891.882 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194131.00,A,3648.16708,N,12147.27897,W,0.253,0.00,091121,,,A*7E 2021-11-09T19:41:31.885Z,1636486891.885 [NAL9602](INFO): GPS fix at 20211109T194131: (36.802785, -121.787983) 2021-11-09T19:41:34.706Z,1636486894.706 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194133.00,A,3648.16701,N,12147.27912,W,0.156,0.00,091121,,,A*7F 2021-11-09T19:41:34.713Z,1636486894.713 [NAL9602](INFO): GPS fix at 20211109T194133: (36.802783, -121.787985) 2021-11-09T19:41:37.936Z,1636486897.936 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194137.00,A,3648.16687,N,12147.27927,W,0.330,0.00,091121,,,A*70 2021-11-09T19:41:37.938Z,1636486897.938 [NAL9602](INFO): GPS fix at 20211109T194137: (36.802781, -121.787988) 2021-11-09T19:41:40.762Z,1636486900.762 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194140.00,A,3648.16721,N,12147.27944,W,0.194,0.00,091121,,,A*74 2021-11-09T19:41:40.765Z,1636486900.765 [NAL9602](INFO): GPS fix at 20211109T194140: (36.802787, -121.787991) 2021-11-09T19:41:43.994Z,1636486903.994 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194143.00,A,3648.16743,N,12147.27961,W,0.428,0.00,091121,,,A*76 2021-11-09T19:41:44.007Z,1636486904.007 [NAL9602](INFO): GPS fix at 20211109T194143: (36.802791, -121.787993) 2021-11-09T19:41:46.833Z,1636486906.833 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194146.00,A,3648.16720,N,12147.27941,W,0.350,0.00,091121,,,A*7C 2021-11-09T19:41:46.836Z,1636486906.836 [NAL9602](INFO): GPS fix at 20211109T194146: (36.802787, -121.787990) 2021-11-09T19:41:50.054Z,1636486910.054 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194149.00,A,3648.16737,N,12147.27951,W,0.233,0.00,091121,,,A*70 2021-11-09T19:41:50.057Z,1636486910.057 [NAL9602](INFO): GPS fix at 20211109T194149: (36.802790, -121.787992) 2021-11-09T19:41:50.917Z,1636486910.917 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired. 2021-11-09T19:41:51.288Z,1636486911.288 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 0.000000 Voltage: 16.690001 2021-11-09T19:41:51.288Z,1636486911.288 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah 2021-11-09T19:41:51.288Z,1636486911.288 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V 2021-11-09T19:41:51.725Z,1636486911.725 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2021-11-09T19:41:51.725Z,1636486911.725 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2021-11-09T19:41:51.726Z,1636486911.726 [IBIT](IMPORTANT): Pressure:7.663367 PSI 2021-11-09T19:41:51.726Z,1636486911.726 [IBIT](IMPORTANT): Humidity:11.543158 % 2021-11-09T19:41:52.122Z,1636486912.122 [IBIT](IMPORTANT): Vehicle Pitch:-3.691171 degrees 2021-11-09T19:41:52.122Z,1636486912.122 [IBIT](IMPORTANT): Vehicle Roll:6.693094 degrees 2021-11-09T19:41:52.122Z,1636486912.122 [IBIT](IMPORTANT): Vehicle Heading:292.943970 degrees 2021-11-09T19:41:52.569Z,1636486912.569 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2021-11-09T19:41:52.569Z,1636486912.569 [IBIT](IMPORTANT): buoyancyNeutral: 233.479797 cc 2021-11-09T19:41:52.569Z,1636486912.569 [IBIT](IMPORTANT): massDefault: 1.027025 cm 2021-11-09T19:41:52.570Z,1636486912.570 [IBIT](IMPORTANT): stopDepth: 295.000000 m 2021-11-09T19:41:52.570Z,1636486912.570 [IBIT](IMPORTANT): abortDepth: 300.000000 m 2021-11-09T19:41:52.570Z,1636486912.570 [IBIT](IMPORTANT): IBIT FAILED 2021-11-09T19:41:52.882Z,1636486912.882 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194152.00,A,3648.16706,N,12147.27956,W,0.330,0.00,091121,,,A*7D 2021-11-09T19:41:52.884Z,1636486912.884 [NAL9602](INFO): GPS fix at 20211109T194152: (36.802784, -121.787993) 2021-11-09T19:41:52.900Z,1636486912.900 [Default:CheckIn:Read_Iridium] Stopped 2021-11-09T19:41:52.900Z,1636486912.900 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-09T19:41:52.900Z,1636486912.900 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-09T19:42:07.396Z,1636486927.396 [CommandExec](IMPORTANT): got command ibit 2021-11-09T19:42:07.466Z,1636486927.466 [IBIT](IMPORTANT): Beginning Initiated BIT 2021-11-09T19:42:07.466Z,1636486927.466 [IBIT](IMPORTANT): Beginning control surface checks. 2021-11-09T19:42:07.469Z,1636486927.469 [CBIT](IMPORTANT): Beginning ground fault scan 2021-11-09T19:42:09.046Z,1636486929.046 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194208.00,A,3648.16748,N,12147.27953,W,0.039,0.00,091121,,,A*74 2021-11-09T19:42:09.048Z,1636486929.048 [NAL9602](INFO): GPS fix at 20211109T194208: (36.802791, -121.787992) 2021-11-09T19:42:11.870Z,1636486931.870 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194211.00,A,3648.16739,N,12147.27966,W,0.175,0.00,091121,,,A*75 2021-11-09T19:42:11.872Z,1636486931.872 [NAL9602](INFO): GPS fix at 20211109T194211: (36.802790, -121.787994) 2021-11-09T19:42:14.700Z,1636486934.700 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194213.00,A,3648.16753,N,12147.27979,W,0.136,0.00,091121,,,A*72 2021-11-09T19:42:14.702Z,1636486934.702 [NAL9602](INFO): GPS fix at 20211109T194213: (36.802792, -121.787997) 2021-11-09T19:42:17.939Z,1636486937.939 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194217.00,A,3648.16781,N,12147.27998,W,0.078,0.00,091121,,,A*7D 2021-11-09T19:42:17.941Z,1636486937.941 [NAL9602](INFO): GPS fix at 20211109T194217: (36.802797, -121.788000) 2021-11-09T19:42:18.380Z,1636486938.380 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.006870 CHAN A1 (24V): -0.006937 CHAN A2 (12V): -0.003621 CHAN A3 (5V): -0.002546 CHAN B0 (3.3V): -0.001458 CHAN B1 (3.15aV): -0.001215 CHAN B2 (3.15bV): -0.000732 CHAN B3 (GND): -0.000156 OPEN: 0.004352 Full Scale: +/- 1 mA 2021-11-09T19:42:20.758Z,1636486940.758 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194220.00,A,3648.16796,N,12147.28003,W,0.311,0.00,091121,,,A*77 2021-11-09T19:42:20.760Z,1636486940.760 [NAL9602](INFO): GPS fix at 20211109T194220: (36.802799, -121.788000) 2021-11-09T19:42:23.994Z,1636486943.994 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194223.00,A,3648.16828,N,12147.28026,W,0.214,0.00,091121,,,A*7D 2021-11-09T19:42:23.997Z,1636486943.997 [NAL9602](INFO): GPS fix at 20211109T194223: (36.802805, -121.788004) 2021-11-09T19:42:26.822Z,1636486946.822 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194226.00,A,3648.16855,N,12147.28031,W,0.233,0.00,091121,,,A*71 2021-11-09T19:42:26.825Z,1636486946.825 [NAL9602](INFO): GPS fix at 20211109T194226: (36.802809, -121.788005) 2021-11-09T19:42:30.054Z,1636486950.054 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194229.00,A,3648.16867,N,12147.28041,W,0.097,0.00,091121,,,A*74 2021-11-09T19:42:30.056Z,1636486950.056 [NAL9602](INFO): GPS fix at 20211109T194229: (36.802811, -121.788007) 2021-11-09T19:42:32.878Z,1636486952.878 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194232.00,A,3648.16887,N,12147.28052,W,0.292,0.00,091121,,,A*75 2021-11-09T19:42:32.880Z,1636486952.880 [NAL9602](INFO): GPS fix at 20211109T194232: (36.802814, -121.788009) 2021-11-09T19:42:35.730Z,1636486955.730 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194235.00,A,3648.16896,N,12147.28051,W,0.117,0.00,091121,,,A*7F 2021-11-09T19:42:35.733Z,1636486955.733 [NAL9602](INFO): GPS fix at 20211109T194235: (36.802816, -121.788009) 2021-11-09T19:42:38.962Z,1636486958.962 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194238.00,A,3648.16889,N,12147.28039,W,0.253,0.00,091121,,,A*71 2021-11-09T19:42:38.965Z,1636486958.965 [NAL9602](INFO): GPS fix at 20211109T194238: (36.802815, -121.788006) 2021-11-09T19:42:41.790Z,1636486961.790 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194241.00,A,3648.16885,N,12147.28031,W,0.175,0.00,091121,,,A*7C 2021-11-09T19:42:41.792Z,1636486961.792 [NAL9602](INFO): GPS fix at 20211109T194241: (36.802814, -121.788005) 2021-11-09T19:42:45.022Z,1636486965.022 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194244.00,A,3648.16879,N,12147.28032,W,0.097,0.00,091121,,,A*74 2021-11-09T19:42:45.025Z,1636486965.025 [NAL9602](INFO): GPS fix at 20211109T194244: (36.802813, -121.788005) 2021-11-09T19:42:47.856Z,1636486967.856 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194247.00,A,3648.16883,N,12147.28034,W,0.233,0.00,091121,,,A*78 2021-11-09T19:42:47.859Z,1636486967.859 [NAL9602](INFO): GPS fix at 20211109T194247: (36.802814, -121.788006) 2021-11-09T19:42:50.679Z,1636486970.679 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194249.00,A,3648.16880,N,12147.28032,W,0.389,0.00,091121,,,A*73 2021-11-09T19:42:50.682Z,1636486970.682 [NAL9602](INFO): GPS fix at 20211109T194249: (36.802813, -121.788005) 2021-11-09T19:42:53.922Z,1636486973.922 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194253.00,A,3648.16864,N,12147.28041,W,0.175,0.00,091121,,,A*77 2021-11-09T19:42:53.925Z,1636486973.925 [NAL9602](INFO): GPS fix at 20211109T194253: (36.802811, -121.788007) 2021-11-09T19:42:56.746Z,1636486976.746 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194256.00,A,3648.16853,N,12147.28035,W,0.058,0.00,091121,,,A*7B 2021-11-09T19:42:56.748Z,1636486976.748 [NAL9602](INFO): GPS fix at 20211109T194256: (36.802809, -121.788006) 2021-11-09T19:42:59.971Z,1636486979.971 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194259.00,A,3648.16855,N,12147.28049,W,0.194,0.00,091121,,,A*78 2021-11-09T19:42:59.973Z,1636486979.973 [NAL9602](INFO): GPS fix at 20211109T194259: (36.802809, -121.788008) 2021-11-09T19:43:02.798Z,1636486982.798 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194302.00,A,3648.16826,N,12147.28058,W,0.194,0.00,091121,,,A*73 2021-11-09T19:43:02.800Z,1636486982.800 [NAL9602](INFO): GPS fix at 20211109T194302: (36.802804, -121.788010) 2021-11-09T19:43:06.030Z,1636486986.030 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194305.00,A,3648.16792,N,12147.28050,W,0.194,0.00,091121,,,A*7C 2021-11-09T19:43:06.032Z,1636486986.032 [NAL9602](INFO): GPS fix at 20211109T194305: (36.802799, -121.788008) 2021-11-09T19:43:08.858Z,1636486988.858 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194308.00,A,3648.16771,N,12147.28071,W,0.214,0.00,091121,,,A*74 2021-11-09T19:43:08.860Z,1636486988.860 [NAL9602](INFO): GPS fix at 20211109T194308: (36.802795, -121.788012) 2021-11-09T19:43:12.093Z,1636486992.093 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194311.00,A,3648.16761,N,12147.28098,W,0.136,0.00,091121,,,A*79 2021-11-09T19:43:12.095Z,1636486992.095 [NAL9602](INFO): GPS fix at 20211109T194311: (36.802793, -121.788016) 2021-11-09T19:43:14.919Z,1636486994.919 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194314.00,A,3648.16732,N,12147.28125,W,0.389,0.00,091121,,,A*7B 2021-11-09T19:43:14.921Z,1636486994.921 [NAL9602](INFO): GPS fix at 20211109T194314: (36.802789, -121.788021) 2021-11-09T19:43:17.750Z,1636486997.750 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194317.00,A,3648.16714,N,12147.28138,W,0.272,0.00,091121,,,A*75 2021-11-09T19:43:17.752Z,1636486997.752 [NAL9602](INFO): GPS fix at 20211109T194317: (36.802786, -121.788023) 2021-11-09T19:43:19.387Z,1636486999.387 [CBIT](INFO): Clearing failed state for component DAT 2021-11-09T19:43:19.388Z,1636486999.388 [DAT] No Fault, FailCount= 8 2021-11-09T19:43:19.769Z,1636486999.769 [DAT](INFO): Powering up 2021-11-09T19:43:19.770Z,1636486999.770 [DAT](DEBUG): Initializing DAT. 2021-11-09T19:43:20.168Z,1636487000.168 [Power24vConverter](INFO): Powering up. 2021-11-09T19:43:20.979Z,1636487000.979 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194320.00,A,3648.16729,N,12147.28163,W,0.156,0.00,091121,,,A*74 2021-11-09T19:43:20.981Z,1636487000.981 [NAL9602](INFO): GPS fix at 20211109T194320: (36.802788, -121.788027) 2021-11-09T19:43:23.806Z,1636487003.806 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194323.00,A,3648.16729,N,12147.28185,W,0.544,0.00,091121,,,A*78 2021-11-09T19:43:23.808Z,1636487003.808 [NAL9602](INFO): GPS fix at 20211109T194323: (36.802788, -121.788031) 2021-11-09T19:43:27.042Z,1636487007.042 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194326.00,A,3648.16709,N,12147.28167,W,0.214,0.00,091121,,,A*71 2021-11-09T19:43:27.044Z,1636487007.044 [NAL9602](INFO): GPS fix at 20211109T194326: (36.802785, -121.788028) 2021-11-09T19:43:29.870Z,1636487009.870 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194329.00,A,3648.16705,N,12147.28170,W,0.369,0.00,091121,,,A*7F 2021-11-09T19:43:29.873Z,1636487009.873 [NAL9602](INFO): GPS fix at 20211109T194329: (36.802784, -121.788028) 2021-11-09T19:43:32.700Z,1636487012.700 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194331.00,A,3648.16703,N,12147.28163,W,0.583,0.00,091121,,,A*70 2021-11-09T19:43:32.702Z,1636487012.702 [NAL9602](INFO): GPS fix at 20211109T194331: (36.802784, -121.788027) 2021-11-09T19:43:35.930Z,1636487015.930 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194335.00,A,3648.16719,N,12147.28160,W,0.311,0.00,091121,,,A*71 2021-11-09T19:43:35.942Z,1636487015.942 [NAL9602](INFO): GPS fix at 20211109T194335: (36.802787, -121.788027) 2021-11-09T19:43:38.754Z,1636487018.754 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194338.00,A,3648.16715,N,12147.28162,W,0.214,0.00,091121,,,A*76 2021-11-09T19:43:38.774Z,1636487018.774 [NAL9602](INFO): GPS fix at 20211109T194338: (36.802786, -121.788027) 2021-11-09T19:43:41.990Z,1636487021.990 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194341.00,A,3648.16700,N,12147.28179,W,0.136,0.00,091121,,,A*75 2021-11-09T19:43:42.002Z,1636487022.002 [NAL9602](INFO): GPS fix at 20211109T194341: (36.802783, -121.788030) 2021-11-09T19:43:44.814Z,1636487024.814 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194344.00,A,3648.16660,N,12147.28167,W,0.194,0.00,091121,,,A*70 2021-11-09T19:43:44.817Z,1636487024.817 [NAL9602](INFO): GPS fix at 20211109T194344: (36.802777, -121.788028) 2021-11-09T19:43:48.057Z,1636487028.057 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194347.00,A,3648.16673,N,12147.28169,W,0.117,0.00,091121,,,A*74 2021-11-09T19:43:48.060Z,1636487028.060 [NAL9602](INFO): GPS fix at 20211109T194347: (36.802779, -121.788028) 2021-11-09T19:43:50.882Z,1636487030.882 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194350.00,A,3648.16687,N,12147.28166,W,0.330,0.00,091121,,,A*71 2021-11-09T19:43:50.885Z,1636487030.885 [NAL9602](INFO): GPS fix at 20211109T194350: (36.802781, -121.788028) 2021-11-09T19:43:53.704Z,1636487033.704 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194353.00,A,3648.16708,N,12147.28174,W,0.175,0.00,091121,,,A*74 2021-11-09T19:43:53.706Z,1636487033.706 [NAL9602](INFO): GPS fix at 20211109T194353: (36.802785, -121.788029) 2021-11-09T19:43:56.935Z,1636487036.935 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194356.00,A,3648.16712,N,12147.28154,W,0.136,0.00,091121,,,A*7F 2021-11-09T19:43:56.937Z,1636487036.937 [NAL9602](INFO): GPS fix at 20211109T194356: (36.802785, -121.788026) 2021-11-09T19:43:58.168Z,1636487038.168 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired. 2021-11-09T19:43:58.585Z,1636487038.585 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 0.000000 Voltage: 16.690001 2021-11-09T19:43:58.585Z,1636487038.585 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah 2021-11-09T19:43:58.586Z,1636487038.586 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V 2021-11-09T19:43:58.969Z,1636487038.969 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2021-11-09T19:43:58.970Z,1636487038.970 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2021-11-09T19:43:58.970Z,1636487038.970 [IBIT](IMPORTANT): Pressure:7.729191 PSI 2021-11-09T19:43:58.971Z,1636487038.971 [IBIT](IMPORTANT): Humidity:11.543158 % 2021-11-09T19:43:59.398Z,1636487039.398 [IBIT](IMPORTANT): Vehicle Pitch:-3.691733 degrees 2021-11-09T19:43:59.399Z,1636487039.399 [IBIT](IMPORTANT): Vehicle Roll:6.706079 degrees 2021-11-09T19:43:59.399Z,1636487039.399 [IBIT](IMPORTANT): Vehicle Heading:292.946014 degrees 2021-11-09T19:43:59.766Z,1636487039.766 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194359.00,A,3648.16729,N,12147.28164,W,0.292,0.00,091121,,,A*76 2021-11-09T19:43:59.769Z,1636487039.769 [NAL9602](INFO): GPS fix at 20211109T194359: (36.802788, -121.788027) 2021-11-09T19:43:59.814Z,1636487039.814 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2021-11-09T19:43:59.819Z,1636487039.819 [IBIT](IMPORTANT): buoyancyNeutral: 233.479797 cc 2021-11-09T19:43:59.820Z,1636487039.820 [IBIT](IMPORTANT): massDefault: 1.027025 cm 2021-11-09T19:43:59.820Z,1636487039.820 [IBIT](IMPORTANT): stopDepth: 295.000000 m 2021-11-09T19:43:59.820Z,1636487039.820 [IBIT](IMPORTANT): abortDepth: 300.000000 m 2021-11-09T19:43:59.820Z,1636487039.820 [IBIT](IMPORTANT): IBIT FAILED 2021-11-09T19:44:19.961Z,1636487059.961 [DAT](FAULT): failed to initialize, no bytes available on serial interface 2021-11-09T19:44:19.961Z,1636487059.961 [DAT] Communications Fault, FailCount= 1 2021-11-09T19:44:19.961Z,1636487059.961 [DAT](ERROR): Communications Fault 2021-11-09T19:44:20.051Z,1636487060.051 [CBIT](ERROR): Communications Fault in component: DAT 2021-11-09T19:44:20.365Z,1636487060.365 [DAT](INFO): Powering down 2021-11-09T19:44:21.244Z,1636487061.244 [CBIT](INFO): Clearing failed state for component DAT 2021-11-09T19:44:21.244Z,1636487061.244 [DAT] No Fault, FailCount= 1 2021-11-09T19:44:23.600Z,1636487063.600 [DAT](INFO): Powering up 2021-11-09T19:44:23.601Z,1636487063.601 [DAT](DEBUG): Initializing DAT. 2021-11-09T19:44:32.484Z,1636487072.484 [NAL9602](INFO): Not Powering down - fast GPS 2021-11-09T19:45:23.804Z,1636487123.804 [DAT](FAULT): failed to initialize, no bytes available on serial interface 2021-11-09T19:45:23.804Z,1636487123.804 [DAT] Communications Fault, FailCount= 2 2021-11-09T19:45:23.804Z,1636487123.804 [DAT](ERROR): Communications Fault 2021-11-09T19:45:23.864Z,1636487123.864 [CBIT](ERROR): Communications Fault in component: DAT 2021-11-09T19:45:24.212Z,1636487124.212 [DAT](INFO): Powering down 2021-11-09T19:45:25.053Z,1636487125.053 [CBIT](INFO): Clearing failed state for component DAT 2021-11-09T19:45:25.053Z,1636487125.053 [DAT] No Fault, FailCount= 2 2021-11-09T19:45:27.448Z,1636487127.448 [DAT](INFO): Powering up 2021-11-09T19:45:27.449Z,1636487127.449 [DAT](DEBUG): Initializing DAT. 2021-11-09T19:46:27.637Z,1636487187.637 [DAT](FAULT): failed to initialize, no bytes available on serial interface 2021-11-09T19:46:27.637Z,1636487187.637 [DAT] Communications Fault, FailCount= 3 2021-11-09T19:46:27.637Z,1636487187.637 [DAT](ERROR): Communications Fault 2021-11-09T19:46:27.710Z,1636487187.710 [CBIT](ERROR): Communications Fault in component: DAT 2021-11-09T19:46:28.045Z,1636487188.045 [DAT](INFO): Powering down 2021-11-09T19:46:28.873Z,1636487188.873 [CBIT](INFO): Clearing failed state for component DAT 2021-11-09T19:46:28.873Z,1636487188.873 [DAT] No Fault, FailCount= 3 2021-11-09T19:46:31.272Z,1636487191.272 [DAT](INFO): Powering up 2021-11-09T19:46:31.273Z,1636487191.273 [DAT](DEBUG): Initializing DAT. 2021-11-09T19:46:53.504Z,1636487213.504 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-09T19:46:53.504Z,1636487213.504 [Default:CheckIn:C.Wait] Stopped 2021-11-09T19:46:53.505Z,1636487213.505 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-09T19:46:53.505Z,1636487213.505 [Default:CheckIn:D] Running Loop=1 2021-11-09T19:46:53.923Z,1636487213.923 [Default:CheckIn:D] Stopped 2021-11-09T19:46:53.924Z,1636487213.924 [Default:CheckIn:E] Running Loop=1 2021-11-09T19:46:54.310Z,1636487214.310 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 13.100157 min 2021-11-09T19:46:54.311Z,1636487214.311 [Default:CheckIn:E] Stopped 2021-11-09T19:46:54.311Z,1636487214.311 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-09T19:46:54.311Z,1636487214.311 [Default:CheckIn] Stopped 2021-11-09T19:46:54.311Z,1636487214.311 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-09T19:46:54.311Z,1636487214.311 [Default:CheckIn](INFO): Running loop #2 2021-11-09T19:46:54.311Z,1636487214.311 [Default:CheckIn] Running Loop=2 2021-11-09T19:46:54.311Z,1636487214.311 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-09T19:46:54.311Z,1636487214.311 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-09T19:46:56.323Z,1636487216.323 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194655.00,A,3648.16258,N,12147.27872,W,0.292,0.00,091121,,,A*7D 2021-11-09T19:46:56.325Z,1636487216.325 [NAL9602](INFO): GPS fix at 20211109T194655: (36.802710, -121.787979) 2021-11-09T19:46:56.337Z,1636487216.337 [Default:CheckIn:Read_GPS] Stopped 2021-11-09T19:46:56.337Z,1636487216.337 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-09T19:47:04.147Z,1636487224.147 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20211109T192939/Courier0007.lzma 2021-11-09T19:47:05.149Z,1636487225.149 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Courier0007.lzma.bak 2021-11-09T19:47:05.149Z,1636487225.149 [DataOverHttps](INFO): SBD MOMSN=16224613 2021-11-09T19:47:23.944Z,1636487243.944 [DataOverHttps](INFO): Sending 1077 bytes from file Logs/20211109T192939/Express0008.lzma 2021-11-09T19:47:24.945Z,1636487244.945 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Express0008.lzma.bak 2021-11-09T19:47:24.945Z,1636487244.945 [DataOverHttps](INFO): SBD MOMSN=16224622 2021-11-09T19:47:26.315Z,1636487246.315 [Default:CheckIn:Read_Iridium] Stopped 2021-11-09T19:47:26.315Z,1636487246.315 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-09T19:47:26.315Z,1636487246.315 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-09T19:47:31.548Z,1636487251.548 [DAT](FAULT): failed to initialize, no bytes available on serial interface 2021-11-09T19:47:31.548Z,1636487251.548 [DAT] Communications Fault, FailCount= 4 2021-11-09T19:47:31.548Z,1636487251.548 [DAT](ERROR): Communications Fault 2021-11-09T19:47:31.606Z,1636487251.606 [CBIT](ERROR): Communications Fault in component: DAT 2021-11-09T19:47:31.938Z,1636487251.938 [DAT](INFO): Powering down 2021-11-09T19:47:32.757Z,1636487252.757 [CBIT](INFO): Clearing failed state for component DAT 2021-11-09T19:47:32.757Z,1636487252.757 [DAT] No Fault, FailCount= 4 2021-11-09T19:47:35.161Z,1636487255.161 [DAT](INFO): Powering up 2021-11-09T19:47:35.161Z,1636487255.161 [DAT](DEBUG): Initializing DAT. 2021-11-09T19:48:35.359Z,1636487315.359 [DAT](FAULT): failed to initialize, no bytes available on serial interface 2021-11-09T19:48:35.359Z,1636487315.359 [DAT] Communications Fault, FailCount= 5 2021-11-09T19:48:35.359Z,1636487315.359 [DAT](ERROR): Communications Fault 2021-11-09T19:48:35.380Z,1636487315.380 [CBIT](ERROR): Communications Fault in component: DAT 2021-11-09T19:48:35.761Z,1636487315.761 [DAT](INFO): Powering down 2021-11-09T19:48:36.588Z,1636487316.588 [CBIT](INFO): Clearing failed state for component DAT 2021-11-09T19:48:36.588Z,1636487316.588 [DAT] No Fault, FailCount= 5 2021-11-09T19:48:38.992Z,1636487318.992 [DAT](INFO): Powering up 2021-11-09T19:48:38.992Z,1636487318.992 [DAT](DEBUG): Initializing DAT. 2021-11-09T19:48:53.046Z,1636487333.046 [CommandExec](IMPORTANT): got command get DAT.simulateHardware 2021-11-09T19:48:53.047Z,1636487333.047 [CommandExec](IMPORTANT): DAT.simulateHardware 0 bool 2021-11-09T19:48:53.149Z,1636487333.149 [DAT](INFO): commRate: 800 2021-11-09T19:48:55.154Z,1636487335.154 [DAT](INFO): entering command mode 2021-11-09T19:48:55.565Z,1636487335.565 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:48:55.961Z,1636487335.961 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:48:56.365Z,1636487336.365 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:48:56.770Z,1636487336.770 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:48:57.174Z,1636487337.174 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:48:57.577Z,1636487337.577 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:48:57.000Z,1636487338.000 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:48:58.400Z,1636487338.400 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:48:58.793Z,1636487338.793 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:48:59.193Z,1636487339.193 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:48:59.599Z,1636487339.599 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:49:00.001Z,1636487340.001 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:49:00.409Z,1636487340.409 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:49:00.809Z,1636487340.809 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:49:01.215Z,1636487341.215 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:49:01.617Z,1636487341.617 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:49:02.045Z,1636487342.045 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:49:02.440Z,1636487342.440 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:49:02.829Z,1636487342.829 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:49:03.237Z,1636487343.237 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:49:03.637Z,1636487343.637 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:49:04.041Z,1636487344.041 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:49:04.446Z,1636487344.446 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:49:04.849Z,1636487344.849 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:49:05.255Z,1636487345.255 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:49:05.658Z,1636487345.658 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:49:06.061Z,1636487346.061 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:49:06.465Z,1636487346.465 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:49:06.872Z,1636487346.872 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:49:07.273Z,1636487347.273 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:49:07.677Z,1636487347.677 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:49:08.084Z,1636487348.084 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:49:08.493Z,1636487348.493 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:49:08.894Z,1636487348.894 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:49:09.308Z,1636487349.308 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:49:09.697Z,1636487349.697 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:49:10.101Z,1636487350.101 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:49:10.517Z,1636487350.517 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-09T19:49:10.517Z,1636487350.517 [DAT](FAULT): failed to enter command mode 2021-11-09T19:49:10.936Z,1636487350.936 [DAT](INFO): entering command mode 2021-11-09T19:49:11.336Z,1636487351.336 [DAT](INFO): setting verbose to 3 2021-11-09T19:49:11.718Z,1636487351.718 [DAT](INFO): set verbose to 3 2021-11-09T19:49:11.719Z,1636487351.719 [DAT](INFO): setting DatVerbose to 27440 2021-11-09T19:49:12.129Z,1636487352.129 [DAT](INFO): set DatVerbose to 27440 2021-11-09T19:49:12.129Z,1636487352.129 [DAT](INFO): setting transmit power to 8 2021-11-09T19:49:12.526Z,1636487352.526 [DAT](INFO): set transmit power to 8 2021-11-09T19:49:12.526Z,1636487352.526 [DAT](INFO): setting local address to 5 2021-11-09T19:49:12.945Z,1636487352.945 [DAT](INFO): set local address to 5 2021-11-09T19:49:18.917Z,1636487358.917 [CommandExec](IMPORTANT): got command show variable 24V 2021-11-09T19:49:18.925Z,1636487358.925 [CommandExec](IMPORTANT): Power24vConverter.loadControl (none) 2021-11-09T19:49:18.946Z,1636487358.946 [CommandExec](IMPORTANT): Power24vConverter.loadAtStartup (bool) 2021-11-09T19:49:18.946Z,1636487358.946 [CommandExec](IMPORTANT): Power24vConverter.simulateHardware (bool) 2021-11-09T19:49:19.031Z,1636487359.031 [CommandExec](IMPORTANT): Power24vConverter.enableBroadcast (bool) 2021-11-09T19:49:19.031Z,1636487359.031 [CommandExec](IMPORTANT): Power24vConverter.component_voltage (volt) 2021-11-09T19:49:19.032Z,1636487359.032 [CommandExec](IMPORTANT): Power24vConverter.component_avgVoltage (volt) 2021-11-09T19:49:19.032Z,1636487359.032 [CommandExec](IMPORTANT): Power24vConverter.component_current (milliampere) 2021-11-09T19:49:19.033Z,1636487359.033 [CommandExec](IMPORTANT): Power24vConverter.component_avgCurrent (milliampere) 2021-11-09T19:49:19.033Z,1636487359.033 [CommandExec](IMPORTANT): Power24vConverter.power24vConverter (bool) 2021-11-09T19:49:28.088Z,1636487368.088 [CommandExec](IMPORTANT): got command get Power24vConverter.loadAtStartup 2021-11-09T19:49:28.088Z,1636487368.088 [CommandExec](IMPORTANT): Power24vConverter.loadAtStartup 1 bool 2021-11-09T19:49:36.366Z,1636487376.366 [NAL9602](INFO): SBD MO Status=2, MOMSN=6615, MT Status=2, MTMSN=0 2021-11-09T19:49:36.366Z,1636487376.366 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-11-09T19:49:50.109Z,1636487390.109 [NAL9602](INFO): SBD MO Status=2, MOMSN=6615, MT Status=2, MTMSN=0 2021-11-09T19:49:50.109Z,1636487390.109 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-11-09T19:51:58.172Z,1636487518.172 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-11-09T19:52:26.877Z,1636487546.877 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-09T19:52:26.877Z,1636487546.877 [Default:CheckIn:C.Wait] Stopped 2021-11-09T19:52:26.877Z,1636487546.877 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-09T19:52:26.877Z,1636487546.877 [Default:CheckIn:D] Running Loop=1 2021-11-09T19:52:27.272Z,1636487547.272 [Default:CheckIn:D] Stopped 2021-11-09T19:52:27.272Z,1636487547.272 [Default:CheckIn:E] Running Loop=1 2021-11-09T19:52:27.675Z,1636487547.675 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.655967 min 2021-11-09T19:52:27.675Z,1636487547.675 [Default:CheckIn:E] Stopped 2021-11-09T19:52:27.675Z,1636487547.675 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-09T19:52:27.675Z,1636487547.675 [Default:CheckIn] Stopped 2021-11-09T19:52:27.675Z,1636487547.675 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-09T19:52:27.676Z,1636487547.676 [Default:CheckIn](INFO): Running loop #3 2021-11-09T19:52:27.676Z,1636487547.676 [Default:CheckIn] Running Loop=3 2021-11-09T19:52:27.676Z,1636487547.676 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-09T19:52:27.676Z,1636487547.676 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-09T19:52:29.683Z,1636487549.683 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195229.00,A,3648.16214,N,12147.27689,W,0.000,0.00,091121,,,A*78 2021-11-09T19:52:29.686Z,1636487549.686 [NAL9602](INFO): GPS fix at 20211109T195229: (36.802702, -121.787948) 2021-11-09T19:52:29.698Z,1636487549.698 [Default:CheckIn:Read_GPS] Stopped 2021-11-09T19:52:29.698Z,1636487549.698 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-09T19:52:37.063Z,1636487557.063 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211109T192939/Courier0010.lzma 2021-11-09T19:52:38.060Z,1636487558.060 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Courier0010.lzma.bak 2021-11-09T19:52:38.061Z,1636487558.061 [DataOverHttps](INFO): SBD MOMSN=16224694 2021-11-09T19:52:56.503Z,1636487576.503 [DataOverHttps](INFO): Sending 513 bytes from file Logs/20211109T192939/Express0011.lzma 2021-11-09T19:52:57.505Z,1636487577.505 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Express0011.lzma.bak 2021-11-09T19:52:57.505Z,1636487577.505 [DataOverHttps](INFO): SBD MOMSN=16224697 2021-11-09T19:52:58.854Z,1636487578.854 [Default:CheckIn:Read_Iridium] Stopped 2021-11-09T19:52:58.854Z,1636487578.854 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-09T19:52:58.855Z,1636487578.855 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-09T19:53:02.472Z,1636487582.472 [NAL9602](INFO): Not Powering down - fast GPS 2021-11-09T19:57:59.438Z,1636487879.438 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-09T19:57:59.439Z,1636487879.439 [Default:CheckIn:C.Wait] Stopped 2021-11-09T19:57:59.439Z,1636487879.439 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-09T19:57:59.439Z,1636487879.439 [Default:CheckIn:D] Running Loop=1 2021-11-09T19:57:59.841Z,1636487879.841 [Default:CheckIn:D] Stopped 2021-11-09T19:57:59.841Z,1636487879.841 [Default:CheckIn:E] Running Loop=1 2021-11-09T19:58:00.257Z,1636487880.257 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 24.198779 min 2021-11-09T19:58:00.258Z,1636487880.258 [Default:CheckIn:E] Stopped 2021-11-09T19:58:00.258Z,1636487880.258 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-09T19:58:00.258Z,1636487880.258 [Default:CheckIn] Stopped 2021-11-09T19:58:00.258Z,1636487880.258 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-09T19:58:00.258Z,1636487880.258 [Default:CheckIn](INFO): Running loop #4 2021-11-09T19:58:00.258Z,1636487880.258 [Default:CheckIn] Running Loop=4 2021-11-09T19:58:00.258Z,1636487880.258 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-09T19:58:00.258Z,1636487880.258 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-09T19:58:02.254Z,1636487882.254 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195801.00,A,3648.16654,N,12147.21647,W,0.039,19.33,091121,,,A*4E 2021-11-09T19:58:02.256Z,1636487882.256 [NAL9602](INFO): GPS fix at 20211109T195801: (36.802776, -121.786941) 2021-11-09T19:58:02.268Z,1636487882.268 [Default:CheckIn:Read_GPS] Stopped 2021-11-09T19:58:02.268Z,1636487882.268 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-09T19:58:10.151Z,1636487890.151 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211109T192939/Courier0013.lzma 2021-11-09T19:58:11.149Z,1636487891.149 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Courier0013.lzma.bak 2021-11-09T19:58:11.149Z,1636487891.149 [DataOverHttps](INFO): SBD MOMSN=16224728 2021-11-09T19:58:20.429Z,1636487900.429 [NAL9602](INFO): SBD MO Status=0, MOMSN=6615, MT Status=0, MTMSN=0 2021-11-09T19:58:20.430Z,1636487900.430 [NAL9602](INFO): No messages in MT queue 2021-11-09T19:58:29.683Z,1636487909.683 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20211109T192939/Express0014.lzma 2021-11-09T19:58:30.685Z,1636487910.685 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Express0014.lzma.bak 2021-11-09T19:58:30.685Z,1636487910.685 [DataOverHttps](INFO): SBD MOMSN=16224732 2021-11-09T19:58:32.635Z,1636487912.635 [Default:CheckIn:Read_Iridium] Stopped 2021-11-09T19:58:32.635Z,1636487912.635 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-09T19:58:32.635Z,1636487912.635 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-09T19:58:51.200Z,1636487931.200 [NAL9602](INFO): Not Powering down - fast GPS 2021-11-09T20:01:01.432Z,1636488061.432 [DataOverHttps](IMPORTANT): SBD MTMSN=20211109T200100 2021-11-09T20:01:11.871Z,1636488071.871 [DataOverHttps](INFO): Received command: ibit 2021-11-09T20:01:11.872Z,1636488071.872 [CommandExec](IMPORTANT): got command ibit 2021-11-09T20:01:11.966Z,1636488071.966 [IBIT](IMPORTANT): Beginning Initiated BIT 2021-11-09T20:01:11.967Z,1636488071.967 [IBIT](IMPORTANT): Beginning control surface checks. 2021-11-09T20:01:11.970Z,1636488071.970 [CBIT](IMPORTANT): Beginning ground fault scan 2021-11-09T20:01:12.872Z,1636488072.872 [DataOverHttps](IMPORTANT): SBD MTMSN=20211109T200111 2021-11-09T20:01:13.587Z,1636488073.587 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200112.00,A,3648.16535,N,12147.21837,W,0.000,97.21,091121,,,A*48 2021-11-09T20:01:13.589Z,1636488073.589 [NAL9602](INFO): GPS fix at 20211109T200112: (36.802756, -121.786973) 2021-11-09T20:01:20.558Z,1636488080.558 [DataOverHttps](INFO): Received command: ibit 2021-11-09T20:01:20.584Z,1636488080.584 [CommandExec](IMPORTANT): got command ibit 2021-11-09T20:01:22.873Z,1636488082.873 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.005743 CHAN A1 (24V): 0.169556 CHAN A2 (12V): -0.004673 CHAN A3 (5V): -0.001987 CHAN B0 (3.3V): -0.001223 CHAN B1 (3.15aV): -0.001690 CHAN B2 (3.15bV): -0.001200 CHAN B3 (GND): -0.000080 OPEN: 0.004629 Full Scale: +/- 1 mA 2021-11-09T20:01:28.490Z,1636488088.490 [NAL9602](INFO): SBD MO Status=0, MOMSN=6616, MT Status=0, MTMSN=0 2021-11-09T20:01:28.490Z,1636488088.490 [NAL9602](INFO): No messages in MT queue 2021-11-09T20:01:29.706Z,1636488089.706 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200129.00,A,3648.16585,N,12147.21918,W,0.078,97.21,091121,,,A*48 2021-11-09T20:01:29.717Z,1636488089.717 [NAL9602](INFO): GPS fix at 20211109T200129: (36.802764, -121.786986) 2021-11-09T20:01:32.135Z,1636488092.135 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200131.00,A,3648.16586,N,12147.21924,W,0.078,97.21,091121,,,A*4D 2021-11-09T20:01:32.137Z,1636488092.137 [NAL9602](INFO): GPS fix at 20211109T200131: (36.802764, -121.786987) 2021-11-09T20:01:34.956Z,1636488094.956 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200134.00,A,3648.16581,N,12147.21935,W,0.058,97.21,091121,,,A*4D 2021-11-09T20:01:34.958Z,1636488094.958 [NAL9602](INFO): GPS fix at 20211109T200134: (36.802763, -121.786989) 2021-11-09T20:01:38.190Z,1636488098.190 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200137.00,A,3648.16582,N,12147.21937,W,0.039,97.21,091121,,,A*48 2021-11-09T20:01:38.192Z,1636488098.192 [NAL9602](INFO): GPS fix at 20211109T200137: (36.802764, -121.786990) 2021-11-09T20:01:41.018Z,1636488101.018 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200140.00,A,3648.16580,N,12147.21944,W,0.194,97.21,091121,,,A*48 2021-11-09T20:01:41.021Z,1636488101.021 [NAL9602](INFO): GPS fix at 20211109T200140: (36.802763, -121.786991) 2021-11-09T20:01:44.250Z,1636488104.250 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200143.00,A,3648.16574,N,12147.21962,W,0.058,97.21,091121,,,A*45 2021-11-09T20:01:44.252Z,1636488104.252 [NAL9602](INFO): GPS fix at 20211109T200143: (36.802762, -121.786994) 2021-11-09T20:01:47.078Z,1636488107.078 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200146.00,A,3648.16569,N,12147.21968,W,0.039,97.21,091121,,,A*41 2021-11-09T20:01:47.081Z,1636488107.081 [NAL9602](INFO): GPS fix at 20211109T200146: (36.802762, -121.786995) 2021-11-09T20:01:50.307Z,1636488110.307 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200149.00,A,3648.16570,N,12147.21967,W,0.019,97.21,091121,,,A*4B 2021-11-09T20:01:50.309Z,1636488110.309 [NAL9602](INFO): GPS fix at 20211109T200149: (36.802762, -121.786995) 2021-11-09T20:01:53.134Z,1636488113.134 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200152.00,A,3648.16572,N,12147.21968,W,0.039,97.21,091121,,,A*4E 2021-11-09T20:01:53.137Z,1636488113.137 [NAL9602](INFO): GPS fix at 20211109T200152: (36.802762, -121.786995) 2021-11-09T20:01:55.968Z,1636488115.968 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200155.00,A,3648.16576,N,12147.21956,W,0.058,97.21,091121,,,A*47 2021-11-09T20:01:55.970Z,1636488115.970 [NAL9602](INFO): GPS fix at 20211109T200155: (36.802763, -121.786993) 2021-11-09T20:01:58.403Z,1636488118.403 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 5 Latitude: 36.802761 Longitude: -121.786995 2021-11-09T20:01:58.831Z,1636488118.831 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 0.000000 Voltage: 16.650999 2021-11-09T20:01:58.831Z,1636488118.831 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah 2021-11-09T20:01:58.831Z,1636488118.831 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V 2021-11-09T20:01:59.194Z,1636488119.194 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200158.00,A,3648.16585,N,12147.21949,W,0.039,97.21,091121,,,A*4F 2021-11-09T20:01:59.196Z,1636488119.196 [NAL9602](INFO): GPS fix at 20211109T200158: (36.802764, -121.786991) 2021-11-09T20:01:59.226Z,1636488119.226 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2021-11-09T20:01:59.243Z,1636488119.243 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2021-11-09T20:01:59.243Z,1636488119.243 [IBIT](IMPORTANT): Pressure:7.785807 PSI 2021-11-09T20:01:59.244Z,1636488119.244 [IBIT](IMPORTANT): Humidity:11.494323 % 2021-11-09T20:01:59.661Z,1636488119.661 [IBIT](IMPORTANT): Vehicle Pitch:-2.271856 degrees 2021-11-09T20:01:59.661Z,1636488119.661 [IBIT](IMPORTANT): Vehicle Roll:-8.604239 degrees 2021-11-09T20:01:59.662Z,1636488119.662 [IBIT](IMPORTANT): Vehicle Heading:203.254776 degrees 2021-11-09T20:02:00.026Z,1636488120.026 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2021-11-09T20:02:00.026Z,1636488120.026 [IBIT](IMPORTANT): buoyancyNeutral: 233.479797 cc 2021-11-09T20:02:00.027Z,1636488120.027 [IBIT](IMPORTANT): massDefault: 1.027025 cm 2021-11-09T20:02:00.027Z,1636488120.027 [IBIT](IMPORTANT): stopDepth: 295.000000 m 2021-11-09T20:02:00.027Z,1636488120.027 [IBIT](IMPORTANT): abortDepth: 300.000000 m 2021-11-09T20:02:00.027Z,1636488120.027 [IBIT](IMPORTANT): IBIT PASSED 2021-11-09T20:02:31.540Z,1636488151.540 [NAL9602](INFO): Not Powering down - fast GPS 2021-11-09T20:03:33.361Z,1636488213.361 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-09T20:03:33.361Z,1636488213.361 [Default:CheckIn:C.Wait] Stopped 2021-11-09T20:03:33.361Z,1636488213.361 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-09T20:03:33.361Z,1636488213.361 [Default:CheckIn:D] Running Loop=1 2021-11-09T20:03:33.750Z,1636488213.750 [Default:CheckIn:D] Stopped 2021-11-09T20:03:33.751Z,1636488213.751 [Default:CheckIn:E] Running Loop=1 2021-11-09T20:03:34.163Z,1636488214.163 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.763938 min 2021-11-09T20:03:34.163Z,1636488214.163 [Default:CheckIn:E] Stopped 2021-11-09T20:03:34.163Z,1636488214.163 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-09T20:03:34.163Z,1636488214.163 [Default:CheckIn] Stopped 2021-11-09T20:03:34.163Z,1636488214.163 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-09T20:03:34.164Z,1636488214.164 [Default:CheckIn](INFO): Running loop #5 2021-11-09T20:03:34.164Z,1636488214.164 [Default:CheckIn] Running Loop=5 2021-11-09T20:03:34.164Z,1636488214.164 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-09T20:03:34.164Z,1636488214.164 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-09T20:03:36.175Z,1636488216.175 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200335.00,A,3648.16411,N,12147.21974,W,0.039,97.21,091121,,,D*41 2021-11-09T20:03:36.177Z,1636488216.177 [NAL9602](INFO): GPS fix at 20211109T200335: (36.802735, -121.786996) 2021-11-09T20:03:36.189Z,1636488216.189 [Default:CheckIn:Read_GPS] Stopped 2021-11-09T20:03:36.189Z,1636488216.189 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-09T20:03:43.154Z,1636488223.154 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211109T192939/Courier0016.lzma 2021-11-09T20:03:44.157Z,1636488224.157 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Courier0016.lzma.bak 2021-11-09T20:03:44.157Z,1636488224.157 [DataOverHttps](INFO): SBD MOMSN=16224797 2021-11-09T20:04:00.006Z,1636488240.006 [NAL9602](INFO): SBD MO Status=2, MOMSN=6617, MT Status=2, MTMSN=0 2021-11-09T20:04:00.006Z,1636488240.006 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-11-09T20:04:00.116Z,1636488240.116 [DataOverHttps](INFO): Sending 816 bytes from file Logs/20211109T192939/Express0017.lzma 2021-11-09T20:04:01.117Z,1636488241.117 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Express0017.lzma.bak 2021-11-09T20:04:01.117Z,1636488241.117 [DataOverHttps](INFO): SBD MOMSN=16224800 2021-11-09T20:04:02.455Z,1636488242.455 [Default:CheckIn:Read_Iridium] Stopped 2021-11-09T20:04:02.455Z,1636488242.455 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-09T20:04:02.455Z,1636488242.455 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-09T20:04:26.674Z,1636488266.674 [NAL9602](INFO): SBD MO Status=0, MOMSN=6617, MT Status=0, MTMSN=0 2021-11-09T20:04:26.674Z,1636488266.674 [NAL9602](INFO): No messages in MT queue 2021-11-09T20:04:57.440Z,1636488297.440 [NAL9602](INFO): Not Powering down - fast GPS 2021-11-09T20:09:03.187Z,1636488543.187 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-09T20:09:03.187Z,1636488543.187 [Default:CheckIn:C.Wait] Stopped 2021-11-09T20:09:03.187Z,1636488543.187 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-09T20:09:03.187Z,1636488543.187 [Default:CheckIn:D] Running Loop=1 2021-11-09T20:09:03.590Z,1636488543.590 [Default:CheckIn:D] Stopped 2021-11-09T20:09:03.590Z,1636488543.590 [Default:CheckIn:E] Running Loop=1 2021-11-09T20:09:04.002Z,1636488544.002 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 35.261271 min 2021-11-09T20:09:04.002Z,1636488544.002 [Default:CheckIn:E] Stopped 2021-11-09T20:09:04.003Z,1636488544.003 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-09T20:09:04.003Z,1636488544.003 [Default:CheckIn] Stopped 2021-11-09T20:09:04.003Z,1636488544.003 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-09T20:09:04.003Z,1636488544.003 [Default:CheckIn](INFO): Running loop #6 2021-11-09T20:09:04.003Z,1636488544.003 [Default:CheckIn] Running Loop=6 2021-11-09T20:09:04.003Z,1636488544.003 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-09T20:09:04.004Z,1636488544.004 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-09T20:09:06.002Z,1636488546.002 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200905.00,A,3648.16304,N,12147.21877,W,0.117,97.21,091121,,,D*44 2021-11-09T20:09:06.004Z,1636488546.004 [NAL9602](INFO): GPS fix at 20211109T200905: (36.802717, -121.786980) 2021-11-09T20:09:06.048Z,1636488546.048 [Default:CheckIn:Read_GPS] Stopped 2021-11-09T20:09:06.048Z,1636488546.048 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-09T20:09:13.970Z,1636488553.970 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211109T192939/Courier0019.lzma 2021-11-09T20:09:14.973Z,1636488554.973 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Courier0019.lzma.bak 2021-11-09T20:09:14.973Z,1636488554.973 [DataOverHttps](INFO): SBD MOMSN=16224931 2021-11-09T20:09:18.949Z,1636488558.949 [NAL9602](INFO): SBD MO Status=0, MOMSN=6618, MT Status=0, MTMSN=0 2021-11-09T20:09:18.950Z,1636488558.950 [NAL9602](INFO): No messages in MT queue 2021-11-09T20:09:31.502Z,1636488571.502 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20211109T192939/Express0021.lzma 2021-11-09T20:09:32.504Z,1636488572.504 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Express0021.lzma.bak 2021-11-09T20:09:32.505Z,1636488572.505 [DataOverHttps](INFO): SBD MOMSN=16224934 2021-11-09T20:09:33.905Z,1636488573.905 [Default:CheckIn:Read_Iridium] Stopped 2021-11-09T20:09:33.905Z,1636488573.905 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-09T20:09:33.905Z,1636488573.905 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-09T20:09:49.632Z,1636488589.632 [NAL9602](INFO): Not Powering down - fast GPS 2021-11-09T20:14:34.377Z,1636488874.377 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-09T20:14:34.377Z,1636488874.377 [Default:CheckIn:C.Wait] Stopped 2021-11-09T20:14:34.377Z,1636488874.377 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-09T20:14:34.377Z,1636488874.377 [Default:CheckIn:D] Running Loop=1 2021-11-09T20:14:34.780Z,1636488874.780 [Default:CheckIn:D] Stopped 2021-11-09T20:14:34.780Z,1636488874.780 [Default:CheckIn:E] Running Loop=1 2021-11-09T20:14:35.194Z,1636488875.194 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 40.781099 min 2021-11-09T20:14:35.194Z,1636488875.194 [Default:CheckIn:E] Stopped 2021-11-09T20:14:35.194Z,1636488875.194 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-09T20:14:35.194Z,1636488875.194 [Default:CheckIn] Stopped 2021-11-09T20:14:35.195Z,1636488875.195 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-09T20:14:35.195Z,1636488875.195 [Default:CheckIn](INFO): Running loop #7 2021-11-09T20:14:35.195Z,1636488875.195 [Default:CheckIn] Running Loop=7 2021-11-09T20:14:35.195Z,1636488875.195 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-09T20:14:35.195Z,1636488875.195 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-09T20:14:37.193Z,1636488877.193 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201436.00,A,3648.16390,N,12147.21585,W,0.097,97.21,091121,,,D*4C 2021-11-09T20:14:37.196Z,1636488877.196 [NAL9602](INFO): GPS fix at 20211109T201436: (36.802732, -121.786931) 2021-11-09T20:14:37.211Z,1636488877.211 [Default:CheckIn:Read_GPS] Stopped 2021-11-09T20:14:37.211Z,1636488877.211 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-09T20:14:47.905Z,1636488887.905 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20211109T192939/Courier0025.lzma 2021-11-09T20:14:48.908Z,1636488888.908 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Courier0025.lzma.bak 2021-11-09T20:14:48.908Z,1636488888.908 [DataOverHttps](INFO): SBD MOMSN=16225087 2021-11-09T20:14:55.820Z,1636488895.820 [NAL9602](INFO): SBD MO Status=0, MOMSN=6619, MT Status=0, MTMSN=0 2021-11-09T20:14:55.821Z,1636488895.821 [NAL9602](INFO): No messages in MT queue 2021-11-09T20:15:05.057Z,1636488905.057 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20211109T192939/Express0026.lzma 2021-11-09T20:15:06.059Z,1636488906.059 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Express0026.lzma.bak 2021-11-09T20:15:06.060Z,1636488906.060 [DataOverHttps](INFO): SBD MOMSN=16225090 2021-11-09T20:15:07.572Z,1636488907.572 [Default:CheckIn:Read_Iridium] Stopped 2021-11-09T20:15:07.572Z,1636488907.572 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-09T20:15:07.572Z,1636488907.572 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-09T20:15:26.527Z,1636488926.527 [NAL9602](INFO): Not Powering down - fast GPS 2021-11-09T20:20:08.213Z,1636489208.213 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-09T20:20:08.226Z,1636489208.226 [Default:CheckIn:C.Wait] Stopped 2021-11-09T20:20:08.226Z,1636489208.226 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-09T20:20:08.226Z,1636489208.226 [Default:CheckIn:D] Running Loop=1 2021-11-09T20:20:08.622Z,1636489208.622 [Default:CheckIn:D] Stopped 2021-11-09T20:20:08.622Z,1636489208.622 [Default:CheckIn:E] Running Loop=1 2021-11-09T20:20:09.029Z,1636489209.029 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 46.345129 min 2021-11-09T20:20:09.030Z,1636489209.030 [Default:CheckIn:E] Stopped 2021-11-09T20:20:09.030Z,1636489209.030 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-09T20:20:09.030Z,1636489209.030 [Default:CheckIn] Stopped 2021-11-09T20:20:09.030Z,1636489209.030 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-09T20:20:09.030Z,1636489209.030 [Default:CheckIn](INFO): Running loop #8 2021-11-09T20:20:09.030Z,1636489209.030 [Default:CheckIn] Running Loop=8 2021-11-09T20:20:09.030Z,1636489209.030 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-09T20:20:09.030Z,1636489209.030 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-09T20:20:11.053Z,1636489211.053 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202010.00,A,3648.16327,N,12147.21398,W,0.039,65.89,091121,,,D*42 2021-11-09T20:20:11.055Z,1636489211.055 [NAL9602](INFO): GPS fix at 20211109T202010: (36.802721, -121.786900) 2021-11-09T20:20:11.075Z,1636489211.075 [Default:CheckIn:Read_GPS] Stopped 2021-11-09T20:20:11.075Z,1636489211.075 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-09T20:20:18.357Z,1636489218.357 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211109T192939/Courier0028.lzma 2021-11-09T20:20:19.370Z,1636489219.370 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Courier0028.lzma.bak 2021-11-09T20:20:19.373Z,1636489219.373 [DataOverHttps](INFO): SBD MOMSN=16225121 2021-11-09T20:20:40.625Z,1636489240.625 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20211109T192939/Express0029.lzma 2021-11-09T20:20:41.628Z,1636489241.628 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Express0029.lzma.bak 2021-11-09T20:20:41.628Z,1636489241.628 [DataOverHttps](INFO): SBD MOMSN=16225124 2021-11-09T20:20:43.427Z,1636489243.427 [Default:CheckIn:Read_Iridium] Stopped 2021-11-09T20:20:43.427Z,1636489243.427 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-09T20:20:43.427Z,1636489243.427 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-09T20:21:16.953Z,1636489276.953 [NAL9602](INFO): SBD MO Status=0, MOMSN=6620, MT Status=0, MTMSN=0 2021-11-09T20:21:16.953Z,1636489276.953 [NAL9602](INFO): No messages in MT queue 2021-11-09T20:21:47.655Z,1636489307.655 [NAL9602](INFO): Not Powering down - fast GPS 2021-11-09T20:25:44.011Z,1636489544.011 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-09T20:25:44.011Z,1636489544.011 [Default:CheckIn:C.Wait] Stopped 2021-11-09T20:25:44.011Z,1636489544.011 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-09T20:25:44.012Z,1636489544.012 [Default:CheckIn:D] Running Loop=1 2021-11-09T20:25:44.426Z,1636489544.426 [Default:CheckIn:D] Stopped 2021-11-09T20:25:44.426Z,1636489544.426 [Default:CheckIn:E] Running Loop=1 2021-11-09T20:25:44.818Z,1636489544.818 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.941870 min 2021-11-09T20:25:44.818Z,1636489544.818 [Default:CheckIn:E] Stopped 2021-11-09T20:25:44.818Z,1636489544.818 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-09T20:25:44.818Z,1636489544.818 [Default:CheckIn] Stopped 2021-11-09T20:25:44.818Z,1636489544.818 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-09T20:25:44.818Z,1636489544.818 [Default:CheckIn](INFO): Running loop #9 2021-11-09T20:25:44.819Z,1636489544.819 [Default:CheckIn] Running Loop=9 2021-11-09T20:25:44.819Z,1636489544.819 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-09T20:25:44.819Z,1636489544.819 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-09T20:25:46.837Z,1636489546.837 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202546.00,A,3648.16376,N,12147.21465,W,0.039,65.89,091121,,,D*45 2021-11-09T20:25:46.840Z,1636489546.840 [NAL9602](INFO): GPS fix at 20211109T202546: (36.802729, -121.786911) 2021-11-09T20:25:46.851Z,1636489546.851 [Default:CheckIn:Read_GPS] Stopped 2021-11-09T20:25:46.851Z,1636489546.851 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-09T20:25:54.573Z,1636489554.573 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211109T192939/Courier0031.lzma 2021-11-09T20:25:55.575Z,1636489555.575 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Courier0031.lzma.bak 2021-11-09T20:25:55.576Z,1636489555.576 [DataOverHttps](INFO): SBD MOMSN=16225150 2021-11-09T20:26:09.453Z,1636489569.453 [NAL9602](INFO): SBD MO Status=0, MOMSN=6621, MT Status=0, MTMSN=0 2021-11-09T20:26:09.453Z,1636489569.453 [NAL9602](INFO): No messages in MT queue 2021-11-09T20:26:11.585Z,1636489571.585 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20211109T192939/Express0032.lzma 2021-11-09T20:26:12.588Z,1636489572.588 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Express0032.lzma.bak 2021-11-09T20:26:12.588Z,1636489572.588 [DataOverHttps](INFO): SBD MOMSN=16225153 2021-11-09T20:26:14.319Z,1636489574.319 [Default:CheckIn:Read_Iridium] Stopped 2021-11-09T20:26:14.319Z,1636489574.319 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-09T20:26:14.319Z,1636489574.319 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-09T20:26:40.164Z,1636489600.164 [NAL9602](INFO): Not Powering down - fast GPS 2021-11-09T20:31:15.055Z,1636489875.055 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-09T20:31:15.055Z,1636489875.055 [Default:CheckIn:C.Wait] Stopped 2021-11-09T20:31:15.055Z,1636489875.055 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-09T20:31:15.055Z,1636489875.055 [Default:CheckIn:D] Running Loop=1 2021-11-09T20:31:15.460Z,1636489875.460 [Default:CheckIn:D] Stopped 2021-11-09T20:31:15.460Z,1636489875.460 [Default:CheckIn:E] Running Loop=1 2021-11-09T20:31:15.876Z,1636489875.876 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 57.459098 min 2021-11-09T20:31:15.876Z,1636489875.876 [Default:CheckIn:E] Stopped 2021-11-09T20:31:15.876Z,1636489875.876 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-09T20:31:15.876Z,1636489875.876 [Default:CheckIn] Stopped 2021-11-09T20:31:15.876Z,1636489875.876 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-09T20:31:15.876Z,1636489875.876 [Default:CheckIn](INFO): Running loop #10 2021-11-09T20:31:15.877Z,1636489875.877 [Default:CheckIn] Running Loop=10 2021-11-09T20:31:15.877Z,1636489875.877 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-09T20:31:15.877Z,1636489875.877 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-09T20:31:17.869Z,1636489877.869 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203117.00,A,3648.16237,N,12147.21317,W,0.019,65.89,091121,,,D*40 2021-11-09T20:31:17.871Z,1636489877.871 [NAL9602](INFO): GPS fix at 20211109T203117: (36.802706, -121.786886) 2021-11-09T20:31:17.883Z,1636489877.883 [Default:CheckIn:Read_GPS] Stopped 2021-11-09T20:31:17.883Z,1636489877.883 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-09T20:31:25.181Z,1636489885.181 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211109T192939/Courier0034.lzma 2021-11-09T20:31:26.184Z,1636489886.184 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Courier0034.lzma.bak 2021-11-09T20:31:26.184Z,1636489886.184 [DataOverHttps](INFO): SBD MOMSN=16225190 2021-11-09T20:31:40.897Z,1636489900.897 [NAL9602](INFO): SBD MO Status=2, MOMSN=6622, MT Status=2, MTMSN=0 2021-11-09T20:31:40.897Z,1636489900.897 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-11-09T20:31:42.201Z,1636489902.201 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20211109T192939/Express0035.lzma 2021-11-09T20:31:43.203Z,1636489903.203 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Express0035.lzma.bak 2021-11-09T20:31:43.204Z,1636489903.204 [DataOverHttps](INFO): SBD MOMSN=16225194 2021-11-09T20:31:44.543Z,1636489904.543 [Default:CheckIn:Read_Iridium] Stopped 2021-11-09T20:31:44.543Z,1636489904.543 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-09T20:31:44.543Z,1636489904.543 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-09T20:32:02.312Z,1636489922.312 [NAL9602](INFO): SBD MO Status=0, MOMSN=6622, MT Status=0, MTMSN=0 2021-11-09T20:32:02.313Z,1636489922.313 [NAL9602](INFO): No messages in MT queue 2021-11-09T20:32:33.011Z,1636489953.011 [NAL9602](INFO): Not Powering down - fast GPS 2021-11-09T20:36:45.169Z,1636490205.169 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-09T20:36:45.170Z,1636490205.170 [Default:CheckIn:C.Wait] Stopped 2021-11-09T20:36:45.170Z,1636490205.170 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-09T20:36:45.172Z,1636490205.172 [Default:CheckIn:D] Running Loop=1 2021-11-09T20:36:45.548Z,1636490205.548 [Default:CheckIn:D] Stopped 2021-11-09T20:36:45.548Z,1636490205.548 [Default:CheckIn:E] Running Loop=1 2021-11-09T20:36:45.935Z,1636490205.935 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.960563 min 2021-11-09T20:36:45.935Z,1636490205.935 [Default:CheckIn:E] Stopped 2021-11-09T20:36:45.936Z,1636490205.936 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-09T20:36:45.936Z,1636490205.936 [Default:CheckIn] Stopped 2021-11-09T20:36:45.936Z,1636490205.936 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-09T20:36:45.936Z,1636490205.936 [Default:CheckIn](INFO): Running loop #11 2021-11-09T20:36:45.936Z,1636490205.936 [Default:CheckIn] Running Loop=11 2021-11-09T20:36:45.936Z,1636490205.936 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-09T20:36:45.936Z,1636490205.936 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-09T20:36:47.950Z,1636490207.950 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203647.00,A,3648.16373,N,12147.21360,W,0.097,65.89,091121,,,D*45 2021-11-09T20:36:47.953Z,1636490207.953 [NAL9602](INFO): GPS fix at 20211109T203647: (36.802729, -121.786893) 2021-11-09T20:36:47.964Z,1636490207.964 [Default:CheckIn:Read_GPS] Stopped 2021-11-09T20:36:47.964Z,1636490207.964 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-09T20:36:55.665Z,1636490215.665 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211109T192939/Courier0037.lzma 2021-11-09T20:36:56.660Z,1636490216.660 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Courier0037.lzma.bak 2021-11-09T20:36:56.660Z,1636490216.660 [DataOverHttps](INFO): SBD MOMSN=16225265 2021-11-09T20:36:58.988Z,1636490218.988 [NAL9602](INFO): SBD MO Status=0, MOMSN=6623, MT Status=0, MTMSN=0 2021-11-09T20:36:58.989Z,1636490218.989 [NAL9602](INFO): No messages in MT queue 2021-11-09T20:37:16.185Z,1636490236.185 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20211109T192939/Express0038.lzma 2021-11-09T20:37:17.187Z,1636490237.187 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Express0038.lzma.bak 2021-11-09T20:37:17.188Z,1636490237.188 [DataOverHttps](INFO): SBD MOMSN=16225269 2021-11-09T20:37:18.620Z,1636490238.620 [Default:CheckIn:Read_Iridium] Stopped 2021-11-09T20:37:18.620Z,1636490238.620 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-09T20:37:18.620Z,1636490238.620 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-09T20:37:29.511Z,1636490249.511 [NAL9602](INFO): Not Powering down - fast GPS 2021-11-09T20:37:37.601Z,1636490257.601 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-11-09T20:37:50.923Z,1636490270.923 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-11-09T20:37:50.924Z,1636490270.924 [BPC1](INFO): Calculating totals. Valid battery stick count: 27. Valid reserve battery stick count: 3. 2021-11-09T20:37:50.927Z,1636490270.927 [BPC1](INFO): Received data from all battery sticks. 2021-11-09T20:42:19.285Z,1636490539.285 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-09T20:42:19.286Z,1636490539.286 [Default:CheckIn:C.Wait] Stopped 2021-11-09T20:42:19.286Z,1636490539.286 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-09T20:42:19.286Z,1636490539.286 [Default:CheckIn:D] Running Loop=1 2021-11-09T20:42:19.679Z,1636490539.679 [Default:CheckIn:D] Stopped 2021-11-09T20:42:19.679Z,1636490539.679 [Default:CheckIn:E] Running Loop=1 2021-11-09T20:42:20.082Z,1636490540.082 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 68.529419 min 2021-11-09T20:42:20.082Z,1636490540.082 [Default:CheckIn:E] Stopped 2021-11-09T20:42:20.082Z,1636490540.082 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-09T20:42:20.083Z,1636490540.083 [Default:CheckIn] Stopped 2021-11-09T20:42:20.083Z,1636490540.083 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-09T20:42:20.083Z,1636490540.083 [Default:CheckIn](INFO): Running loop #12 2021-11-09T20:42:20.083Z,1636490540.083 [Default:CheckIn] Running Loop=12 2021-11-09T20:42:20.083Z,1636490540.083 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-09T20:42:20.083Z,1636490540.083 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-09T20:42:22.102Z,1636490542.102 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204221.00,A,3648.16303,N,12147.21456,W,0.039,65.89,091121,,,D*47 2021-11-09T20:42:22.105Z,1636490542.105 [NAL9602](INFO): GPS fix at 20211109T204221: (36.802717, -121.786909) 2021-11-09T20:42:22.116Z,1636490542.116 [Default:CheckIn:Read_GPS] Stopped 2021-11-09T20:42:22.116Z,1636490542.116 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-09T20:42:32.418Z,1636490552.418 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20211109T192939/Courier0040.lzma 2021-11-09T20:42:33.420Z,1636490553.420 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Courier0040.lzma.bak 2021-11-09T20:42:33.420Z,1636490553.420 [DataOverHttps](INFO): SBD MOMSN=16225328 2021-11-09T20:42:39.181Z,1636490559.181 [NAL9602](INFO): SBD MO Status=0, MOMSN=6624, MT Status=0, MTMSN=0 2021-11-09T20:42:39.181Z,1636490559.181 [NAL9602](INFO): No messages in MT queue 2021-11-09T20:42:53.761Z,1636490573.761 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20211109T192939/Express0041.lzma 2021-11-09T20:42:54.764Z,1636490574.764 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Express0041.lzma.bak 2021-11-09T20:42:54.764Z,1636490574.764 [DataOverHttps](INFO): SBD MOMSN=16225335 2021-11-09T20:42:56.187Z,1636490576.187 [Default:CheckIn:Read_Iridium] Stopped 2021-11-09T20:42:56.187Z,1636490576.187 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-09T20:42:56.187Z,1636490576.187 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-09T20:43:09.935Z,1636490589.935 [NAL9602](INFO): Not Powering down - fast GPS 2021-11-09T20:47:56.842Z,1636490876.842 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-09T20:47:56.842Z,1636490876.842 [Default:CheckIn:C.Wait] Stopped 2021-11-09T20:47:56.842Z,1636490876.842 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-09T20:47:56.842Z,1636490876.842 [Default:CheckIn:D] Running Loop=1 2021-11-09T20:47:57.246Z,1636490877.246 [Default:CheckIn:D] Stopped 2021-11-09T20:47:57.246Z,1636490877.246 [Default:CheckIn:E] Running Loop=1 2021-11-09T20:47:57.654Z,1636490877.654 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 74.155526 min 2021-11-09T20:47:57.654Z,1636490877.654 [Default:CheckIn:E] Stopped 2021-11-09T20:47:57.654Z,1636490877.654 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-09T20:47:57.654Z,1636490877.654 [Default:CheckIn] Stopped 2021-11-09T20:47:57.654Z,1636490877.654 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-09T20:47:57.655Z,1636490877.655 [Default:CheckIn](INFO): Running loop #13 2021-11-09T20:47:57.655Z,1636490877.655 [Default:CheckIn] Running Loop=13 2021-11-09T20:47:57.655Z,1636490877.655 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-09T20:47:57.655Z,1636490877.655 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-09T20:47:59.661Z,1636490879.661 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204758.00,A,3648.16433,N,12147.21416,W,0.078,65.89,091121,,,D*49 2021-11-09T20:47:59.663Z,1636490879.663 [NAL9602](INFO): GPS fix at 20211109T204758: (36.802739, -121.786903) 2021-11-09T20:47:59.703Z,1636490879.703 [Default:CheckIn:Read_GPS] Stopped 2021-11-09T20:47:59.703Z,1636490879.703 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-09T20:48:07.213Z,1636490887.213 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211109T192939/Courier0043.lzma 2021-11-09T20:48:08.215Z,1636490888.215 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Courier0043.lzma.bak 2021-11-09T20:48:08.216Z,1636490888.216 [DataOverHttps](INFO): SBD MOMSN=16225359 2021-11-09T20:48:20.669Z,1636490900.669 [NAL9602](INFO): SBD MO Status=2, MOMSN=6625, MT Status=2, MTMSN=0 2021-11-09T20:48:20.669Z,1636490900.669 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-11-09T20:48:24.197Z,1636490904.197 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20211109T192939/Express0044.lzma 2021-11-09T20:48:25.200Z,1636490905.200 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Express0044.lzma.bak 2021-11-09T20:48:25.200Z,1636490905.200 [DataOverHttps](INFO): SBD MOMSN=16225368 2021-11-09T20:48:26.739Z,1636490906.739 [Default:CheckIn:Read_Iridium] Stopped 2021-11-09T20:48:26.739Z,1636490906.739 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-09T20:48:26.739Z,1636490906.739 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-09T20:49:00.154Z,1636490940.154 [NAL9602](INFO): SBD MO Status=2, MOMSN=6625, MT Status=2, MTMSN=0 2021-11-09T20:49:00.154Z,1636490940.154 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-11-09T20:50:02.767Z,1636491002.767 [NAL9602](INFO): SBD MO Status=2, MOMSN=6625, MT Status=2, MTMSN=0 2021-11-09T20:50:02.768Z,1636491002.768 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-11-09T20:50:23.371Z,1636491023.371 [NAL9602](INFO): SBD MO Status=2, MOMSN=6625, MT Status=2, MTMSN=0 2021-11-09T20:50:23.372Z,1636491023.372 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-11-09T20:50:38.753Z,1636491038.753 [NAL9602](INFO): SBD MO Status=0, MOMSN=6625, MT Status=0, MTMSN=0 2021-11-09T20:50:38.754Z,1636491038.754 [NAL9602](INFO): No messages in MT queue 2021-11-09T20:51:09.446Z,1636491069.446 [NAL9602](INFO): Not Powering down - fast GPS 2021-11-09T20:53:27.313Z,1636491207.313 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-09T20:53:27.313Z,1636491207.313 [Default:CheckIn:C.Wait] Stopped 2021-11-09T20:53:27.313Z,1636491207.313 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-09T20:53:27.313Z,1636491207.313 [Default:CheckIn:D] Running Loop=1 2021-11-09T20:53:27.718Z,1636491207.718 [Default:CheckIn:D] Stopped 2021-11-09T20:53:27.718Z,1636491207.718 [Default:CheckIn:E] Running Loop=1 2021-11-09T20:53:28.138Z,1636491208.138 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 79.663395 min 2021-11-09T20:53:28.138Z,1636491208.138 [Default:CheckIn:E] Stopped 2021-11-09T20:53:28.139Z,1636491208.139 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-09T20:53:28.139Z,1636491208.139 [Default:CheckIn] Stopped 2021-11-09T20:53:28.139Z,1636491208.139 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-09T20:53:28.139Z,1636491208.139 [Default:CheckIn](INFO): Running loop #14 2021-11-09T20:53:28.139Z,1636491208.139 [Default:CheckIn] Running Loop=14 2021-11-09T20:53:28.139Z,1636491208.139 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-09T20:53:28.139Z,1636491208.139 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-09T20:53:30.136Z,1636491210.136 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205329.00,A,3648.16526,N,12147.21310,W,0.058,0.00,091121,,,D*7E 2021-11-09T20:53:30.139Z,1636491210.139 [NAL9602](INFO): GPS fix at 20211109T205329: (36.802754, -121.786885) 2021-11-09T20:53:30.187Z,1636491210.187 [Default:CheckIn:Read_GPS] Stopped 2021-11-09T20:53:30.188Z,1636491210.188 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-09T20:53:37.920Z,1636491217.920 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211109T192939/Courier0046.lzma 2021-11-09T20:53:38.923Z,1636491218.923 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Courier0046.lzma.bak 2021-11-09T20:53:38.923Z,1636491218.923 [DataOverHttps](INFO): SBD MOMSN=16225407 2021-11-09T20:53:46.295Z,1636491226.295 [NAL9602](INFO): SBD MO Status=0, MOMSN=6626, MT Status=0, MTMSN=0 2021-11-09T20:53:46.295Z,1636491226.295 [NAL9602](INFO): No messages in MT queue 2021-11-09T20:53:54.836Z,1636491234.836 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20211109T192939/Express0047.lzma 2021-11-09T20:53:55.839Z,1636491235.839 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Express0047.lzma.bak 2021-11-09T20:53:55.839Z,1636491235.839 [DataOverHttps](INFO): SBD MOMSN=16225410 2021-11-09T20:53:57.210Z,1636491237.210 [Default:CheckIn:Read_Iridium] Stopped 2021-11-09T20:53:57.210Z,1636491237.210 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-09T20:53:57.210Z,1636491237.210 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-09T20:54:16.994Z,1636491256.994 [NAL9602](INFO): Not Powering down - fast GPS 2021-11-09T20:58:57.868Z,1636491537.868 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-09T20:58:57.868Z,1636491537.868 [Default:CheckIn:C.Wait] Stopped 2021-11-09T20:58:57.868Z,1636491537.868 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-09T20:58:57.869Z,1636491537.869 [Default:CheckIn:D] Running Loop=1 2021-11-09T20:58:58.281Z,1636491538.281 [Default:CheckIn:D] Stopped 2021-11-09T20:58:58.281Z,1636491538.281 [Default:CheckIn:E] Running Loop=1 2021-11-09T20:58:58.690Z,1636491538.690 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 85.172786 min 2021-11-09T20:58:58.690Z,1636491538.690 [Default:CheckIn:E] Stopped 2021-11-09T20:58:58.690Z,1636491538.690 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-09T20:58:58.690Z,1636491538.690 [Default:CheckIn] Stopped 2021-11-09T20:58:58.690Z,1636491538.690 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-09T20:58:58.690Z,1636491538.690 [Default:CheckIn](INFO): Running loop #15 2021-11-09T20:58:58.691Z,1636491538.691 [Default:CheckIn] Running Loop=15 2021-11-09T20:58:58.691Z,1636491538.691 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-09T20:58:58.691Z,1636491538.691 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-09T20:59:00.692Z,1636491540.692 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205859.00,A,3648.16421,N,12147.21434,W,0.058,0.00,091121,,,D*75 2021-11-09T20:59:00.695Z,1636491540.695 [NAL9602](INFO): GPS fix at 20211109T205859: (36.802737, -121.786906) 2021-11-09T20:59:00.735Z,1636491540.735 [Default:CheckIn:Read_GPS] Stopped 2021-11-09T20:59:00.735Z,1636491540.735 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-09T20:59:08.060Z,1636491548.060 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211109T192939/Courier0049.lzma 2021-11-09T20:59:09.063Z,1636491549.063 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Courier0049.lzma.bak 2021-11-09T20:59:09.063Z,1636491549.063 [DataOverHttps](INFO): SBD MOMSN=16225432 2021-11-09T20:59:10.792Z,1636491550.792 [NAL9602](INFO): SBD MO Status=0, MOMSN=6627, MT Status=0, MTMSN=0 2021-11-09T20:59:10.792Z,1636491550.792 [NAL9602](INFO): No messages in MT queue 2021-11-09T20:59:24.973Z,1636491564.973 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20211109T192939/Express0050.lzma 2021-11-09T20:59:25.975Z,1636491565.975 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Express0050.lzma.bak 2021-11-09T20:59:25.975Z,1636491565.975 [DataOverHttps](INFO): SBD MOMSN=16225438 2021-11-09T20:59:27.378Z,1636491567.378 [Default:CheckIn:Read_Iridium] Stopped 2021-11-09T20:59:27.379Z,1636491567.379 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-09T20:59:27.379Z,1636491567.379 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-09T20:59:41.499Z,1636491581.499 [NAL9602](INFO): Not Powering down - fast GPS 2021-11-09T21:04:27.770Z,1636491867.770 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-09T21:04:27.770Z,1636491867.770 [Default:CheckIn:C.Wait] Stopped 2021-11-09T21:04:27.770Z,1636491867.770 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-09T21:04:27.770Z,1636491867.770 [Default:CheckIn:D] Running Loop=1 2021-11-09T21:04:28.127Z,1636491868.127 [Default:CheckIn:D] Stopped 2021-11-09T21:04:28.127Z,1636491868.127 [Default:CheckIn:E] Running Loop=1 2021-11-09T21:04:28.541Z,1636491868.541 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 90.670207 min 2021-11-09T21:04:28.541Z,1636491868.541 [Default:CheckIn:E] Stopped 2021-11-09T21:04:28.541Z,1636491868.541 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-09T21:04:28.541Z,1636491868.541 [Default:CheckIn] Stopped 2021-11-09T21:04:28.541Z,1636491868.541 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-09T21:04:28.542Z,1636491868.542 [Default:CheckIn](INFO): Running loop #16 2021-11-09T21:04:28.542Z,1636491868.542 [Default:CheckIn] Running Loop=16 2021-11-09T21:04:28.542Z,1636491868.542 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-09T21:04:28.542Z,1636491868.542 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-09T21:04:30.528Z,1636491870.528 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210429.00,A,3648.16472,N,12147.21297,W,0.039,0.00,091121,,,D*74 2021-11-09T21:04:30.548Z,1636491870.548 [NAL9602](INFO): GPS fix at 20211109T210429: (36.802745, -121.786883) 2021-11-09T21:04:30.568Z,1636491870.568 [Default:CheckIn:Read_GPS] Stopped 2021-11-09T21:04:30.568Z,1636491870.568 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-09T21:04:41.528Z,1636491881.528 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20211109T192939/Courier0052.lzma 2021-11-09T21:04:42.531Z,1636491882.531 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Courier0052.lzma.bak 2021-11-09T21:04:42.531Z,1636491882.531 [DataOverHttps](INFO): SBD MOMSN=16225488 2021-11-09T21:04:54.088Z,1636491894.088 [NAL9602](INFO): SBD MO Status=2, MOMSN=6628, MT Status=2, MTMSN=0 2021-11-09T21:04:54.088Z,1636491894.088 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-11-09T21:04:59.296Z,1636491899.296 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20211109T192939/Express0053.lzma 2021-11-09T21:05:00.299Z,1636491900.299 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Express0053.lzma.bak 2021-11-09T21:05:00.299Z,1636491900.299 [DataOverHttps](INFO): SBD MOMSN=16225491 2021-11-09T21:05:01.770Z,1636491901.770 [Default:CheckIn:Read_Iridium] Stopped 2021-11-09T21:05:01.770Z,1636491901.770 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-09T21:05:01.770Z,1636491901.770 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-09T21:06:24.578Z,1636491984.578 [NAL9602](INFO): SBD MO Status=2, MOMSN=6628, MT Status=2, MTMSN=0 2021-11-09T21:06:24.578Z,1636491984.578 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-11-09T21:06:52.047Z,1636492012.047 [NAL9602](INFO): SBD MO Status=2, MOMSN=6628, MT Status=2, MTMSN=0 2021-11-09T21:06:52.048Z,1636492012.048 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-11-09T21:07:10.231Z,1636492030.231 [NAL9602](INFO): SBD MO Status=0, MOMSN=6628, MT Status=0, MTMSN=0 2021-11-09T21:07:10.232Z,1636492030.232 [NAL9602](INFO): No messages in MT queue 2021-11-09T21:07:40.936Z,1636492060.936 [NAL9602](INFO): Not Powering down - fast GPS 2021-11-09T21:10:02.408Z,1636492202.408 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-09T21:10:02.408Z,1636492202.408 [Default:CheckIn:C.Wait] Stopped 2021-11-09T21:10:02.408Z,1636492202.408 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-09T21:10:02.408Z,1636492202.408 [Default:CheckIn:D] Running Loop=1 2021-11-09T21:10:02.813Z,1636492202.813 [Default:CheckIn:D] Stopped 2021-11-09T21:10:02.814Z,1636492202.814 [Default:CheckIn:E] Running Loop=1 2021-11-09T21:10:03.223Z,1636492203.223 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 96.248324 min 2021-11-09T21:10:03.223Z,1636492203.223 [Default:CheckIn:E] Stopped 2021-11-09T21:10:03.223Z,1636492203.223 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-09T21:10:03.223Z,1636492203.223 [Default:CheckIn] Stopped 2021-11-09T21:10:03.223Z,1636492203.223 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-09T21:10:03.224Z,1636492203.224 [Default:CheckIn](INFO): Running loop #17 2021-11-09T21:10:03.224Z,1636492203.224 [Default:CheckIn] Running Loop=17 2021-11-09T21:10:03.224Z,1636492203.224 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-09T21:10:03.224Z,1636492203.224 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-09T21:10:05.236Z,1636492205.236 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211004.00,A,3648.16193,N,12147.20936,W,0.661,92.01,091121,,,D*44 2021-11-09T21:10:05.248Z,1636492205.248 [NAL9602](INFO): GPS fix at 20211109T211004: (36.802699, -121.786823) 2021-11-09T21:10:05.259Z,1636492205.259 [Default:CheckIn:Read_GPS] Stopped 2021-11-09T21:10:05.259Z,1636492205.259 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-09T21:10:12.960Z,1636492212.960 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20211109T192939/Courier0055.lzma 2021-11-09T21:10:13.963Z,1636492213.963 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Courier0055.lzma.bak 2021-11-09T21:10:13.963Z,1636492213.963 [DataOverHttps](INFO): SBD MOMSN=16225512 2021-11-09T21:10:29.944Z,1636492229.944 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20211109T192939/Express0056.lzma 2021-11-09T21:10:30.275Z,1636492230.275 [NAL9602](INFO): SBD MO Status=0, MOMSN=6629, MT Status=0, MTMSN=0 2021-11-09T21:10:30.276Z,1636492230.276 [NAL9602](INFO): No messages in MT queue 2021-11-09T21:10:30.947Z,1636492230.947 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Express0056.lzma.bak 2021-11-09T21:10:30.947Z,1636492230.947 [DataOverHttps](INFO): SBD MOMSN=16225516 2021-11-09T21:10:32.725Z,1636492232.725 [Default:CheckIn:Read_Iridium] Stopped 2021-11-09T21:10:32.726Z,1636492232.726 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-09T21:10:32.726Z,1636492232.726 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-09T21:11:01.058Z,1636492261.058 [NAL9602](INFO): Not Powering down - fast GPS 2021-11-09T21:15:33.425Z,1636492533.425 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-09T21:15:33.425Z,1636492533.425 [Default:CheckIn:C.Wait] Stopped 2021-11-09T21:15:33.425Z,1636492533.425 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-09T21:15:33.425Z,1636492533.425 [Default:CheckIn:D] Running Loop=1 2021-11-09T21:15:33.847Z,1636492533.847 [Default:CheckIn:D] Stopped 2021-11-09T21:15:33.847Z,1636492533.847 [Default:CheckIn:E] Running Loop=1 2021-11-09T21:15:34.230Z,1636492534.230 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 101.765177 min 2021-11-09T21:15:34.230Z,1636492534.230 [Default:CheckIn:E] Stopped 2021-11-09T21:15:34.230Z,1636492534.230 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-09T21:15:34.230Z,1636492534.230 [Default:CheckIn] Stopped 2021-11-09T21:15:34.230Z,1636492534.230 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-09T21:15:34.231Z,1636492534.231 [Default:CheckIn](INFO): Running loop #18 2021-11-09T21:15:34.231Z,1636492534.231 [Default:CheckIn] Running Loop=18 2021-11-09T21:15:34.231Z,1636492534.231 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-09T21:15:34.231Z,1636492534.231 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-09T21:15:36.243Z,1636492536.243 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211535.00,A,3648.50580,N,12147.21766,W,8.728,249.45,091121,,,D*7D 2021-11-09T21:15:36.245Z,1636492536.245 [NAL9602](INFO): GPS fix at 20211109T211535: (36.808430, -121.786961) 2021-11-09T21:15:36.257Z,1636492536.257 [Default:CheckIn:Read_GPS] Stopped 2021-11-09T21:15:36.257Z,1636492536.257 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-09T21:15:43.620Z,1636492543.620 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211109T192939/Courier0058.lzma 2021-11-09T21:15:44.623Z,1636492544.623 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Courier0058.lzma.bak 2021-11-09T21:15:44.623Z,1636492544.623 [DataOverHttps](INFO): SBD MOMSN=16225550 2021-11-09T21:15:50.376Z,1636492550.376 [NAL9602](INFO): SBD MO Status=0, MOMSN=6630, MT Status=0, MTMSN=0 2021-11-09T21:15:50.376Z,1636492550.376 [NAL9602](INFO): No messages in MT queue 2021-11-09T21:16:00.557Z,1636492560.557 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20211109T192939/Express0059.lzma 2021-11-09T21:16:01.559Z,1636492561.559 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Express0059.lzma.bak 2021-11-09T21:16:01.559Z,1636492561.559 [DataOverHttps](INFO): SBD MOMSN=16225553 2021-11-09T21:16:02.928Z,1636492562.928 [Default:CheckIn:Read_Iridium] Stopped 2021-11-09T21:16:02.928Z,1636492562.928 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-09T21:16:02.929Z,1636492562.929 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-09T21:16:21.078Z,1636492581.078 [NAL9602](INFO): Not Powering down - fast GPS 2021-11-09T21:21:03.392Z,1636492863.392 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-09T21:21:03.392Z,1636492863.392 [Default:CheckIn:C.Wait] Stopped 2021-11-09T21:21:03.392Z,1636492863.392 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-09T21:21:03.392Z,1636492863.392 [Default:CheckIn:D] Running Loop=1 2021-11-09T21:21:03.797Z,1636492863.797 [Default:CheckIn:D] Stopped 2021-11-09T21:21:03.797Z,1636492863.797 [Default:CheckIn:E] Running Loop=1 2021-11-09T21:21:04.201Z,1636492864.201 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 107.264714 min 2021-11-09T21:21:04.201Z,1636492864.201 [Default:CheckIn:E] Stopped 2021-11-09T21:21:04.201Z,1636492864.201 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-09T21:21:04.201Z,1636492864.201 [Default:CheckIn] Stopped 2021-11-09T21:21:04.201Z,1636492864.201 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-09T21:21:04.202Z,1636492864.202 [Default:CheckIn](INFO): Running loop #19 2021-11-09T21:21:04.202Z,1636492864.202 [Default:CheckIn] Running Loop=19 2021-11-09T21:21:04.202Z,1636492864.202 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-09T21:21:04.202Z,1636492864.202 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-09T21:21:06.211Z,1636492866.211 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212105.00,A,3648.32744,N,12148.43958,W,15.045,280.27,091121,,,D*4E 2021-11-09T21:21:06.214Z,1636492866.214 [NAL9602](INFO): GPS fix at 20211109T212105: (36.805457, -121.807326) 2021-11-09T21:21:06.249Z,1636492866.249 [Default:CheckIn:Read_GPS] Stopped 2021-11-09T21:21:06.249Z,1636492866.249 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-09T21:21:14.195Z,1636492874.195 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211109T192939/Courier0061.lzma 2021-11-09T21:21:15.197Z,1636492875.197 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Courier0061.lzma.bak 2021-11-09T21:21:15.198Z,1636492875.198 [DataOverHttps](INFO): SBD MOMSN=16225575 2021-11-09T21:21:17.528Z,1636492877.528 [NAL9602](INFO): SBD MO Status=0, MOMSN=6631, MT Status=0, MTMSN=0 2021-11-09T21:21:17.528Z,1636492877.528 [NAL9602](INFO): No messages in MT queue 2021-11-09T21:21:34.951Z,1636492894.951 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20211109T192939/Express0062.lzma 2021-11-09T21:21:35.953Z,1636492895.953 [DataOverHttps](INFO): Moved sent file to Logs/20211109T192939/Express0062.lzma.bak 2021-11-09T21:21:35.954Z,1636492895.954 [DataOverHttps](INFO): SBD MOMSN=16225583 2021-11-09T21:21:37.739Z,1636492897.739 [Default:CheckIn:Read_Iridium] Stopped 2021-11-09T21:21:37.739Z,1636492897.739 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-09T21:21:37.739Z,1636492897.739 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-09T21:21:48.230Z,1636492908.230 [NAL9602](INFO): Not Powering down - fast GPS 2021-11-09T21:25:41.092Z,1636493141.092 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2021-11-09T21:25:49.124Z,1636493149.124 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.766846 2021-11-09T21:26:38.358Z,1636493198.358 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-09T21:26:38.358Z,1636493198.358 [Default:CheckIn:C.Wait] Stopped 2021-11-09T21:26:38.358Z,1636493198.358 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-09T21:26:38.358Z,1636493198.358 [Default:CheckIn:D] Running Loop=1 2021-11-09T21:26:38.772Z,1636493198.772 [Default:CheckIn:D] Stopped 2021-11-09T21:26:38.772Z,1636493198.772 [Default:CheckIn:E] Running Loop=1 2021-11-09T21:26:39.164Z,1636493199.164 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 112.847624 min 2021-11-09T21:26:39.164Z,1636493199.164 [Default:CheckIn:E] Stopped 2021-11-09T21:26:39.165Z,1636493199.165 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-09T21:26:39.165Z,1636493199.165 [Default:CheckIn] Stopped 2021-11-09T21:26:39.165Z,1636493199.165 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-09T21:26:39.165Z,1636493199.165 [Default:CheckIn](INFO): Running loop #20 2021-11-09T21:26:39.165Z,1636493199.165 [Default:CheckIn] Running Loop=20 2021-11-09T21:26:39.165Z,1636493199.165 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-09T21:26:39.165Z,1636493199.165 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-09T21:26:41.179Z,1636493201.179 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212640.00,A,3648.44543,N,12148.89621,W,0.544,169.96,091121,,,A*70 2021-11-09T21:26:41.181Z,1636493201.181 [NAL9602](INFO): GPS fix at 20211109T212640: (36.807424, -121.814937) 2021-11-09T21:26:41.193Z,1636493201.193 [Default:CheckIn:Read_GPS] Stopped 2021-11-09T21:26:41.194Z,1636493201.194 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-09T21:26:50.982Z,1636493210.982 [NAL9602](INFO): SBD MO Status=1, MOMSN=6632, MT Status=0, MTMSN=0 2021-11-09T21:26:51.028Z,1636493211.028 [NAL9602](INFO): Sent 71 bytes from file Logs/20211109T192939/Courier0064.lzma 2021-11-09T21:26:51.028Z,1636493211.028 [NAL9602](INFO): Packets left to send: 0 2021-11-09T21:26:51.384Z,1636493211.384 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-11-09T21:26:58.866Z,1636493218.866 [NAL9602](INFO): SBD MO Status=1, MOMSN=6633, MT Status=0, MTMSN=0 2021-11-09T21:26:58.916Z,1636493218.916 [NAL9602](INFO): Sent 145 bytes from file Logs/20211109T192939/Express0065.lzma 2021-11-09T21:26:58.916Z,1636493218.916 [NAL9602](INFO): Packets left to send: 0 2021-11-09T21:27:08.187Z,1636493228.187 [NAL9602](INFO): SBD MO Status=0, MOMSN=6634, MT Status=0, MTMSN=0 2021-11-09T21:27:08.278Z,1636493228.278 [Default:CheckIn:Read_Iridium] Stopped 2021-11-09T21:27:08.278Z,1636493228.278 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-09T21:27:08.278Z,1636493228.278 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-09T21:27:26.524Z,1636493246.524 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-11-09T21:27:38.936Z,1636493258.936 [NAL9602](INFO): Not Powering down - fast GPS 2021-11-09T21:27:41.565Z,1636493261.565 [DataOverHttps](IMPORTANT): SBD MTMSN=20211109T212740 2021-11-09T21:27:41.568Z,1636493261.568 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003186