2021-12-07T15:07:46.628Z,1638889666.628 [Supervisor](DEBUG): Initializing supervisor. 2021-12-07T15:07:46.632Z,1638889666.632 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2021-12-07T15:07:46.633Z,1638889666.633 [SyncHandler](INFO): Protected caller Thread ID is 836 2021-12-07T15:07:46.633Z,1638889666.633 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2021-12-07T15:07:46.634Z,1638889666.634 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2021-12-07T15:07:46.635Z,1638889666.635 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 837 2021-12-07T15:07:46.639Z,1638889666.639 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2021-12-07T15:07:46.657Z,1638889666.657 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2021-12-07T15:07:46.658Z,1638889666.658 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2021-12-07T15:07:46.658Z,1638889666.658 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 838 2021-12-07T15:07:46.663Z,1638889666.663 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2021-12-07T15:07:46.664Z,1638889666.664 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2021-12-07T15:07:46.664Z,1638889666.664 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 839 2021-12-07T15:07:46.666Z,1638889666.666 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2021-12-07T15:07:46.667Z,1638889666.667 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2021-12-07T15:07:46.668Z,1638889666.668 [logger ThreadHandler](INFO): Protected caller Thread ID is 840 2021-12-07T15:07:46.671Z,1638889666.671 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2021-12-07T15:07:46.672Z,1638889666.672 [Supervisor](INFO): Looking for Config files in directory: Config/ 2021-12-07T15:07:46.675Z,1638889666.675 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2021-12-07T15:07:46.772Z,1638889666.772 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2021-12-07T15:07:46.774Z,1638889666.774 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2021-12-07T15:07:47.372Z,1638889667.372 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2021-12-07T15:07:47.374Z,1638889667.374 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2021-12-07T15:07:47.586Z,1638889667.586 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2021-12-07T15:07:47.588Z,1638889667.588 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2021-12-07T15:07:47.667Z,1638889667.667 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2021-12-07T15:07:47.790Z,1638889667.790 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2021-12-07T15:07:47.791Z,1638889667.791 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2021-12-07T15:07:47.874Z,1638889667.874 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2021-12-07T15:07:47.980Z,1638889667.980 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2021-12-07T15:07:47.982Z,1638889667.982 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2021-12-07T15:07:48.338Z,1638889668.338 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2021-12-07T15:07:48.338Z,1638889668.338 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2021-12-07T15:07:48.943Z,1638889668.943 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2021-12-07T15:07:48.945Z,1638889668.945 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2021-12-07T15:07:49.094Z,1638889669.094 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2021-12-07T15:07:49.095Z,1638889669.095 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2021-12-07T15:07:49.283Z,1638889669.283 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2021-12-07T15:07:49.283Z,1638889669.283 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2021-12-07T15:07:49.984Z,1638889669.984 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2021-12-07T15:07:49.985Z,1638889669.985 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2021-12-07T15:07:50.221Z,1638889670.221 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2021-12-07T15:07:50.223Z,1638889670.223 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2021-12-07T15:07:50.424Z,1638889670.424 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2021-12-07T15:07:50.425Z,1638889670.425 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2021-12-07T15:07:50.774Z,1638889670.774 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2021-12-07T15:07:50.776Z,1638889670.776 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2021-12-07T15:07:51.113Z,1638889671.113 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2021-12-07T15:07:51.115Z,1638889671.115 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/ 2021-12-07T15:07:51.118Z,1638889671.118 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg 2021-12-07T15:07:51.202Z,1638889671.202 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg 2021-12-07T15:07:51.353Z,1638889671.353 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg 2021-12-07T15:07:51.461Z,1638889671.461 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg 2021-12-07T15:07:51.546Z,1638889671.546 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg 2021-12-07T15:07:51.640Z,1638889671.640 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg 2021-12-07T15:07:51.826Z,1638889671.826 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg 2021-12-07T15:07:52.083Z,1638889672.083 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2021-12-07T15:07:52.084Z,1638889672.084 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg 2021-12-07T15:07:52.177Z,1638889672.177 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg 2021-12-07T15:07:52.276Z,1638889672.276 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg 2021-12-07T15:07:52.413Z,1638889672.413 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg 2021-12-07T15:07:52.512Z,1638889672.512 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/root/ 2021-12-07T15:07:52.513Z,1638889672.513 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2021-12-07T15:07:52.526Z,1638889672.526 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2021-12-07T15:07:52.647Z,1638889672.647 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2021-12-07T15:07:52.649Z,1638889672.649 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2021-12-07T15:07:52.720Z,1638889672.720 [VerticalControl](DEBUG): Construct VerticalControl. 2021-12-07T15:07:52.783Z,1638889672.783 [VerticalControl] Loaded 2021-12-07T15:07:52.783Z,1638889672.783 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2021-12-07T15:07:52.786Z,1638889672.786 [HorizontalControl](DEBUG): Construct HorizontalControl. 2021-12-07T15:07:52.825Z,1638889672.825 [HorizontalControl] Loaded 2021-12-07T15:07:52.825Z,1638889672.825 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2021-12-07T15:07:52.827Z,1638889672.827 [SpeedControl](DEBUG): Construct SpeedControl. 2021-12-07T15:07:52.831Z,1638889672.831 [SpeedControl] Loaded 2021-12-07T15:07:52.831Z,1638889672.831 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2021-12-07T15:07:52.833Z,1638889672.833 [LoopControl](DEBUG): Construct LoopControl. 2021-12-07T15:07:52.834Z,1638889672.834 [LoopControl] Loaded 2021-12-07T15:07:52.834Z,1638889672.834 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2021-12-07T15:07:52.835Z,1638889672.835 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2021-12-07T15:07:52.837Z,1638889672.837 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2021-12-07T15:07:52.897Z,1638889672.897 [DepthRateCalculator] Loaded 2021-12-07T15:07:52.897Z,1638889672.897 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2021-12-07T15:07:52.902Z,1638889672.902 [PitchRateCalculator] Loaded 2021-12-07T15:07:52.902Z,1638889672.902 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2021-12-07T15:07:52.912Z,1638889672.912 [SpeedCalculator] Loaded 2021-12-07T15:07:52.912Z,1638889672.912 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2021-12-07T15:07:52.926Z,1638889672.926 [TempGradientCalculator] Loaded 2021-12-07T15:07:52.926Z,1638889672.926 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2021-12-07T15:07:52.931Z,1638889672.931 [YawRateCalculator] Loaded 2021-12-07T15:07:52.931Z,1638889672.931 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2021-12-07T15:07:52.948Z,1638889672.948 [ElevatorOffsetCalculator] Loaded 2021-12-07T15:07:52.949Z,1638889672.949 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2021-12-07T15:07:52.949Z,1638889672.949 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2021-12-07T15:07:52.950Z,1638889672.950 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2021-12-07T15:07:52.994Z,1638889672.994 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2021-12-07T15:07:52.996Z,1638889672.996 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2021-12-07T15:07:53.078Z,1638889673.078 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2021-12-07T15:07:53.079Z,1638889673.079 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2021-12-07T15:07:53.458Z,1638889673.458 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2021-12-07T15:07:53.460Z,1638889673.460 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2021-12-07T15:07:53.600Z,1638889673.600 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2021-12-07T15:07:53.601Z,1638889673.601 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2021-12-07T15:07:54.319Z,1638889674.319 [AHRS_M2] Loaded 2021-12-07T15:07:54.320Z,1638889674.320 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2021-12-07T15:07:54.583Z,1638889674.583 [BackseatComponent] Loaded 2021-12-07T15:07:54.583Z,1638889674.583 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2021-12-07T15:07:54.584Z,1638889674.584 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 409474E0 2021-12-07T15:07:54.585Z,1638889674.585 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 923 2021-12-07T15:07:54.588Z,1638889674.588 [LcmUniversalReporter] Loaded 2021-12-07T15:07:54.588Z,1638889674.588 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2021-12-07T15:07:55.366Z,1638889675.366 [BPC1] Loaded 2021-12-07T15:07:55.366Z,1638889675.366 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2021-12-07T15:07:55.505Z,1638889675.505 [DataOverHttps] Loaded 2021-12-07T15:07:55.505Z,1638889675.505 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2021-12-07T15:07:55.506Z,1638889675.506 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409774E0 2021-12-07T15:07:55.507Z,1638889675.507 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 924 2021-12-07T15:07:55.527Z,1638889675.527 [Depth_Keller] Loaded 2021-12-07T15:07:55.527Z,1638889675.527 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2021-12-07T15:07:55.531Z,1638889675.531 [DropWeight] Loaded 2021-12-07T15:07:55.532Z,1638889675.532 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2021-12-07T15:07:55.591Z,1638889675.591 [NAL9602] Loaded 2021-12-07T15:07:55.591Z,1638889675.591 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2021-12-07T15:07:55.620Z,1638889675.620 [Onboard] Loaded 2021-12-07T15:07:55.620Z,1638889675.620 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2021-12-07T15:07:55.621Z,1638889675.621 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409A74E0 2021-12-07T15:07:55.622Z,1638889675.622 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 925 2021-12-07T15:07:55.634Z,1638889675.634 [Power24vConverter] Loaded 2021-12-07T15:07:55.635Z,1638889675.635 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2021-12-07T15:07:55.647Z,1638889675.647 [Radio_Surface] Loaded 2021-12-07T15:07:55.648Z,1638889675.648 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2021-12-07T15:07:55.649Z,1638889675.649 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409D74E0 2021-12-07T15:07:55.649Z,1638889675.649 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 926 2021-12-07T15:07:55.691Z,1638889675.691 [RDI_Pathfinder] Loaded 2021-12-07T15:07:55.692Z,1638889675.692 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread. 2021-12-07T15:07:55.773Z,1638889675.773 [DAT] Loaded 2021-12-07T15:07:55.774Z,1638889675.774 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2021-12-07T15:07:55.774Z,1638889675.774 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2021-12-07T15:07:55.775Z,1638889675.775 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2021-12-07T15:07:56.034Z,1638889676.034 [DeadReckonUsingMultipleVelocitySources] Loaded 2021-12-07T15:07:56.035Z,1638889676.035 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2021-12-07T15:07:56.048Z,1638889676.048 [NavChart] Loaded 2021-12-07T15:07:56.048Z,1638889676.048 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2021-12-07T15:07:56.054Z,1638889676.054 [UniversalFixResidualReporter] Loaded 2021-12-07T15:07:56.054Z,1638889676.054 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2021-12-07T15:07:56.055Z,1638889676.055 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2021-12-07T15:07:56.590Z,1638889676.590 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2021-12-07T15:07:57.011Z,1638889677.011 [SBIT](DEBUG): Construct Startup Built In Test. 2021-12-07T15:07:57.020Z,1638889677.020 [SBIT] Loaded 2021-12-07T15:07:57.020Z,1638889677.020 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2021-12-07T15:07:57.023Z,1638889677.023 [IBIT](DEBUG): Construct Initiated Built In Test. 2021-12-07T15:07:57.037Z,1638889677.037 [IBIT] Loaded 2021-12-07T15:07:57.037Z,1638889677.037 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2021-12-07T15:07:57.043Z,1638889677.043 [CBIT](DEBUG): Construct Continuous Built In Test. 2021-12-07T15:07:57.143Z,1638889677.143 [CBIT] Loaded 2021-12-07T15:07:57.143Z,1638889677.143 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2021-12-07T15:07:57.144Z,1638889677.144 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2021-12-07T15:07:57.144Z,1638889677.144 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2021-12-07T15:07:57.303Z,1638889677.303 [BuoyancyServo] Loaded 2021-12-07T15:07:57.304Z,1638889677.304 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2021-12-07T15:07:57.323Z,1638889677.323 [ElevatorServo] Loaded 2021-12-07T15:07:57.324Z,1638889677.324 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2021-12-07T15:07:57.343Z,1638889677.343 [MassServo] Loaded 2021-12-07T15:07:57.343Z,1638889677.343 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2021-12-07T15:07:57.362Z,1638889677.362 [RudderServo] Loaded 2021-12-07T15:07:57.362Z,1638889677.362 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2021-12-07T15:07:57.381Z,1638889677.381 [ThrusterServo] Loaded 2021-12-07T15:07:57.381Z,1638889677.381 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2021-12-07T15:07:57.381Z,1638889677.381 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2021-12-07T15:07:57.382Z,1638889677.382 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2021-12-07T15:07:57.399Z,1638889677.399 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2021-12-07T15:07:57.399Z,1638889677.399 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2021-12-07T15:07:57.621Z,1638889677.621 [CTD_Seabird] Loaded 2021-12-07T15:07:57.622Z,1638889677.622 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2021-12-07T15:07:57.623Z,1638889677.623 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B104E0 2021-12-07T15:07:57.624Z,1638889677.624 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 927 2021-12-07T15:07:57.644Z,1638889677.644 [PAR_Licor] Loaded 2021-12-07T15:07:57.644Z,1638889677.644 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2021-12-07T15:07:57.676Z,1638889677.676 [WetLabsBB2FL] Loaded 2021-12-07T15:07:57.677Z,1638889677.677 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2021-12-07T15:07:57.678Z,1638889677.678 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B404E0 2021-12-07T15:07:57.678Z,1638889677.678 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 928 2021-12-07T15:07:57.698Z,1638889677.698 [WetLabsUBAT] Loaded 2021-12-07T15:07:57.699Z,1638889677.699 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread. 2021-12-07T15:07:57.700Z,1638889677.700 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40B704E0 2021-12-07T15:07:57.700Z,1638889677.700 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 929 2021-12-07T15:07:57.701Z,1638889677.701 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2021-12-07T15:07:57.707Z,1638889677.707 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2021-12-07T15:07:57.710Z,1638889677.710 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2021-12-07T15:07:57.721Z,1638889677.721 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2021-12-07T15:07:57.722Z,1638889677.722 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BA04E0 2021-12-07T15:07:57.722Z,1638889677.722 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 930 2021-12-07T15:07:57.727Z,1638889677.727 [Supervisor](INFO): Main Thread ID is 830 2021-12-07T15:07:57.727Z,1638889677.727 [Supervisor](DEBUG): Running supervisor. 2021-12-07T15:07:57.728Z,1638889677.728 [CommandExec ThreadHandler](INFO): Handler Thread ID is 931 2021-12-07T15:07:57.728Z,1638889677.728 [CommandExec](INFO): Initializing the command executive. 2021-12-07T15:07:57.730Z,1638889677.730 [CommandLine ThreadHandler](INFO): Handler Thread ID is 932 2021-12-07T15:07:57.732Z,1638889677.732 [controlThread ThreadHandler](INFO): Handler Thread ID is 933 2021-12-07T15:07:57.732Z,1638889677.732 [controlThread](DEBUG): Initializing ControlThread 2021-12-07T15:07:57.733Z,1638889677.733 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2021-12-07T15:07:57.736Z,1638889677.736 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2021-12-07T15:07:57.737Z,1638889677.737 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2021-12-07T15:07:57.737Z,1638889677.737 [LoopControl](DEBUG): Initialize LoopControlComponent. 2021-12-07T15:07:57.738Z,1638889677.738 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2021-12-07T15:07:57.738Z,1638889677.738 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2021-12-07T15:07:57.738Z,1638889677.738 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2021-12-07T15:07:57.739Z,1638889677.739 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2021-12-07T15:07:57.739Z,1638889677.739 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2021-12-07T15:07:57.740Z,1638889677.740 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2021-12-07T15:07:57.745Z,1638889677.745 [NavChart](DEBUG): Initialize NavChart Navigation. 2021-12-07T15:07:57.745Z,1638889677.745 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2021-12-07T15:07:57.746Z,1638889677.746 [SBIT](INFO): Initialize SBIT Component. 2021-12-07T15:07:57.746Z,1638889677.746 [SBIT](IMPORTANT): git: 2021-11-29 2021-12-07T15:07:57.747Z,1638889677.747 [SBIT](INFO): git hash: f462e1af5d4560b0531ff1e41adede0f51e7b106 2021-12-07T15:07:57.747Z,1638889677.747 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2021-12-07T15:07:57.748Z,1638889677.748 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019 Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021 2021-12-07T15:07:57.749Z,1638889677.749 [SBIT](INFO): Beginning SBIT in 52.000000 seconds. 2021-12-07T15:07:57.750Z,1638889677.750 [IBIT](INFO): Initialize IBIT Component. 2021-12-07T15:07:57.751Z,1638889677.751 [CBIT](DEBUG): Initialize CBIT Component. 2021-12-07T15:07:57.752Z,1638889677.752 [logger ThreadHandler](INFO): Handler Thread ID is 934 2021-12-07T15:07:57.762Z,1638889677.762 [CBIT](DEBUG): Initialized mux pins. 2021-12-07T15:07:57.762Z,1638889677.762 [CBIT](DEBUG): Initializing the watchdog timer. 2021-12-07T15:07:57.771Z,1638889677.771 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 935 2021-12-07T15:07:57.783Z,1638889677.783 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 936 2021-12-07T15:07:57.784Z,1638889677.784 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2021-12-07T15:07:57.786Z,1638889677.786 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2021-12-07T15:07:57.787Z,1638889677.787 [CBIT](DEBUG): Initializing heartbeat. 2021-12-07T15:07:57.795Z,1638889677.795 [Onboard ThreadHandler](INFO): Handler Thread ID is 937 2021-12-07T15:07:57.812Z,1638889677.812 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 938 2021-12-07T15:07:57.831Z,1638889677.831 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 939 2021-12-07T15:07:57.831Z,1638889677.831 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2021-12-07T15:07:57.836Z,1638889677.836 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 941 2021-12-07T15:07:57.839Z,1638889677.839 [WetLabsBB2FL](INFO): Powering up 2021-12-07T15:07:57.840Z,1638889677.840 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 943 2021-12-07T15:07:57.843Z,1638889677.843 [WetLabsUBAT](INFO): Powering up 2021-12-07T15:07:57.844Z,1638889677.844 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 945 2021-12-07T15:07:57.853Z,1638889677.853 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2021-12-07T15:07:57.853Z,1638889677.853 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2021-12-07T15:07:57.854Z,1638889677.854 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2021-12-07T15:07:57.854Z,1638889677.854 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2021-12-07T15:07:57.854Z,1638889677.854 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2021-12-07T15:07:57.854Z,1638889677.854 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2021-12-07T15:07:57.854Z,1638889677.854 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2021-12-07T15:07:57.855Z,1638889677.855 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2021-12-07T15:07:57.855Z,1638889677.855 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2021-12-07T15:07:57.855Z,1638889677.855 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2021-12-07T15:07:57.855Z,1638889677.855 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2021-12-07T15:07:57.855Z,1638889677.855 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2021-12-07T15:07:57.856Z,1638889677.856 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2021-12-07T15:07:57.856Z,1638889677.856 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2021-12-07T15:07:57.856Z,1638889677.856 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2021-12-07T15:07:57.856Z,1638889677.856 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2021-12-07T15:07:57.858Z,1638889677.858 [CBIT](DEBUG): Deactivating GF circuits. 2021-12-07T15:07:57.858Z,1638889677.858 [CBIT](DEBUG): Deactivating emergency mode. 2021-12-07T15:07:57.894Z,1638889677.894 [CBIT](DEBUG): Backplane powered. 2021-12-07T15:07:57.899Z,1638889677.899 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2021-12-07T15:07:57.940Z,1638889677.940 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2021-12-07T15:07:57.956Z,1638889677.956 [MissionManager](DEBUG): 2021-12-07T15:07:57.956Z,1638889677.956 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2021-12-07T15:07:58.047Z,1638889678.047 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2021-12-07T15:07:58.048Z,1638889678.048 [Default:A.Wait](DEBUG): Construct Wait. 2021-12-07T15:07:58.059Z,1638889678.059 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2021-12-07T15:07:58.107Z,1638889678.107 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2021-12-07T15:07:58.109Z,1638889678.109 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2021-12-07T15:07:58.136Z,1638889678.136 [Default:E.Execute](DEBUG): Construct Execute. 2021-12-07T15:07:58.150Z,1638889678.150 [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-12-07T15:07:58.159Z,1638889678.159 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,RDI_Pathfinder,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,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2021-12-07T15:07:58.191Z,1638889678.191 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2021-12-07T15:07:58.226Z,1638889678.226 [Radio_Surface](INFO): Powering up 2021-12-07T15:07:58.349Z,1638889678.349 [Power24vConverter](INFO): Powering up. 2021-12-07T15:07:58.356Z,1638889678.356 [DAT](INFO): Powering up 2021-12-07T15:07:58.356Z,1638889678.356 [DAT](DEBUG): Initializing DAT. 2021-12-07T15:07:58.455Z,1638889678.455 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2021-12-07T15:07:58.463Z,1638889678.463 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2021-12-07T15:07:58.464Z,1638889678.464 [ElevatorServo](DEBUG): Initializing EZServoServo. 2021-12-07T15:07:58.471Z,1638889678.471 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2021-12-07T15:07:58.472Z,1638889678.472 [MassServo](DEBUG): Initializing EZServoServo. 2021-12-07T15:07:58.479Z,1638889678.479 [MassServo](DEBUG): Initializing MassServo. 2021-12-07T15:07:58.479Z,1638889678.479 [RudderServo](DEBUG): Initializing EZServoServo. 2021-12-07T15:07:58.487Z,1638889678.487 [RudderServo](DEBUG): Initializing RudderServo. 2021-12-07T15:07:58.488Z,1638889678.488 [ThrusterServo](DEBUG): Initializing EZServoServo. 2021-12-07T15:07:58.495Z,1638889678.495 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2021-12-07T15:07:59.306Z,1638889679.306 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2021-12-07T15:07:59.307Z,1638889679.307 [RudderServo](FAULT): Rudder failed to initialize 2021-12-07T15:07:59.307Z,1638889679.307 [RudderServo] Communications Fault, FailCount= 1 2021-12-07T15:07:59.307Z,1638889679.307 [RudderServo](ERROR): Communications Fault 2021-12-07T15:07:59.407Z,1638889679.407 [CBIT](ERROR): Communications Fault in component: RudderServo 2021-12-07T15:07:59.576Z,1638889679.576 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2021-12-07T15:07:59.576Z,1638889679.576 [RudderServo](INFO): Powering down 2021-12-07T15:08:00.243Z,1638889680.243 [RudderServo](DEBUG): Initializing EZServoServo. 2021-12-07T15:08:00.363Z,1638889680.363 [RudderServo](DEBUG): Initializing RudderServo. 2021-12-07T15:08:00.368Z,1638889680.368 [CBIT](INFO): Clearing failed state for component RudderServo 2021-12-07T15:08:00.368Z,1638889680.368 [RudderServo] No Fault, FailCount= 1 2021-12-07T15:08:00.450Z,1638889680.450 [WetLabsBB2FL](INFO): Powering down 2021-12-07T15:08:07.163Z,1638889687.163 [WetLabsUBAT](INFO): Powering down 2021-12-07T15:08:12.755Z,1638889692.755 [DAT](INFO): commRate: 800 2021-12-07T15:08:14.773Z,1638889694.773 [DAT](INFO): entering command mode 2021-12-07T15:08:15.177Z,1638889695.177 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:15.581Z,1638889695.581 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:16.067Z,1638889696.067 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:16.389Z,1638889696.389 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:16.793Z,1638889696.793 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:17.200Z,1638889697.200 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:17.601Z,1638889697.601 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:18.030Z,1638889698.030 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:18.409Z,1638889698.409 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:18.813Z,1638889698.813 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:19.217Z,1638889699.217 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:19.621Z,1638889699.621 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:20.058Z,1638889700.058 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:20.429Z,1638889700.429 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:20.833Z,1638889700.833 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:21.244Z,1638889701.244 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:21.641Z,1638889701.641 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:22.094Z,1638889702.094 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:22.449Z,1638889702.449 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:22.857Z,1638889702.857 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:23.257Z,1638889703.257 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:23.661Z,1638889703.661 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:24.121Z,1638889704.121 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:24.477Z,1638889704.477 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:24.885Z,1638889704.885 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:25.277Z,1638889705.277 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:25.680Z,1638889705.680 [NAL9602](INFO): Powering up NAL9602 2021-12-07T15:08:25.682Z,1638889705.682 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:26.121Z,1638889706.121 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:26.495Z,1638889706.495 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:26.893Z,1638889706.893 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:27.297Z,1638889707.297 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:27.701Z,1638889707.701 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:28.145Z,1638889708.145 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:28.509Z,1638889708.509 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:28.913Z,1638889708.913 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:29.317Z,1638889709.317 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:29.729Z,1638889709.729 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:30.166Z,1638889710.166 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-07T15:08:30.166Z,1638889710.166 [DAT](FAULT): failed to enter command mode 2021-12-07T15:08:30.529Z,1638889710.529 [DAT](INFO): entering command mode 2021-12-07T15:08:30.934Z,1638889710.934 [DAT](INFO): setting verbose to 3 2021-12-07T15:08:31.338Z,1638889711.338 [DAT](INFO): set verbose to 3 2021-12-07T15:08:31.339Z,1638889711.339 [DAT](INFO): setting DatVerbose to 27440 2021-12-07T15:08:31.749Z,1638889711.749 [DAT](INFO): set DatVerbose to 27440 2021-12-07T15:08:31.750Z,1638889711.750 [DAT](INFO): setting transmit power to 8 2021-12-07T15:08:32.182Z,1638889712.182 [DAT](INFO): set transmit power to 8 2021-12-07T15:08:32.183Z,1638889712.183 [DAT](INFO): setting local address to 9 2021-12-07T15:08:32.550Z,1638889712.550 [DAT](INFO): set local address to 9 2021-12-07T15:08:36.595Z,1638889716.595 [NAL9602](INFO): NAL9602 initialized 2021-12-07T15:08:50.414Z,1638889730.414 [SBIT](IMPORTANT): Beginning Startup BIT 2021-12-07T15:08:50.434Z,1638889730.434 [CBIT](IMPORTANT): Beginning ground fault scan 2021-12-07T15:09:01.712Z,1638889741.712 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.010327 CHAN A1 (24V): 0.000094 CHAN A2 (12V): -0.007517 CHAN A3 (5V): -0.002187 CHAN B0 (3.3V): 0.000140 CHAN B1 (3.15aV): -0.000557 CHAN B2 (3.15bV): 0.000675 CHAN B3 (GND): 0.002142 OPEN: -0.003481 Full Scale: +/- 1 mA 2021-12-07T15:09:30.378Z,1638889770.378 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-07T15:09:44.479Z,1638889784.479 [SBIT](IMPORTANT): SBIT PASSED 2021-12-07T15:09:44.479Z,1638889784.479 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2021-12-07T15:09:44.480Z,1638889784.480 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count; 2021-12-07T15:09:44.480Z,1638889784.480 [SBIT](IMPORTANT): CBIT.gf24Offset=143 microampere; 2021-12-07T15:09:44.481Z,1638889784.481 [SBIT](IMPORTANT): DAT.baud=115200 bit_per_second; 2021-12-07T15:09:44.481Z,1638889784.481 [SBIT](IMPORTANT): DAT.loadAtStartup=1 bool; 2021-12-07T15:09:44.481Z,1638889784.481 [SBIT](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 0.300000 liter_per_second; 2021-12-07T15:09:44.481Z,1638889784.481 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=24 ampere_hour; 2021-12-07T15:09:44.481Z,1638889784.481 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=13 volt; 2021-12-07T15:09:44.481Z,1638889784.481 [SBIT](IMPORTANT): Power24vConverter.simulateHardware=0 bool; 2021-12-07T15:09:44.481Z,1638889784.481 [SBIT](IMPORTANT): RDI_Pathfinder.loadAtStartup=1 bool; 2021-12-07T15:09:44.481Z,1638889784.481 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=228.666848 cubic_centimeter; 2021-12-07T15:09:44.482Z,1638889784.482 [SBIT](IMPORTANT): VerticalControl.massDefault=8.215154 millimeter; 2021-12-07T15:09:44.885Z,1638889784.885 [MissionManager](IMPORTANT): Started mission Startup 2021-12-07T15:09:44.885Z,1638889784.885 [Startup] Running Loop=1 2021-12-07T15:09:44.885Z,1638889784.885 [Startup](DEBUG): Aggregate::initialize Startup 2021-12-07T15:09:44.885Z,1638889784.885 [Startup:A.GoToSurface] Running Loop=1 2021-12-07T15:09:44.885Z,1638889784.885 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2021-12-07T15:09:44.886Z,1638889784.886 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2021-12-07T15:09:44.887Z,1638889784.887 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2021-12-07T15:09:44.887Z,1638889784.887 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2021-12-07T15:09:44.887Z,1638889784.887 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2021-12-07T15:09:44.888Z,1638889784.888 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2021-12-07T15:09:44.889Z,1638889784.889 [Startup:StartupSatComms] Running Loop=1 2021-12-07T15:09:44.889Z,1638889784.889 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2021-12-07T15:09:44.890Z,1638889784.890 [Startup:StartupSatComms:A] Running Loop=1 2021-12-07T15:09:45.298Z,1638889785.298 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2021-12-07T15:10:30.885Z,1638889830.885 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005064 2021-12-07T15:10:44.987Z,1638889844.987 [Startup:StartupSatComms:A](INFO): Timed out from 2021-12-07T15:09:44.9Z 2021-12-07T15:10:44.987Z,1638889844.987 [Startup:StartupSatComms:A] Stopped 2021-12-07T15:10:44.987Z,1638889844.987 [Startup:StartupSatComms:B] Running Loop=1 2021-12-07T15:10:45.298Z,1638889845.298 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2021-12-07T15:10:48.497Z,1638889848.497 [CommandExec](IMPORTANT): got command burn on 2021-12-07T15:10:48.497Z,1638889848.497 [CommandExec](IMPORTANT): Activating dropweight wire 2021-12-07T15:10:52.300Z,1638889852.300 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20211207T150746/Courier0000.lzma 2021-12-07T15:10:53.302Z,1638889853.302 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Courier0000.lzma.bak 2021-12-07T15:10:53.302Z,1638889853.302 [DataOverHttps](INFO): SBD MOMSN=16334662 2021-12-07T15:10:57.846Z,1638889857.846 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2021-12-07T15:10:57.846Z,1638889857.846 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T15:10:57.882Z,1638889857.882 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T15:10:58.252Z,1638889858.252 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T15:10:58.252Z,1638889858.252 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2021-12-07T15:11:09.486Z,1638889869.486 [DataOverHttps](INFO): Sending 953 bytes from file Logs/20211207T150746/Express0001.lzma 2021-12-07T15:11:10.486Z,1638889870.486 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Express0001.lzma.bak 2021-12-07T15:11:10.486Z,1638889870.486 [DataOverHttps](INFO): SBD MOMSN=16334665 2021-12-07T15:11:11.544Z,1638889871.544 [Startup:StartupSatComms:B] Stopped 2021-12-07T15:11:11.545Z,1638889871.545 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2021-12-07T15:11:11.545Z,1638889871.545 [Startup:StartupSatComms] Stopped 2021-12-07T15:11:11.545Z,1638889871.545 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2021-12-07T15:11:11.546Z,1638889871.546 [Startup](INFO): Completed Startup 2021-12-07T15:11:11.546Z,1638889871.546 [MissionManager](INFO): Startup is completed. 2021-12-07T15:11:11.546Z,1638889871.546 [MissionManager](INFO): Uninitializing Mission Startup 2021-12-07T15:11:11.546Z,1638889871.546 [Startup] Stopped 2021-12-07T15:11:11.546Z,1638889871.546 [Startup](DEBUG): Aggregate::uninitialize Startup 2021-12-07T15:11:11.546Z,1638889871.546 [Startup:A.GoToSurface] Stopped 2021-12-07T15:11:11.546Z,1638889871.546 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2021-12-07T15:11:11.955Z,1638889871.955 [MissionManager](IMPORTANT): Started mission Default 2021-12-07T15:11:11.955Z,1638889871.955 [Default] Running Loop=1 2021-12-07T15:11:11.955Z,1638889871.955 [Default](DEBUG): Aggregate::initialize Default 2021-12-07T15:11:11.955Z,1638889871.955 [Default:B.GoToSurface] Running Loop=1 2021-12-07T15:11:11.955Z,1638889871.955 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2021-12-07T15:11:11.956Z,1638889871.956 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2021-12-07T15:11:11.957Z,1638889871.957 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2021-12-07T15:11:11.957Z,1638889871.957 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2021-12-07T15:11:11.957Z,1638889871.957 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2021-12-07T15:11:11.958Z,1638889871.958 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2021-12-07T15:11:11.958Z,1638889871.958 [Default:A.Wait] Running Loop=1 2021-12-07T15:11:11.958Z,1638889871.958 [Default:A.Wait](DEBUG): Initialize Wait Component. 2021-12-07T15:11:25.161Z,1638889885.161 [CommandExec](IMPORTANT): got command burn off 2021-12-07T15:11:25.161Z,1638889885.161 [CommandExec](IMPORTANT): Deactivating dropweight wire 2021-12-07T15:11:25.317Z,1638889885.317 [Default:A.Wait](INFO): Done Waiting. 2021-12-07T15:11:25.317Z,1638889885.317 [Default:A.Wait] Stopped 2021-12-07T15:11:25.317Z,1638889885.317 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T15:11:25.684Z,1638889885.684 [Default:CheckIn] Running Loop=1 2021-12-07T15:11:25.684Z,1638889885.684 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T15:11:25.684Z,1638889885.684 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T15:11:26.079Z,1638889886.079 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2021-12-07T15:12:48.355Z,1638889968.355 [CommandExec](IMPORTANT): got command failComponent 2021-12-07T15:12:48.356Z,1638889968.356 [CommandExec](IMPORTANT): Failed components: 2021-12-07T15:12:48.356Z,1638889968.356 [CommandExec](IMPORTANT): No failed Components. 2021-12-07T15:13:39.772Z,1638890019.772 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-12-07T15:13:58.784Z,1638890038.784 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2021-12-07T15:13:58.784Z,1638890038.784 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T15:13:58.799Z,1638890038.799 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T15:13:59.221Z,1638890039.221 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T15:13:59.221Z,1638890039.221 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2021-12-07T15:16:25.850Z,1638890185.850 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T15:11:25.7Z 2021-12-07T15:16:25.850Z,1638890185.850 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T15:16:25.850Z,1638890185.850 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T15:16:26.251Z,1638890186.251 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2021-12-07T15:16:33.130Z,1638890193.130 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20211207T150746/Courier0004.lzma 2021-12-07T15:16:34.134Z,1638890194.134 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Courier0004.lzma.bak 2021-12-07T15:16:34.134Z,1638890194.134 [DataOverHttps](INFO): SBD MOMSN=16334691 2021-12-07T15:16:50.151Z,1638890210.151 [DataOverHttps](INFO): Sending 307 bytes from file Logs/20211207T150746/Express0005.lzma 2021-12-07T15:16:51.152Z,1638890211.152 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Express0005.lzma.bak 2021-12-07T15:16:51.153Z,1638890211.153 [DataOverHttps](INFO): SBD MOMSN=16334693 2021-12-07T15:16:52.518Z,1638890212.518 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T15:16:52.518Z,1638890212.518 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T15:16:52.518Z,1638890212.518 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T15:16:56.109Z,1638890216.109 [BPC1](ERROR): BPC1B buffer size (90D bytes) exceeded the max device response limit. 2021-12-07T15:16:56.109Z,1638890216.109 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-12-07T15:16:59.766Z,1638890219.766 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2021-12-07T15:16:59.766Z,1638890219.766 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T15:16:59.777Z,1638890219.777 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T15:17:00.193Z,1638890220.193 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T15:17:00.193Z,1638890220.193 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2021-12-07T15:17:08.255Z,1638890228.255 [CommandExec](IMPORTANT): got command failComponent 2021-12-07T15:17:08.255Z,1638890228.255 [CommandExec](IMPORTANT): Failed components: 2021-12-07T15:17:08.256Z,1638890228.256 [CommandExec](IMPORTANT): No failed Components. 2021-12-07T15:17:09.046Z,1638890229.046 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2021-12-07T15:17:09.050Z,1638890229.050 [BPC1](INFO): Received data from all battery sticks. 2021-12-07T15:17:22.548Z,1638890242.548 [CommandExec](IMPORTANT): got command configSet list 2021-12-07T15:17:22.549Z,1638890242.549 [CommandExec](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2021-12-07T15:17:22.549Z,1638890242.549 [CommandExec](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count; 2021-12-07T15:17:22.550Z,1638890242.550 [CommandExec](IMPORTANT): CBIT.gf24Offset=143 microampere; 2021-12-07T15:17:22.550Z,1638890242.550 [CommandExec](IMPORTANT): DAT.baud=115200 bit_per_second; 2021-12-07T15:17:22.550Z,1638890242.550 [CommandExec](IMPORTANT): DAT.loadAtStartup=1 bool; 2021-12-07T15:17:22.550Z,1638890242.550 [CommandExec](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 0.300000 liter_per_second; 2021-12-07T15:17:22.550Z,1638890242.550 [CommandExec](IMPORTANT): IBIT.batteryCapacityThreshold=24 ampere_hour; 2021-12-07T15:17:22.550Z,1638890242.550 [CommandExec](IMPORTANT): IBIT.batteryVoltageThreshold=13 volt; 2021-12-07T15:17:22.551Z,1638890242.551 [CommandExec](IMPORTANT): Power24vConverter.simulateHardware=0 bool; 2021-12-07T15:17:22.551Z,1638890242.551 [CommandExec](IMPORTANT): RDI_Pathfinder.loadAtStartup=1 bool; 2021-12-07T15:17:22.551Z,1638890242.551 [CommandExec](IMPORTANT): VerticalControl.buoyancyNeutral=228.666848 cubic_centimeter; 2021-12-07T15:17:22.551Z,1638890242.551 [CommandExec](IMPORTANT): VerticalControl.massDefault=8.215154 millimeter; 2021-12-07T15:18:39.141Z,1638890319.141 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-12-07T15:18:39.141Z,1638890319.141 [NAL9602] Data Fault, FailCount= 1 2021-12-07T15:18:39.141Z,1638890319.141 [NAL9602](ERROR): Data Fault 2021-12-07T15:18:39.231Z,1638890319.231 [CBIT](ERROR): Data Fault in component: NAL9602 2021-12-07T15:18:39.536Z,1638890319.536 [NAL9602](INFO): Powering down 2021-12-07T15:18:40.363Z,1638890320.363 [CBIT](INFO): Clearing failed state for component NAL9602 2021-12-07T15:18:40.363Z,1638890320.363 [NAL9602] No Fault, FailCount= 1 2021-12-07T15:19:09.834Z,1638890349.834 [NAL9602](INFO): Powering up NAL9602 2021-12-07T15:19:20.745Z,1638890360.745 [NAL9602](INFO): NAL9602 initialized 2021-12-07T15:20:00.762Z,1638890400.762 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2021-12-07T15:20:00.762Z,1638890400.762 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T15:20:00.774Z,1638890400.774 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T15:20:01.192Z,1638890401.192 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T15:20:01.192Z,1638890401.192 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2021-12-07T15:21:53.121Z,1638890513.121 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T15:21:53.121Z,1638890513.121 [Default:CheckIn:C.Wait] Stopped 2021-12-07T15:21:53.121Z,1638890513.121 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T15:21:53.121Z,1638890513.121 [Default:CheckIn:D] Running Loop=1 2021-12-07T15:21:53.478Z,1638890513.478 [Default:CheckIn:D] Stopped 2021-12-07T15:21:53.478Z,1638890513.478 [Default:CheckIn:E] Running Loop=1 2021-12-07T15:21:53.883Z,1638890513.883 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.692046 min 2021-12-07T15:21:53.883Z,1638890513.883 [Default:CheckIn:E] Stopped 2021-12-07T15:21:53.883Z,1638890513.883 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T15:21:53.883Z,1638890513.883 [Default:CheckIn] Stopped 2021-12-07T15:21:53.883Z,1638890513.883 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T15:21:53.884Z,1638890513.884 [Default:CheckIn](INFO): Running loop #2 2021-12-07T15:21:53.884Z,1638890513.884 [Default:CheckIn] Running Loop=2 2021-12-07T15:21:53.884Z,1638890513.884 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T15:21:53.884Z,1638890513.884 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T15:23:01.745Z,1638890581.745 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2021-12-07T15:23:01.745Z,1638890581.745 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T15:23:01.756Z,1638890581.756 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T15:23:02.169Z,1638890582.169 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T15:23:02.169Z,1638890582.169 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2021-12-07T15:26:02.768Z,1638890762.768 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2021-12-07T15:26:02.768Z,1638890762.768 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T15:26:02.780Z,1638890762.780 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T15:26:03.237Z,1638890763.237 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T15:26:03.237Z,1638890763.237 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2021-12-07T15:26:54.079Z,1638890814.079 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T15:21:53.9Z 2021-12-07T15:26:54.079Z,1638890814.079 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T15:26:54.079Z,1638890814.079 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T15:27:01.815Z,1638890821.815 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20211207T150746/Courier0007.lzma 2021-12-07T15:27:02.816Z,1638890822.816 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Courier0007.lzma.bak 2021-12-07T15:27:02.817Z,1638890822.817 [DataOverHttps](INFO): SBD MOMSN=16334724 2021-12-07T15:27:18.756Z,1638890838.756 [DataOverHttps](INFO): Sending 618 bytes from file Logs/20211207T150746/Express0008.lzma 2021-12-07T15:27:19.756Z,1638890839.756 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Express0008.lzma.bak 2021-12-07T15:27:19.757Z,1638890839.757 [DataOverHttps](INFO): SBD MOMSN=16334726 2021-12-07T15:27:21.197Z,1638890841.197 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T15:27:21.197Z,1638890841.197 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T15:27:21.197Z,1638890841.197 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T15:29:03.769Z,1638890943.769 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2021-12-07T15:29:03.769Z,1638890943.769 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T15:29:03.805Z,1638890943.805 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T15:29:04.186Z,1638890944.186 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T15:29:04.186Z,1638890944.186 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2021-12-07T15:29:21.924Z,1638890961.924 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-12-07T15:29:21.924Z,1638890961.924 [NAL9602] Data Fault, FailCount= 2 2021-12-07T15:29:21.924Z,1638890961.924 [NAL9602](ERROR): Data Fault 2021-12-07T15:29:21.944Z,1638890961.944 [CBIT](ERROR): Data Fault in component: NAL9602 2021-12-07T15:29:22.324Z,1638890962.324 [NAL9602](INFO): Powering down 2021-12-07T15:29:23.215Z,1638890963.215 [CBIT](INFO): Clearing failed state for component NAL9602 2021-12-07T15:29:23.215Z,1638890963.215 [NAL9602] No Fault, FailCount= 2 2021-12-07T15:29:52.628Z,1638890992.628 [NAL9602](INFO): Powering up NAL9602 2021-12-07T15:30:03.533Z,1638891003.533 [NAL9602](INFO): NAL9602 initialized 2021-12-07T15:31:25.191Z,1638891085.191 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout 2021-12-07T15:31:25.191Z,1638891085.191 [RDI_Pathfinder] Communications Fault, FailCount= 1 2021-12-07T15:31:25.191Z,1638891085.191 [RDI_Pathfinder](ERROR): Communications Fault 2021-12-07T15:31:25.239Z,1638891085.239 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder 2021-12-07T15:31:25.631Z,1638891085.631 [RDI_Pathfinder](INFO): Powering down 2021-12-07T15:31:26.380Z,1638891086.380 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder 2021-12-07T15:31:26.380Z,1638891086.380 [RDI_Pathfinder] No Fault, FailCount= 1 2021-12-07T15:32:04.769Z,1638891124.769 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2021-12-07T15:32:04.769Z,1638891124.769 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T15:32:04.812Z,1638891124.812 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T15:32:05.195Z,1638891125.195 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T15:32:05.195Z,1638891125.195 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2021-12-07T15:32:21.753Z,1638891141.753 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T15:32:21.753Z,1638891141.753 [Default:CheckIn:C.Wait] Stopped 2021-12-07T15:32:21.753Z,1638891141.753 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T15:32:21.753Z,1638891141.753 [Default:CheckIn:D] Running Loop=1 2021-12-07T15:32:22.211Z,1638891142.211 [Default:CheckIn:D] Stopped 2021-12-07T15:32:22.211Z,1638891142.211 [Default:CheckIn:E] Running Loop=1 2021-12-07T15:32:22.575Z,1638891142.575 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.170931 min 2021-12-07T15:32:22.575Z,1638891142.575 [Default:CheckIn:E] Stopped 2021-12-07T15:32:22.575Z,1638891142.575 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T15:32:22.575Z,1638891142.575 [Default:CheckIn] Stopped 2021-12-07T15:32:22.576Z,1638891142.576 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T15:32:22.576Z,1638891142.576 [Default:CheckIn](INFO): Running loop #3 2021-12-07T15:32:22.576Z,1638891142.576 [Default:CheckIn] Running Loop=3 2021-12-07T15:32:22.576Z,1638891142.576 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T15:32:22.576Z,1638891142.576 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T15:33:02.149Z,1638891182.149 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153300.00,A,3648.16264,N,12147.27336,W,0.058,0.00,071221,,,A*7E 2021-12-07T15:33:02.160Z,1638891182.160 [NAL9602](INFO): GPS fix at 20211207T153300: (36.802711, -121.787889) 2021-12-07T15:33:02.233Z,1638891182.233 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T15:33:02.233Z,1638891182.233 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T15:33:12.999Z,1638891192.999 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20211207T150746/Courier0010.lzma 2021-12-07T15:33:14.001Z,1638891194.001 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Courier0010.lzma.bak 2021-12-07T15:33:14.001Z,1638891194.001 [DataOverHttps](INFO): SBD MOMSN=16334748 2021-12-07T15:33:31.040Z,1638891211.040 [DataOverHttps](INFO): Sending 293 bytes from file Logs/20211207T150746/Express0011.lzma 2021-12-07T15:33:32.040Z,1638891212.040 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Express0011.lzma.bak 2021-12-07T15:33:32.041Z,1638891212.041 [DataOverHttps](INFO): SBD MOMSN=16334751 2021-12-07T15:33:33.259Z,1638891213.259 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T15:33:33.259Z,1638891213.259 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T15:33:33.260Z,1638891213.260 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T15:33:34.456Z,1638891214.456 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-07T15:34:50.424Z,1638891290.424 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2021-12-07T15:38:33.836Z,1638891513.836 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T15:38:33.836Z,1638891513.836 [Default:CheckIn:C.Wait] Stopped 2021-12-07T15:38:33.836Z,1638891513.836 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T15:38:33.836Z,1638891513.836 [Default:CheckIn:D] Running Loop=1 2021-12-07T15:38:34.261Z,1638891514.261 [Default:CheckIn:D] Stopped 2021-12-07T15:38:34.261Z,1638891514.261 [Default:CheckIn:E] Running Loop=1 2021-12-07T15:38:34.657Z,1638891514.657 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 27.371767 min 2021-12-07T15:38:34.657Z,1638891514.657 [Default:CheckIn:E] Stopped 2021-12-07T15:38:34.658Z,1638891514.658 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T15:38:34.658Z,1638891514.658 [Default:CheckIn] Stopped 2021-12-07T15:38:34.658Z,1638891514.658 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T15:38:34.658Z,1638891514.658 [Default:CheckIn](INFO): Running loop #4 2021-12-07T15:38:34.658Z,1638891514.658 [Default:CheckIn] Running Loop=4 2021-12-07T15:38:34.658Z,1638891514.658 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T15:38:34.658Z,1638891514.658 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T15:38:36.658Z,1638891516.658 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153834.00,A,3648.15712,N,12147.27984,W,1.438,355.11,071221,,,A*76 2021-12-07T15:38:36.660Z,1638891516.660 [NAL9602](INFO): GPS fix at 20211207T153834: (36.802619, -121.787997) 2021-12-07T15:38:36.672Z,1638891516.672 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T15:38:36.673Z,1638891516.673 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T15:38:44.326Z,1638891524.326 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211207T150746/Courier0013.lzma 2021-12-07T15:38:45.328Z,1638891525.328 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Courier0013.lzma.bak 2021-12-07T15:38:45.329Z,1638891525.329 [DataOverHttps](INFO): SBD MOMSN=16334757 2021-12-07T15:39:01.771Z,1638891541.771 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20211207T150746/Express0014.lzma 2021-12-07T15:39:02.764Z,1638891542.764 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Express0014.lzma.bak 2021-12-07T15:39:02.765Z,1638891542.765 [DataOverHttps](INFO): SBD MOMSN=16334760 2021-12-07T15:39:04.194Z,1638891544.194 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T15:39:04.194Z,1638891544.194 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T15:39:04.194Z,1638891544.194 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T15:43:39.324Z,1638891819.324 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-12-07T15:44:04.804Z,1638891844.804 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T15:44:04.804Z,1638891844.804 [Default:CheckIn:C.Wait] Stopped 2021-12-07T15:44:04.804Z,1638891844.804 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T15:44:04.804Z,1638891844.804 [Default:CheckIn:D] Running Loop=1 2021-12-07T15:44:05.216Z,1638891845.216 [Default:CheckIn:D] Stopped 2021-12-07T15:44:05.216Z,1638891845.216 [Default:CheckIn:E] Running Loop=1 2021-12-07T15:44:05.645Z,1638891845.645 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.887683 min 2021-12-07T15:44:05.645Z,1638891845.645 [Default:CheckIn:E] Stopped 2021-12-07T15:44:05.645Z,1638891845.645 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T15:44:05.645Z,1638891845.645 [Default:CheckIn] Stopped 2021-12-07T15:44:05.645Z,1638891845.645 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T15:44:05.646Z,1638891845.646 [Default:CheckIn](INFO): Running loop #5 2021-12-07T15:44:05.646Z,1638891845.646 [Default:CheckIn] Running Loop=5 2021-12-07T15:44:05.646Z,1638891845.646 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T15:44:05.646Z,1638891845.646 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T15:44:07.616Z,1638891847.616 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154406.00,A,3648.17491,N,12147.28221,W,1.516,123.47,071221,,,A*70 2021-12-07T15:44:07.618Z,1638891847.618 [NAL9602](INFO): GPS fix at 20211207T154406: (36.802915, -121.788037) 2021-12-07T15:44:07.639Z,1638891847.639 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T15:44:07.639Z,1638891847.639 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T15:44:16.090Z,1638891856.090 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211207T150746/Courier0016.lzma 2021-12-07T15:44:17.092Z,1638891857.092 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Courier0016.lzma.bak 2021-12-07T15:44:17.093Z,1638891857.093 [DataOverHttps](INFO): SBD MOMSN=16334765 2021-12-07T15:44:33.603Z,1638891873.603 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20211207T150746/Express0017.lzma 2021-12-07T15:44:34.604Z,1638891874.604 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Express0017.lzma.bak 2021-12-07T15:44:34.605Z,1638891874.605 [DataOverHttps](INFO): SBD MOMSN=16334768 2021-12-07T15:44:35.937Z,1638891875.937 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T15:44:35.937Z,1638891875.937 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T15:44:35.937Z,1638891875.937 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T15:44:39.550Z,1638891879.550 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-07T15:49:36.544Z,1638892176.544 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T15:49:36.545Z,1638892176.545 [Default:CheckIn:C.Wait] Stopped 2021-12-07T15:49:36.545Z,1638892176.545 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T15:49:36.545Z,1638892176.545 [Default:CheckIn:D] Running Loop=1 2021-12-07T15:49:36.916Z,1638892176.916 [Default:CheckIn:D] Stopped 2021-12-07T15:49:36.916Z,1638892176.916 [Default:CheckIn:E] Running Loop=1 2021-12-07T15:49:37.317Z,1638892177.317 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 38.416016 min 2021-12-07T15:49:37.317Z,1638892177.317 [Default:CheckIn:E] Stopped 2021-12-07T15:49:37.317Z,1638892177.317 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T15:49:37.317Z,1638892177.317 [Default:CheckIn] Stopped 2021-12-07T15:49:37.317Z,1638892177.317 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T15:49:37.317Z,1638892177.317 [Default:CheckIn](INFO): Running loop #6 2021-12-07T15:49:37.317Z,1638892177.317 [Default:CheckIn] Running Loop=6 2021-12-07T15:49:37.317Z,1638892177.317 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T15:49:37.318Z,1638892177.318 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T15:49:39.330Z,1638892179.330 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154938.00,A,3648.19949,N,12147.28241,W,0.136,123.47,071221,,,A*77 2021-12-07T15:49:39.341Z,1638892179.341 [NAL9602](INFO): GPS fix at 20211207T154938: (36.803325, -121.788040) 2021-12-07T15:49:39.353Z,1638892179.353 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T15:49:39.353Z,1638892179.353 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T15:49:46.938Z,1638892186.938 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211207T150746/Courier0019.lzma 2021-12-07T15:49:47.940Z,1638892187.940 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Courier0019.lzma.bak 2021-12-07T15:49:47.941Z,1638892187.941 [DataOverHttps](INFO): SBD MOMSN=16334772 2021-12-07T15:50:05.351Z,1638892205.351 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20211207T150746/Express0020.lzma 2021-12-07T15:50:06.353Z,1638892206.353 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Express0020.lzma.bak 2021-12-07T15:50:06.353Z,1638892206.353 [DataOverHttps](INFO): SBD MOMSN=16334775 2021-12-07T15:50:07.641Z,1638892207.641 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T15:50:07.641Z,1638892207.641 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T15:50:07.642Z,1638892207.642 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T15:50:10.064Z,1638892210.064 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-12-07T15:50:10.147Z,1638892210.147 [NAL9602](ERROR): received: +CSQ:0 OK 2021-12-07T15:50:26.645Z,1638892226.645 [NAL9602](INFO): SBD MO Status=0, MOMSN=17823, MT Status=0, MTMSN=0 2021-12-07T15:50:26.646Z,1638892226.646 [NAL9602](INFO): No messages in MT queue 2021-12-07T15:50:57.348Z,1638892257.348 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-07T15:55:08.284Z,1638892508.284 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T15:55:08.284Z,1638892508.284 [Default:CheckIn:C.Wait] Stopped 2021-12-07T15:55:08.284Z,1638892508.284 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T15:55:08.284Z,1638892508.284 [Default:CheckIn:D] Running Loop=1 2021-12-07T15:55:08.655Z,1638892508.655 [Default:CheckIn:D] Stopped 2021-12-07T15:55:08.655Z,1638892508.655 [Default:CheckIn:E] Running Loop=1 2021-12-07T15:55:09.061Z,1638892509.061 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.944999 min 2021-12-07T15:55:09.061Z,1638892509.061 [Default:CheckIn:E] Stopped 2021-12-07T15:55:09.061Z,1638892509.061 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T15:55:09.062Z,1638892509.062 [Default:CheckIn] Stopped 2021-12-07T15:55:09.062Z,1638892509.062 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T15:55:09.062Z,1638892509.062 [Default:CheckIn](INFO): Running loop #7 2021-12-07T15:55:09.062Z,1638892509.062 [Default:CheckIn] Running Loop=7 2021-12-07T15:55:09.062Z,1638892509.062 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T15:55:09.062Z,1638892509.062 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T15:55:11.081Z,1638892511.081 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155510.00,A,3648.14217,N,12147.22854,W,0.039,64.57,071221,,,D*41 2021-12-07T15:55:11.083Z,1638892511.083 [NAL9602](INFO): GPS fix at 20211207T155510: (36.802369, -121.787142) 2021-12-07T15:55:11.095Z,1638892511.095 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T15:55:11.096Z,1638892511.096 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T15:55:18.786Z,1638892518.786 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20211207T150746/Courier0022.lzma 2021-12-07T15:55:19.788Z,1638892519.788 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Courier0022.lzma.bak 2021-12-07T15:55:19.789Z,1638892519.789 [DataOverHttps](INFO): SBD MOMSN=16334779 2021-12-07T15:55:33.697Z,1638892533.697 [NAL9602](INFO): SBD MO Status=0, MOMSN=17824, MT Status=0, MTMSN=0 2021-12-07T15:55:33.698Z,1638892533.698 [NAL9602](INFO): No messages in MT queue 2021-12-07T15:55:36.486Z,1638892536.486 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20211207T150746/Express0023.lzma 2021-12-07T15:55:37.489Z,1638892537.489 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Express0023.lzma.bak 2021-12-07T15:55:37.489Z,1638892537.489 [DataOverHttps](IMPORTANT): SBD MOMSN=16334783, MTMSN=20211207T155536 2021-12-07T15:55:38.573Z,1638892538.573 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T15:55:38.573Z,1638892538.573 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T15:55:38.573Z,1638892538.573 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T15:55:45.043Z,1638892545.043 [DataOverHttps](INFO): Received command: Ibit 2021-12-07T15:55:45.060Z,1638892545.060 [CommandExec](IMPORTANT): got command ibit 2021-12-07T15:55:45.440Z,1638892545.440 [IBIT](IMPORTANT): Beginning Initiated BIT 2021-12-07T15:55:45.440Z,1638892545.440 [IBIT](IMPORTANT): Beginning control surface checks. 2021-12-07T15:55:45.443Z,1638892545.443 [CBIT](IMPORTANT): Beginning ground fault scan 2021-12-07T15:55:47.030Z,1638892547.030 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155546.00,A,3648.14179,N,12147.22805,W,0.019,64.57,071221,,,D*4F 2021-12-07T15:55:47.032Z,1638892547.032 [NAL9602](INFO): GPS fix at 20211207T155546: (36.802363, -121.787134) 2021-12-07T15:55:50.262Z,1638892550.262 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155549.00,A,3648.14179,N,12147.22794,W,0.019,64.57,071221,,,D*47 2021-12-07T15:55:50.264Z,1638892550.264 [NAL9602](INFO): GPS fix at 20211207T155549: (36.802363, -121.787132) 2021-12-07T15:55:53.094Z,1638892553.094 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155552.00,A,3648.14185,N,12147.22787,W,0.039,64.57,071221,,,D*4E 2021-12-07T15:55:53.097Z,1638892553.097 [NAL9602](INFO): GPS fix at 20211207T155552: (36.802364, -121.787131) 2021-12-07T15:55:55.914Z,1638892555.914 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155555.00,A,3648.14189,N,12147.22798,W,0.019,64.57,071221,,,D*49 2021-12-07T15:55:55.928Z,1638892555.928 [NAL9602](INFO): GPS fix at 20211207T155555: (36.802365, -121.787133) 2021-12-07T15:55:56.400Z,1638892556.400 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.010906 CHAN A1 (24V): -0.000432 CHAN A2 (12V): -0.007533 CHAN A3 (5V): -0.001884 CHAN B0 (3.3V): 0.000176 CHAN B1 (3.15aV): -0.000482 CHAN B2 (3.15bV): 0.000104 CHAN B3 (GND): 0.002416 OPEN: 0.005209 Full Scale: +/- 1 mA 2021-12-07T15:55:59.150Z,1638892559.150 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155558.00,A,3648.14193,N,12147.22807,W,0.000,64.57,071221,,,D*4E 2021-12-07T15:55:59.152Z,1638892559.152 [NAL9602](INFO): GPS fix at 20211207T155558: (36.802366, -121.787134) 2021-12-07T15:56:01.974Z,1638892561.974 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155601.00,A,3648.14200,N,12147.22810,W,0.039,64.57,071221,,,D*44 2021-12-07T15:56:01.976Z,1638892561.976 [NAL9602](INFO): GPS fix at 20211207T155601: (36.802367, -121.787135) 2021-12-07T15:56:05.206Z,1638892565.206 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155604.00,A,3648.14214,N,12147.22812,W,0.058,64.57,071221,,,D*41 2021-12-07T15:56:05.208Z,1638892565.208 [NAL9602](INFO): GPS fix at 20211207T155604: (36.802369, -121.787135) 2021-12-07T15:56:08.048Z,1638892568.048 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155607.00,A,3648.14225,N,12147.22825,W,0.000,64.57,071221,,,D*49 2021-12-07T15:56:08.051Z,1638892568.051 [NAL9602](INFO): GPS fix at 20211207T155607: (36.802371, -121.787138) 2021-12-07T15:56:11.266Z,1638892571.266 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155610.00,A,3648.14226,N,12147.22848,W,0.019,64.57,071221,,,D*4F 2021-12-07T15:56:11.268Z,1638892571.268 [NAL9602](INFO): GPS fix at 20211207T155610: (36.802371, -121.787141) 2021-12-07T15:56:14.098Z,1638892574.098 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155613.00,A,3648.14233,N,12147.22862,W,0.019,64.57,071221,,,D*40 2021-12-07T15:56:14.115Z,1638892574.115 [NAL9602](INFO): GPS fix at 20211207T155613: (36.802372, -121.787144) 2021-12-07T15:56:16.922Z,1638892576.922 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155616.00,A,3648.14239,N,12147.22878,W,0.019,64.57,071221,,,D*44 2021-12-07T15:56:16.925Z,1638892576.925 [NAL9602](INFO): GPS fix at 20211207T155616: (36.802373, -121.787146) 2021-12-07T15:56:20.201Z,1638892580.201 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155619.00,A,3648.14242,N,12147.22890,W,0.078,64.57,071221,,,D*46 2021-12-07T15:56:20.208Z,1638892580.208 [NAL9602](INFO): GPS fix at 20211207T155619: (36.802374, -121.787148) 2021-12-07T15:56:22.986Z,1638892582.986 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155622.00,A,3648.14251,N,12147.22892,W,0.039,64.57,071221,,,D*4B 2021-12-07T15:56:22.988Z,1638892582.988 [NAL9602](INFO): GPS fix at 20211207T155622: (36.802375, -121.787149) 2021-12-07T15:56:26.239Z,1638892586.239 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155625.00,A,3648.14262,N,12147.22901,W,0.019,64.57,071221,,,D*45 2021-12-07T15:56:26.241Z,1638892586.241 [NAL9602](INFO): GPS fix at 20211207T155625: (36.802377, -121.787150) 2021-12-07T15:56:29.046Z,1638892589.046 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155628.00,A,3648.14271,N,12147.22908,W,0.039,64.57,071221,,,D*41 2021-12-07T15:56:29.057Z,1638892589.057 [NAL9602](INFO): GPS fix at 20211207T155628: (36.802379, -121.787151) 2021-12-07T15:56:31.483Z,1638892591.483 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 5 Latitude: 36.802380 Longitude: -121.787148 2021-12-07T15:56:31.906Z,1638892591.906 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 0.000000 Voltage: 16.572001 2021-12-07T15:56:31.907Z,1638892591.907 [IBIT](IMPORTANT): batteryCapacityThreshold: 24.000000 Ah 2021-12-07T15:56:31.907Z,1638892591.907 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.000000 V 2021-12-07T15:56:32.274Z,1638892592.274 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155631.00,A,3648.14270,N,12147.22913,W,0.039,64.57,071221,,,D*42 2021-12-07T15:56:32.276Z,1638892592.276 [NAL9602](INFO): GPS fix at 20211207T155631: (36.802378, -121.787152) 2021-12-07T15:56:32.349Z,1638892592.349 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2021-12-07T15:56:32.349Z,1638892592.349 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2021-12-07T15:56:32.349Z,1638892592.349 [IBIT](IMPORTANT): Pressure:7.537723 PSI 2021-12-07T15:56:32.350Z,1638892592.350 [IBIT](IMPORTANT): Humidity:21.700647 % 2021-12-07T15:56:32.726Z,1638892592.726 [IBIT](IMPORTANT): Vehicle Pitch:-0.699885 degrees 2021-12-07T15:56:32.726Z,1638892592.726 [IBIT](IMPORTANT): Vehicle Roll:-2.497216 degrees 2021-12-07T15:56:32.727Z,1638892592.727 [IBIT](IMPORTANT): Vehicle Heading:210.661072 degrees 2021-12-07T15:56:33.100Z,1638892593.100 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2021-12-07T15:56:33.100Z,1638892593.100 [IBIT](IMPORTANT): buoyancyNeutral: 228.666855 cc 2021-12-07T15:56:33.101Z,1638892593.101 [IBIT](IMPORTANT): massDefault: 0.821515 cm 2021-12-07T15:56:33.101Z,1638892593.101 [IBIT](IMPORTANT): stopDepth: 215.000000 m 2021-12-07T15:56:33.101Z,1638892593.101 [IBIT](IMPORTANT): abortDepth: 255.000000 m 2021-12-07T15:56:33.101Z,1638892593.101 [IBIT](IMPORTANT): IBIT PASSED 2021-12-07T15:57:04.592Z,1638892624.592 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-07T16:00:39.198Z,1638892839.198 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T16:00:39.198Z,1638892839.198 [Default:CheckIn:C.Wait] Stopped 2021-12-07T16:00:39.198Z,1638892839.198 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T16:00:39.198Z,1638892839.198 [Default:CheckIn:D] Running Loop=1 2021-12-07T16:00:39.579Z,1638892839.579 [Default:CheckIn:D] Stopped 2021-12-07T16:00:39.580Z,1638892839.580 [Default:CheckIn:E] Running Loop=1 2021-12-07T16:00:39.991Z,1638892839.991 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 49.460404 min 2021-12-07T16:00:39.991Z,1638892839.991 [Default:CheckIn:E] Stopped 2021-12-07T16:00:39.992Z,1638892839.992 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T16:00:39.992Z,1638892839.992 [Default:CheckIn] Stopped 2021-12-07T16:00:39.992Z,1638892839.992 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T16:00:39.992Z,1638892839.992 [Default:CheckIn](INFO): Running loop #8 2021-12-07T16:00:39.992Z,1638892839.992 [Default:CheckIn] Running Loop=8 2021-12-07T16:00:39.992Z,1638892839.992 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T16:00:39.992Z,1638892839.992 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T16:00:41.998Z,1638892841.998 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160041.00,A,3648.14945,N,12147.22277,W,0.156,31.64,071221,,,D*49 2021-12-07T16:00:42.012Z,1638892842.012 [NAL9602](INFO): GPS fix at 20211207T160041: (36.802491, -121.787046) 2021-12-07T16:00:42.024Z,1638892842.024 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T16:00:42.024Z,1638892842.024 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T16:00:50.070Z,1638892850.070 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211207T150746/Courier0025.lzma 2021-12-07T16:00:51.072Z,1638892851.072 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Courier0025.lzma.bak 2021-12-07T16:00:51.073Z,1638892851.073 [DataOverHttps](INFO): SBD MOMSN=16334788 2021-12-07T16:00:52.917Z,1638892852.917 [NAL9602](INFO): SBD MO Status=0, MOMSN=17825, MT Status=0, MTMSN=0 2021-12-07T16:00:52.917Z,1638892852.917 [NAL9602](INFO): No messages in MT queue 2021-12-07T16:01:07.540Z,1638892867.540 [DataOverHttps](INFO): Sending 817 bytes from file Logs/20211207T150746/Express0026.lzma 2021-12-07T16:01:08.540Z,1638892868.540 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Express0026.lzma.bak 2021-12-07T16:01:08.541Z,1638892868.541 [DataOverHttps](INFO): SBD MOMSN=16334791 2021-12-07T16:01:17.092Z,1638892877.092 [DataOverHttps](IMPORTANT): SBD MTMSN=20211207T160116 2021-12-07T16:01:23.612Z,1638892883.612 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-07T16:01:24.802Z,1638892884.802 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20211207T150746/Express0029.lzma 2021-12-07T16:01:24.804Z,1638892884.804 [DataOverHttps](INFO): Received command: Maintain control speedcontrol.propomegaaction 75 rpm 2021-12-07T16:01:25.996Z,1638892885.996 [CommandExec](IMPORTANT): got command maintain control SpeedControl.propOmegaAction 75.000000 revolution_per_minute 2021-12-07T16:01:26.004Z,1638892886.004 [ComponentRegistry](DEBUG): SyncComponent "Maintain_SpeedControl.propOmegaAction" handled in the control thread. 2021-12-07T16:01:26.144Z,1638892886.144 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,RDI_Pathfinder,DAT,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_SpeedControl.propOmegaAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2021-12-07T16:01:26.219Z,1638892886.219 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Express0029.lzma.bak 2021-12-07T16:01:26.220Z,1638892886.220 [DataOverHttps](INFO): SBD MOMSN=16334818 2021-12-07T16:01:42.602Z,1638892902.602 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20211207T150746/Courier0031.lzma 2021-12-07T16:01:43.605Z,1638892903.605 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Courier0031.lzma.bak 2021-12-07T16:01:43.605Z,1638892903.605 [DataOverHttps](INFO): SBD MOMSN=16334821 2021-12-07T16:02:00.375Z,1638892920.375 [DataOverHttps](INFO): Sending 103 bytes from file Logs/20211207T150746/Express0032.lzma 2021-12-07T16:02:01.377Z,1638892921.377 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Express0032.lzma.bak 2021-12-07T16:02:01.377Z,1638892921.377 [DataOverHttps](IMPORTANT): SBD MOMSN=16334824, MTMSN=20211207T160200 2021-12-07T16:02:13.263Z,1638892933.263 [DataOverHttps](INFO): Received command: Maintain clear 2021-12-07T16:02:13.301Z,1638892933.301 [CommandExec](IMPORTANT): got command maintain clear 2021-12-07T16:02:13.473Z,1638892933.473 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,RDI_Pathfinder,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,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2021-12-07T16:02:21.890Z,1638892941.890 [DataOverHttps](INFO): Sending 110 bytes from file Logs/20211207T150746/Express0033.lzma 2021-12-07T16:02:22.892Z,1638892942.892 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Express0033.lzma.bak 2021-12-07T16:02:22.893Z,1638892942.893 [DataOverHttps](INFO): SBD MOMSN=16334828 2021-12-07T16:02:39.250Z,1638892959.250 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20211207T150746/Courier0034.lzma 2021-12-07T16:02:40.253Z,1638892960.253 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Courier0034.lzma.bak 2021-12-07T16:02:40.253Z,1638892960.253 [DataOverHttps](INFO): SBD MOMSN=16334831 2021-12-07T16:02:56.935Z,1638892976.935 [DataOverHttps](INFO): Sending 148 bytes from file Logs/20211207T150746/Express0035.lzma 2021-12-07T16:02:57.937Z,1638892977.937 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Express0035.lzma.bak 2021-12-07T16:02:57.937Z,1638892977.937 [DataOverHttps](INFO): SBD MOMSN=16334833 2021-12-07T16:02:59.062Z,1638892979.062 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T16:02:59.062Z,1638892979.062 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T16:02:59.063Z,1638892979.063 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T16:07:59.655Z,1638893279.655 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T16:07:59.655Z,1638893279.655 [Default:CheckIn:C.Wait] Stopped 2021-12-07T16:07:59.655Z,1638893279.655 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T16:07:59.656Z,1638893279.656 [Default:CheckIn:D] Running Loop=1 2021-12-07T16:08:00.064Z,1638893280.064 [Default:CheckIn:D] Stopped 2021-12-07T16:08:00.064Z,1638893280.064 [Default:CheckIn:E] Running Loop=1 2021-12-07T16:08:00.491Z,1638893280.491 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.801815 min 2021-12-07T16:08:00.491Z,1638893280.491 [Default:CheckIn:E] Stopped 2021-12-07T16:08:00.491Z,1638893280.491 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T16:08:00.491Z,1638893280.491 [Default:CheckIn] Stopped 2021-12-07T16:08:00.491Z,1638893280.491 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T16:08:00.491Z,1638893280.491 [Default:CheckIn](INFO): Running loop #9 2021-12-07T16:08:00.492Z,1638893280.492 [Default:CheckIn] Running Loop=9 2021-12-07T16:08:00.492Z,1638893280.492 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T16:08:00.492Z,1638893280.492 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T16:08:02.474Z,1638893282.474 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160801.00,A,3648.14991,N,12147.22197,W,0.058,31.64,071221,,,D*4E 2021-12-07T16:08:02.476Z,1638893282.476 [NAL9602](INFO): GPS fix at 20211207T160801: (36.802498, -121.787033) 2021-12-07T16:08:02.564Z,1638893282.564 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T16:08:02.564Z,1638893282.564 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T16:08:13.842Z,1638893293.842 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211207T150746/Courier0037.lzma 2021-12-07T16:08:14.845Z,1638893294.845 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Courier0037.lzma.bak 2021-12-07T16:08:14.845Z,1638893294.845 [DataOverHttps](INFO): SBD MOMSN=16334838 2021-12-07T16:08:21.122Z,1638893301.122 [NAL9602](INFO): SBD MO Status=2, MOMSN=17826, MT Status=2, MTMSN=0 2021-12-07T16:08:21.122Z,1638893301.122 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-07T16:08:31.386Z,1638893311.386 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20211207T150746/Express0038.lzma 2021-12-07T16:08:32.388Z,1638893312.388 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Express0038.lzma.bak 2021-12-07T16:08:32.389Z,1638893312.389 [DataOverHttps](INFO): SBD MOMSN=16334841 2021-12-07T16:08:33.648Z,1638893313.648 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T16:08:33.648Z,1638893313.648 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T16:08:33.648Z,1638893313.648 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T16:08:56.261Z,1638893336.261 [NAL9602](INFO): SBD MO Status=0, MOMSN=17826, MT Status=0, MTMSN=0 2021-12-07T16:08:56.261Z,1638893336.261 [NAL9602](INFO): No messages in MT queue 2021-12-07T16:09:26.968Z,1638893366.968 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-07T16:13:34.279Z,1638893614.279 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T16:13:34.280Z,1638893614.280 [Default:CheckIn:C.Wait] Stopped 2021-12-07T16:13:34.280Z,1638893614.280 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T16:13:34.280Z,1638893614.280 [Default:CheckIn:D] Running Loop=1 2021-12-07T16:13:34.644Z,1638893614.644 [Default:CheckIn:D] Stopped 2021-12-07T16:13:34.644Z,1638893614.644 [Default:CheckIn:E] Running Loop=1 2021-12-07T16:13:35.056Z,1638893615.056 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.378145 min 2021-12-07T16:13:35.056Z,1638893615.056 [Default:CheckIn:E] Stopped 2021-12-07T16:13:35.056Z,1638893615.056 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T16:13:35.056Z,1638893615.056 [Default:CheckIn] Stopped 2021-12-07T16:13:35.056Z,1638893615.056 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T16:13:35.056Z,1638893615.056 [Default:CheckIn](INFO): Running loop #10 2021-12-07T16:13:35.056Z,1638893615.056 [Default:CheckIn] Running Loop=10 2021-12-07T16:13:35.057Z,1638893615.057 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T16:13:35.057Z,1638893615.057 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T16:13:37.089Z,1638893617.089 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161336.00,A,3648.16576,N,12147.20108,W,1.866,4.82,071221,,,D*79 2021-12-07T16:13:37.095Z,1638893617.095 [NAL9602](INFO): GPS fix at 20211207T161336: (36.802763, -121.786685) 2021-12-07T16:13:37.124Z,1638893617.124 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T16:13:37.124Z,1638893617.124 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T16:13:45.194Z,1638893625.194 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20211207T150746/Courier0040.lzma 2021-12-07T16:13:46.201Z,1638893626.201 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Courier0040.lzma.bak 2021-12-07T16:13:46.202Z,1638893626.202 [DataOverHttps](INFO): SBD MOMSN=16334847 2021-12-07T16:13:57.665Z,1638893637.665 [NAL9602](INFO): SBD MO Status=2, MOMSN=17827, MT Status=2, MTMSN=0 2021-12-07T16:13:57.665Z,1638893637.665 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-07T16:14:02.562Z,1638893642.562 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20211207T150746/Express0041.lzma 2021-12-07T16:14:03.565Z,1638893643.565 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Express0041.lzma.bak 2021-12-07T16:14:03.565Z,1638893643.565 [DataOverHttps](INFO): SBD MOMSN=16334850 2021-12-07T16:14:04.634Z,1638893644.634 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T16:14:04.634Z,1638893644.634 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T16:14:04.634Z,1638893644.634 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T16:14:34.082Z,1638893674.082 [NAL9602](INFO): SBD MO Status=0, MOMSN=17827, MT Status=0, MTMSN=0 2021-12-07T16:14:34.083Z,1638893674.083 [NAL9602](INFO): No messages in MT queue 2021-12-07T16:15:04.780Z,1638893704.780 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-07T16:19:05.178Z,1638893945.178 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T16:19:05.178Z,1638893945.178 [Default:CheckIn:C.Wait] Stopped 2021-12-07T16:19:05.178Z,1638893945.178 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T16:19:05.178Z,1638893945.178 [Default:CheckIn:D] Running Loop=1 2021-12-07T16:19:05.586Z,1638893945.586 [Default:CheckIn:D] Stopped 2021-12-07T16:19:05.586Z,1638893945.586 [Default:CheckIn:E] Running Loop=1 2021-12-07T16:19:06.003Z,1638893946.003 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 67.893848 min 2021-12-07T16:19:06.003Z,1638893946.003 [Default:CheckIn:E] Stopped 2021-12-07T16:19:06.003Z,1638893946.003 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T16:19:06.004Z,1638893946.004 [Default:CheckIn] Stopped 2021-12-07T16:19:06.004Z,1638893946.004 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T16:19:06.004Z,1638893946.004 [Default:CheckIn](INFO): Running loop #11 2021-12-07T16:19:06.004Z,1638893946.004 [Default:CheckIn] Running Loop=11 2021-12-07T16:19:06.004Z,1638893946.004 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T16:19:06.004Z,1638893946.004 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T16:19:07.998Z,1638893947.998 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161907.00,A,3648.51314,N,12147.13296,W,5.482,324.24,071221,,,D*7B 2021-12-07T16:19:08.000Z,1638893948.000 [NAL9602](INFO): GPS fix at 20211207T161907: (36.808552, -121.785549) 2021-12-07T16:19:08.012Z,1638893948.012 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T16:19:08.012Z,1638893948.012 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T16:19:15.694Z,1638893955.694 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211207T150746/Courier0043.lzma 2021-12-07T16:19:16.696Z,1638893956.696 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Courier0043.lzma.bak 2021-12-07T16:19:16.697Z,1638893956.697 [DataOverHttps](INFO): SBD MOMSN=16334882 2021-12-07T16:19:29.813Z,1638893969.813 [NAL9602](INFO): SBD MO Status=0, MOMSN=17828, MT Status=0, MTMSN=0 2021-12-07T16:19:29.813Z,1638893969.813 [NAL9602](INFO): No messages in MT queue 2021-12-07T16:19:33.438Z,1638893973.438 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20211207T150746/Express0044.lzma 2021-12-07T16:19:34.441Z,1638893974.441 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Express0044.lzma.bak 2021-12-07T16:19:34.441Z,1638893974.441 [DataOverHttps](INFO): SBD MOMSN=16334885 2021-12-07T16:19:35.487Z,1638893975.487 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T16:19:35.487Z,1638893975.487 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T16:19:35.487Z,1638893975.487 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T16:20:00.512Z,1638894000.512 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-07T16:24:36.070Z,1638894276.070 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T16:24:36.070Z,1638894276.070 [Default:CheckIn:C.Wait] Stopped 2021-12-07T16:24:36.070Z,1638894276.070 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T16:24:36.070Z,1638894276.070 [Default:CheckIn:D] Running Loop=1 2021-12-07T16:24:36.493Z,1638894276.493 [Default:CheckIn:D] Stopped 2021-12-07T16:24:36.493Z,1638894276.493 [Default:CheckIn:E] Running Loop=1 2021-12-07T16:24:36.867Z,1638894276.867 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 73.408968 min 2021-12-07T16:24:36.867Z,1638894276.867 [Default:CheckIn:E] Stopped 2021-12-07T16:24:36.868Z,1638894276.868 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T16:24:36.868Z,1638894276.868 [Default:CheckIn] Stopped 2021-12-07T16:24:36.868Z,1638894276.868 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T16:24:36.868Z,1638894276.868 [Default:CheckIn](INFO): Running loop #12 2021-12-07T16:24:36.868Z,1638894276.868 [Default:CheckIn] Running Loop=12 2021-12-07T16:24:36.868Z,1638894276.868 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T16:24:36.868Z,1638894276.868 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T16:24:38.878Z,1638894278.878 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2021-12-07T16:24:38.882Z,1638894278.882 [BPC1](INFO): Received data from all battery sticks. 2021-12-07T16:24:38.886Z,1638894278.886 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162438.00,A,3647.60241,N,12148.37882,W,25.892,209.16,071221,,,D*43 2021-12-07T16:24:38.889Z,1638894278.889 [NAL9602](INFO): GPS fix at 20211207T162438: (36.793374, -121.806314) 2021-12-07T16:24:38.901Z,1638894278.901 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T16:24:38.901Z,1638894278.901 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T16:24:46.426Z,1638894286.426 [DataOverHttps](INFO): Sending 82 bytes from file Logs/20211207T150746/Courier0046.lzma 2021-12-07T16:24:47.432Z,1638894287.432 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Courier0046.lzma.bak 2021-12-07T16:24:47.432Z,1638894287.432 [DataOverHttps](INFO): SBD MOMSN=16334891 2021-12-07T16:24:58.269Z,1638894298.269 [NAL9602](INFO): SBD MO Status=0, MOMSN=17829, MT Status=0, MTMSN=0 2021-12-07T16:24:58.270Z,1638894298.270 [NAL9602](INFO): No messages in MT queue 2021-12-07T16:25:03.842Z,1638894303.842 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20211207T150746/Express0047.lzma 2021-12-07T16:25:04.845Z,1638894304.845 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Express0047.lzma.bak 2021-12-07T16:25:04.845Z,1638894304.845 [DataOverHttps](INFO): SBD MOMSN=16334894 2021-12-07T16:25:05.952Z,1638894305.952 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T16:25:05.952Z,1638894305.952 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T16:25:05.952Z,1638894305.952 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T16:25:28.967Z,1638894328.967 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-07T16:30:06.637Z,1638894606.637 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T16:30:06.637Z,1638894606.637 [Default:CheckIn:C.Wait] Stopped 2021-12-07T16:30:06.638Z,1638894606.638 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T16:30:06.638Z,1638894606.638 [Default:CheckIn:D] Running Loop=1 2021-12-07T16:30:06.993Z,1638894606.993 [Default:CheckIn:D] Stopped 2021-12-07T16:30:06.993Z,1638894606.993 [Default:CheckIn:E] Running Loop=1 2021-12-07T16:30:07.420Z,1638894607.420 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 78.917293 min 2021-12-07T16:30:07.420Z,1638894607.420 [Default:CheckIn:E] Stopped 2021-12-07T16:30:07.421Z,1638894607.421 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T16:30:07.421Z,1638894607.421 [Default:CheckIn] Stopped 2021-12-07T16:30:07.421Z,1638894607.421 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T16:30:07.421Z,1638894607.421 [Default:CheckIn](INFO): Running loop #13 2021-12-07T16:30:07.421Z,1638894607.421 [Default:CheckIn] Running Loop=13 2021-12-07T16:30:07.421Z,1638894607.421 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T16:30:07.421Z,1638894607.421 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T16:30:09.406Z,1638894609.406 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163008.00,A,3645.44138,N,12149.51430,W,25.523,203.28,071221,,,D*48 2021-12-07T16:30:09.408Z,1638894609.408 [NAL9602](INFO): GPS fix at 20211207T163008: (36.757356, -121.825238) 2021-12-07T16:30:09.429Z,1638894609.429 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T16:30:09.429Z,1638894609.429 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T16:30:17.578Z,1638894617.578 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20211207T150746/Courier0049.lzma 2021-12-07T16:30:18.580Z,1638894618.580 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Courier0049.lzma.bak 2021-12-07T16:30:18.581Z,1638894618.581 [DataOverHttps](INFO): SBD MOMSN=16334921 2021-12-07T16:30:35.975Z,1638894635.975 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20211207T150746/Express0050.lzma 2021-12-07T16:30:36.117Z,1638894636.117 [NAL9602](INFO): SBD MO Status=2, MOMSN=17830, MT Status=2, MTMSN=0 2021-12-07T16:30:36.117Z,1638894636.117 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-07T16:30:36.977Z,1638894636.977 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Express0050.lzma.bak 2021-12-07T16:30:36.977Z,1638894636.977 [DataOverHttps](INFO): SBD MOMSN=16334924 2021-12-07T16:30:38.135Z,1638894638.135 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T16:30:38.135Z,1638894638.135 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T16:30:38.136Z,1638894638.136 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T16:30:51.054Z,1638894651.054 [NAL9602](INFO): SBD MO Status=0, MOMSN=17830, MT Status=0, MTMSN=0 2021-12-07T16:30:51.054Z,1638894651.054 [NAL9602](INFO): No messages in MT queue 2021-12-07T16:31:21.752Z,1638894681.752 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-07T16:31:47.984Z,1638894707.984 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.130428 2021-12-07T16:31:56.683Z,1638894716.683 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002951 2021-12-07T16:32:54.911Z,1638894774.911 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-12-07T16:32:56.919Z,1638894776.919 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.239162 2021-12-07T16:33:30.083Z,1638894810.083 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-12-07T16:34:05.223Z,1638894845.223 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-12-07T16:34:40.363Z,1638894880.363 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-12-07T16:35:15.503Z,1638894915.503 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-12-07T16:35:38.715Z,1638894938.715 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T16:35:38.715Z,1638894938.715 [Default:CheckIn:C.Wait] Stopped 2021-12-07T16:35:38.715Z,1638894938.715 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T16:35:38.716Z,1638894938.716 [Default:CheckIn:D] Running Loop=1 2021-12-07T16:35:39.123Z,1638894939.123 [Default:CheckIn:D] Stopped 2021-12-07T16:35:39.123Z,1638894939.123 [Default:CheckIn:E] Running Loop=1 2021-12-07T16:35:39.525Z,1638894939.525 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 84.452799 min 2021-12-07T16:35:39.525Z,1638894939.525 [Default:CheckIn:E] Stopped 2021-12-07T16:35:39.525Z,1638894939.525 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T16:35:39.526Z,1638894939.526 [Default:CheckIn] Stopped 2021-12-07T16:35:39.526Z,1638894939.526 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T16:35:39.526Z,1638894939.526 [Default:CheckIn](INFO): Running loop #14 2021-12-07T16:35:39.526Z,1638894939.526 [Default:CheckIn] Running Loop=14 2021-12-07T16:35:39.526Z,1638894939.526 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T16:35:39.526Z,1638894939.526 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T16:35:41.542Z,1638894941.542 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163540.00,A,3643.29045,N,12150.73733,W,24.629,200.35,071221,,,D*48 2021-12-07T16:35:41.544Z,1638894941.544 [NAL9602](INFO): GPS fix at 20211207T163540: (36.721508, -121.845622) 2021-12-07T16:35:41.576Z,1638894941.576 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T16:35:41.576Z,1638894941.576 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T16:35:50.643Z,1638894950.643 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-12-07T16:36:12.349Z,1638894972.349 [NAL9602](INFO): SBD MO Status=2, MOMSN=17831, MT Status=2, MTMSN=0 2021-12-07T16:36:12.350Z,1638894972.350 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-07T16:36:25.788Z,1638894985.788 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-12-07T16:36:38.276Z,1638894998.276 [NAL9602](INFO): SBD MO Status=2, MOMSN=17831, MT Status=2, MTMSN=0 2021-12-07T16:36:38.277Z,1638894998.277 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-07T16:37:00.946Z,1638895020.946 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-12-07T16:37:12.262Z,1638895032.262 [NAL9602](INFO): SBD MO Status=2, MOMSN=17831, MT Status=2, MTMSN=0 2021-12-07T16:37:12.262Z,1638895032.262 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-07T16:37:36.091Z,1638895056.091 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-12-07T16:37:40.645Z,1638895060.645 [NAL9602](INFO): SBD MO Status=1, MOMSN=17831, MT Status=0, MTMSN=0 2021-12-07T16:37:40.707Z,1638895060.707 [NAL9602](INFO): Sent 72 bytes from file Logs/20211207T150746/Courier0052.lzma 2021-12-07T16:37:40.707Z,1638895060.707 [NAL9602](INFO): Packets left to send: 0 2021-12-07T16:37:52.014Z,1638895072.014 [NAL9602](INFO): SBD MO Status=1, MOMSN=17832, MT Status=0, MTMSN=0 2021-12-07T16:37:52.063Z,1638895072.063 [NAL9602](INFO): Sent 147 bytes from file Logs/20211207T150746/Express0053.lzma 2021-12-07T16:37:52.063Z,1638895072.063 [NAL9602](INFO): Packets left to send: 0 2021-12-07T16:38:00.501Z,1638895080.501 [NAL9602](INFO): SBD MO Status=0, MOMSN=17833, MT Status=0, MTMSN=0 2021-12-07T16:38:00.602Z,1638895080.602 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T16:38:00.602Z,1638895080.602 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T16:38:00.603Z,1638895080.603 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T16:38:11.235Z,1638895091.235 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-12-07T16:38:31.208Z,1638895111.208 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-07T16:38:46.383Z,1638895126.383 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-12-07T16:39:21.523Z,1638895161.523 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-12-07T16:39:56.671Z,1638895196.671 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-12-07T16:40:13.195Z,1638895213.195 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002960 2021-12-07T16:43:01.152Z,1638895381.152 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T16:43:01.152Z,1638895381.152 [Default:CheckIn:C.Wait] Stopped 2021-12-07T16:43:01.152Z,1638895381.152 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T16:43:01.152Z,1638895381.152 [Default:CheckIn:D] Running Loop=1 2021-12-07T16:43:01.563Z,1638895381.563 [Default:CheckIn:D] Stopped 2021-12-07T16:43:01.564Z,1638895381.564 [Default:CheckIn:E] Running Loop=1 2021-12-07T16:43:01.956Z,1638895381.956 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 91.826807 min 2021-12-07T16:43:01.956Z,1638895381.956 [Default:CheckIn:E] Stopped 2021-12-07T16:43:01.957Z,1638895381.957 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T16:43:01.957Z,1638895381.957 [Default:CheckIn] Stopped 2021-12-07T16:43:01.957Z,1638895381.957 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T16:43:01.957Z,1638895381.957 [Default:CheckIn](INFO): Running loop #15 2021-12-07T16:43:01.957Z,1638895381.957 [Default:CheckIn] Running Loop=15 2021-12-07T16:43:01.957Z,1638895381.957 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T16:43:01.957Z,1638895381.957 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T16:43:03.966Z,1638895383.966 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164303.00,A,3640.31428,N,12152.06105,W,26.883,207.55,071221,,,D*45 2021-12-07T16:43:03.968Z,1638895383.968 [NAL9602](INFO): GPS fix at 20211207T164303: (36.671905, -121.867684) 2021-12-07T16:43:04.029Z,1638895384.029 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T16:43:04.029Z,1638895384.029 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T16:43:07.718Z,1638895387.718 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211207T150746/Courier0055.lzma 2021-12-07T16:43:08.721Z,1638895388.721 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Courier0055.lzma.bak 2021-12-07T16:43:08.721Z,1638895388.721 [DataOverHttps](INFO): SBD MOMSN=16334936 2021-12-07T16:43:21.033Z,1638895401.033 [NAL9602](INFO): SBD MO Status=0, MOMSN=17834, MT Status=0, MTMSN=0 2021-12-07T16:43:21.034Z,1638895401.034 [NAL9602](INFO): No messages in MT queue 2021-12-07T16:43:25.247Z,1638895405.247 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20211207T150746/Express0056.lzma 2021-12-07T16:43:26.249Z,1638895406.249 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Express0056.lzma.bak 2021-12-07T16:43:26.249Z,1638895406.249 [DataOverHttps](INFO): SBD MOMSN=16334939 2021-12-07T16:43:27.507Z,1638895407.507 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T16:43:27.507Z,1638895407.507 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T16:43:27.507Z,1638895407.507 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T16:43:51.738Z,1638895431.738 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-07T16:48:28.176Z,1638895708.176 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T16:48:28.176Z,1638895708.176 [Default:CheckIn:C.Wait] Stopped 2021-12-07T16:48:28.176Z,1638895708.176 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T16:48:28.177Z,1638895708.177 [Default:CheckIn:D] Running Loop=1 2021-12-07T16:48:28.582Z,1638895708.582 [Default:CheckIn:D] Stopped 2021-12-07T16:48:28.582Z,1638895708.582 [Default:CheckIn:E] Running Loop=1 2021-12-07T16:48:28.956Z,1638895708.956 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 97.277108 min 2021-12-07T16:48:28.956Z,1638895708.956 [Default:CheckIn:E] Stopped 2021-12-07T16:48:28.956Z,1638895708.956 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T16:48:28.956Z,1638895708.956 [Default:CheckIn] Stopped 2021-12-07T16:48:28.956Z,1638895708.956 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T16:48:28.956Z,1638895708.956 [Default:CheckIn](INFO): Running loop #16 2021-12-07T16:48:28.956Z,1638895708.956 [Default:CheckIn] Running Loop=16 2021-12-07T16:48:28.957Z,1638895708.957 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T16:48:28.957Z,1638895708.957 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T16:48:30.962Z,1638895710.962 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164830.00,A,3638.56749,N,12153.79743,W,23.715,219.20,071221,,,D*41 2021-12-07T16:48:30.980Z,1638895710.980 [NAL9602](INFO): GPS fix at 20211207T164830: (36.642792, -121.896624) 2021-12-07T16:48:30.992Z,1638895710.992 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T16:48:30.992Z,1638895710.992 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T16:48:40.042Z,1638895720.042 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211207T150746/Courier0058.lzma 2021-12-07T16:48:41.045Z,1638895721.045 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Courier0058.lzma.bak 2021-12-07T16:48:41.045Z,1638895721.045 [DataOverHttps](INFO): SBD MOMSN=16334945 2021-12-07T16:48:56.814Z,1638895736.814 [NAL9602](INFO): SBD MO Status=2, MOMSN=17835, MT Status=2, MTMSN=0 2021-12-07T16:48:56.814Z,1638895736.814 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-07T16:48:57.575Z,1638895737.575 [DataOverHttps](INFO): Sending 147 bytes from file Logs/20211207T150746/Express0059.lzma 2021-12-07T16:48:58.577Z,1638895738.577 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Express0059.lzma.bak 2021-12-07T16:48:58.577Z,1638895738.577 [DataOverHttps](INFO): SBD MOMSN=16334948 2021-12-07T16:48:59.652Z,1638895739.652 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T16:48:59.652Z,1638895739.652 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T16:48:59.652Z,1638895739.652 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T16:49:49.344Z,1638895789.344 [NAL9602](INFO): SBD MO Status=2, MOMSN=17835, MT Status=2, MTMSN=0 2021-12-07T16:49:49.344Z,1638895789.344 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-07T16:50:00.249Z,1638895800.249 [NAL9602](INFO): SBD MO Status=0, MOMSN=17835, MT Status=0, MTMSN=0 2021-12-07T16:50:00.249Z,1638895800.249 [NAL9602](INFO): No messages in MT queue 2021-12-07T16:50:30.948Z,1638895830.948 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-07T16:53:34.410Z,1638896014.410 [RDI_Pathfinder](ERROR): only read 0 of 4 data items 2021-12-07T16:54:00.285Z,1638896040.285 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T16:54:00.285Z,1638896040.285 [Default:CheckIn:C.Wait] Stopped 2021-12-07T16:54:00.285Z,1638896040.285 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T16:54:00.285Z,1638896040.285 [Default:CheckIn:D] Running Loop=1 2021-12-07T16:54:00.683Z,1638896040.683 [Default:CheckIn:D] Stopped 2021-12-07T16:54:00.683Z,1638896040.683 [Default:CheckIn:E] Running Loop=1 2021-12-07T16:54:01.065Z,1638896041.065 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 102.812134 min 2021-12-07T16:54:01.065Z,1638896041.065 [Default:CheckIn:E] Stopped 2021-12-07T16:54:01.065Z,1638896041.065 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T16:54:01.065Z,1638896041.065 [Default:CheckIn] Stopped 2021-12-07T16:54:01.065Z,1638896041.065 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T16:54:01.065Z,1638896041.065 [Default:CheckIn](INFO): Running loop #17 2021-12-07T16:54:01.065Z,1638896041.065 [Default:CheckIn] Running Loop=17 2021-12-07T16:54:01.066Z,1638896041.066 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T16:54:01.066Z,1638896041.066 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T16:54:03.074Z,1638896043.074 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165402.00,A,3637.66981,N,12154.60163,W,1.147,105.90,071221,,,D*74 2021-12-07T16:54:03.076Z,1638896043.076 [NAL9602](INFO): GPS fix at 20211207T165402: (36.627830, -121.910027) 2021-12-07T16:54:03.115Z,1638896043.115 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T16:54:03.115Z,1638896043.115 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T16:54:20.192Z,1638896060.192 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211207T150746/Courier0061.lzma 2021-12-07T16:54:21.181Z,1638896061.181 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Courier0061.lzma.bak 2021-12-07T16:54:21.181Z,1638896061.181 [DataOverHttps](INFO): SBD MOMSN=16334958 2021-12-07T16:54:26.917Z,1638896066.917 [NAL9602](INFO): SBD MO Status=0, MOMSN=17836, MT Status=0, MTMSN=0 2021-12-07T16:54:26.917Z,1638896066.917 [NAL9602](INFO): No messages in MT queue 2021-12-07T16:54:40.677Z,1638896080.677 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20211207T150746/Express0062.lzma 2021-12-07T16:54:41.677Z,1638896081.677 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Express0062.lzma.bak 2021-12-07T16:54:41.677Z,1638896081.677 [DataOverHttps](INFO): SBD MOMSN=16334963 2021-12-07T16:54:42.708Z,1638896082.708 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T16:54:42.708Z,1638896082.708 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T16:54:42.708Z,1638896082.708 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T16:54:57.613Z,1638896097.613 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-07T16:59:43.266Z,1638896383.266 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T16:59:43.266Z,1638896383.266 [Default:CheckIn:C.Wait] Stopped 2021-12-07T16:59:43.266Z,1638896383.266 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T16:59:43.266Z,1638896383.266 [Default:CheckIn:D] Running Loop=1 2021-12-07T16:59:43.664Z,1638896383.664 [Default:CheckIn:D] Stopped 2021-12-07T16:59:43.665Z,1638896383.665 [Default:CheckIn:E] Running Loop=1 2021-12-07T16:59:44.065Z,1638896384.065 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 108.528491 min 2021-12-07T16:59:44.065Z,1638896384.065 [Default:CheckIn:E] Stopped 2021-12-07T16:59:44.065Z,1638896384.065 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T16:59:44.065Z,1638896384.065 [Default:CheckIn] Stopped 2021-12-07T16:59:44.065Z,1638896384.065 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T16:59:44.065Z,1638896384.065 [Default:CheckIn](INFO): Running loop #18 2021-12-07T16:59:44.065Z,1638896384.065 [Default:CheckIn] Running Loop=18 2021-12-07T16:59:44.065Z,1638896384.065 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T16:59:44.066Z,1638896384.066 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T16:59:46.078Z,1638896386.078 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165945.00,A,3637.67189,N,12154.59716,W,0.350,35.50,071221,,,D*4E 2021-12-07T16:59:46.090Z,1638896386.090 [NAL9602](INFO): GPS fix at 20211207T165945: (36.627865, -121.909953) 2021-12-07T16:59:46.102Z,1638896386.102 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T16:59:46.102Z,1638896386.102 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T16:59:54.177Z,1638896394.177 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211207T150746/Courier0064.lzma 2021-12-07T16:59:55.173Z,1638896395.173 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Courier0064.lzma.bak 2021-12-07T16:59:55.173Z,1638896395.173 [DataOverHttps](INFO): SBD MOMSN=16334971 2021-12-07T17:00:02.633Z,1638896402.633 [NAL9602](INFO): SBD MO Status=0, MOMSN=17837, MT Status=0, MTMSN=0 2021-12-07T17:00:02.633Z,1638896402.633 [NAL9602](INFO): No messages in MT queue 2021-12-07T17:00:14.851Z,1638896414.851 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20211207T150746/Express0065.lzma 2021-12-07T17:00:15.853Z,1638896415.853 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Express0065.lzma.bak 2021-12-07T17:00:15.853Z,1638896415.853 [DataOverHttps](INFO): SBD MOMSN=16334974 2021-12-07T17:00:16.871Z,1638896416.871 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T17:00:16.871Z,1638896416.871 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T17:00:16.871Z,1638896416.871 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T17:00:33.412Z,1638896433.412 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-07T17:03:59.396Z,1638896639.396 [DataOverHttps](IMPORTANT): SBD MTMSN=20211207T170358 2021-12-07T17:04:10.482Z,1638896650.482 [DataOverHttps](INFO): Received command: Failc 2021-12-07T17:04:10.499Z,1638896650.499 [CommandExec](IMPORTANT): got command failComponent 2021-12-07T17:04:10.499Z,1638896650.499 [CommandExec](IMPORTANT): Failed components: 2021-12-07T17:04:10.500Z,1638896650.500 [CommandExec](IMPORTANT): No failed Components. 2021-12-07T17:05:17.571Z,1638896717.571 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T17:05:17.571Z,1638896717.571 [Default:CheckIn:C.Wait] Stopped 2021-12-07T17:05:17.571Z,1638896717.571 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T17:05:17.571Z,1638896717.571 [Default:CheckIn:D] Running Loop=1 2021-12-07T17:05:17.963Z,1638896717.963 [Default:CheckIn:D] Stopped 2021-12-07T17:05:17.963Z,1638896717.963 [Default:CheckIn:E] Running Loop=1 2021-12-07T17:05:18.386Z,1638896718.386 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 114.100138 min 2021-12-07T17:05:18.386Z,1638896718.386 [Default:CheckIn:E] Stopped 2021-12-07T17:05:18.387Z,1638896718.387 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T17:05:18.387Z,1638896718.387 [Default:CheckIn] Stopped 2021-12-07T17:05:18.387Z,1638896718.387 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T17:05:18.387Z,1638896718.387 [Default:CheckIn](INFO): Running loop #19 2021-12-07T17:05:18.387Z,1638896718.387 [Default:CheckIn] Running Loop=19 2021-12-07T17:05:18.387Z,1638896718.387 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T17:05:18.387Z,1638896718.387 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T17:05:20.374Z,1638896720.374 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170519.00,A,3637.67383,N,12154.59530,W,0.330,211.96,071221,,,D*79 2021-12-07T17:05:20.376Z,1638896720.376 [NAL9602](INFO): GPS fix at 20211207T170519: (36.627897, -121.909922) 2021-12-07T17:05:20.459Z,1638896720.459 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T17:05:20.460Z,1638896720.460 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T17:05:28.062Z,1638896728.062 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211207T150746/Courier0067.lzma 2021-12-07T17:05:29.064Z,1638896729.064 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Courier0067.lzma.bak 2021-12-07T17:05:29.065Z,1638896729.065 [DataOverHttps](INFO): SBD MOMSN=16334982 2021-12-07T17:05:45.599Z,1638896745.599 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20211207T150746/Express0068.lzma 2021-12-07T17:05:46.601Z,1638896746.601 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Express0068.lzma.bak 2021-12-07T17:05:46.601Z,1638896746.601 [DataOverHttps](INFO): SBD MOMSN=16334985 2021-12-07T17:05:48.249Z,1638896748.249 [NAL9602](INFO): SBD MO Status=0, MOMSN=17838, MT Status=0, MTMSN=0 2021-12-07T17:05:48.250Z,1638896748.250 [NAL9602](INFO): No messages in MT queue 2021-12-07T17:06:02.866Z,1638896762.866 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20211207T150746/Express0071.lzma 2021-12-07T17:06:03.869Z,1638896763.869 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Express0071.lzma.bak 2021-12-07T17:06:03.869Z,1638896763.869 [DataOverHttps](INFO): SBD MOMSN=16334992 2021-12-07T17:06:04.910Z,1638896764.910 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T17:06:04.910Z,1638896764.910 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T17:06:04.910Z,1638896764.910 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T17:06:18.999Z,1638896778.999 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-07T17:11:05.457Z,1638897065.457 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T17:11:05.458Z,1638897065.458 [Default:CheckIn:C.Wait] Stopped 2021-12-07T17:11:05.458Z,1638897065.458 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T17:11:05.458Z,1638897065.458 [Default:CheckIn:D] Running Loop=1 2021-12-07T17:11:05.852Z,1638897065.852 [Default:CheckIn:D] Stopped 2021-12-07T17:11:05.852Z,1638897065.852 [Default:CheckIn:E] Running Loop=1 2021-12-07T17:11:06.293Z,1638897066.293 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 119.898275 min 2021-12-07T17:11:06.293Z,1638897066.293 [Default:CheckIn:E] Stopped 2021-12-07T17:11:06.293Z,1638897066.293 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T17:11:06.293Z,1638897066.293 [Default:CheckIn] Stopped 2021-12-07T17:11:06.293Z,1638897066.293 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T17:11:06.293Z,1638897066.293 [Default:CheckIn](INFO): Running loop #20 2021-12-07T17:11:06.293Z,1638897066.293 [Default:CheckIn] Running Loop=20 2021-12-07T17:11:06.293Z,1638897066.293 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T17:11:06.294Z,1638897066.294 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T17:11:08.274Z,1638897068.274 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171107.00,A,3637.67632,N,12154.60146,W,1.089,294.96,071221,,,D*7E 2021-12-07T17:11:08.276Z,1638897068.276 [NAL9602](INFO): GPS fix at 20211207T171107: (36.627939, -121.910024) 2021-12-07T17:11:08.308Z,1638897068.308 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T17:11:08.308Z,1638897068.308 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T17:11:15.906Z,1638897075.906 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20211207T150746/Courier0073.lzma 2021-12-07T17:11:16.909Z,1638897076.909 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Courier0073.lzma.bak 2021-12-07T17:11:16.909Z,1638897076.909 [DataOverHttps](INFO): SBD MOMSN=16334995 2021-12-07T17:11:18.773Z,1638897078.773 [NAL9602](INFO): SBD MO Status=0, MOMSN=17839, MT Status=0, MTMSN=0 2021-12-07T17:11:18.774Z,1638897078.774 [NAL9602](INFO): No messages in MT queue 2021-12-07T17:11:33.478Z,1638897093.478 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20211207T150746/Express0074.lzma 2021-12-07T17:11:34.481Z,1638897094.481 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Express0074.lzma.bak 2021-12-07T17:11:34.481Z,1638897094.481 [DataOverHttps](INFO): SBD MOMSN=16334998 2021-12-07T17:11:35.756Z,1638897095.756 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T17:11:35.756Z,1638897095.756 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T17:11:35.756Z,1638897095.756 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T17:11:49.476Z,1638897109.476 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-07T17:16:36.390Z,1638897396.390 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T17:16:36.390Z,1638897396.390 [Default:CheckIn:C.Wait] Stopped 2021-12-07T17:16:36.390Z,1638897396.390 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T17:16:36.391Z,1638897396.391 [Default:CheckIn:D] Running Loop=1 2021-12-07T17:16:36.789Z,1638897396.789 [Default:CheckIn:D] Stopped 2021-12-07T17:16:36.789Z,1638897396.789 [Default:CheckIn:E] Running Loop=1 2021-12-07T17:16:37.172Z,1638897397.172 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 125.413900 min 2021-12-07T17:16:37.173Z,1638897397.173 [Default:CheckIn:E] Stopped 2021-12-07T17:16:37.173Z,1638897397.173 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T17:16:37.173Z,1638897397.173 [Default:CheckIn] Stopped 2021-12-07T17:16:37.173Z,1638897397.173 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T17:16:37.173Z,1638897397.173 [Default:CheckIn](INFO): Running loop #21 2021-12-07T17:16:37.173Z,1638897397.173 [Default:CheckIn] Running Loop=21 2021-12-07T17:16:37.173Z,1638897397.173 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T17:16:37.173Z,1638897397.173 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T17:16:39.180Z,1638897399.180 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171638.00,A,3637.81258,N,12154.50086,W,0.369,166.97,071221,,,A*7D 2021-12-07T17:16:39.182Z,1638897399.182 [NAL9602](INFO): GPS fix at 20211207T171638: (36.630210, -121.908348) 2021-12-07T17:16:39.194Z,1638897399.194 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T17:16:39.194Z,1638897399.194 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T17:16:46.853Z,1638897406.853 [NAL9602](INFO): SBD MO Status=0, MOMSN=17840, MT Status=0, MTMSN=0 2021-12-07T17:16:46.854Z,1638897406.854 [NAL9602](INFO): No messages in MT queue 2021-12-07T17:16:49.994Z,1638897409.994 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211207T150746/Courier0076.lzma 2021-12-07T17:16:50.997Z,1638897410.997 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Courier0076.lzma.bak 2021-12-07T17:16:50.997Z,1638897410.997 [DataOverHttps](INFO): SBD MOMSN=16335002 2021-12-07T17:17:08.623Z,1638897428.623 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20211207T150746/Express0077.lzma 2021-12-07T17:17:09.625Z,1638897429.625 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Express0077.lzma.bak 2021-12-07T17:17:09.625Z,1638897429.625 [DataOverHttps](INFO): SBD MOMSN=16335006 2021-12-07T17:17:10.700Z,1638897430.700 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T17:17:10.700Z,1638897430.700 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T17:17:10.700Z,1638897430.700 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T17:17:17.566Z,1638897437.566 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-07T17:22:11.364Z,1638897731.364 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T17:22:11.364Z,1638897731.364 [Default:CheckIn:C.Wait] Stopped 2021-12-07T17:22:11.364Z,1638897731.364 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T17:22:11.365Z,1638897731.365 [Default:CheckIn:D] Running Loop=1 2021-12-07T17:22:11.700Z,1638897731.700 [Default:CheckIn:D] Stopped 2021-12-07T17:22:11.700Z,1638897731.700 [Default:CheckIn:E] Running Loop=1 2021-12-07T17:22:12.219Z,1638897732.219 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 130.995752 min 2021-12-07T17:22:12.219Z,1638897732.219 [Default:CheckIn:E] Stopped 2021-12-07T17:22:12.219Z,1638897732.219 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T17:22:12.220Z,1638897732.220 [Default:CheckIn] Stopped 2021-12-07T17:22:12.220Z,1638897732.220 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T17:22:12.220Z,1638897732.220 [Default:CheckIn](INFO): Running loop #22 2021-12-07T17:22:12.220Z,1638897732.220 [Default:CheckIn] Running Loop=22 2021-12-07T17:22:12.220Z,1638897732.220 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T17:22:12.220Z,1638897732.220 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T17:22:14.100Z,1638897734.100 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172213.00,A,3637.83268,N,12154.54294,W,0.350,311.77,071221,,,A*71 2021-12-07T17:22:14.102Z,1638897734.102 [NAL9602](INFO): GPS fix at 20211207T172213: (36.630545, -121.909049) 2021-12-07T17:22:14.135Z,1638897734.135 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T17:22:14.135Z,1638897734.135 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T17:22:21.882Z,1638897741.882 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211207T150746/Courier0079.lzma 2021-12-07T17:22:22.885Z,1638897742.885 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Courier0079.lzma.bak 2021-12-07T17:22:22.885Z,1638897742.885 [DataOverHttps](INFO): SBD MOMSN=16335030 2021-12-07T17:22:29.449Z,1638897749.449 [NAL9602](INFO): SBD MO Status=0, MOMSN=17841, MT Status=0, MTMSN=0 2021-12-07T17:22:29.449Z,1638897749.449 [NAL9602](INFO): No messages in MT queue 2021-12-07T17:22:39.658Z,1638897759.658 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20211207T150746/Express0080.lzma 2021-12-07T17:22:40.661Z,1638897760.661 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Express0080.lzma.bak 2021-12-07T17:22:40.661Z,1638897760.661 [DataOverHttps](INFO): SBD MOMSN=16335033 2021-12-07T17:22:42.000Z,1638897762.000 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T17:22:42.000Z,1638897762.000 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T17:22:42.001Z,1638897762.001 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T17:23:00.158Z,1638897780.158 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-07T17:23:25.448Z,1638897805.448 [DataOverHttps](IMPORTANT): SBD MTMSN=20211207T172324