2021-04-12T14:53:47.101Z,1618239227.101 [Supervisor](DEBUG): Initializing supervisor. 2021-04-12T14:53:47.106Z,1618239227.106 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2021-04-12T14:53:47.106Z,1618239227.106 [SyncHandler](INFO): Protected caller Thread ID is 819 2021-04-12T14:53:47.107Z,1618239227.107 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2021-04-12T14:53:47.108Z,1618239227.108 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2021-04-12T14:53:47.108Z,1618239227.108 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 820 2021-04-12T14:53:47.112Z,1618239227.112 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2021-04-12T14:53:47.130Z,1618239227.130 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2021-04-12T14:53:47.131Z,1618239227.131 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2021-04-12T14:53:47.132Z,1618239227.132 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 821 2021-04-12T14:53:47.134Z,1618239227.134 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2021-04-12T14:53:47.135Z,1618239227.135 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2021-04-12T14:53:47.135Z,1618239227.135 [logger ThreadHandler](INFO): Protected caller Thread ID is 822 2021-04-12T14:53:47.139Z,1618239227.139 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2021-04-12T14:53:47.139Z,1618239227.139 [Supervisor](INFO): Looking for Config files in directory: Config/ 2021-04-12T14:53:47.143Z,1618239227.143 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2021-04-12T14:53:47.484Z,1618239227.484 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2021-04-12T14:53:47.486Z,1618239227.486 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2021-04-12T14:53:48.095Z,1618239228.095 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2021-04-12T14:53:48.097Z,1618239228.097 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2021-04-12T14:53:48.198Z,1618239228.198 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2021-04-12T14:53:48.198Z,1618239228.198 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2021-04-12T14:53:48.718Z,1618239228.718 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2021-04-12T14:53:48.720Z,1618239228.720 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2021-04-12T14:53:48.816Z,1618239228.816 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2021-04-12T14:53:48.817Z,1618239228.817 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2021-04-12T14:53:48.898Z,1618239228.898 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2021-04-12T14:53:49.255Z,1618239229.255 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2021-04-12T14:53:49.257Z,1618239229.257 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2021-04-12T14:53:49.405Z,1618239229.405 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2021-04-12T14:53:49.407Z,1618239229.407 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2021-04-12T14:53:49.534Z,1618239229.534 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2021-04-12T14:53:49.535Z,1618239229.535 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2021-04-12T14:53:49.766Z,1618239229.766 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2021-04-12T14:53:49.767Z,1618239229.767 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2021-04-12T14:53:50.214Z,1618239230.214 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2021-04-12T14:53:50.216Z,1618239230.216 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2021-04-12T14:53:50.583Z,1618239230.583 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2021-04-12T14:53:50.584Z,1618239230.584 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2021-04-12T14:53:51.182Z,1618239231.182 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2021-04-12T14:53:51.375Z,1618239231.375 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2021-04-12T14:53:51.377Z,1618239231.377 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2021-04-12T14:53:51.586Z,1618239231.586 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2021-04-12T14:53:51.587Z,1618239231.587 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2021-04-12T14:53:51.835Z,1618239231.835 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2021-04-12T14:53:51.837Z,1618239231.837 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-brizo/ 2021-04-12T14:53:51.840Z,1618239231.840 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Control.cfg 2021-04-12T14:53:51.939Z,1618239231.939 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Sensor.cfg 2021-04-12T14:53:52.087Z,1618239232.087 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Simulator.cfg 2021-04-12T14:53:52.175Z,1618239232.175 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/secure.cfg 2021-04-12T14:53:52.259Z,1618239232.259 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Servo.cfg 2021-04-12T14:53:52.367Z,1618239232.367 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/vehicle.cfg 2021-04-12T14:53:52.554Z,1618239232.554 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Battery.cfg 2021-04-12T14:53:52.813Z,1618239232.813 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2021-04-12T14:53:52.815Z,1618239232.815 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Science.cfg 2021-04-12T14:53:52.997Z,1618239232.997 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/logger.cfg 2021-04-12T14:53:53.092Z,1618239233.092 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/BIT.cfg 2021-04-12T14:53:53.199Z,1618239233.199 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Navigation.cfg 2021-04-12T14:53:53.294Z,1618239233.294 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2021-04-12T14:53:53.305Z,1618239233.305 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2021-04-12T14:53:53.412Z,1618239233.412 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2021-04-12T14:53:53.414Z,1618239233.414 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2021-04-12T14:53:53.430Z,1618239233.430 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2021-04-12T14:53:53.431Z,1618239233.431 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2021-04-12T14:53:53.488Z,1618239233.488 [DepthRateCalculator] Loaded 2021-04-12T14:53:53.488Z,1618239233.488 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2021-04-12T14:53:53.493Z,1618239233.493 [PitchRateCalculator] Loaded 2021-04-12T14:53:53.493Z,1618239233.493 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2021-04-12T14:53:53.503Z,1618239233.503 [SpeedCalculator] Loaded 2021-04-12T14:53:53.504Z,1618239233.504 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2021-04-12T14:53:53.516Z,1618239233.516 [TempGradientCalculator] Loaded 2021-04-12T14:53:53.517Z,1618239233.517 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2021-04-12T14:53:53.521Z,1618239233.521 [YawRateCalculator] Loaded 2021-04-12T14:53:53.522Z,1618239233.522 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2021-04-12T14:53:53.541Z,1618239233.541 [ElevatorOffsetCalculator] Loaded 2021-04-12T14:53:53.542Z,1618239233.542 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2021-04-12T14:53:53.542Z,1618239233.542 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2021-04-12T14:53:53.543Z,1618239233.543 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2021-04-12T14:53:53.611Z,1618239233.611 [VerticalControl](DEBUG): Construct VerticalControl. 2021-04-12T14:53:53.666Z,1618239233.666 [VerticalControl] Loaded 2021-04-12T14:53:53.666Z,1618239233.666 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2021-04-12T14:53:53.668Z,1618239233.668 [HorizontalControl](DEBUG): Construct HorizontalControl. 2021-04-12T14:53:53.705Z,1618239233.705 [HorizontalControl] Loaded 2021-04-12T14:53:53.706Z,1618239233.706 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2021-04-12T14:53:53.708Z,1618239233.708 [SpeedControl](DEBUG): Construct SpeedControl. 2021-04-12T14:53:53.711Z,1618239233.711 [SpeedControl] Loaded 2021-04-12T14:53:53.711Z,1618239233.711 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2021-04-12T14:53:53.714Z,1618239233.714 [LoopControl](DEBUG): Construct LoopControl. 2021-04-12T14:53:53.714Z,1618239233.714 [LoopControl] Loaded 2021-04-12T14:53:53.714Z,1618239233.714 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2021-04-12T14:53:53.715Z,1618239233.715 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2021-04-12T14:53:53.715Z,1618239233.715 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2021-04-12T14:53:53.812Z,1618239233.812 [DeadReckonUsingMultipleVelocitySources] Loaded 2021-04-12T14:53:53.812Z,1618239233.812 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2021-04-12T14:53:53.825Z,1618239233.825 [NavChart] Loaded 2021-04-12T14:53:53.825Z,1618239233.825 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2021-04-12T14:53:53.831Z,1618239233.831 [UniversalFixResidualReporter] Loaded 2021-04-12T14:53:53.831Z,1618239233.831 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2021-04-12T14:53:53.832Z,1618239233.832 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2021-04-12T14:53:53.832Z,1618239233.832 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2021-04-12T14:53:53.957Z,1618239233.957 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2021-04-12T14:53:53.958Z,1618239233.958 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2021-04-12T14:53:54.667Z,1618239234.667 [AHRS_M2] Loaded 2021-04-12T14:53:54.667Z,1618239234.667 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2021-04-12T14:53:54.910Z,1618239234.910 [BackseatComponent] Loaded 2021-04-12T14:53:54.910Z,1618239234.910 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2021-04-12T14:53:54.911Z,1618239234.911 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408674E0 2021-04-12T14:53:54.912Z,1618239234.912 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 905 2021-04-12T14:53:54.914Z,1618239234.914 [LcmUniversalReporter] Loaded 2021-04-12T14:53:54.914Z,1618239234.914 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2021-04-12T14:53:55.676Z,1618239235.676 [BPC1] Loaded 2021-04-12T14:53:55.676Z,1618239235.676 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2021-04-12T14:53:55.814Z,1618239235.814 [DataOverHttps] Loaded 2021-04-12T14:53:55.815Z,1618239235.815 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2021-04-12T14:53:55.815Z,1618239235.815 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408974E0 2021-04-12T14:53:55.816Z,1618239235.816 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 906 2021-04-12T14:53:55.835Z,1618239235.835 [Depth_Keller] Loaded 2021-04-12T14:53:55.835Z,1618239235.835 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2021-04-12T14:53:55.840Z,1618239235.840 [DropWeight] Loaded 2021-04-12T14:53:55.840Z,1618239235.840 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2021-04-12T14:53:55.873Z,1618239235.873 [DVL_micro] Loaded 2021-04-12T14:53:55.874Z,1618239235.874 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2021-04-12T14:53:55.931Z,1618239235.931 [NAL9602] Loaded 2021-04-12T14:53:55.938Z,1618239235.938 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2021-04-12T14:53:56.006Z,1618239236.006 [Onboard] Loaded 2021-04-12T14:53:56.006Z,1618239236.006 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2021-04-12T14:53:56.007Z,1618239236.007 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408C74E0 2021-04-12T14:53:56.008Z,1618239236.008 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 907 2021-04-12T14:53:56.028Z,1618239236.028 [Radio_Surface] Loaded 2021-04-12T14:53:56.028Z,1618239236.028 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2021-04-12T14:53:56.038Z,1618239236.038 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408F74E0 2021-04-12T14:53:56.038Z,1618239236.038 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 908 2021-04-12T14:53:56.276Z,1618239236.276 [DAT] Loaded 2021-04-12T14:53:56.276Z,1618239236.276 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2021-04-12T14:53:56.277Z,1618239236.277 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2021-04-12T14:53:56.277Z,1618239236.277 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2021-04-12T14:53:56.685Z,1618239236.685 [BuoyancyServo] Loaded 2021-04-12T14:53:56.685Z,1618239236.685 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2021-04-12T14:53:56.704Z,1618239236.704 [ElevatorServo] Loaded 2021-04-12T14:53:56.704Z,1618239236.704 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2021-04-12T14:53:56.723Z,1618239236.723 [MassServo] Loaded 2021-04-12T14:53:56.723Z,1618239236.723 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2021-04-12T14:53:56.740Z,1618239236.740 [RudderServo] Loaded 2021-04-12T14:53:56.740Z,1618239236.740 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2021-04-12T14:53:56.757Z,1618239236.757 [ThrusterServo] Loaded 2021-04-12T14:53:56.758Z,1618239236.758 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2021-04-12T14:53:56.758Z,1618239236.758 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2021-04-12T14:53:56.759Z,1618239236.759 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2021-04-12T14:53:56.835Z,1618239236.835 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2021-04-12T14:53:56.835Z,1618239236.835 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2021-04-12T14:53:56.877Z,1618239236.877 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2021-04-12T14:53:56.878Z,1618239236.878 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2021-04-12T14:53:57.232Z,1618239237.232 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2021-04-12T14:53:57.232Z,1618239237.232 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2021-04-12T14:53:57.446Z,1618239237.446 [CTD_Seabird] Loaded 2021-04-12T14:53:57.446Z,1618239237.446 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2021-04-12T14:53:57.447Z,1618239237.447 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A7F4E0 2021-04-12T14:53:57.447Z,1618239237.447 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 909 2021-04-12T14:53:57.479Z,1618239237.479 [ESPComponent] Loaded 2021-04-12T14:53:57.479Z,1618239237.479 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2021-04-12T14:53:57.498Z,1618239237.498 [PAR_Licor] Loaded 2021-04-12T14:53:57.498Z,1618239237.498 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2021-04-12T14:53:57.528Z,1618239237.528 [WetLabsBB2FL] Loaded 2021-04-12T14:53:57.528Z,1618239237.528 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2021-04-12T14:53:57.530Z,1618239237.530 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AAF4E0 2021-04-12T14:53:57.530Z,1618239237.530 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 910 2021-04-12T14:53:57.531Z,1618239237.531 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2021-04-12T14:53:57.531Z,1618239237.531 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2021-04-12T14:53:57.695Z,1618239237.695 [SBIT](DEBUG): Construct Startup Built In Test. 2021-04-12T14:53:57.704Z,1618239237.704 [SBIT] Loaded 2021-04-12T14:53:57.705Z,1618239237.705 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2021-04-12T14:53:57.707Z,1618239237.707 [IBIT](DEBUG): Construct Initiated Built In Test. 2021-04-12T14:53:57.720Z,1618239237.720 [IBIT] Loaded 2021-04-12T14:53:57.721Z,1618239237.721 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2021-04-12T14:53:57.726Z,1618239237.726 [CBIT](DEBUG): Construct Continuous Built In Test. 2021-04-12T14:53:57.825Z,1618239237.825 [CBIT] Loaded 2021-04-12T14:53:57.825Z,1618239237.825 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2021-04-12T14:53:57.825Z,1618239237.825 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2021-04-12T14:53:57.831Z,1618239237.831 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2021-04-12T14:53:57.834Z,1618239237.834 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2021-04-12T14:53:57.844Z,1618239237.844 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2021-04-12T14:53:57.845Z,1618239237.845 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B1B4E0 2021-04-12T14:53:57.845Z,1618239237.845 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 911 2021-04-12T14:53:57.850Z,1618239237.850 [Supervisor](INFO): Main Thread ID is 815 2021-04-12T14:53:57.850Z,1618239237.850 [Supervisor](DEBUG): Running supervisor. 2021-04-12T14:53:57.851Z,1618239237.851 [CommandLine ThreadHandler](INFO): Handler Thread ID is 912 2021-04-12T14:53:57.853Z,1618239237.853 [controlThread ThreadHandler](INFO): Handler Thread ID is 913 2021-04-12T14:53:57.854Z,1618239237.854 [controlThread](DEBUG): Initializing ControlThread 2021-04-12T14:53:57.854Z,1618239237.854 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2021-04-12T14:53:57.855Z,1618239237.855 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2021-04-12T14:53:57.855Z,1618239237.855 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2021-04-12T14:53:57.855Z,1618239237.855 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2021-04-12T14:53:57.856Z,1618239237.856 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2021-04-12T14:53:57.856Z,1618239237.856 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2021-04-12T14:53:57.857Z,1618239237.857 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2021-04-12T14:53:57.859Z,1618239237.859 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2021-04-12T14:53:57.860Z,1618239237.860 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2021-04-12T14:53:57.860Z,1618239237.860 [LoopControl](DEBUG): Initialize LoopControlComponent. 2021-04-12T14:53:57.861Z,1618239237.861 [NavChart](DEBUG): Initialize NavChart Navigation. 2021-04-12T14:53:57.861Z,1618239237.861 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2021-04-12T14:53:57.870Z,1618239237.870 [SBIT](INFO): Initialize SBIT Component. 2021-04-12T14:53:57.871Z,1618239237.871 [SBIT](IMPORTANT): git: 2021-04-12 2021-04-12T14:53:57.871Z,1618239237.871 [SBIT](INFO): git hash: 4d37ca66b772b9605b4b6eba7ca05c94731fcf29 2021-04-12T14:53:57.871Z,1618239237.871 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2021-04-12T14:53:57.871Z,1618239237.871 [SBIT](IMPORTANT): Kernel Version:#1 PREEMPT Tue Sep 24 11:12:27 PDT 2019 2021-04-12T14:53:57.872Z,1618239237.872 [SBIT](INFO): Beginning SBIT in 22.000000 seconds. 2021-04-12T14:53:57.873Z,1618239237.873 [IBIT](INFO): Initialize IBIT Component. 2021-04-12T14:53:57.874Z,1618239237.874 [CBIT](DEBUG): Initialize CBIT Component. 2021-04-12T14:53:57.875Z,1618239237.875 [logger ThreadHandler](INFO): Handler Thread ID is 914 2021-04-12T14:53:57.886Z,1618239237.886 [CBIT](DEBUG): Initialized mux pins. 2021-04-12T14:53:57.886Z,1618239237.886 [CBIT](DEBUG): Initializing the watchdog timer. 2021-04-12T14:53:57.894Z,1618239237.894 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 915 2021-04-12T14:53:57.906Z,1618239237.906 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 916 2021-04-12T14:53:57.907Z,1618239237.907 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2021-04-12T14:53:57.910Z,1618239237.910 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2021-04-12T14:53:57.910Z,1618239237.910 [CBIT](DEBUG): Initializing heartbeat. 2021-04-12T14:53:57.918Z,1618239237.918 [Onboard ThreadHandler](INFO): Handler Thread ID is 917 2021-04-12T14:53:57.936Z,1618239237.936 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 918 2021-04-12T14:53:57.954Z,1618239237.954 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 919 2021-04-12T14:53:57.955Z,1618239237.955 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2021-04-12T14:53:57.959Z,1618239237.959 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 921 2021-04-12T14:53:57.962Z,1618239237.962 [WetLabsBB2FL](INFO): Powering up 2021-04-12T14:53:57.963Z,1618239237.963 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 923 2021-04-12T14:53:57.972Z,1618239237.972 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2021-04-12T14:53:57.973Z,1618239237.973 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2021-04-12T14:53:57.973Z,1618239237.973 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2021-04-12T14:53:57.973Z,1618239237.973 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2021-04-12T14:53:57.973Z,1618239237.973 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2021-04-12T14:53:57.973Z,1618239237.973 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2021-04-12T14:53:57.973Z,1618239237.973 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2021-04-12T14:53:57.974Z,1618239237.974 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2021-04-12T14:53:57.974Z,1618239237.974 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2021-04-12T14:53:57.974Z,1618239237.974 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2021-04-12T14:53:57.974Z,1618239237.974 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2021-04-12T14:53:57.974Z,1618239237.974 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2021-04-12T14:53:57.975Z,1618239237.975 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2021-04-12T14:53:57.975Z,1618239237.975 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2021-04-12T14:53:57.975Z,1618239237.975 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2021-04-12T14:53:57.975Z,1618239237.975 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2021-04-12T14:53:57.982Z,1618239237.982 [CBIT](DEBUG): Deactivating GF circuits. 2021-04-12T14:53:57.982Z,1618239237.982 [CBIT](DEBUG): Deactivating emergency mode. 2021-04-12T14:53:58.018Z,1618239238.018 [CBIT](DEBUG): Backplane powered. 2021-04-12T14:53:58.019Z,1618239238.019 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2021-04-12T14:53:58.046Z,1618239238.046 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2021-04-12T14:53:58.072Z,1618239238.072 [MissionManager](DEBUG): 2021-04-12T14:53:58.073Z,1618239238.073 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2021-04-12T14:53:58.167Z,1618239238.167 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2021-04-12T14:53:58.168Z,1618239238.168 [Default:A.Wait](DEBUG): Construct Wait. 2021-04-12T14:53:58.177Z,1618239238.177 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2021-04-12T14:53:58.204Z,1618239238.204 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2021-04-12T14:53:58.224Z,1618239238.224 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2021-04-12T14:53:58.229Z,1618239238.229 [Default:E.Execute](DEBUG): Construct Execute. 2021-04-12T14:53:58.249Z,1618239238.249 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2021-04-12T14:53:58.254Z,1618239238.254 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,DAT,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2021-04-12T14:53:58.274Z,1618239238.274 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2021-04-12T14:53:58.342Z,1618239238.342 [Radio_Surface](INFO): Powering up 2021-04-12T14:53:58.395Z,1618239238.395 [Depth_Keller](ERROR): Pressure reading out of range: 1829.799438 decibar 2021-04-12T14:53:58.405Z,1618239238.405 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2021-04-12T14:53:58.405Z,1618239238.405 [DAT](INFO): Powering up 2021-04-12T14:53:58.406Z,1618239238.406 [DAT](DEBUG): Initializing DAT. 2021-04-12T14:53:58.432Z,1618239238.432 [DepthRateCalculator](ERROR): Depth measurement is not active 2021-04-12T14:53:58.451Z,1618239238.451 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2021-04-12T14:53:58.524Z,1618239238.524 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2021-04-12T14:53:58.530Z,1618239238.530 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2021-04-12T14:53:58.531Z,1618239238.531 [ElevatorServo](DEBUG): Initializing EZServoServo. 2021-04-12T14:53:58.542Z,1618239238.542 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2021-04-12T14:53:58.543Z,1618239238.543 [MassServo](DEBUG): Initializing EZServoServo. 2021-04-12T14:53:58.554Z,1618239238.554 [MassServo](DEBUG): Initializing MassServo. 2021-04-12T14:53:58.555Z,1618239238.555 [RudderServo](DEBUG): Initializing EZServoServo. 2021-04-12T14:53:58.566Z,1618239238.566 [RudderServo](DEBUG): Initializing RudderServo. 2021-04-12T14:53:58.567Z,1618239238.567 [ThrusterServo](DEBUG): Initializing EZServoServo. 2021-04-12T14:53:58.578Z,1618239238.578 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2021-04-12T14:53:59.402Z,1618239239.402 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2021-04-12T14:53:59.402Z,1618239239.402 [RudderServo](FAULT): Rudder failed to initialize 2021-04-12T14:53:59.402Z,1618239239.402 [RudderServo] Communications Fault, FailCount= 1 2021-04-12T14:53:59.402Z,1618239239.402 [RudderServo](ERROR): Communications Fault 2021-04-12T14:53:59.502Z,1618239239.502 [CBIT](ERROR): Communications Fault in component: RudderServo 2021-04-12T14:53:59.655Z,1618239239.655 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2021-04-12T14:53:59.655Z,1618239239.655 [RudderServo](INFO): Powering down 2021-04-12T14:54:00.333Z,1618239240.333 [RudderServo](DEBUG): Initializing EZServoServo. 2021-04-12T14:54:00.451Z,1618239240.451 [RudderServo](DEBUG): Initializing RudderServo. 2021-04-12T14:54:00.455Z,1618239240.455 [CBIT](INFO): Clearing failed state for component RudderServo 2021-04-12T14:54:00.455Z,1618239240.455 [RudderServo] No Fault, FailCount= 1 2021-04-12T14:54:00.574Z,1618239240.574 [WetLabsBB2FL](INFO): Powering down 2021-04-12T14:54:12.847Z,1618239252.847 [DAT](INFO): commRate: 800 2021-04-12T14:54:14.864Z,1618239254.864 [DAT](INFO): entering command mode 2021-04-12T14:54:15.269Z,1618239255.269 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:15.672Z,1618239255.672 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:16.085Z,1618239256.085 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:16.480Z,1618239256.480 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:16.892Z,1618239256.892 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:17.288Z,1618239257.288 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:17.692Z,1618239257.692 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:18.096Z,1618239258.096 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:18.516Z,1618239258.516 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:18.904Z,1618239258.904 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:19.308Z,1618239259.308 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:19.712Z,1618239259.712 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:20.120Z,1618239260.120 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:20.520Z,1618239260.520 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:20.557Z,1618239260.557 [SBIT](IMPORTANT): Beginning Startup BIT 2021-04-12T14:54:20.565Z,1618239260.565 [CBIT](IMPORTANT): Beginning ground fault scan 2021-04-12T14:54:20.933Z,1618239260.933 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:21.328Z,1618239261.328 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:21.732Z,1618239261.732 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:22.136Z,1618239262.136 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:22.540Z,1618239262.540 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:22.975Z,1618239262.975 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:23.348Z,1618239263.348 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:23.761Z,1618239263.761 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:24.156Z,1618239264.156 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:24.572Z,1618239264.572 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:24.964Z,1618239264.964 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:25.368Z,1618239265.368 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:25.772Z,1618239265.772 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:26.194Z,1618239266.194 [NAL9602](INFO): Powering up NAL9602 2021-04-12T14:54:26.195Z,1618239266.195 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:26.580Z,1618239266.580 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:26.984Z,1618239266.984 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:27.388Z,1618239267.388 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:27.792Z,1618239267.792 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:28.196Z,1618239268.196 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:28.609Z,1618239268.609 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:29.004Z,1618239269.004 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:29.408Z,1618239269.408 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:29.817Z,1618239269.817 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:30.216Z,1618239270.216 [DAT](DEBUG): checking for command mode acknowledgment 2021-04-12T14:54:30.217Z,1618239270.217 [DAT](FAULT): failed to enter command mode 2021-04-12T14:54:30.620Z,1618239270.620 [DAT](INFO): entering command mode 2021-04-12T14:54:31.026Z,1618239271.026 [DAT](INFO): setting verbose to 3 2021-04-12T14:54:31.442Z,1618239271.442 [DAT](INFO): set verbose to 3 2021-04-12T14:54:31.443Z,1618239271.443 [DAT](INFO): setting DatVerbose to 27440 2021-04-12T14:54:31.544Z,1618239271.544 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.004535 CHAN A1 (24V): -0.002103 CHAN A2 (12V): -0.001258 CHAN A3 (5V): 0.001029 CHAN B0 (3.3V): 0.000248 CHAN B1 (3.15aV): 0.000400 CHAN B2 (3.15bV): 0.000675 CHAN B3 (GND): 0.000129 OPEN: -0.003864 Full Scale Calc: 4.765 mA, -1.589 mA 2021-04-12T14:54:31.833Z,1618239271.833 [DAT](INFO): set DatVerbose to 27440 2021-04-12T14:54:31.833Z,1618239271.833 [DAT](INFO): setting transmit power to 8 2021-04-12T14:54:32.237Z,1618239272.237 [DAT](INFO): set transmit power to 8 2021-04-12T14:54:32.238Z,1618239272.238 [DAT](INFO): setting local address to 8 2021-04-12T14:54:32.641Z,1618239272.641 [DAT](INFO): set local address to 8 2021-04-12T14:54:37.084Z,1618239277.084 [NAL9602](INFO): NAL9602 initialized 2021-04-12T14:55:14.711Z,1618239314.711 [SBIT](IMPORTANT): SBIT PASSED 2021-04-12T14:55:14.711Z,1618239314.711 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2021-04-12T14:55:14.712Z,1618239314.712 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count; 2021-04-12T14:55:14.712Z,1618239314.712 [SBIT](IMPORTANT): BackseatComponent.loadAtStartup=1 bool; 2021-04-12T14:55:14.712Z,1618239314.712 [SBIT](IMPORTANT): BackseatComponent.simulateHardware=1 bool; 2021-04-12T14:55:14.713Z,1618239314.713 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=194.169302 cubic_centimeter; 2021-04-12T14:55:14.713Z,1618239314.713 [SBIT](IMPORTANT): VerticalControl.massDefault=-0.743969 millimeter; 2021-04-12T14:55:15.075Z,1618239315.075 [MissionManager](IMPORTANT): Started mission Startup 2021-04-12T14:55:15.076Z,1618239315.076 [Startup] Running Loop=1 2021-04-12T14:55:15.076Z,1618239315.076 [Startup](DEBUG): Aggregate::initialize Startup 2021-04-12T14:55:15.076Z,1618239315.076 [Startup:A.GoToSurface] Running Loop=1 2021-04-12T14:55:15.076Z,1618239315.076 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2021-04-12T14:55:15.076Z,1618239315.076 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2021-04-12T14:55:15.077Z,1618239315.077 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2021-04-12T14:55:15.077Z,1618239315.077 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2021-04-12T14:55:15.078Z,1618239315.078 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2021-04-12T14:55:15.078Z,1618239315.078 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2021-04-12T14:55:15.080Z,1618239315.080 [Startup:StartupSatComms] Running Loop=1 2021-04-12T14:55:15.080Z,1618239315.080 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2021-04-12T14:55:15.080Z,1618239315.080 [Startup:StartupSatComms:A] Running Loop=1 2021-04-12T14:55:15.482Z,1618239315.482 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2021-04-12T14:56:15.274Z,1618239375.274 [Startup:StartupSatComms:A](INFO): Timed out from 2021-04-12T14:55:15.1Z 2021-04-12T14:56:15.274Z,1618239375.274 [Startup:StartupSatComms:A] Stopped 2021-04-12T14:56:15.274Z,1618239375.274 [Startup:StartupSatComms:B] Running Loop=1 2021-04-12T14:56:15.696Z,1618239375.696 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2021-04-12T14:56:56.836Z,1618239416.836 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004428 2021-04-12T14:56:58.125Z,1618239418.125 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2021-04-12T14:56:58.125Z,1618239418.125 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-04-12T14:56:58.135Z,1618239418.135 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-04-12T14:56:58.551Z,1618239418.551 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-04-12T14:56:58.551Z,1618239418.551 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2021-04-12T14:57:04.115Z,1618239424.115 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210412T144027/Courier0007.lzma 2021-04-12T14:57:05.116Z,1618239425.116 [DataOverHttps](INFO): Moved sent file to Logs/20210412T144027/Courier0007.lzma.bak 2021-04-12T14:57:05.116Z,1618239425.116 [DataOverHttps](INFO): SBD MOMSN=15559680 2021-04-12T14:57:15.484Z,1618239435.484 [Startup:StartupSatComms:B](INFO): Timed out from 2021-04-12T14:56:15.3Z 2021-04-12T14:57:15.484Z,1618239435.484 [Startup:StartupSatComms:B] Stopped 2021-04-12T14:57:15.484Z,1618239435.484 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2021-04-12T14:57:15.484Z,1618239435.484 [Startup:StartupSatComms] Stopped 2021-04-12T14:57:15.484Z,1618239435.484 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2021-04-12T14:57:15.485Z,1618239435.485 [Startup](INFO): Completed Startup 2021-04-12T14:57:15.485Z,1618239435.485 [MissionManager](INFO): Startup is completed. 2021-04-12T14:57:15.486Z,1618239435.486 [MissionManager](INFO): Uninitializing Mission Startup 2021-04-12T14:57:15.486Z,1618239435.486 [Startup] Stopped 2021-04-12T14:57:15.486Z,1618239435.486 [Startup](DEBUG): Aggregate::uninitialize Startup 2021-04-12T14:57:15.486Z,1618239435.486 [Startup:A.GoToSurface] Stopped 2021-04-12T14:57:15.486Z,1618239435.486 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2021-04-12T14:57:15.908Z,1618239435.908 [MissionManager](IMPORTANT): Started mission Default 2021-04-12T14:57:15.909Z,1618239435.909 [Default] Running Loop=1 2021-04-12T14:57:15.909Z,1618239435.909 [Default](DEBUG): Aggregate::initialize Default 2021-04-12T14:57:15.909Z,1618239435.909 [Default:B.GoToSurface] Running Loop=1 2021-04-12T14:57:15.909Z,1618239435.909 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2021-04-12T14:57:15.909Z,1618239435.909 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2021-04-12T14:57:15.909Z,1618239435.909 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2021-04-12T14:57:15.910Z,1618239435.910 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2021-04-12T14:57:15.910Z,1618239435.910 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2021-04-12T14:57:15.911Z,1618239435.911 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2021-04-12T14:57:15.911Z,1618239435.911 [Default:A.Wait] Running Loop=1 2021-04-12T14:57:15.911Z,1618239435.911 [Default:A.Wait](DEBUG): Initialize Wait Component. 2021-04-12T14:57:20.693Z,1618239440.693 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20210412T145347/Courier0000.lzma 2021-04-12T14:57:21.695Z,1618239441.695 [DataOverHttps](INFO): Moved sent file to Logs/20210412T145347/Courier0000.lzma.bak 2021-04-12T14:57:21.696Z,1618239441.696 [DataOverHttps](INFO): SBD MOMSN=15559687 2021-04-12T14:57:29.246Z,1618239449.246 [Default:A.Wait](INFO): Done Waiting. 2021-04-12T14:57:29.246Z,1618239449.246 [Default:A.Wait] Stopped 2021-04-12T14:57:29.246Z,1618239449.246 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2021-04-12T14:57:29.621Z,1618239449.621 [Default:CheckIn] Running Loop=1 2021-04-12T14:57:29.621Z,1618239449.621 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-12T14:57:29.621Z,1618239449.621 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-12T14:57:30.025Z,1618239450.025 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2021-04-12T14:57:33.653Z,1618239453.653 [NAL9602](INFO): SBD MO Status=0, MOMSN=1808, MT Status=0, MTMSN=0 2021-04-12T14:57:33.654Z,1618239453.654 [NAL9602](INFO): No messages in MT queue 2021-04-12T14:58:56.127Z,1618239536.127 [DVL_micro](ERROR): Failed to parse: :WI,-0178,+01404,+00000,A 2021-04-12T14:59:23.401Z,1618239563.401 [CommandLine](IMPORTANT): got command failComponent 2021-04-12T14:59:23.402Z,1618239563.402 [CommandLine](IMPORTANT): Failed components: 2021-04-12T14:59:23.402Z,1618239563.402 [CommandLine](IMPORTANT): No failed Components. 2021-04-12T14:59:59.178Z,1618239599.178 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2021-04-12T14:59:59.178Z,1618239599.178 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-04-12T14:59:59.188Z,1618239599.188 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-04-12T14:59:59.577Z,1618239599.577 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-04-12T14:59:59.577Z,1618239599.577 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2021-04-12T15:00:02.049Z,1618239602.049 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150000.00,A,3648.14221,N,12147.23100,W,0.233,5.69,120421,,,A*78 2021-04-12T15:00:02.061Z,1618239602.061 [NAL9602](INFO): GPS fix at 20210412T150000: (36.802370, -121.787183) 2021-04-12T15:00:02.117Z,1618239602.117 [Default:CheckIn:Read_GPS] Stopped 2021-04-12T15:00:02.117Z,1618239602.117 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-12T15:00:02.439Z,1618239602.439 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2021-04-12T15:00:17.314Z,1618239617.314 [DataOverHttps](INFO): Sending 221 bytes from file Logs/20210412T145347/Courier0004.lzma 2021-04-12T15:00:18.316Z,1618239618.316 [DataOverHttps](INFO): Moved sent file to Logs/20210412T145347/Courier0004.lzma.bak 2021-04-12T15:00:18.316Z,1618239618.316 [DataOverHttps](INFO): SBD MOMSN=15559729 2021-04-12T15:00:34.307Z,1618239634.307 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-12T15:00:42.275Z,1618239642.275 [DataOverHttps](INFO): Sending 379 bytes from file Logs/20210412T144027/Express0008.lzma 2021-04-12T15:00:43.277Z,1618239643.277 [DataOverHttps](INFO): Moved sent file to Logs/20210412T144027/Express0008.lzma.bak 2021-04-12T15:00:43.277Z,1618239643.277 [DataOverHttps](INFO): SBD MOMSN=15559732 2021-04-12T15:01:00.216Z,1618239660.216 [DataOverHttps](INFO): Sending 884 bytes from file Logs/20210412T145347/Express0001.lzma 2021-04-12T15:01:01.207Z,1618239661.207 [DataOverHttps](INFO): Moved sent file to Logs/20210412T145347/Express0001.lzma.bak 2021-04-12T15:01:01.208Z,1618239661.208 [DataOverHttps](INFO): SBD MOMSN=15559748 2021-04-12T15:01:19.466Z,1618239679.466 [DataOverHttps](INFO): Sending 285 bytes from file Logs/20210412T145347/Express0005.lzma 2021-04-12T15:01:20.467Z,1618239680.467 [DataOverHttps](INFO): Moved sent file to Logs/20210412T145347/Express0005.lzma.bak 2021-04-12T15:01:20.468Z,1618239680.468 [DataOverHttps](INFO): SBD MOMSN=15559770 2021-04-12T15:01:22.845Z,1618239682.845 [Default:CheckIn:Read_Iridium] Stopped 2021-04-12T15:01:22.845Z,1618239682.845 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-12T15:01:22.845Z,1618239682.845 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-12T15:01:36.537Z,1618239696.537 [BPC1](ERROR): Battery stick #6 (s/n: 00CA) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2021-04-12T15:01:36.558Z,1618239696.558 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5. 2021-04-12T15:01:36.562Z,1618239696.562 [BPC1](INFO): Received data from all battery sticks. 2021-04-12T15:03:02.791Z,1618239782.791 [CommandLine](IMPORTANT): got command failComponent 2021-04-12T15:03:02.791Z,1618239782.791 [CommandLine](IMPORTANT): Failed components: 2021-04-12T15:03:02.791Z,1618239782.791 [CommandLine](IMPORTANT): No failed Components. 2021-04-12T15:03:59.881Z,1618239839.881 [CommandLine](IMPORTANT): got command ibit 2021-04-12T15:04:00.021Z,1618239840.021 [IBIT](IMPORTANT): Beginning Initiated BIT 2021-04-12T15:04:00.021Z,1618239840.021 [IBIT](IMPORTANT): Beginning control surface checks. 2021-04-12T15:04:00.024Z,1618239840.024 [CBIT](IMPORTANT): Beginning ground fault scan 2021-04-12T15:04:01.627Z,1618239841.627 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150400.00,A,3648.13502,N,12147.23076,W,0.078,5.69,120421,,,D*75 2021-04-12T15:04:01.630Z,1618239841.630 [NAL9602](INFO): GPS fix at 20210412T150400: (36.802250, -121.787179) 2021-04-12T15:04:10.986Z,1618239850.986 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.004632 CHAN A1 (24V): -0.002391 CHAN A2 (12V): -0.000831 CHAN A3 (5V): 0.000535 CHAN B0 (3.3V): 0.000575 CHAN B1 (3.15aV): 0.000177 CHAN B2 (3.15bV): 0.000644 CHAN B3 (GND): -0.000145 OPEN: 0.003705 Full Scale Calc: 4.765 mA, -1.589 mA 2021-04-12T15:04:18.181Z,1618239858.181 [NAL9602](INFO): SBD MO Status=0, MOMSN=1809, MT Status=0, MTMSN=0 2021-04-12T15:04:18.181Z,1618239858.181 [NAL9602](INFO): No messages in MT queue 2021-04-12T15:04:19.393Z,1618239859.393 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150417.00,A,3648.13530,N,12147.23099,W,0.117,5.69,120421,,,D*7B 2021-04-12T15:04:19.396Z,1618239859.396 [NAL9602](INFO): GPS fix at 20210412T150417: (36.802255, -121.787183) 2021-04-12T15:04:23.027Z,1618239863.027 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150421.00,A,3648.13529,N,12147.23091,W,0.019,5.69,120421,,,D*71 2021-04-12T15:04:23.029Z,1618239863.029 [NAL9602](INFO): GPS fix at 20210412T150421: (36.802255, -121.787182) 2021-04-12T15:04:25.861Z,1618239865.861 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150424.00,A,3648.13522,N,12147.23076,W,0.058,5.69,120421,,,D*73 2021-04-12T15:04:25.864Z,1618239865.864 [NAL9602](INFO): GPS fix at 20210412T150424: (36.802254, -121.787179) 2021-04-12T15:04:29.109Z,1618239869.109 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150427.00,A,3648.13518,N,12147.23078,W,0.058,5.69,120421,,,D*77 2021-04-12T15:04:29.111Z,1618239869.111 [NAL9602](INFO): GPS fix at 20210412T150427: (36.802253, -121.787180) 2021-04-12T15:04:31.946Z,1618239871.946 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150430.00,A,3648.13519,N,12147.23070,W,0.019,5.69,120421,,,D*7D 2021-04-12T15:04:31.955Z,1618239871.955 [NAL9602](INFO): GPS fix at 20210412T150430: (36.802253, -121.787178) 2021-04-12T15:04:34.746Z,1618239874.746 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150433.00,A,3648.13516,N,12147.23061,W,0.039,5.69,120421,,,D*73 2021-04-12T15:04:34.748Z,1618239874.748 [NAL9602](INFO): GPS fix at 20210412T150433: (36.802253, -121.787177) 2021-04-12T15:04:37.979Z,1618239877.979 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150436.00,A,3648.13505,N,12147.23064,W,0.058,5.69,120421,,,D*76 2021-04-12T15:04:37.981Z,1618239877.981 [NAL9602](INFO): GPS fix at 20210412T150436: (36.802251, -121.787177) 2021-04-12T15:04:40.806Z,1618239880.806 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150439.00,A,3648.13495,N,12147.23064,W,0.019,5.69,120421,,,D*74 2021-04-12T15:04:40.808Z,1618239880.808 [NAL9602](INFO): GPS fix at 20210412T150439: (36.802249, -121.787177) 2021-04-12T15:04:44.037Z,1618239884.037 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150442.00,A,3648.13491,N,12147.23066,W,0.019,5.69,120421,,,D*7E 2021-04-12T15:04:44.039Z,1618239884.039 [NAL9602](INFO): GPS fix at 20210412T150442: (36.802248, -121.787178) 2021-04-12T15:04:46.505Z,1618239886.505 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 4 Latitude: 36.802250 Longitude: -121.787178 2021-04-12T15:04:46.874Z,1618239886.874 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150445.00,A,3648.13453,N,12147.23083,W,0.058,5.69,120421,,,D*79 2021-04-12T15:04:46.876Z,1618239886.876 [NAL9602](INFO): GPS fix at 20210412T150445: (36.802242, -121.787181) 2021-04-12T15:04:46.893Z,1618239886.893 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 0.000000 Voltage: 16.532000 2021-04-12T15:04:46.893Z,1618239886.893 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah 2021-04-12T15:04:46.894Z,1618239886.894 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V 2021-04-12T15:04:47.312Z,1618239887.312 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2021-04-12T15:04:47.312Z,1618239887.312 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2021-04-12T15:04:47.312Z,1618239887.312 [IBIT](IMPORTANT): Pressure:8.082463 PSI 2021-04-12T15:04:47.313Z,1618239887.313 [IBIT](IMPORTANT): Humidity:14.497620 % 2021-04-12T15:04:47.712Z,1618239887.712 [IBIT](IMPORTANT): Vehicle Pitch:-1.311406 degrees 2021-04-12T15:04:47.712Z,1618239887.712 [IBIT](IMPORTANT): Vehicle Roll:1.812157 degrees 2021-04-12T15:04:47.712Z,1618239887.712 [IBIT](IMPORTANT): Vehicle Heading:268.755402 degrees 2021-04-12T15:04:48.092Z,1618239888.092 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2021-04-12T15:04:48.092Z,1618239888.092 [IBIT](IMPORTANT): buoyancyNeutral: 194.169296 cc 2021-04-12T15:04:48.093Z,1618239888.093 [IBIT](IMPORTANT): massDefault: -0.074397 cm 2021-04-12T15:04:48.093Z,1618239888.093 [IBIT](IMPORTANT): stopDepth: 265.000000 m 2021-04-12T15:04:48.093Z,1618239888.093 [IBIT](IMPORTANT): abortDepth: 300.000000 m 2021-04-12T15:04:48.093Z,1618239888.093 [IBIT](IMPORTANT): IBIT PASSED 2021-04-12T15:05:19.187Z,1618239919.187 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-12T15:06:23.438Z,1618239983.438 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-12T15:06:23.438Z,1618239983.438 [Default:CheckIn:C.Wait] Stopped 2021-04-12T15:06:23.438Z,1618239983.438 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-12T15:06:23.438Z,1618239983.438 [Default:CheckIn:D] Running Loop=1 2021-04-12T15:06:23.856Z,1618239983.856 [Default:CheckIn:D] Stopped 2021-04-12T15:06:23.856Z,1618239983.856 [Default:CheckIn:E] Running Loop=1 2021-04-12T15:06:24.267Z,1618239984.267 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 9.132449 min 2021-04-12T15:06:24.267Z,1618239984.267 [Default:CheckIn:E] Stopped 2021-04-12T15:06:24.267Z,1618239984.267 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-12T15:06:24.268Z,1618239984.268 [Default:CheckIn] Stopped 2021-04-12T15:06:24.268Z,1618239984.268 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-12T15:06:24.268Z,1618239984.268 [Default:CheckIn](INFO): Running loop #2 2021-04-12T15:06:24.268Z,1618239984.268 [Default:CheckIn] Running Loop=2 2021-04-12T15:06:24.268Z,1618239984.268 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-12T15:06:24.268Z,1618239984.268 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-12T15:06:26.267Z,1618239986.267 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150625.00,A,3648.13266,N,12147.23243,W,0.000,5.69,120421,,,D*7E 2021-04-12T15:06:26.269Z,1618239986.269 [NAL9602](INFO): GPS fix at 20210412T150625: (36.802211, -121.787207) 2021-04-12T15:06:26.280Z,1618239986.280 [Default:CheckIn:Read_GPS] Stopped 2021-04-12T15:06:26.280Z,1618239986.280 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-12T15:06:33.534Z,1618239993.534 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20210412T145347/Courier0007.lzma 2021-04-12T15:06:34.535Z,1618239994.535 [DataOverHttps](INFO): Moved sent file to Logs/20210412T145347/Courier0007.lzma.bak 2021-04-12T15:06:34.536Z,1618239994.536 [DataOverHttps](INFO): SBD MOMSN=15559813 2021-04-12T15:06:43.655Z,1618240003.655 [NAL9602](INFO): SBD MO Status=0, MOMSN=1810, MT Status=0, MTMSN=0 2021-04-12T15:06:43.655Z,1618240003.655 [NAL9602](INFO): No messages in MT queue 2021-04-12T15:06:51.403Z,1618240011.403 [DataOverHttps](INFO): Sending 829 bytes from file Logs/20210412T145347/Express0008.lzma 2021-04-12T15:06:52.404Z,1618240012.404 [DataOverHttps](INFO): Moved sent file to Logs/20210412T145347/Express0008.lzma.bak 2021-04-12T15:06:52.404Z,1618240012.404 [DataOverHttps](INFO): SBD MOMSN=15559818 2021-04-12T15:06:54.602Z,1618240014.602 [Default:CheckIn:Read_Iridium] Stopped 2021-04-12T15:06:54.602Z,1618240014.602 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-12T15:06:54.602Z,1618240014.602 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-12T15:07:14.401Z,1618240034.401 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-12T15:08:51.380Z,1618240131.380 [DVL_micro](ERROR): only read 3 of 4 data items 2021-04-12T15:08:51.381Z,1618240131.381 [DVL_micro](ERROR): Failed to parse: :BI,+01756,-01161,+0000,I 2021-04-12T15:11:55.253Z,1618240315.253 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-12T15:11:55.253Z,1618240315.253 [Default:CheckIn:C.Wait] Stopped 2021-04-12T15:11:55.253Z,1618240315.253 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-12T15:11:55.254Z,1618240315.254 [Default:CheckIn:D] Running Loop=1 2021-04-12T15:11:55.662Z,1618240315.662 [Default:CheckIn:D] Stopped 2021-04-12T15:11:55.662Z,1618240315.662 [Default:CheckIn:E] Running Loop=1 2021-04-12T15:11:56.052Z,1618240316.052 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 14.662557 min 2021-04-12T15:11:56.052Z,1618240316.052 [Default:CheckIn:E] Stopped 2021-04-12T15:11:56.052Z,1618240316.052 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-12T15:11:56.052Z,1618240316.052 [Default:CheckIn] Stopped 2021-04-12T15:11:56.052Z,1618240316.052 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-12T15:11:56.052Z,1618240316.052 [Default:CheckIn](INFO): Running loop #3 2021-04-12T15:11:56.052Z,1618240316.052 [Default:CheckIn] Running Loop=3 2021-04-12T15:11:56.053Z,1618240316.053 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-12T15:11:56.053Z,1618240316.053 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-12T15:11:58.065Z,1618240318.065 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151157.00,A,3648.16492,N,12147.21424,W,0.039,23.70,120421,,,A*43 2021-04-12T15:11:58.068Z,1618240318.068 [NAL9602](INFO): GPS fix at 20210412T151157: (36.802749, -121.786904) 2021-04-12T15:11:58.079Z,1618240318.079 [Default:CheckIn:Read_GPS] Stopped 2021-04-12T15:11:58.079Z,1618240318.079 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-12T15:12:05.797Z,1618240325.797 [NAL9602](INFO): SBD MO Status=0, MOMSN=1811, MT Status=0, MTMSN=0 2021-04-12T15:12:05.797Z,1618240325.797 [NAL9602](INFO): No messages in MT queue 2021-04-12T15:12:07.477Z,1618240327.477 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210412T145347/Courier0010.lzma 2021-04-12T15:12:08.480Z,1618240328.480 [DataOverHttps](INFO): Moved sent file to Logs/20210412T145347/Courier0010.lzma.bak 2021-04-12T15:12:08.480Z,1618240328.480 [DataOverHttps](INFO): SBD MOMSN=15559969 2021-04-12T15:12:30.433Z,1618240350.433 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20210412T145347/Express0011.lzma 2021-04-12T15:12:31.436Z,1618240351.436 [DataOverHttps](INFO): Moved sent file to Logs/20210412T145347/Express0011.lzma.bak 2021-04-12T15:12:31.436Z,1618240351.436 [DataOverHttps](INFO): SBD MOMSN=15559972 2021-04-12T15:12:33.770Z,1618240353.770 [Default:CheckIn:Read_Iridium] Stopped 2021-04-12T15:12:33.770Z,1618240353.770 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-12T15:12:33.770Z,1618240353.770 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-12T15:12:36.567Z,1618240356.567 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-12T15:14:45.469Z,1618240485.469 [DVL_micro](ERROR): Failed to parse: 0000000000,35.0,+20.7,0000.0,1489.0,000 2021-04-12T15:17:34.362Z,1618240654.362 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-12T15:17:34.362Z,1618240654.362 [Default:CheckIn:C.Wait] Stopped 2021-04-12T15:17:34.362Z,1618240654.362 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-12T15:17:34.362Z,1618240654.362 [Default:CheckIn:D] Running Loop=1 2021-04-12T15:17:34.761Z,1618240654.761 [Default:CheckIn:D] Stopped 2021-04-12T15:17:34.761Z,1618240654.761 [Default:CheckIn:E] Running Loop=1 2021-04-12T15:17:35.166Z,1618240655.166 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.314209 min 2021-04-12T15:17:35.166Z,1618240655.166 [Default:CheckIn:E] Stopped 2021-04-12T15:17:35.166Z,1618240655.166 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-12T15:17:35.166Z,1618240655.166 [Default:CheckIn] Stopped 2021-04-12T15:17:35.166Z,1618240655.166 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-12T15:17:35.166Z,1618240655.166 [Default:CheckIn](INFO): Running loop #4 2021-04-12T15:17:35.166Z,1618240655.166 [Default:CheckIn] Running Loop=4 2021-04-12T15:17:35.166Z,1618240655.166 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-12T15:17:35.167Z,1618240655.167 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-12T15:17:37.172Z,1618240657.172 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151736.00,A,3648.16548,N,12147.21375,W,0.019,23.70,120421,,,D*40 2021-04-12T15:17:37.174Z,1618240657.174 [NAL9602](INFO): GPS fix at 20210412T151736: (36.802758, -121.786896) 2021-04-12T15:17:37.185Z,1618240657.185 [Default:CheckIn:Read_GPS] Stopped 2021-04-12T15:17:37.185Z,1618240657.185 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-12T15:17:44.857Z,1618240664.857 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210412T145347/Courier0013.lzma 2021-04-12T15:17:45.859Z,1618240665.859 [DataOverHttps](INFO): Moved sent file to Logs/20210412T145347/Courier0013.lzma.bak 2021-04-12T15:17:45.860Z,1618240665.860 [DataOverHttps](INFO): SBD MOMSN=15559983 2021-04-12T15:17:50.505Z,1618240670.505 [NAL9602](INFO): SBD MO Status=0, MOMSN=1812, MT Status=0, MTMSN=0 2021-04-12T15:17:50.505Z,1618240670.505 [NAL9602](INFO): No messages in MT queue 2021-04-12T15:18:03.030Z,1618240683.030 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210412T145347/Express0014.lzma 2021-04-12T15:18:04.032Z,1618240684.032 [DataOverHttps](INFO): Moved sent file to Logs/20210412T145347/Express0014.lzma.bak 2021-04-12T15:18:04.032Z,1618240684.032 [DataOverHttps](INFO): SBD MOMSN=15559987 2021-04-12T15:18:07.127Z,1618240687.127 [Default:CheckIn:Read_Iridium] Stopped 2021-04-12T15:18:07.127Z,1618240687.127 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-12T15:18:07.127Z,1618240687.127 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-12T15:18:21.295Z,1618240701.295 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-12T15:18:24.234Z,1618240704.234 [DVL_micro](ERROR): Failed to parse: 7,+01505,+00000,I 2021-04-12T15:20:54.481Z,1618240854.481 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-04-12T15:20:54.482Z,1618240854.482 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+20.4,00000,000 2021-04-12T15:23:07.829Z,1618240987.829 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-12T15:23:07.834Z,1618240987.834 [Default:CheckIn:C.Wait] Stopped 2021-04-12T15:23:07.834Z,1618240987.834 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-12T15:23:07.834Z,1618240987.834 [Default:CheckIn:D] Running Loop=1 2021-04-12T15:23:08.242Z,1618240988.242 [Default:CheckIn:D] Stopped 2021-04-12T15:23:08.242Z,1618240988.242 [Default:CheckIn:E] Running Loop=1 2021-04-12T15:23:08.670Z,1618240988.670 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 25.872148 min 2021-04-12T15:23:08.670Z,1618240988.670 [Default:CheckIn:E] Stopped 2021-04-12T15:23:08.670Z,1618240988.670 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-12T15:23:08.670Z,1618240988.670 [Default:CheckIn] Stopped 2021-04-12T15:23:08.670Z,1618240988.670 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-12T15:23:08.670Z,1618240988.670 [Default:CheckIn](INFO): Running loop #5 2021-04-12T15:23:08.670Z,1618240988.670 [Default:CheckIn] Running Loop=5 2021-04-12T15:23:08.671Z,1618240988.671 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-12T15:23:08.671Z,1618240988.671 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-12T15:23:10.637Z,1618240990.637 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,152310.00,A,3648.16446,N,12147.21341,W,0.019,23.70,120421,,,D*4B 2021-04-12T15:23:10.639Z,1618240990.639 [NAL9602](INFO): GPS fix at 20210412T152310: (36.802741, -121.786890) 2021-04-12T15:23:10.650Z,1618240990.650 [Default:CheckIn:Read_GPS] Stopped 2021-04-12T15:23:10.650Z,1618240990.650 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-12T15:23:11.761Z,1618240991.761 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210412T145347/Courier0016.lzma 2021-04-12T15:23:12.108Z,1618240992.108 [DataOverHttps](INFO): Moved sent file to Logs/20210412T145347/Courier0016.lzma.bak 2021-04-12T15:23:12.108Z,1618240992.108 [DataOverHttps](INFO): SBD MOMSN=15560023 2021-04-12T15:23:14.737Z,1618240994.737 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-04-12T15:23:14.738Z,1618240994.738 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+0.0,1489.0,000 2021-04-12T15:23:28.886Z,1618241008.886 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210412T145347/Express0017.lzma 2021-04-12T15:23:29.888Z,1618241009.888 [DataOverHttps](INFO): Moved sent file to Logs/20210412T145347/Express0017.lzma.bak 2021-04-12T15:23:29.888Z,1618241009.888 [DataOverHttps](INFO): SBD MOMSN=15560026 2021-04-12T15:23:32.145Z,1618241012.145 [Default:CheckIn:Read_Iridium] Stopped 2021-04-12T15:23:32.145Z,1618241012.145 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-12T15:23:32.145Z,1618241012.145 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-12T15:23:54.322Z,1618241034.322 [NAL9602](INFO): SBD MO Status=0, MOMSN=1813, MT Status=0, MTMSN=0 2021-04-12T15:23:54.322Z,1618241034.322 [NAL9602](INFO): No messages in MT queue 2021-04-12T15:24:25.044Z,1618241065.044 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-12T15:28:32.783Z,1618241312.783 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-12T15:28:32.784Z,1618241312.784 [Default:CheckIn:C.Wait] Stopped 2021-04-12T15:28:32.784Z,1618241312.784 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-12T15:28:32.784Z,1618241312.784 [Default:CheckIn:D] Running Loop=1 2021-04-12T15:28:33.205Z,1618241313.205 [Default:CheckIn:D] Stopped 2021-04-12T15:28:33.205Z,1618241313.205 [Default:CheckIn:E] Running Loop=1 2021-04-12T15:28:33.594Z,1618241313.594 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.288267 min 2021-04-12T15:28:33.594Z,1618241313.594 [Default:CheckIn:E] Stopped 2021-04-12T15:28:33.594Z,1618241313.594 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-12T15:28:33.595Z,1618241313.595 [Default:CheckIn] Stopped 2021-04-12T15:28:33.595Z,1618241313.595 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-12T15:28:33.595Z,1618241313.595 [Default:CheckIn](INFO): Running loop #6 2021-04-12T15:28:33.595Z,1618241313.595 [Default:CheckIn] Running Loop=6 2021-04-12T15:28:33.595Z,1618241313.595 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-12T15:28:33.595Z,1618241313.595 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-12T15:28:35.605Z,1618241315.605 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,152835.00,A,3648.47214,N,12147.12373,W,6.609,342.43,120421,,,D*76 2021-04-12T15:28:35.608Z,1618241315.608 [NAL9602](INFO): GPS fix at 20210412T152835: (36.807869, -121.785396) 2021-04-12T15:28:35.619Z,1618241315.619 [Default:CheckIn:Read_GPS] Stopped 2021-04-12T15:28:35.619Z,1618241315.619 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-12T15:28:42.749Z,1618241322.749 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210412T145347/Courier0019.lzma 2021-04-12T15:28:43.752Z,1618241323.752 [DataOverHttps](INFO): Moved sent file to Logs/20210412T145347/Courier0019.lzma.bak 2021-04-12T15:28:43.752Z,1618241323.752 [DataOverHttps](INFO): SBD MOMSN=15560059 2021-04-12T15:28:55.401Z,1618241335.401 [NAL9602](INFO): SBD MO Status=0, MOMSN=1814, MT Status=0, MTMSN=0 2021-04-12T15:28:55.401Z,1618241335.401 [NAL9602](INFO): No messages in MT queue 2021-04-12T15:29:00.626Z,1618241340.626 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20210412T145347/Express0020.lzma 2021-04-12T15:29:01.627Z,1618241341.627 [DataOverHttps](INFO): Moved sent file to Logs/20210412T145347/Express0020.lzma.bak 2021-04-12T15:29:01.628Z,1618241341.628 [DataOverHttps](INFO): SBD MOMSN=15560062 2021-04-12T15:29:03.938Z,1618241343.938 [Default:CheckIn:Read_Iridium] Stopped 2021-04-12T15:29:03.938Z,1618241343.938 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-12T15:29:03.938Z,1618241343.938 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-12T15:29:26.099Z,1618241366.099 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-12T15:30:02.461Z,1618241402.461 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-04-12T15:30:02.462Z,1618241402.462 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+20.0,0000.0000 2021-04-12T15:31:44.683Z,1618241504.683 [DVL_micro](ERROR): only read 3 of 4 data items 2021-04-12T15:31:44.684Z,1618241504.684 [DVL_micro](ERROR): Failed to parse: :BI,+01263,-00695,+0000,I 2021-04-12T15:34:04.550Z,1618241644.550 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-12T15:34:04.550Z,1618241644.550 [Default:CheckIn:C.Wait] Stopped 2021-04-12T15:34:04.550Z,1618241644.550 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-12T15:34:04.550Z,1618241644.550 [Default:CheckIn:D] Running Loop=1 2021-04-12T15:34:04.982Z,1618241644.982 [Default:CheckIn:D] Stopped 2021-04-12T15:34:04.982Z,1618241644.982 [Default:CheckIn:E] Running Loop=1 2021-04-12T15:34:05.377Z,1618241645.377 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 36.817883 min 2021-04-12T15:34:05.377Z,1618241645.377 [Default:CheckIn:E] Stopped 2021-04-12T15:34:05.377Z,1618241645.377 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-12T15:34:05.382Z,1618241645.382 [Default:CheckIn] Stopped 2021-04-12T15:34:05.382Z,1618241645.382 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-12T15:34:05.382Z,1618241645.382 [Default:CheckIn](INFO): Running loop #7 2021-04-12T15:34:05.382Z,1618241645.382 [Default:CheckIn] Running Loop=7 2021-04-12T15:34:05.382Z,1618241645.382 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-12T15:34:05.382Z,1618241645.382 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-12T15:34:07.381Z,1618241647.381 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153406.00,A,3648.21767,N,12148.28732,W,18.505,252.06,120421,,,D*4C 2021-04-12T15:34:07.384Z,1618241647.384 [NAL9602](INFO): GPS fix at 20210412T153406: (36.803628, -121.804789) 2021-04-12T15:34:07.427Z,1618241647.427 [Default:CheckIn:Read_GPS] Stopped 2021-04-12T15:34:07.427Z,1618241647.427 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-12T15:34:19.565Z,1618241659.565 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210412T145347/Courier0022.lzma 2021-04-12T15:34:20.568Z,1618241660.568 [DataOverHttps](INFO): Moved sent file to Logs/20210412T145347/Courier0022.lzma.bak 2021-04-12T15:34:20.568Z,1618241660.568 [DataOverHttps](INFO): SBD MOMSN=15560073 2021-04-12T15:34:23.670Z,1618241663.670 [NAL9602](INFO): SBD MO Status=0, MOMSN=1815, MT Status=0, MTMSN=0 2021-04-12T15:34:23.670Z,1618241663.670 [NAL9602](INFO): No messages in MT queue 2021-04-12T15:34:39.485Z,1618241679.485 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20210412T145347/Express0023.lzma 2021-04-12T15:34:40.488Z,1618241680.488 [DataOverHttps](INFO): Moved sent file to Logs/20210412T145347/Express0023.lzma.bak 2021-04-12T15:34:40.488Z,1618241680.488 [DataOverHttps](INFO): SBD MOMSN=15560076 2021-04-12T15:34:42.683Z,1618241682.683 [Default:CheckIn:Read_Iridium] Stopped 2021-04-12T15:34:42.683Z,1618241682.683 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-12T15:34:42.683Z,1618241682.683 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-12T15:34:54.363Z,1618241694.363 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-12T15:35:31.538Z,1618241731.538 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2021-04-12T15:38:55.648Z,1618241935.648 [DVL_micro](ERROR): only read 3 of 4 data items 2021-04-12T15:38:55.648Z,1618241935.648 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+9999.99, 2021-04-12T15:39:43.321Z,1618241983.321 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-12T15:39:43.321Z,1618241983.321 [Default:CheckIn:C.Wait] Stopped 2021-04-12T15:39:43.322Z,1618241983.322 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-12T15:39:43.322Z,1618241983.322 [Default:CheckIn:D] Running Loop=1 2021-04-12T15:39:43.726Z,1618241983.726 [Default:CheckIn:D] Stopped 2021-04-12T15:39:43.726Z,1618241983.726 [Default:CheckIn:E] Running Loop=1 2021-04-12T15:39:44.147Z,1618241984.147 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.463631 min 2021-04-12T15:39:44.147Z,1618241984.147 [Default:CheckIn:E] Stopped 2021-04-12T15:39:44.147Z,1618241984.147 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-12T15:39:44.147Z,1618241984.147 [Default:CheckIn] Stopped 2021-04-12T15:39:44.147Z,1618241984.147 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-12T15:39:44.147Z,1618241984.147 [Default:CheckIn](INFO): Running loop #8 2021-04-12T15:39:44.147Z,1618241984.147 [Default:CheckIn] Running Loop=8 2021-04-12T15:39:44.148Z,1618241984.148 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-12T15:39:44.148Z,1618241984.148 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-12T15:39:46.137Z,1618241986.137 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153945.00,A,3647.89109,N,12150.30300,W,15.648,262.75,120421,,,D*40 2021-04-12T15:39:46.140Z,1618241986.140 [NAL9602](INFO): GPS fix at 20210412T153945: (36.798185, -121.838383) 2021-04-12T15:39:46.150Z,1618241986.150 [Default:CheckIn:Read_GPS] Stopped 2021-04-12T15:39:46.151Z,1618241986.151 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-12T15:39:53.877Z,1618241993.877 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210412T145347/Courier0025.lzma 2021-04-12T15:39:54.880Z,1618241994.880 [DataOverHttps](INFO): Moved sent file to Logs/20210412T145347/Courier0025.lzma.bak 2021-04-12T15:39:54.880Z,1618241994.880 [DataOverHttps](INFO): SBD MOMSN=15560089 2021-04-12T15:40:03.510Z,1618242003.510 [NAL9602](INFO): SBD MO Status=0, MOMSN=1816, MT Status=0, MTMSN=0 2021-04-12T15:40:03.510Z,1618242003.510 [NAL9602](INFO): No messages in MT queue 2021-04-12T15:40:15.654Z,1618242015.654 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20210412T145347/Express0026.lzma 2021-04-12T15:40:16.656Z,1618242016.656 [DataOverHttps](INFO): Moved sent file to Logs/20210412T145347/Express0026.lzma.bak 2021-04-12T15:40:16.656Z,1618242016.656 [DataOverHttps](INFO): SBD MOMSN=15560092 2021-04-12T15:40:19.418Z,1618242019.418 [Default:CheckIn:Read_Iridium] Stopped 2021-04-12T15:40:19.418Z,1618242019.418 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-12T15:40:19.418Z,1618242019.418 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-12T15:40:33.927Z,1618242033.927 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-12T15:45:20.098Z,1618242320.098 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-12T15:45:20.098Z,1618242320.098 [Default:CheckIn:C.Wait] Stopped 2021-04-12T15:45:20.098Z,1618242320.098 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-12T15:45:20.099Z,1618242320.099 [Default:CheckIn:D] Running Loop=1 2021-04-12T15:45:20.473Z,1618242320.473 [Default:CheckIn:D] Stopped 2021-04-12T15:45:20.478Z,1618242320.478 [Default:CheckIn:E] Running Loop=1 2021-04-12T15:45:20.878Z,1618242320.878 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.076070 min 2021-04-12T15:45:20.878Z,1618242320.878 [Default:CheckIn:E] Stopped 2021-04-12T15:45:20.878Z,1618242320.878 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-12T15:45:20.878Z,1618242320.878 [Default:CheckIn] Stopped 2021-04-12T15:45:20.878Z,1618242320.878 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-12T15:45:20.879Z,1618242320.879 [Default:CheckIn](INFO): Running loop #9 2021-04-12T15:45:20.879Z,1618242320.879 [Default:CheckIn] Running Loop=9 2021-04-12T15:45:20.879Z,1618242320.879 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-12T15:45:20.879Z,1618242320.879 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-12T15:45:22.878Z,1618242322.878 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154522.00,A,3647.86361,N,12150.99371,W,1.147,335.47,120421,,,D*73 2021-04-12T15:45:22.880Z,1618242322.880 [NAL9602](INFO): GPS fix at 20210412T154522: (36.797727, -121.849895) 2021-04-12T15:45:22.908Z,1618242322.908 [Default:CheckIn:Read_GPS] Stopped 2021-04-12T15:45:22.908Z,1618242322.908 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-12T15:45:25.717Z,1618242325.717 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-04-12T15:45:25.717Z,1618242325.717 [DVL_micro](ERROR): Failed to parse: :TS,01489.0,0+01328,-01186,+0000,A 2021-04-12T15:45:30.193Z,1618242330.193 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210412T145347/Courier0028.lzma 2021-04-12T15:45:31.196Z,1618242331.196 [DataOverHttps](INFO): Moved sent file to Logs/20210412T145347/Courier0028.lzma.bak 2021-04-12T15:45:31.196Z,1618242331.196 [DataOverHttps](INFO): SBD MOMSN=15560099 2021-04-12T15:45:46.709Z,1618242346.709 [NAL9602](INFO): SBD MO Status=0, MOMSN=1817, MT Status=0, MTMSN=0 2021-04-12T15:45:46.709Z,1618242346.709 [NAL9602](INFO): No messages in MT queue 2021-04-12T15:45:49.245Z,1618242349.245 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20210412T145347/Express0029.lzma 2021-04-12T15:45:50.248Z,1618242350.248 [DataOverHttps](INFO): Moved sent file to Logs/20210412T145347/Express0029.lzma.bak 2021-04-12T15:45:50.248Z,1618242350.248 [DataOverHttps](INFO): SBD MOMSN=15560102 2021-04-12T15:45:52.394Z,1618242352.394 [Default:CheckIn:Read_Iridium] Stopped 2021-04-12T15:45:52.394Z,1618242352.394 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-12T15:45:52.394Z,1618242352.394 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-12T15:46:17.267Z,1618242377.267 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-12T15:48:01.115Z,1618242481.115 [DVL_micro](ERROR): Failed to parse: :7,+00406,00000,A 2021-04-12T15:48:28.999Z,1618242508.999 [DVL_micro](ERROR): Failed to parse: :SA,-14.43,+03.07,267.5 2021-04-12T15:49:06.075Z,1618242546.075 [DataOverHttps](IMPORTANT): SBD MTMSN=20210412T154905 2021-04-12T15:49:06.153Z,1618242546.153 [DVL_micro](ERROR): Failed to parse: :T00000000,35.0,+12.7,0000.0,1489.0,000